** Changed in: ubuntu-power-systems
Status: In Progress => Fix Committed
--
You received this bug notification because you are a member of Kernel
Packages, which is subscribed to linux in Ubuntu.
https://bugs.launchpad.net/bugs/1773964
Title:
IPL: ppc64_cpu --frequency hang with INFO: rcu_sched detected stalls
on CPUs/tasks on w34 and wsbmc016 with 920.1714.20170330n
Status in The Ubuntu-power-systems project:
Fix Committed
Status in linux package in Ubuntu:
In Progress
Status in linux source package in Bionic:
Fix Committed
Bug description:
== SRU Justification ==
IBM is requesting these two commits in powerpc to fix an error they are
seeing:
IPL: ppc64_cpu --frequency hang with INFO: rcu_sched detected stalls on
CPUs/tasks on w34 and wsbmc016 with 920.1714.20170330n
The first commit reduces some existing high latency delays. The second
commit fixes the fact that the OPAL RTC driver does not sleep in case it gets
OPAL_BUSY or
OPAL_BUSY_EVENT from firmware.
== Fixes ==
34dd25de9fe3 ("powerpc/powernv: define a standard delay for OPAL_BUSY type
retry loops")
682e6b4da5cb ("rtc: opal: Fix OPAL RTC driver OPAL_BUSY loops")
== Regression Potential ==
Low. The first commit is specific to powerpc. The second commit is, commit
628daa8d5abf
and it been cc'd to upstream stable to fix a regression, so it has had
additional upstream review.
== Test Case ==
A test kernel was built with these patches and tested by the original bug
reporter.
The bug reporter states the test kernel resolved the bug.
== Comment: #0 - Application Cdeadmin <> - 2018-05-22 09:36:12 ==
== Comment: #1 - Application Cdeadmin <> - 2018-05-22 09:36:14 ==
==== State: Open by: swanman on 22 May 2018 09:17:33 ====
Both w34 and wsbmc016 are stopped on this failure, where we get hung
up on the following FFDC gathering step in the OS:
#(CDT) 2018/05/22 05:07:19.398218 - 0.211662 - Issuing: OS Execute Command
ppc64_cpu --frequency ignore_err=1
#(CDT) 2018/05/22 05:07:19.437808 - 0.024108 - Issuing: ppc64_cpu --frequency
, and the last console output shows:
# tail -200 /var/log/obmc-console.log
s this GP) idle=82a/140000000000000/0 softirq=2689/2689 fqs=241989
[13668.719850] (detected by 3, t=3075620 jiffies, g=30289, c=30288, q=796881)
[13732.630691] INFO: rcu_sched detected stalls on CPUs/tasks:
[13732.630727] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=242996
[13732.630757] (detected by 3, t=3091597 jiffies, g=30289, c=30288, q=799822)
[13795.649568] INFO: rcu_sched detected stalls on CPUs/tasks:
[13795.649597] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=243942
[13795.649631] (detected by 7, t=3107351 jiffies, g=30289, c=30288, q=802916)
[13860.140483] INFO: rcu_sched detected stalls on CPUs/tasks:
[13860.140516] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=244940
[13860.140557] (detected by 3, t=3123473 jiffies, g=30289, c=30288, q=806646)
[13924.731404] INFO: rcu_sched detected stalls on CPUs/tasks:
[13924.731438] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=245874
[13924.731484] (detected by 3, t=3139620 jiffies, g=30289, c=30288, q=809909)
[13988.642290] INFO: rcu_sched detected stalls on CPUs/tasks:
[13988.642321] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=246892
[13988.642362] (detected by 3, t=3155596 jiffies, g=30289, c=30288, q=813048)
[14052.661176] INFO: rcu_sched detected stalls on CPUs/tasks:
[14052.661211] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=247857
[14052.661266] (detected by 3, t=3171600 jiffies, g=30289, c=30288, q=816185)
[14115.680024] INFO: rcu_sched detected stalls on CPUs/tasks:
[14115.680051] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=248819
[14115.680085] (detected by 4, t=3187355 jiffies, g=30289, c=30288, q=819190)
[14180.154911] INFO: rcu_sched detected stalls on CPUs/tasks:
[14180.154945] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=249833
[14180.154986] (detected by 132, t=3203473 jiffies, g=30289, c=30288,
q=822138)
[14244.968067]I F: Ne talls onCPUs/tasks
[14244669838] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=2[14244.669944] (detected by 3, t=3219600 jiffies,
g=30289, c=30288, q=825384)
[14308.748680] Id detected stalls on CPUs/tasks:
[14308.748719] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=251755
[14308.748755] (detected by 3, t=3235620 jiffies, g=30289, c=30288, q=828445)
[14333.081775] Watchdog CPU:132 Hard LOCKUP
[14344.750295] Watchdog CPU:132 became unstuck
[14372.735558] INFO: rcu_sched detected stalls on CPUs/tasks:
[14372.735587] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=252722
[14372.735611] (detected by 6, t=3251616 jiffies, g=30289, c=30288, q=831375)
[14435.910193] INFO: rcu_sched detected stalls on CPUs/tasks:
[14435.910219] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=253675
[14435.910253] (detected by 3, t=3267409 jiffies, g=30289, c=30288, q=834375)
[14500.167195] INFO: rcu_sched detected stalls on CPUs/tasks:
[14500.167230] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=254601
[14500.167273] (detected by 134, t=3283473 jiffies, g=30289, c=30288,
q=837600)
[14564.664395] INFO: rcu_sched detected stalls on CPUs/tasks:
[14564.664427] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=255493
[14564.664470] (detected by 3, t=3299596 jiffies, g=30289, c=30288, q=840539)
[14628.665755] INFO: rcu_sched detected stalls on CPUs/tasks:
[14628.665790] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=256471
[14628.665824] (detected by 3, t=3315596 jiffies, g=30289, c=30288, q=843505)
[14692.759268] INFO: rcu_sched detected stalls on CPUs/tasks:
[14692.759299] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=257372
[14692.759330] (detected by 3, t=3331620 jiffies, g=30289, c=30288, q=846522)
[14755.916887] INFO: rcu_sched detected stalls on CPUs/tasks:
[14755.916918] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=258248
[14755.916943] (detected by 3, t=3347409 jiffies, g=30289, c=30288, q=849740)
[14820.174651] INFO: rcu_sched detected stalls on CPUs/tasks:
[14820.174680] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=259206
[14820.174710] (detected by 3, t=3363473 jiffies, g=30289, c=30288, q=852406)
[14884.688523] IO:N Fcr_suhecd 8 75-....: (5904 ticks this GP)
idle=82a/140000000000000/0 softirq=2689/2689 fqs=260089
[14884.688651] y 3, t=3379600 jiffies, g=30289, c=30288, q=855646)
[14948.674473] I stalls on CPUs/tasks:
[14948.674517] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=261047
[14948.674568] (detected by 3, t=3395597 jiffies, g=30289, c=30288, q=858963)
[15012.676503] INFO: rcu_sched detected stalls on CPUs/tasks:
[15012.676531] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=262011
[15012.676579] (detected by 3, t=3411596 jiffies, g=30289, c=30288, q=861906)
[15075.694581] INFO: rcu_sched detected stalls on CPUs/tasks:
[15075.694612] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=262943
[15075.694645] (detected by 7, t=3427351 jiffies, g=30289, c=30288, q=864958)
[15140.184 77P] 88FdelCU75-....: (5904 ticks this GP)
idle=82a/140000000000000/0 softirqfqs=263861
[15140.184895] (detected by 132, t=3443473 jiffies, g=30289, c=30288,
q=868102)
[15204.774985] Isched detected stalls on CPUs/tasks:
[15204.775026] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=264786
[15204.775075] (detected by 3, t=3459620 jiffies, g=30289, c=30288, q=871323)
[158.2706298 4]FOIl asksP
1526[870277]. 75-...: (5904ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=265714
[15268.709381] ce by 3, t=3475603 jiffies, g=30289, c=30288, q=874564)
[15332.707555] Iched detected stalls on CPUs/tasks:
[15332.707594] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=266614
[15332.707641] (detected by 3, t=3491602 jiffies, g=30289, c=30288, q=877578)
[15395.729876] INFO: rcu_sched detected stalls on CPUs/tasks:
[15395.729904] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=267583
[15395.729947] (detected by 7, t=3507357 jiffies, g=30289, c=30288, q=880546)
[15460.196261] INFO: rcu_sched detected stalls on CPUs/tasks:
[15460.196293] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=268585
[15460.196324] (detected by 3, t=3523473 jiffies, g=30289, c=30288, q=883448)
[15524.714688] INFO: rcu_sched detected stalls on CPUs/tasks:
[15524.714728] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=269506
[15524.714766] (detected by 3, t=3539601 jiffies, g=30289, c=30288, q=886049)
[15588.717133] INFO: rcu_sched detected stalls on CPUs/tasks:
[15588.717167] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=270465
[15588.717201] (detected by 6, t=3555602 jiffies, g=30289, c=30288, q=889197)
[15652.791581] INFO: rcu_sched detected stalls on CPUs/tasks:
[15652.791613] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=271387
[15652.791653] (detected by 3, t=3571620 jiffies, g=30289, c=30288, q=891919)
[15715.950025] INFO: rcu_sched detected stalls on CPUs/tasks:
[15715.950057] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=272317
[15715.950081] (detected by 3, t=3587409 jiffies, g=30289, c=30288, q=894689)
[15780.208530] INFO: rcu_sched detected stalls on CPUs/tasks:
[15780.208562] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=273264
[15780.208592] (detected by 3, t=3603473 jiffies, g=30289, c=30288, q=897742)
[15844.799063] INFO: rcu_sched detected stalls on CPUs/tasks:
[15844.799092] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=274155
[15844.799125] (detected by 3, t=3619620 jiffies, g=30289, c=30288, q=900825)
[15908.713583]I O: rcu_NFhsoas:
[15908.13616] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=275069
[15908.713715] 3 t=3635597 jiffies, g=30289, c=30288, q=903951)
[15972.712119] Ited stalls on CPUs/tasks:
[15972.712163] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=276037
[15972.712200] (detected by 3, t=3651597 jiffies, g=30289, c=30288, q=906870)
[16035.730638] INFO: rcu_sched detected stalls on CPUs/tasks:
[16035.730674] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=277022
[16035.730712] (detected by 130, t=3667351 jiffies, g=30289, c=30288,
q=909454)
[16100.221204] INFO: rcu_sched detected stalls on CPUs/tasks:
[16100.221234] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=277993
[16100.221274] (detected by 3, t=3683473 jiffies, g=30289, c=30288, q=912612)
[16164.751789] INFO:rO _cuscd a:
s[1616.16164.751[]2 2 75-....: (504 ticks this GP)
idle=82a/140000000000000/0 softirq=2689/2689 fqs=278956
[16164.751920] td y 3, t=3699604 jiffies, g=30289, c=30288, q=915666)
[16228.722360] I stalls on CPUs/tasks:
[16228.722404] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=279926
[16228.722443] (detected by 3, t=3715596 jiffies, g=30289, c=30288, q=918675)
[16292.720966] INFO: rcu_sched detected stalls on CPUs/tasks:
[16292.721030] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=280867
[16292.721072] (detected by 25, t=3731596 jiffies, g=30289, c=30288,
q=921494)
[16355.743495] INFO: rcu_sched detected stalls on CPUs/tasks:
[16355.743522] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=281853
[16355.743547] (detected by 6, t=3747351 jiffies, g=30289, c=30288, q=924261)
[16420.234094] INFO: rcu_sched detected stalls on CPUs/tasks:
[16420.234121] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=282785
[16420.234162] (detected by 3, t=3763473 jiffies, g=30289, c=30288, q=927318)
[16484.755k5] IN75-....:7 (9504t icks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=283749
[16484.752853] eted by3, t=3779601 jiffies, g=30289, c=30288, q=930422)
[16548.827505] Icted stalls on CPUs/tasks:
[16548.827547] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=284725
[16548.827592] (detected by 3, t=3795620 jiffies, g=30289, c=30288, q=933304)
[16612.758266] INFO: rcu_sched detected stalls on CPUs/tasks:
[16612.758301] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=285631
[16612.758345] (detected by 3, t=3811601 jiffies, g=30289, c=30288, q=936097)
[16675.780986] INFO: rcu_sched detected stalls on CPUs/tasks:
[16675.781016] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=286540
[16675.781053] (detected by 130, t=3827357 jiffies, g=30289, c=30288,
q=938924)
[16740.247733] INFO: rcu_sched detected stalls on CPUs/tasks:
[16740.247767] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=287491
[16740.247807] (detected by 3, t=3843473 jiffies, g=30289, c=30288, q=942104)
[16804.762481] NIO:rFttslsa no PCUs/aks
[s160:4.2511] 7675-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=288410
[16804.762616] dteced by 3, t=3859601 jiffies, g=30289, c=30288, q=945426)
[16868.841201] I detected stalls on CPUs/tasks:
[16868.841242] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=289383
[16868.841281] (detected by 3, t=3875620 jiffies, g=30289, c=30288, q=948853)
[16932.751907] INFO: rcu_sched detected stalls on CPUs/tasks:
[16932.751938] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=290305
[16932.751978] (detected by 3, t=3891597 jiffies, g=30289, c=30288, q=952379)
[16995.770578] INFO: rcu_sched detected stalls on CPUs/tasks:
[16995.770613] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=291234
[16995.770651] (detected by 130, t=3907351 jiffies, g=30289, c=30288,
q=955472)
[17060.261283] INFO: rcu_sched detected stalls on CPUs/tasks:
[17060.261314] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=292159
[17060.261354] (detected by 3, t=3923473 jiffies, g=30289, c=30288, q=959072)
[17124.791994] INFO: rcu_sched detected stalls on CPUs/tasks:
[17124.792029] 75-....: (5904 ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=293083
[17124.792069] (detected by 3, t=3939604 jiffies, g=30289, c=30288, q=962221)
71888.57141688]075- ..:.59 (0 4ticks this GP) idle=82a/140000000000000/0
softirq=2689/2689 fqs=294027
[17188.854815] t=3955620 jiffies, g=30289, c=30288, q=965699)
-----------------------------------
Keyword 'Check State' failed after retrying for 15 minutes. The last error
was:
#(CDT) 2018/05/22 05:05:49.896460 - 10.672026 - **ERROR** The current state
of the machine does NOT match the match state:
state:
state[rest]: 1
state[host]: Off
state[operating_system]: Inactive
state[boot_progress]: Unspecified
state[chassis]: On
state[os_login]: 0
state[os_run_cmd]: 0
state[os_ping]: 0
boot_end_time: (CDT) 2018/05/22 05:05:49.900677
#(CDT) 2018/05/22 05:05:49.900677 - 0.004217 - BOOT_FAILED: "REST OBMC Reboot
(run)" failed.
build_name: 920.1808.20180518b
platform: witherspoon
== Comment: #2 - Application Cdeadmin <> - 2018-05-22 09:56:15 ==
==== State: Open by: swanman on 22 May 2018 09:53:43 ====
#=#=# 2018-05-22 09:53:40 (CDT) #=#=#
#=#=#=#=#=#=#=#=#=#=#=#=#=#=#=#=#=#=#
== Comment: #3 - Application Cdeadmin <> - 2018-05-22 12:42:02 ==
==== State: Open by: swanman on 22 May 2018 12:31:06 ====
Unfortunately we lost the hang state on wsbmc016, but here is what I
was able to save off prior ...
Looks like someone stopped the test on wsbmc016, so we lost the failed state
#(CDT) 2018/05/21 17:12:19.564819 - 0.014776 - Issuing: ppc64_cpu --frequency
#(CDT) 2018/05/22 11:32:36.223134 - 66386.779704 - Executing:
obmc_boot::exit_function "EXIT" "0"
#(CDT) 2018/05/22 11:32:36.286650 - 0.063516 - Issuing: kill_autoend
autoend_pid
root@witherspoon:~# tail -200 /var/log/obmc-console.log
c000000fdd92f720] [c0000000002061ac] tick_sched_timer+0x8c/0x1b0
[54800.623485] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[54800.623593] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[54800.623692] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[54800.623791] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[54800.623856] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[54800.623973] --- interrupt: 901 at smp_call_function_single+0x180/0x2b0
[54800.623973] LR = smp_call_function_single+0x15c/0x2b0
[54800.624130] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[54800.624236] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[54800.624323] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[54800.624430] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[54980.670091] INFO: rcu_sched self-detected stall on CPU
[54980.670137] 49-...: (5479214 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2714915
[54980.670211] (t=5479215 jiffies g=5834 c=5833 q=3610838)
[54980.670267] Task dump for CPU 49:
[54980.670291] ppc64_cpu R running task 0 6588 6516
0x00042084
[54980.670401] Call Trace:
[54980.670429] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[54980.670565] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[54980.670655] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[54980.670774] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[54980.670890] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[54980.671009] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[54980.671154] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[54980.671270] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[54980.671367] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[54980.671465] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[54980.671574] --- interrupt: 901 at smp_call_function_single+0x188/0x2b0
[54980.671574] LR = smp_call_function_single+0x15c/0x2b0
[54980.671689] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[54980.671806] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[54980.671913] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[54980.672029] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[55160.717672] INFO: rcu_sched self-detected stall on CPU
[55160.717720] 49-...: (5497218 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2723789
[55160.717803] (t=5497219 jiffies g=5834 c=5833 q=3621302)
[55160.717869] Task dump for CPU 49:
[55160.717903] ppc64_cpu R running task 0 6588 6516
0x00042084
[55160.718019] Call Trace:
[55160.718059] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[55160.718193] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[55160.718290] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[55160.718421] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[55160.718540] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[55160.718641] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[55160.718739] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[55160.718838] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[55160.718934] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[55160.719013] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[55160.719113] --- interrupt: 901 at smp_call_function_single+0x184/0x2b0
[55160.719113] LR = smp_call_function_single+0x15c/0x2b0
[55160.719277] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[55160.719373] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[55160.719463] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[55160.719559] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[55340.765251] INFO: rcu_sched self-detected stall on CPU
[55340.765305] 49-...: (5515222 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2732670
[55340.765392] (t=5515223 jiffies g=5834 c=5833 q=3631900)
[55340.765458] Task dump for CPU 49:
[55340.765492] ppc64_cpu R running task 0 6588 6516
0x00042084
[55340.765575] Call Trace:
[55340.765603] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[55340.765727] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[55340.765818] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[55340.765927] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[55340.766023] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[55340.766123] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[55340.766239] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[55340.766368] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[55340.766509] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[55340.766609] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[55340.766726] --- interrupt: 901 at smp_call_function_single+0x180/0x2b0
[55340.766726] LR = smp_call_function_single+0x15c/0x2b0
[55340.766886] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[55340.766993] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[55340.767093] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[55340.767171] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[55520.812831] INFO: rcu_sched self-detected stall on CPU
[55520.812888] 49-...: (5533226 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2741558
[55520.812971] (t=5533227 jiffies g=5834 c=5833 q=3642556)
[55520.813046] Task dump for CPU 49:
[55520.813090] ppc64_cpu R running task 0 6588 6516
0x00042084
[55520.813189] Call Trace:
[55520.813208] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[55520.813344] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[55520.813461] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[55520.813551] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[55520.813672] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[55520.813768] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[55520.813903] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[55520.814011] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[55520.814110] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[55520.814198] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[55520.814296] --- interrupt: 901 at smp_call_function_single+0x180/0x2b0
[55520.814296] LR = smp_call_function_single+0x15c/0x2b0
[55520.814449] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[55520.814553] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[55520.814658] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[55520.814756] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[55700.860411] INFO: rcu_sched self-detected stall on CPU
[55700.860464] 49-...: (5551230 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2750435
[55700.860577] (t=5551231 jiffies g=5834 c=5833 q=3653059)
[55700.860635] Task dump for CPU 49:
[55700.860688] ppc64_cpu R running task 0 6588 6516
0x00042084
[55700.860777] Call Trace:
[55700.860815] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[55700.860949] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[55700.861049] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[55700.861166] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[55700.861286] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[55700.861386] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[55700.861484] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[55700.861588] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[55700.861684] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[55700.861773] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[55700.861879] --- interrupt: 901 at smp_call_function_single+0x188/0x2b0
[55700.861879] LR = smp_call_function_single+0x15c/0x2b0
[55700.862026] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[55700.862127] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[55700.862227] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[55700.862331] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[55880.907991] INFO: rcu_sched self-detected stall on CPU
[55880.908047] 49-...: (5569234 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2759321
[55880.908131] (t=5569235 jiffies g=5834 c=5833 q=3663812)
[55880.908187] Task dump for CPU 49:
[55880.908230] ppc64_cpu R running task 0 6588 6516
0x00042084
[55880.908328] Call Trace:
[55880.908357] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[55880.908471] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[55880.908593] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[55880.908707] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[55880.908822] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[55880.908939] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[55880.909070] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[55880.909170] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[55880.909263] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[55880.909350] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[55880.909443] --- interrupt: 901 at smp_call_function_single+0x188/0x2b0
[55880.909600] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[55880.909678] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[55880.909809] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[55880.909906] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
[56060.955572] INFO: rcu_sched self-detected stall on CPU
[56060.955620] 49-...: (5587238 ticks this GP) idle=72b/140000000000001/0
softirq=706/706 fqs=2768201
[56060.955694] (t=5587239 jiffies g=5834 c=5833 q=3673981)
[56060.955760] Task dump for CPU 49:
[56060.955826] ppc64_cpu R running task 0 6588 6516
0x00042084
[56060.955944] Call Trace:
[56060.955993] [c000000fdd92f500] [c000000000bfdddc]
sched_show_task.part.61+0x80/0x98 (unreliable)
[56060.956127] [c000000fdd92f570] [c000000000bfe50c]
rcu_dump_cpu_stacks+0xd8/0x13c
[56060.956244] [c000000fdd92f5c0] [c0000000001dfc84]
rcu_check_callbacks+0xbf4/0xcd0
[56060.956352] [c000000fdd92f6e0] [c0000000001e9264]
update_process_times+0x84/0xf0
[56060.956455] [c000000fdd92f720] [c0000000002061ac]
tick_sched_timer+0x8c/0x1b0
[56060.956550] [c000000fdd92f760] [c0000000001ea198]
__hrtimer_run_queues+0x118/0x3e0
[56060.956647] [c000000fdd92f800] [c0000000001eb3ac]
hrtimer_interrupt+0xfc/0x310
[56060.956749] [c000000fdd92f8d0] [c000000000025ed0]
__timer_interrupt+0x90/0x270
[56060.956848] [c000000fdd92f920] [c0000000000262e0] timer_interrupt+0xa0/0xe0
[56060.956935] [c000000fdd92f950] [c000000000008f84]
decrementer_common+0x114/0x120
[56060.957039] --- interrupt: 901 at smp_call_function_single+0x184/0x2b0
[56060.957039] LR = smp_call_function_single+0x15c/0x2b0
[56060.957194] [c000000fdd92fc40] [c000000fdd92fc90] 0xc000000fdd92fc90
(unreliable)
[56060.957293] [c000000fdd92fca0] [c0000000002d7b64]
perf_install_in_context+0x1d4/0x250
[56060.957394] [c000000fdd92fd30] [c0000000002e9784]
SyS_perf_event_open+0xb14/0xda0
[56060.957492] [c000000fdd92fe30] [c00000000000b004] system_call+0x38/0xe0
root@witherspoon:~#
== Comment: #9 - Shilpasri G. Bhat <shigb...@in.ibm.com> - 2018-05-28
00:40:16 ==
Stewart has pointed to these missing kernel commits required for this bug:
1) 682e6b4da5cbe8e9a53f979a58c2a9d7dc997175 rtc: opal: Fix OPAL RTC driver
OPAL_BUSY loops
2) 34dd25de9fe3f60bfdb31b473bf04b28262d0896 powerpc/powernv: define a
standard delay for OPAL_BUSY type retry loops
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-power-systems/+bug/1773964/+subscriptions
--
Mailing list: https://launchpad.net/~kernel-packages
Post to : kernel-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~kernel-packages
More help : https://help.launchpad.net/ListHelp
