** Changed in: linux (Ubuntu Bionic) 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: In Progress 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