Created attachment 256515 [details] dmesg output From time to time I get these rcu_sched stalls on my G5, seemingly random. The machine stays usable afterwards. This has been occuring since kernel 4.8 or so, so I decided to file a bug. [ 1144.413310] INFO: rcu_sched detected stalls on CPUs/tasks: [ 1144.413319] (detected by 0, t=6302 jiffies, g=11405, c=11404, q=1880) [ 1144.413326] All QSes seen, last rcu_sched kthread activity 6233 (4295220632-4295214399), jiffies_till_next_fqs=2, root ->qsmask 0x0 [ 1144.413328] modprobe R running task 0 623 620 0x00000014 [ 1144.413333] Call Trace: [ 1144.413336] [c00000026c9f2d30] [c000000000089ccc] 0xc000000000089ccc (unreliable) [ 1144.413339] [c00000026c9f2db0] [c0000000000c1f94] 0xc0000000000c1f94 [ 1144.413342] [c00000026c9f2ee0] [c0000000000c5414] 0xc0000000000c5414 [ 1144.413344] [c00000026c9f2f60] [c0000000000d8f9c] 0xc0000000000d8f9c [ 1144.413347] [c00000026c9f2fd0] [c0000000000d9004] 0xc0000000000d9004 [ 1144.413349] [c00000026c9f3060] [c0000000000c632c] 0xc0000000000c632c [ 1144.413352] [c00000026c9f3130] [c0000000000c6800] 0xc0000000000c6800 [ 1144.413354] [c00000026c9f3220] [c000000000019bb0] 0xc000000000019bb0 [ 1144.413357] [c00000026c9f32b0] [c000000000019d18] 0xc000000000019d18 [ 1144.413359] [c00000026c9f3330] [c000000000007ff8] 0xc000000000007ff8 [ 1144.413362] --- interrupt: 901 at 0xc000000000417f44 LR = 0xd000000000df6f30 [ 1144.413364] [c00000026c9f3620] [d000000000df6f00] 0xd000000000df6f00 (unreliable) [ 1144.413367] [c00000026c9f3710] [d0000000057b7c6c] 0xd0000000057b7c6c [ 1144.413369] [c00000026c9f37b0] [d0000000057bbb5c] 0xd0000000057bbb5c [ 1144.413372] [c00000026c9f39a0] [d0000000057bcb78] 0xd0000000057bcb78 [ 1144.413374] [c00000026c9f3a30] [c00000000000b4d4] 0xc00000000000b4d4 [ 1144.413377] [c00000026c9f3b00] [c00000000069b8fc] 0xc00000000069b8fc [ 1144.413379] [c00000026c9f3ba0] [c0000000000e3fc4] 0xc0000000000e3fc4 [ 1144.413382] [c00000026c9f3d30] [c0000000000e4490] 0xc0000000000e4490 [ 1144.413384] [c00000026c9f3e30] [c00000000000a118] 0xc00000000000a118 [ 1144.413389] rcu_sched kthread starved for 6233 jiffies! g11405 c11404 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0 [ 1144.413390] rcu_sched R running task 0 8 2 0x00000800 [ 1144.413394] Call Trace: [ 1144.413396] [c00000026c0db790] [c000000000098c54] 0xc000000000098c54 (unreliable) [ 1144.413399] [c00000026c0db960] [c000000000012e50] 0xc000000000012e50 [ 1144.413402] [c00000026c0dba10] [c000000000693e70] 0xc000000000693e70 [ 1144.413404] [c00000026c0dbae0] [c000000000694398] 0xc000000000694398 [ 1144.413407] [c00000026c0dbb60] [c000000000699960] 0xc000000000699960 [ 1144.413409] [c00000026c0dbc50] [c0000000000c0dc4] 0xc0000000000c0dc4 [ 1144.413412] [c00000026c0dbd70] [c00000000007c6d8] 0xc00000000007c6d8 [ 1144.413414] [c00000026c0dbe30] [c00000000000a460] 0xc00000000000a460 Machine: # inxi -b System: Host: T800 Kernel: 4.11.0-gentoo ppc64 (32 bit) Console: tty 0 Distro: Gentoo Base System release 2.3 Machine: No /sys/class/dmi; using dmidecode: dmidecode is not installed. CPU: Dual core PPC970FX altivec supported (-MCP-) speed/max: 1800.000000MHz/2300 MHz Graphics: Card: Advanced Micro Devices [AMD/ATI] RV350 [Radeon 9550/9600/X1050 Series] Display Server: X.org 1.19.2 drivers: ati,radeon (unloaded: fbdev) tty size: 211x52 Advanced Data: N/A for root out of X Network: Card: Apple K2 GMAC (Sun GEM) driver: gem Drives: HDD Total Size: 500.1GB (3.8% used) Info: Processes: 97 Uptime: 3 min Memory: 164.5/7866.4MB Init: systemd Client: Shell (bash) inxi: 2.3.4
Created attachment 256551 [details] kernel .config
Can you turn on CONFIG_KALLSYMS and maybe CONFIG_DEBUG_BUGVERBOSE, so the backtrace has symbols.
Did that. Will report back as soon as I get another rcu_sched stall.
[ 65.530255] INFO: rcu_sched detected stalls on CPUs/tasks: [ 65.538807] 0-...: (0 ticks this GP) idle=aa7/1/0 softirq=1074/1074 fqs=2100 [ 65.547527] (detected by 1, t=6302 jiffies, g=261, c=260, q=42) [ 65.556222] Task dump for CPU 0: [ 65.564820] swapper/0 R running task 0 0 0 0x00000004 [ 65.573494] Call Trace: [ 65.581990] [c0000000008f7910] [c0000000008f79b0] 0xc0000000008f79b0 (unreliable) [ 65.590339] [c0000000008f7ae0] [c00000026de0b400] 0xc00000026de0b400
Created attachment 256597 [details] kernel .config
Created attachment 256599 [details] dmesg output 02
Seems this bug has gone for good with kernel 4.13.x. I have not seen it once since I am running it. Maybe it's also due to the updated toolchain I use ( toolchain: gcc-6.4.0, glibc-2.24-r4, binutils-2.28.1, linux-headers-4.9).
Meanwhile on kernel 4.14.2 (toolchain: gcc-6.4.0, glibc-2.25, binutils-2.29.1, linux-headers-4.9). Unfortunately the issue prevails: [ 7795.645815] INFO: rcu_sched detected stalls on CPUs/tasks: [ 7795.645833] 1-...: (0 ticks this GP) idle=c6e/1/0 softirq=544966/544966 fqs=2100 [ 7795.645836] (detected by 0, t=6302 jiffies, g=294436, c=294435, q=71) [ 7795.645842] Task dump for CPU 1: [ 7795.645845] swapper/1 R running task 0 0 1 0x00000804 [ 7795.645850] Call Trace: [ 7795.645856] [c00000026c0ef9c0] [00000723fa0850c8] 0x723fa0850c8 (unreliable) The stacktrace does not get any better, although the following flags are set: CONFIG_KALLSYMS=y CONFIG_DEBUG_BUGVERBOSE=y CONFIG_DEBUG_INFO=y CONFIG_DEBUG_KERNEL=y
Created attachment 260835 [details] kernel .config
Ok, at least with CONFIG_KALLSYMS_ALL=y some useful information: [ 1772.872044] INFO: rcu_sched detected stalls on CPUs/tasks: [ 1772.872174] 1-...: (1 GPs behind) idle=672/2/0 softirq=228429/228430 fqs=2100 [ 1772.872345] (detected by 0, t=6302 jiffies, g=124108, c=124107, q=2) [ 1772.872493] Task dump for CPU 1: [ 1772.872548] swapper/1 R running task 0 0 1 0x00000804 [ 1772.872715] Call Trace: [ 1772.872751] [c00000026c0ef9c0] [000001b236f76770] 0x1b236f76770 (unreliable) [ 5663.928871] pmac64_cpufreq: Timeout in clock slewing ! [12521.243717] INFO: rcu_sched detected stalls on CPUs/tasks: [12521.243847] 1-...: (1 ticks this GP) idle=d3e/2/0 softirq=1330606/1330606 fqs=0 [12521.244023] (detected by 0, t=6302 jiffies, g=691707, c=691706, q=76) [12521.244173] Task dump for CPU 1: [12521.244228] swapper/1 R running task 0 0 1 0x00000804 [12521.244395] Call Trace: [12521.244431] [c00000026c0ef9c0] [00000b68d8929770] 0xb68d8929770 (unreliable) [12521.244598] rcu_sched kthread starved for 6302 jiffies! g691707 c691706 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x402 ->cpu=1 [12521.244861] rcu_sched I 0 8 2 0x00000800 [12521.244980] Call Trace: [12521.245014] [c00000026c0db790] [c00000026c0db910] 0xc00000026c0db910 (unreliable) [12521.245195] [c00000026c0db960] [c000000000012c40] .__switch_to+0x1f0/0x2a0 [12521.245357] [c00000026c0dba10] [c000000000700918] .__schedule+0x1f8/0x750 [12521.245515] [c00000026c0dbae0] [c000000000700ea8] .schedule+0x38/0xb0 [12521.245663] [c00000026c0dbb60] [c000000000705608] .schedule_timeout+0x168/0x340 [12521.245836] [c00000026c0dbc50] [c0000000000c382c] .rcu_gp_kthread+0x5fc/0xa30 [12521.246005] [c00000026c0dbd70] [c0000000000815c4] .kthread+0x154/0x1a0 [12521.246156] [c00000026c0dbe30] [c00000000000a460] .ret_from_kernel_thread+0x58/0x78
And some more. Hope this output is helpful! [38006.594499] Task dump for CPU 0: [38006.604084] swapper/0 R running task 0 0 0 0x00000000 [38006.613723] Call Trace: [38006.623222] [c000000000a132f0] [c000000000088d40] .sched_show_task.part.15+0xc0/0x100 (unreliable) [38006.632969] [c000000000a13370] [c0000000000c5120] .rcu_dump_cpu_stacks+0xbc/0x11c [38006.642706] [c000000000a13410] [c0000000000c4b48] .rcu_check_callbacks+0x9a8/0xa00 [38006.652392] [c000000000a13540] [c0000000000c9324] .update_process_times+0x34/0x80 [38006.662015] [c000000000a135c0] [c0000000000dd3ec] .tick_sched_handle.isra.5+0x3c/0x60 [38006.671619] [c000000000a13630] [c0000000000dd460] .tick_sched_timer+0x50/0xd0 [38006.681195] [c000000000a136c0] [c0000000000ca1ec] .__hrtimer_run_queues+0x14c/0x250 [38006.690721] [c000000000a13790] [c0000000000ca5bc] .hrtimer_interrupt+0xec/0x330 [38006.700193] [c000000000a13870] [c000000000019ad0] .__timer_interrupt+0x70/0x140 [38006.709530] [c000000000a13900] [c000000000019c34] .timer_interrupt+0x94/0xd0 [38006.718852] [c000000000a13980] [c000000000008008] decrementer_common+0x138/0x140 [38006.728188] --- interrupt: 901 at .arch_cpu_idle+0x64/0x150 LR = .arch_cpu_idle+0x64/0x150 [38006.746551] [c000000000a13c70] [0000000001400000] 0x1400000 (unreliable) [38006.755670] [c000000000a13cf0] [c00000000070640c] .default_idle_call+0x3c/0x6c [38006.764819] [c000000000a13d60] [c0000000000a3c88] .do_idle+0x168/0x1d0 [38006.773865] [c000000000a13e00] [c0000000000a3ea8] .cpu_startup_entry+0x28/0x30 [38006.782911] [c000000000a13e80] [c00000000000b714] .rest_init+0xc4/0xe0 [38006.791978] [c000000000a13ef0] [c0000000008e0e88] .start_kernel+0x504/0x524 [38006.801043] [c000000000a13f90] [c000000000009c00] start_here_common+0x1c/0x41c [38124.286867] INFO: rcu_sched detected stalls on CPUs/tasks: [38124.296065] 1-...: (0 ticks this GP) idle=20c/0/0 softirq=3674349/3674349 fqs=0 [38124.305300] (detected by 0, t=11133 jiffies, g=1922773, c=1922772, q=14) [38124.314605] Task dump for CPU 1: [38124.323789] swapper/1 R running task 0 0 1 0x00000800 [38124.333045] Call Trace: [38124.342122] [c00000026c0ef9c0] [000022f2c613fcbc] 0x22f2c613fcbc (unreliable) [38124.351362] [c00000026c0efa50] [c0000000000d9ab0] .clockevents_program_event+0x50/0x210 [38124.360637] [c00000026c0efae0] [c0000000000dc604] .tick_program_event+0x64/0xe0 [38124.369860] [c00000026c0efb70] [c0000000000c9ea0] .hrtimer_start_range_ns+0x230/0x430 [38124.379048] [c00000026c0efc50] [c0000000000dd134] .__tick_nohz_idle_enter+0x4a4/0x510 [38124.388227] [c00000026c0efd20] [c00000000070640c] .default_idle_call+0x3c/0x6c [38124.397304] [c00000026c0efd90] [c0000000000a3c88] .do_idle+0x168/0x1d0 [38124.406311] [c00000026c0efe30] [c0000000000a3eac] .cpu_startup_entry+0x2c/0x30 [38124.415239] [c00000026c0efeb0] [c0000000000282d4] .start_secondary+0x454/0x4a0 [38124.424184] [c00000026c0eff90] [c000000000009afc] start_secondary_prolog+0x10/0x14 [38124.433076] rcu_sched kthread starved for 11162 jiffies! g1922773 c1922772 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x402 ->cpu=0 [38124.442210] rcu_sched I 0 8 2 0x00000800 [38124.451166] Call Trace: [38124.459901] [c00000026c0db960] [c000000000012c40] .__switch_to+0x1f0/0x2a0 [38124.468737] [c00000026c0dba10] [c000000000700918] .__schedule+0x1f8/0x750 [38124.477488] [c00000026c0dbae0] [c000000000700ea8] .schedule+0x38/0xb0 [38124.486196] [c00000026c0dbb60] [c000000000705608] .schedule_timeout+0x168/0x340 [38124.494885] [c00000026c0dbc50] [c0000000000c382c] .rcu_gp_kthread+0x5fc/0xa30 [38124.503507] [c00000026c0dbd70] [c0000000000815c4] .kthread+0x154/0x1a0 [38124.511981] [c00000026c0dbe30] [c00000000000a460] .ret_from_kernel_thread+0x58/0x78
Created attachment 260903 [details] dmesg output
Sorry there's nothing immediately obvious in the back traces. Are you still seeing this on a current kernel?
I am certainly seeing this on 4.14.x (another Gentoo setup but the same machine) but not on 4.16.x yet.
Created attachment 277323 [details] dmesg (4.18-rc4) Still here on 4.18-rc4. Though it occurs more rarely on more recent kernels.
[ 30.389950] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 1-... } 7947 jiffies s: 53 root: 0x2/. [ 30.389974] blocking rcu_node structures: [ 30.389983] Task dump for CPU 1: [ 30.389990] swapper/1 R running task 0 0 1 0x00000808 [ 30.390005] Call Trace: [ 30.390014] [c00000027ed039c0] [c00000027ed03a50] 0xc00000027ed03a50 (unreliable) [ 30.390033] [c00000027ed03a50] [c0000000000277cc] .power4_idle+0x0/0x94
Created attachment 277325 [details] kernel -config (4.18-rc4)
Created attachment 277453 [details] dmesg (4.18-rc5) Jul 11 02:39:57 T800 kernel: INFO: rcu_sched detected stalls on CPUs/tasks: Jul 11 02:39:57 T800 kernel: (detected by 0, t=7802 jiffies, g=1323, c=1322, q=338) Jul 11 02:39:57 T800 kernel: All QSes seen, last rcu_sched kthread activity 7798 (4294914947-4294907149), jiffies_till_next_fqs=2, root ->qsmask 0x0 Jul 11 02:39:57 T800 kernel: swapper/0 R running task 0 0 0 0x00000008 Jul 11 02:39:57 T800 kernel: Call Trace: Jul 11 02:39:57 T800 kernel: [c000000000e573e0] [c00000000009e5c4] .sched_show_task.part.2+0x184/0x2b0 (unreliable) Jul 11 02:39:57 T800 kernel: [c000000000e57470] [c0000000000f9e44] .rcu_check_callbacks+0x974/0x980 Jul 11 02:39:57 T800 kernel: [c000000000e575a0] [c000000000100424] .update_process_times+0x34/0x80 Jul 11 02:39:57 T800 kernel: [c000000000e57620] [c000000000116ecc] .tick_sched_handle.isra.5+0x3c/0x60 Jul 11 02:39:57 T800 kernel: [c000000000e57690] [c000000000116f48] .tick_sched_timer+0x58/0xd0 Jul 11 02:39:57 T800 kernel: [c000000000e57720] [c0000000001018a0] .__hrtimer_run_queues+0x140/0x2e0 Jul 11 02:39:57 T800 kernel: [c000000000e57800] [c000000000101f1c] .hrtimer_interrupt+0xfc/0x2f0 Jul 11 02:39:57 T800 kernel: [c000000000e578c0] [c00000000001bd6c] .timer_interrupt+0x15c/0x1f0 Jul 11 02:39:57 T800 kernel: [c000000000e57960] [c000000000008280] decrementer_common+0x150/0x160 Jul 11 02:39:57 T800 kernel: --- interrupt: 901 at .arch_cpu_idle+0x60/0x180 LR = .arch_cpu_idle+0x60/0x180 Jul 11 02:39:57 T800 kernel: [c000000000e57cd0] [c000000000867a4c] .default_idle_call+0x3c/0x74 Jul 11 02:39:57 T800 kernel: [c000000000e57d40] [c0000000000a93e8] .do_idle+0x118/0x250 Jul 11 02:39:57 T800 kernel: [c000000000e57de0] [c0000000000a9888] .cpu_startup_entry+0x28/0x40 Jul 11 02:39:57 T800 kernel: [c000000000e57e60] [c00000000000bf24] .rest_init+0x2e4/0x310 Jul 11 02:39:57 T800 kernel: [c000000000e57ef0] [c000000000ab6e0c] .start_kernel+0x530/0x550 Jul 11 02:39:57 T800 kernel: [c000000000e57f90] [c00000000000a10c] start_here_common+0x1c/0x410 Jul 11 02:39:57 T800 kernel: rcu_sched kthread starved for 7798 jiffies! g1323 c1322 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x200 ->cpu=1 Jul 11 02:39:57 T800 kernel: RCU grace-period kthread stack dump: Jul 11 02:39:57 T800 kernel: rcu_sched R 0 10 2 0x00000808 Jul 11 02:39:57 T800 kernel: Call Trace: Jul 11 02:39:57 T800 kernel: [c00000027ecef940] [c0000000000148a8] .__switch_to+0x228/0x340 Jul 11 02:39:57 T800 kernel: [c00000027ecef9f0] [c0000000008607cc] .__schedule+0x2ec/0xa70 Jul 11 02:39:57 T800 kernel: [c00000027ecefac0] [c000000000860f80] .schedule+0x30/0xb0 Jul 11 02:39:57 T800 kernel: [c00000027ecefb30] [c0000000008670b0] .schedule_timeout+0xd0/0x430 Jul 11 02:39:57 T800 kernel: [c00000027ecefc40] [c0000000000f78c4] .rcu_gp_kthread+0x524/0x970 Jul 11 02:39:57 T800 kernel: [c00000027ecefd70] [c0000000000957f8] .kthread+0x198/0x1a0 Jul 11 02:39:57 T800 kernel: [c00000027ecefe30] [c00000000000a9b8] .ret_from_kernel_thread+0x58/0xa0
Created attachment 279079 [details] dmesg (4.19-rc6) [ 7835.179274] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 7835.179436] rcu: 1-...0: (1 GPs behind) idle=e72/0/0x3 softirq=1037537/1037538 fqs=2600 [ 7835.179639] rcu: (detected by 0, t=7802 jiffies, g=1761981, q=37) [ 7835.179789] Sending NMI from CPU 0 to CPUs 1: [ 7841.392691] CPU 1 didn't respond to backtrace IPI, inspecting paca. [ 7841.392839] irq_soft_mask: 0x01 in_mce: 0 in_nmi: 0 current: 0 (swapper/1) [ 7841.393006] Back trace of paca->saved_r1 (0xc00000000ffeff00) (possibly stale): [ 7841.393185] Call Trace: [ 7841.393226] [c00000000ffeff00] [c00000000001586c] .__do_irq+0x1c/0x340 (unreliable) [ 7841.393421] [c00000000ffeff90] [c000000000025760] .call_do_irq+0x14/0x24 [ 7841.393582] [c00000027ed87360] [c000000000015c1c] .do_IRQ+0x8c/0x120 [ 7841.393735] [c00000027ed87400] [c000000000007cb8] hardware_interrupt_common+0x148/0x150 [ 7841.393938] --- interrupt: 501 at replay_interrupt_return+0x0/0x4 LR = .arch_local_irq_restore.part.3+0x68/0x80 [ 7841.394202] [c00000027ed876f0] [c000000000014ffc] .arch_local_irq_restore.part.3+0x2c/0x80 (unreliable) [ 7841.394447] [c00000027ed87770] [c0000000009493a0] .__do_softirq+0x120/0x5a0 [ 7841.394618] [c00000027ed87880] [c00000000007bb78] .irq_exit+0xf8/0x1b0 [ 7841.394775] [c00000027ed878f0] [c000000000020488] .timer_interrupt+0x158/0x430 [ 7841.394954] [c00000027ed879a0] [c00000000000d058] fast_exception_return+0x198/0x1ac [ 7841.395146] --- interrupt: 901 at .arch_cpu_idle+0x60/0x180 LR = .arch_cpu_idle+0x60/0x180 [ 7841.395357] [c00000027ed87d10] [c0000000009483bc] .default_idle_call+0x3c/0x74 [ 7841.395536] [c00000027ed87d80] [c0000000000be088] .do_idle+0x118/0x250 [ 7841.395693] [c00000027ed87e20] [c0000000000be52c] .cpu_startup_entry+0x2c/0x40 [ 7841.395871] [c00000027ed87ea0] [c000000000032d00] .start_secondary+0x4f0/0x510 [ 7841.404699] [c00000027ed87f90] [c000000000009e00] start_secondary_prolog+0x10/0x14
Created attachment 280897 [details] dmesg (4.19.19) [...] [ 1057.521394] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 1057.521419] rcu: 0-...0: (6 GPs behind) idle=cfa/0/0x3 softirq=83119/83119 fqs=2600 [ 1057.521430] rcu: (detected by 1, t=7802 jiffies, g=176657, q=166) [ 1057.521446] Sending NMI from CPU 1 to CPUs 0: [ 1063.734640] CPU 0 didn't respond to backtrace IPI, inspecting paca. [ 1063.734649] irq_soft_mask: 0x01 in_mce: 0 in_nmi: 0 current: 0 (swapper/0) [ 1063.734662] Back trace of paca->saved_r1 (0xc00000000fff7f00) (possibly stale): [ 1063.734672] Call Trace: [ 1063.734683] [c00000000fff7f00] [c00000000001587c] .__do_irq+0x1c/0x340 (unreliable) [ 1063.734700] [c00000000fff7f90] [c0000000000258a0] .call_do_irq+0x14/0x24 [ 1063.734713] [c000000000deecc0] [c000000000015c2c] .do_IRQ+0x8c/0x120 [ 1063.734727] [c000000000deed60] [c000000000007cb8] hardware_interrupt_common+0x148/0x150 [ 1063.734745] --- interrupt: 501 at .sock_def_readable+0xc4/0x3b0 LR = .sock_def_readable+0x7c/0x3b0 [ 1063.734760] [c000000000def050] [c000000000790318] .sock_def_readable+0x48/0x3b0 (unreliable) [ 1063.734778] [c000000000def0e0] [c00000000081c0a8] .__netlink_sendskb+0x58/0x80 [ 1063.734792] [c000000000def170] [c00000000081c458] .netlink_broadcast_filtered+0x388/0x570 [ 1063.734806] [c000000000def290] [c0000000008204a4] .nlmsg_notify+0x74/0x160 [ 1063.734820] [c000000000def330] [c0000000007da6e0] .rtnl_notify+0x50/0x70 [ 1063.734834] [c000000000def3a0] [c0000000007d0040] .__neigh_notify+0x100/0x140 [ 1063.734847] [c000000000def440] [c0000000007d91f4] .neigh_timer_handler+0xe4/0x350 [ 1063.734862] [c000000000def4e0] [c00000000011bc1c] .call_timer_fn+0xbc/0x3a0 [ 1063.734874] [c000000000def5a0] [c00000000011c034] .expire_timers+0x134/0x270 [ 1063.734887] [c000000000def650] [c00000000011c258] .run_timer_softirq+0xe8/0x210 [ 1063.734902] [c000000000def730] [c000000000964bec] .__do_softirq+0x16c/0x5c0 [ 1063.734916] [c000000000def840] [c00000000007bdd8] .irq_exit+0xf8/0x1b0 [ 1063.734929] [c000000000def8b0] [c000000000020508] .timer_interrupt+0x158/0x450 [ 1063.734942] [c000000000def960] [c0000000000081f8] decrementer_common+0x148/0x150 [ 1063.734958] --- interrupt: 901 at .arch_cpu_idle+0x60/0x180 LR = .arch_cpu_idle+0x60/0x180 [ 1063.734972] [c000000000defcd0] [c000000000963bbc] .default_idle_call+0x3c/0x74 [ 1063.734986] [c000000000defd40] [c0000000000be4d8] .do_idle+0x118/0x250 [ 1063.734999] [c000000000defde0] [c0000000000be978] .cpu_startup_entry+0x28/0x30 [ 1063.735012] [c000000000defe60] [c00000000000edb4] .rest_init+0x2e4/0x310 [ 1063.735027] [c000000000defef0] [c000000000c1100c] .start_kernel+0x5b8/0x5d8 [ 1063.735041] [c000000000deff90] [c000000000009f00] start_here_common+0x1c/0x41c
Created attachment 281541 [details] dmesg (5.0.0, G5 7,3) [ 2032.976459] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 2032.976626] rcu: 1-...0: (12 ticks this GP) idle=2e2/0/0x3 softirq=126417/126418 fqs=2600 [ 2032.976835] rcu: (detected by 0, t=7802 jiffies, g=271505, q=687) [ 2032.976986] Sending NMI from CPU 0 to CPUs 1: [ 2039.190161] CPU 1 didn't respond to backtrace IPI, inspecting paca. [ 2039.190309] irq_soft_mask: 0x01 in_mce: 0 in_nmi: 0 current: 0 (swapper/1) [ 2039.190476] Back trace of paca->saved_r1 (0xc00000000ffeff00) (possibly stale): [ 2039.190654] Call Trace: [ 2039.190695] [c00000000ffeff00] [c0000000000160ac] .__do_irq+0x1c/0x340 (unreliable) [ 2039.190888] [c00000000ffeff90] [c0000000000272a0] .call_do_irq+0x14/0x24 [ 2039.191049] [c00000027ed83340] [c00000000001645c] .do_IRQ+0x8c/0x120 [ 2039.191202] [c00000027ed833e0] [c00000000000d018] fast_exception_return+0x158/0x1a8 [ 2039.191395] --- interrupt: 501 at replay_interrupt_return+0x0/0x4 LR = .arch_local_irq_restore.part.3+0x68/0x80 [ 2039.191660] [c00000027ed836e0] [c00000000001583c] .arch_local_irq_restore.part.3+0x2c/0x80 (unreliable) [ 2039.191903] [c00000027ed83760] [c0000000009b7340] .__do_softirq+0x130/0x604 [ 2039.192074] [c00000027ed83870] [c00000000007f2f8] .irq_exit+0xf8/0x1b0 [ 2039.192231] [c00000027ed838e0] [c000000000021ea8] .timer_interrupt+0x158/0x450 [ 2039.192408] [c00000027ed83990] [c00000000000d054] fast_exception_return+0x194/0x1a8 [ 2039.192600] --- interrupt: 901 at .arch_cpu_idle+0x60/0x180 LR = .arch_cpu_idle+0x60/0x180 [ 2039.192811] [c00000027ed83d10] [c0000000009b634c] .default_idle_call+0x3c/0x74 [ 2039.192990] [c00000027ed83d80] [c0000000000c4c48] .do_idle+0x118/0x250 [ 2039.193147] [c00000027ed83e20] [c0000000000c5108] .cpu_startup_entry+0x28/0x40 [ 2039.193324] [c00000027ed83ea0] [c000000000034c48] .start_secondary+0x618/0x640 [ 2039.193502] [c00000027ed83f90] [c000000000009e00] start_secondary_prolog+0x10/0x14
Created attachment 281543 [details] kernel .config (5.0.0, G5 7,3)
Created attachment 281921 [details] dmesg (5.1-rc1, G5 7,3) Still around in 5.1-rc1. [...] [36129.708179] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [36129.708336] rcu: (detected by 0, t=17340 jiffies, g=1696629, q=28) [36129.708489] rcu: All QSes seen, last rcu_sched kthread activity 17340 (4305716668-4305699328), jiffies_till_next_fqs=2, root ->qsmask 0x0 [36129.708814] swapper/0 R running task 0 0 0 0x00000004 [36129.708986] Call Trace: [36129.709027] [c000000000e67400] [c0000000000b78d4] .sched_show_task+0x2d4/0x320 (unreliable) [36129.709240] [c000000000e674a0] [c00000000011d19c] .rcu_sched_clock_irq+0xa7c/0xa90 [36129.709428] [c000000000e67580] [c000000000128dc4] .update_process_times+0x34/0xc0 [36129.709614] [c000000000e67600] [c000000000142898] .tick_sched_handle.isra.6+0x48/0x60 [36129.709809] [c000000000e67670] [c000000000142908] .tick_sched_timer+0x58/0xd0 [36129.709985] [c000000000e67700] [c000000000129e28] .__hrtimer_run_queues+0x1a8/0x6b0 [36129.710179] [c000000000e677f0] [c00000000012b374] .hrtimer_interrupt+0x114/0x2e0 [36129.710366] [c000000000e678b0] [c0000000000216c8] .timer_interrupt+0x118/0x430 [36129.710548] [c000000000e67960] [c000000000008184] decrementer_common+0x144/0x150 [36129.710737] --- interrupt: 901 at .arch_cpu_idle+0x60/0x170 LR = .arch_cpu_idle+0x60/0x170 [36129.710955] [c000000000e67ce0] [c0000000009c7554] .default_idle_call+0x64/0x78 [36129.711137] [c000000000e67d50] [c0000000000c3ab4] .do_idle+0x1e4/0x230 [36129.711298] [c000000000e67df0] [c0000000000c3e8c] .cpu_startup_entry+0x2c/0x40 [36129.711478] [c000000000e67e60] [c00000000000ed7c] .rest_init+0x21c/0x338 [36129.711645] [c000000000e67ef0] [c000000000c89118] .start_kernel+0x600/0x640 [36129.711819] [c000000000e67f90] [c000000000009ef0] start_here_common+0x1c/0x42c [36129.712002] rcu: rcu_sched kthread starved for 17341 jiffies! g1696629 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x200 ->cpu=0 [36129.712277] rcu: RCU grace-period kthread stack dump: [36129.712391] rcu_sched R 0 10 2 0x00000800 [36129.712520] Call Trace: [36129.712558] [c00000027ed73710] [0000000000000001] 0x1 (unreliable) [36129.712709] [c00000027ed738f0] [c0000000000190e0] .__switch_to+0x200/0x340 [36129.712881] [c00000027ed739a0] [c0000000009bf8d8] .__schedule+0x318/0xc50 [36129.713050] [c00000027ed73a90] [c0000000009c0248] .schedule+0x38/0xa0 [36129.713210] [c00000027ed73b00] [c0000000009c68e4] .schedule_timeout+0x244/0x600 [36129.713394] [c00000027ed73c20] [c00000000011b988] .rcu_gp_kthread+0x658/0x9d0 [36129.713574] [c00000027ed73d60] [c0000000000aa99c] .kthread+0x19c/0x1b0 [36129.713736] [c00000027ed73e20] [c00000000000a798] .ret_from_kernel_thread+0x58/0x60
Created attachment 282019 [details] dmesg (5.1-rc2, G5 7,3) 5.1-rc2 shows some additional output: [...] Mär 25 15:54:19 T800 kernel: rcu: INFO: rcu_sched detected stalls on CPUs/tasks: Mär 25 15:54:19 T800 kernel: rcu: (detected by 0, t=7802 jiffies, g=-1091, q=143) Mär 25 15:54:19 T800 kernel: rcu: All QSes seen, last rcu_sched kthread activity 7799 (4294885881-42948> Mär 25 15:54:19 T800 kernel: rcu_sched R running task 0 10 2 0x00000804 Mär 25 15:54:19 T800 kernel: Call Trace: Mär 25 15:54:19 T800 kernel: [c00000027ed73080] [c0000000000b7854] .sched_show_task+0x2d4/0x320 (unreli> Mär 25 15:54:19 T800 kernel: [c00000027ed73120] [c00000000011d1dc] .rcu_sched_clock_irq+0xa7c/0xa90 Mär 25 15:54:19 T800 kernel: [c00000027ed73200] [c000000000128e04] .update_process_times+0x34/0xc0 Mär 25 15:54:19 T800 kernel: [c00000027ed73280] [c0000000001428d8] .tick_sched_handle.isra.6+0x48/0x60 Mär 25 15:54:19 T800 kernel: [c00000027ed732f0] [c000000000142948] .tick_sched_timer+0x58/0xd0 Mär 25 15:54:19 T800 kernel: [c00000027ed73380] [c000000000129e68] .__hrtimer_run_queues+0x1a8/0x6b0 Mär 25 15:54:19 T800 kernel: [c00000027ed73470] [c00000000012b3b4] .hrtimer_interrupt+0x114/0x2e0 Mär 25 15:54:19 T800 kernel: [c00000027ed73530] [c0000000000216c8] .timer_interrupt+0x118/0x430 Mär 25 15:54:19 T800 kernel: [c00000027ed735e0] [c000000000008184] decrementer_common+0x144/0x150 Mär 25 15:54:19 T800 kernel: --- interrupt: 901 at replay_interrupt_return+0x0/0x4 LR = .arch_local_irq_restore.part.0+0x68/0x80 Mär 25 15:54:19 T800 kernel: [c00000027ed738e0] [c00000000001534c] .arch_local_irq_restore.part.0+0x2c/> Mär 25 15:54:19 T800 kernel: [c00000027ed73960] [c0000000009d1230] ._raw_spin_unlock_irqrestore+0x80/0x> Mär 25 15:54:19 T800 kernel: [c00000027ed739e0] [c0000000001266a4] .try_to_del_timer_sync+0x64/0xb0 Mär 25 15:54:19 T800 kernel: [c00000027ed73a70] [c000000000126990] .del_timer_sync+0xd0/0x120 Mär 25 15:54:19 T800 kernel: [c00000027ed73b00] [c0000000009d0150] .schedule_timeout+0x250/0x600 Mär 25 15:54:19 T800 kernel: [c00000027ed73c20] [c00000000011b9c8] .rcu_gp_kthread+0x658/0x9d0 Mär 25 15:54:19 T800 kernel: [c00000027ed73d60] [c0000000000aa92c] .kthread+0x19c/0x1b0 Mär 25 15:54:19 T800 kernel: [c00000027ed73e20] [c00000000000a798] .ret_from_kernel_thread+0x58/0x60
Created attachment 282021 [details] kernel .config (5.1-rc2, G5 7,3)
Have not seen this again on the G5 7,2 since kernel 5.2.x, nor 5.3.x. Will close the bug for now and hopefully it does not return. ;)
I see this bug is back in kernel 5.3.x Sep 28 15:40:01 [ 611.520537][ C0] rcu: INFO: rcu_sched self-detected stall on CPU Sep 28 15:40:01 [ 611.520992][ C0] rcu: 0-...!: (5998 ticks this GP) idle=ace/1/0x4000000000000004 softirq=46973/46973 fqs=73 Sep 28 15:40:01 [ 611.521721][ C0] (t=6000 jiffies g=83505 q=2615) Sep 28 15:40:01 [ 611.522076][ C0] rcu: rcu_sched kthread starved for 5853 jiffies! g83505 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=1 Sep 28 15:40:01 [ 611.522858][ C0] rcu: RCU grace-period kthread stack dump: Sep 28 15:40:01 [ 611.523269][ C0] rcu_sched I 0 10 2 0x80004000 Sep 28 15:40:01 [ 611.523710][ C0] Call Trace: Sep 28 15:40:01 [ 611.523938][ C0] ? __schedule+0x1db/0x5d0 Sep 28 15:40:01 [ 611.524251][ C0] schedule+0x34/0xa0 Sep 28 15:40:01 [ 611.524525][ C0] schedule_timeout+0x1f7/0x3e0 Sep 28 15:40:01 [ 611.524861][ C0] ? collect_expired_timers+0x270/0x270 Sep 28 15:40:01 [ 611.525248][ C0] rcu_gp_kthread+0x49f/0xea0 Sep 28 15:40:01 [ 611.525572][ C0] kthread+0x11a/0x150 Sep 28 15:40:01 [ 611.525851][ C0] ? rcu_report_qs_rnp+0x160/0x160 Sep 28 15:40:01 [ 611.534554][ C0] ? kthread_park+0x70/0x70 Sep 28 15:40:01 [ 611.543250][ C0] ret_from_fork+0x1f/0x30 Sep 28 15:40:01 [ 611.551953][ C0] NMI backtrace for cpu 0 Sep 28 15:40:01 [ 611.560402][ C0] CPU: 0 PID: 10870 Comm: ifmgr Tainted: G O 5.3.1 #1 Sep 28 15:40:01 [ 611.576928][ C0] Hardware name: HP ProLiant ML110 G7, BIOS J01 08/10/2012 Sep 28 15:40:01 [ 611.585641][ C0] Call Trace: Sep 28 15:40:01 [ 611.594279][ C0] <IRQ> Sep 28 15:40:01 [ 611.602783][ C0] dump_stack+0x47/0x5a Sep 28 15:40:01 [ 611.611375][ C0] nmi_cpu_backtrace.cold+0x14/0x53 Sep 28 15:40:01 [ 611.620076][ C0] ? lapic_can_unplug_cpu.cold+0x37/0x37 Sep 28 15:40:01 [ 611.628588][ C0] nmi_trigger_cpumask_backtrace+0xef/0xf1 Sep 28 15:40:01 [ 611.637040][ C0] rcu_dump_cpu_stacks+0x8d/0xbb Sep 28 15:40:01 [ 611.645425][ C0] rcu_sched_clock_irq.cold+0x1b1/0x3a6 Sep 28 15:40:01 [ 611.653707][ C0] update_process_times+0x5b/0x90 Sep 28 15:40:01 [ 611.661857][ C0] tick_sched_timer+0x65/0x100 Sep 28 15:40:01 [ 611.669733][ C0] ? get_cpu_iowait_time_us+0x100/0x100 Sep 28 15:40:01 [ 611.677571][ C0] __hrtimer_run_queues+0x105/0x1b0 Sep 28 15:40:01 [ 611.685267][ C0] hrtimer_interrupt+0x10b/0x3d0 Sep 28 15:40:01 [ 611.692709][ C0] smp_apic_timer_interrupt+0x50/0x80 Sep 28 15:40:01 [ 611.700044][ C0] apic_timer_interrupt+0xf/0x20 Sep 28 15:40:01 [ 611.707293][ C0] RIP: 0010:native_queued_spin_lock_slowpath+0x63/0x1d0 Sep 28 15:40:01 [ 611.714847][ C0] Code: ba 2f 08 0f 92 c0 0f b6 c0 c1 e0 08 89 c2 8b 07 30 e4 09 d0 a9 00 01 ff ff 75 1c 85 c0 74 0f 8b 07 84 c0 74 09 0f ae e8 8b 07 <84> c0 75 f7 b8 01 00 00 00 66 89 07 c3 f6 c4 01 75 04 c6 47 01 00 Sep 28 15:40:01 [ 611.738876][ C0] RSP: 0000:ffffc90000003ad8 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13 Sep 28 15:40:01 [ 611.755477][ C0] RAX: 0000000000080101 RBX: 0000000000000000 RCX: 0000000000000000 Sep 28 15:40:01 [ 611.772993][ C0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff8882dcf72080 Sep 28 15:40:01 [ 611.791481][ C0] RBP: ffff8882c7527800 R08: ffff8882c7765890 R09: 0000000000000000 Sep 28 15:40:01 [ 611.810932][ C0] R10: 0000000000000000 R11: ffffffff817b5d30 R12: ffff8882db3a7000 Sep 28 15:40:01 [ 611.830825][ C0] R13: ffff8882dcf72000 R14: ffff8882dcf71800 R15: ffff8882db3a7000 Sep 28 15:40:01 [ 611.851397][ C0] ? apic_timer_interrupt+0xa/0x20 Sep 28 15:40:01 [ 611.862019][ C0] ? ip_fragment.constprop.0+0x80/0x80 Sep 28 15:40:01 [ 611.872654][ C0] _raw_spin_lock+0x15/0x20 Sep 28 15:40:01 [ 611.883227][ C0] __imq_nf_queue+0x3a5/0x6d0 [imq] Sep 28 15:40:01 [ 611.893786][ C0] imq_nf_queue+0x326/0x423 [imq] Sep 28 15:40:01 [ 611.904278][ C0] nf_queue+0x1b8/0x320 Sep 28 15:40:01 [ 611.914713][ C0] nf_hook_slow+0x82/0xe0 Sep 28 15:40:01 [ 611.925061][ C0] ip_output+0xb3/0x280 Sep 28 15:40:01 [ 611.935355][ C0] ? ip_fragment.constprop.0+0x80/0x80 Sep 28 15:40:01 [ 611.945745][ C0] ip_push_pending_frames+0x52/0x80 Sep 28 15:40:01 [ 611.956106][ C0] __icmp_send+0x4ac/0x5a0 Sep 28 15:40:01 [ 611.966513][ C0] ? nf_xfrm_me_harder+0xf4/0x110 [nf_nat] Sep 28 15:40:02 [ 611.976960][ C0] ? ip_fragment.constprop.0+0x6d/0x80 Sep 28 15:40:02 [ 611.987406][ C0] ip_fragment.constprop.0+0x6d/0x80 Sep 28 15:40:02 [ 611.997743][ C0] nf_reinject+0x15d/0x18f Sep 28 15:40:02 [ 612.007855][ C0] imq_dev_xmit+0x70/0xb0 [imq] Sep 28 15:40:02 [ 612.017725][ C0] dev_hard_start_xmit+0x96/0x130 Sep 28 15:40:02 [ 612.027513][ C0] __qdisc_run+0x1bf/0x2d0 Sep 28 15:40:02 [ 612.037043][ C0] net_tx_action+0xd3/0x150 Sep 28 15:40:02 [ 612.046310][ C0] __do_softirq+0xc8/0x206 Sep 28 15:40:02 [ 612.055317][ C0] irq_exit+0xa7/0xf0 Sep 28 15:40:02 [ 612.064020][ C0] smp_apic_timer_interrupt+0x55/0x80 Sep 28 15:40:02 [ 612.072615][ C0] apic_timer_interrupt+0xf/0x20 Sep 28 15:40:02 [ 612.080970][ C0] </IRQ> Sep 28 15:40:02 [ 612.088957][ C0] RIP: 0033:0x55e6e4 Sep 28 15:40:02 [ 612.096796][ C0] Code: 48 01 d0 48 89 c2 4c 01 c0 4c 0f be 47 fb 48 c1 e2 05 48 01 c2 48 89 d0 48 c1 e0 05 4c 01 c2 4c 0f be 47 fc 48 01 d0 48 89 c2 <48> c1 e2 05 4c 01 c0 48 01 d0 48 0f be 57 fd 49 89 c0 49 c1 e0 05 Sep 28 15:40:02 [ 612.120192][ C0] RSP: 002b:00007ffc8f1f1fd8 EFLAGS: 00000287 ORIG_RAX: ffffffffffffff13 Sep 28 15:40:02 [ 612.135465][ C0] RAX: a888682638287cbb RBX: 00000000000002d0 RCX: 00007fb6b4431f88 Sep 28 15:40:02 [ 612.151470][ C0] RDX: a888682638287cbb RSI: 000000000000001a RDI: 00007fb6b4431f80 Sep 28 15:40:02 [ 612.168344][ C0] RBP: 0000000000001680 R08: 000000000000004c R09: 000000000000001a Sep 28 15:40:02 [ 612.186162][ C0] R10: 00007fb6b8541948 R11: 00007fb6b8a930a0 R12: 0000000000000090 Sep 28 15:40:02 [ 612.205010][ C0] R13: 00007fb6b442daa0 R14: 00007fb6b41044d0 R15: 0000000001619440
Mkay... seems I was only lucky with my top-notch G5 hardware not having seen this bug for quite some time. Re-opening 'cause this is already the 2nd report this bug (still) affects other hardware.
I know this is old but I have been having some issues for a while, I was finally able to get something useful: [165716.089703] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [165716.095949] rcu: 1-...!: (0 ticks this GP) idle=354/0/0x0 softirq=2154363/2154363 fqs=0 [165716.104512] rcu: 3-...!: (0 ticks this GP) idle=29c/0/0x0 softirq=883832/883832 fqs=0 [165716.112873] rcu: 4-...!: (8 GPs behind) idle=ad8/0/0x0 softirq=2165586/2165586 fqs=0 [165716.121179] rcu: 9-...!: (9 GPs behind) idle=acc/0/0x0 softirq=1340600/1340600 fqs=0 [165716.129467] rcu: 11-...!: (2 GPs behind) idle=a18/0/0x0 softirq=4538536/4538537 fqs=0 [165716.137828] rcu: 12-...!: (0 ticks this GP) idle=870/0/0x0 softirq=2158040/2158040 fqs=0 [165775.697763] rcu: rcu_sched kthread starved for 29898 jiffies! g36134941 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=3 [165775.709013] rcu: RCU grace-period kthread stack dump: [165837.494623] watchdog: BUG: soft lockup - CPU#6 stuck for 23s! [(resolved):52315] [165865.494840] watchdog: BUG: soft lockup - CPU#6 stuck for 23s! [(resolved):52315] This happened just after freshclam ran but I don't know if it's related. This is with a Ryzen 7 1800X CPU. 5.4.0-48-generic #52-Ubuntu I thought I had sysrq configured but it seems not so I can't really provide any more information, other than this is driving me crazy.
I experienced this problem today, a freeze on an processor : 3 vendor_id : AuthenticAMD cpu family : 22 model : 48 model name : AMD GX-412TC SOC on Debian 10 4.19.0-11-amd64 #1 SMP Debian 4.19.146-1 (2020-09-17) x86_64 GNU/Linux with more and more sysrq messages coming up resulting in the following syslog entry Oct 15 11:43:45 gate kernel: [1545118.045973] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: leading to the system becoming unreachable. Only after a reboot this works again.
Same error on RK3399pro (Radxa N10) with kernel 5.13.0-rc7 [13081.586168] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13081.586749] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=2081 [13081.587613] (detected by 1, t=6302 jiffies, g=1226929, q=7859) [13081.588159] Task dump for CPU 5: [13081.588462] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13081.589388] Call trace: [13081.589619] __switch_to+0xdc/0x130 [13081.589967] 0xffff800016db3bc8 [13144.605054] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13144.605636] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=8283 [13144.606501] (detected by 1, t=25207 jiffies, g=1226929, q=8960) [13144.607055] Task dump for CPU 5: [13144.607358] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13144.608283] Call trace: [13144.608513] __switch_to+0xdc/0x130 [13144.608862] 0xffff800016db3bc8 [13207.623887] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13207.624453] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=14520 [13207.625307] (detected by 1, t=44112 jiffies, g=1226929, q=9270) [13207.625851] Task dump for CPU 5: [13207.626146] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13207.627052] Call trace: [13207.627278] __switch_to+0xdc/0x130 [13207.627614] 0xffff800016db3bc8 [13270.642861] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13270.643441] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=20751 [13270.644314] (detected by 1, t=63017 jiffies, g=1226929, q=9388) [13270.644867] Task dump for CPU 5: [13270.645170] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13270.646095] Call trace: [13270.646326] __switch_to+0xdc/0x130 [13270.646673] 0xffff800016db3bc8 [13333.661672] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13333.662238] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=26980 [13333.663092] (detected by 1, t=81922 jiffies, g=1226929, q=9585) [13333.663636] Task dump for CPU 5: [13333.663931] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13333.664838] Call trace: [13333.665063] __switch_to+0xdc/0x130 [13333.665399] 0xffff800016db3bc8 [13396.680495] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13396.681062] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=33213 [13396.681917] (detected by 1, t=100827 jiffies, g=1226929, q=9817) [13396.682469] Task dump for CPU 5: [13396.682765] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13396.683671] Call trace: [13396.683896] __switch_to+0xdc/0x130 [13396.684233] 0xffff800016db3bc8 [13459.699554] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13459.700120] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=39406 [13459.700974] (detected by 1, t=119732 jiffies, g=1226929, q=10436) [13459.701533] Task dump for CPU 5: [13459.701829] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13459.702735] Call trace: [13459.702961] __switch_to+0xdc/0x130 [13459.703297] 0xffff800016db3bc8 [13522.718478] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13522.719049] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=45667 [13522.719902] (detected by 1, t=138637 jiffies, g=1226929, q=10742) [13522.720460] Task dump for CPU 5: [13522.720755] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13522.721662] Call trace: [13522.721888] __switch_to+0xdc/0x130 [13522.722224] 0xffff800016db3bc8 [13585.737386] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13585.737953] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=51904 [13585.738807] (detected by 1, t=157542 jiffies, g=1226929, q=10947) [13585.739365] Task dump for CPU 5: [13585.739661] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13585.740567] Call trace: [13585.740793] __switch_to+0xdc/0x130 [13585.741129] 0xffff800016db3bc8 [13648.756295] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13648.756862] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=58090 [13648.757715] (detected by 1, t=176447 jiffies, g=1226929, q=12205) [13648.758274] Task dump for CPU 5: [13648.758570] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13648.759476] Call trace: [13648.759701] __switch_to+0xdc/0x130 [13648.760036] 0xffff800016db3bc8 [13711.775146] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13711.775715] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=64362 [13711.776569] (detected by 1, t=195352 jiffies, g=1226929, q=12462) [13711.777127] Task dump for CPU 5: [13711.777423] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13711.778329] Call trace: [13711.778555] __switch_to+0xdc/0x130 [13711.778892] 0xffff800016db3bc8 [13774.793985] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13774.794553] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=70639 [13774.795408] (detected by 1, t=214257 jiffies, g=1226929, q=12569) [13774.795967] Task dump for CPU 5: [13774.796262] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13774.797168] Call trace: [13774.797394] __switch_to+0xdc/0x130 [13774.797730] 0xffff800016db3bc8 [13837.813008] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13837.813575] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=76909 [13837.814429] (detected by 1, t=233162 jiffies, g=1226929, q=12746) [13837.814986] Task dump for CPU 5: [13837.815281] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13837.816188] Call trace: [13837.816414] __switch_to+0xdc/0x130 [13837.816750] 0xffff800016db3bc8 [13900.831934] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13900.832514] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=83140 [13900.833387] (detected by 1, t=252067 jiffies, g=1226929, q=12831) [13900.833957] Task dump for CPU 5: [13900.834260] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13900.835184] Call trace: [13900.835416] __switch_to+0xdc/0x130 [13900.835763] 0xffff800016db3bc8 [13963.850798] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [13963.851365] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=89428 [13963.852219] (detected by 1, t=270972 jiffies, g=1226929, q=12997) [13963.852777] Task dump for CPU 5: [13963.853072] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[13963.853978] Call trace: [13963.854204] __switch_to+0xdc/0x130 [13963.854539] 0xffff800016db3bc8 [14026.869692] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14026.870256] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=95711 [14026.871109] (detected by 1, t=289877 jiffies, g=1226929, q=13189) [14026.871669] Task dump for CPU 5: [14026.871964] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14026.872870] Call trace: [14026.873096] __switch_to+0xdc/0x130 [14026.873432] 0xffff800016db3bc8 [14089.888567] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14089.889132] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=101977 [14089.889994] (detected by 1, t=308782 jiffies, g=1226929, q=13301) [14089.890552] Task dump for CPU 5: [14089.890847] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14089.891753] Call trace: [14089.891977] __switch_to+0xdc/0x130 [14089.892312] 0xffff800016db3bc8 [14152.907476] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14152.908040] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=108248 [14152.908901] (detected by 1, t=327687 jiffies, g=1226929, q=13583) [14152.909459] Task dump for CPU 5: [14152.909755] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14152.910661] Call trace: [14152.910885] __switch_to+0xdc/0x130 [14152.911221] 0xffff800016db3bc8 [14215.926397] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14215.926980] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=114520 [14215.927859] (detected by 1, t=346592 jiffies, g=1226929, q=14824) [14215.928430] Task dump for CPU 5: [14215.928732] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14215.929657] Call trace: [14215.929888] __switch_to+0xdc/0x130 [14215.930235] 0xffff800016db3bc8 [14278.945254] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14278.945819] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=120755 [14278.946681] (detected by 1, t=365497 jiffies, g=1226929, q=14953) [14278.947240] Task dump for CPU 5: [14278.947534] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14278.948441] Call trace: [14278.948665] __switch_to+0xdc/0x130 [14278.949001] 0xffff800016db3bc8 [14341.964082] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14341.964650] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=127008 [14341.965512] (detected by 1, t=384402 jiffies, g=1226929, q=15207) [14341.966069] Task dump for CPU 5: [14341.966365] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14341.967271] Call trace: [14341.967497] __switch_to+0xdc/0x130 [14341.967832] 0xffff800016db3bc8 [14404.982988] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14404.983555] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=133228 [14404.984415] (detected by 1, t=403307 jiffies, g=1226929, q=15393) [14404.984974] Task dump for CPU 5: [14404.985270] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14404.986176] Call trace: [14404.986402] __switch_to+0xdc/0x130 [14404.986738] 0xffff800016db3bc8 [14468.001845] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14468.002412] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=139490 [14468.003274] (detected by 1, t=422212 jiffies, g=1226929, q=15648) [14468.003833] Task dump for CPU 5: [14468.004128] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14468.005035] Call trace: [14468.005260] __switch_to+0xdc/0x130 [14468.005594] 0xffff800016db3bc8 [14531.020589] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14531.021155] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=145729 [14531.022018] (detected by 1, t=441117 jiffies, g=1226929, q=15794) [14531.022577] Task dump for CPU 5: [14531.022873] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14531.023779] Call trace: [14531.024005] __switch_to+0xdc/0x130 [14531.024341] 0xffff800016db3bc8 [14594.039456] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14594.040025] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=151980 [14594.040886] (detected by 1, t=460022 jiffies, g=1226929, q=15878) [14594.041446] Task dump for CPU 5: [14594.041741] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14594.042647] Call trace: [14594.042872] __switch_to+0xdc/0x130 [14594.043207] 0xffff800016db3bc8 [14657.058389] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14657.058959] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=158250 [14657.059822] (detected by 1, t=478927 jiffies, g=1226929, q=16066) [14657.060381] Task dump for CPU 5: [14657.060676] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14657.061583] Call trace: [14657.061807] __switch_to+0xdc/0x130 [14657.062141] 0xffff800016db3bc8 [14720.077324] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14720.077890] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=164517 [14720.078752] (detected by 1, t=497832 jiffies, g=1226929, q=16282) [14720.079312] Task dump for CPU 5: [14720.079607] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14720.080513] Call trace: [14720.080739] __switch_to+0xdc/0x130 [14720.081075] 0xffff800016db3bc8 [14783.096138] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14783.096707] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=170813 [14783.097569] (detected by 1, t=516737 jiffies, g=1226929, q=16500) [14783.098129] Task dump for CPU 5: [14783.098425] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14783.099331] Call trace: [14783.099557] __switch_to+0xdc/0x130 [14783.099892] 0xffff800016db3bc8 [14846.115081] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14846.115662] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=177083 [14846.116542] (detected by 1, t=535642 jiffies, g=1226929, q=17790) [14846.117111] Task dump for CPU 5: [14846.117414] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14846.118339] Call trace: [14846.118572] __switch_to+0xdc/0x130 [14846.118919] 0xffff800016db3bc8 [14909.133891] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14909.134461] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=183326 [14909.135323] (detected by 1, t=554547 jiffies, g=1226929, q=17940) [14909.135882] Task dump for CPU 5: [14909.136177] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14909.137084] Call trace: [14909.137309] __switch_to+0xdc/0x130 [14909.137644] 0xffff800016db3bc8 [14972.152771] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [14972.153341] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=189592 [14972.154203] (detected by 1, t=573452 jiffies, g=1226929, q=18093) [14972.154763] Task dump for CPU 5: [14972.155058] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[14972.155964] Call trace: [14972.156190] __switch_to+0xdc/0x130 [14972.156525] 0xffff800016db3bc8 [15035.171590] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15035.172159] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=195867 [15035.173022] (detected by 1, t=592357 jiffies, g=1226929, q=18270) [15035.173583] Task dump for CPU 5: [15035.173878] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15035.174785] Call trace: [15035.175012] __switch_to+0xdc/0x130 [15035.175347] 0xffff800016db3bc8 [15098.190534] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15098.191104] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=202159 [15098.191966] (detected by 1, t=611262 jiffies, g=1226929, q=18399) [15098.192524] Task dump for CPU 5: [15098.192819] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15098.193726] Call trace: [15098.193952] __switch_to+0xdc/0x130 [15098.194288] 0xffff800016db3bc8 [15161.209414] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15161.209983] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=208429 [15161.210846] (detected by 1, t=630167 jiffies, g=1226929, q=18573) [15161.211404] Task dump for CPU 5: [15161.211699] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15161.212606] Call trace: [15161.212832] __switch_to+0xdc/0x130 [15161.213168] 0xffff800016db3bc8 [15224.228338] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15224.228905] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=214694 [15224.229767] (detected by 1, t=649072 jiffies, g=1226929, q=18750) [15224.230326] Task dump for CPU 5: [15224.230622] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15224.231527] Call trace: [15224.231753] __switch_to+0xdc/0x130 [15224.232088] 0xffff800016db3bc8 [15287.247240] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15287.247805] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=220945 [15287.248668] (detected by 1, t=667977 jiffies, g=1226929, q=18876) [15287.249226] Task dump for CPU 5: [15287.249521] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15287.250427] Call trace: [15287.250652] __switch_to+0xdc/0x130 [15287.250987] 0xffff800016db3bc8 [15350.266060] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15350.266628] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=227219 [15350.267491] (detected by 1, t=686882 jiffies, g=1226929, q=19238) [15350.268050] Task dump for CPU 5: [15350.268345] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15350.269252] Call trace: [15350.269477] __switch_to+0xdc/0x130 [15350.269812] 0xffff800016db3bc8 [15413.284937] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15413.285504] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=233484 [15413.286368] (detected by 1, t=705787 jiffies, g=1226929, q=20770) [15413.286926] Task dump for CPU 5: [15413.287221] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15413.288128] Call trace: [15413.288353] __switch_to+0xdc/0x130 [15413.288689] 0xffff800016db3bc8 [15476.304113] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15476.304693] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=239734 [15476.305571] (detected by 1, t=724692 jiffies, g=1226929, q=21025) [15476.306141] Task dump for CPU 5: [15476.306444] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15476.307370] Call trace: [15476.307601] __switch_to+0xdc/0x130 [15476.307949] 0xffff800016db3bc8 [15539.322826] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15539.323390] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=245985 [15539.324252] (detected by 1, t=743597 jiffies, g=1226929, q=21217) [15539.324812] Task dump for CPU 5: [15539.325108] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15539.326014] Call trace: [15539.326240] __switch_to+0xdc/0x130 [15539.326578] 0xffff800016db3bc8 [15602.341877] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15602.342442] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=252236 [15602.343304] (detected by 1, t=762502 jiffies, g=1226929, q=21374) [15602.343864] Task dump for CPU 5: [15602.344159] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15602.345065] Call trace: [15602.345290] __switch_to+0xdc/0x130 [15602.345625] 0xffff800016db3bc8 [15665.360673] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15665.361243] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=258527 [15665.362106] (detected by 3, t=781407 jiffies, g=1226929, q=21533) [15665.362666] Task dump for CPU 5: [15665.362961] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15665.363867] Call trace: [15665.364093] __switch_to+0xdc/0x130 [15665.364430] 0xffff800016db3bc8 [15728.379714] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15728.380280] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=264799 [15728.381141] (detected by 1, t=800312 jiffies, g=1226929, q=21623) [15728.381699] Task dump for CPU 5: [15728.381995] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15728.382901] Call trace: [15728.383127] __switch_to+0xdc/0x130 [15728.383462] 0xffff800016db3bc8 [15791.398498] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15791.399064] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=271031 [15791.399927] (detected by 1, t=819217 jiffies, g=1226929, q=21803) [15791.400486] Task dump for CPU 5: [15791.400781] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15791.401687] Call trace: [15791.401911] __switch_to+0xdc/0x130 [15791.402247] 0xffff800016db3bc8 [15854.417401] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15854.417968] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=277248 [15854.418832] (detected by 2, t=838122 jiffies, g=1226929, q=21993) [15854.419391] Task dump for CPU 5: [15854.419686] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15854.420593] Call trace: [15854.420817] __switch_to+0xdc/0x130 [15854.421153] 0xffff800016db3bc8 [15917.436445] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15917.437012] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=283509 [15917.437874] (detected by 1, t=857027 jiffies, g=1226929, q=22214) [15917.438434] Task dump for CPU 5: [15917.438729] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15917.439634] Call trace: [15917.439859] __switch_to+0xdc/0x130 [15917.440195] 0xffff800016db3bc8 [15980.455269] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [15980.455839] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=289795 [15980.456702] (detected by 1, t=875932 jiffies, g=1226929, q=22336) [15980.457260] Task dump for CPU 5: [15980.457555] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[15980.458462] Call trace: [15980.458688] __switch_to+0xdc/0x130 [15980.459024] 0xffff800016db3bc8 [16043.474210] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16043.474775] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=296074 [16043.475637] (detected by 1, t=894837 jiffies, g=1226929, q=23604) [16043.476197] Task dump for CPU 5: [16043.476492] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16043.477398] Call trace: [16043.477623] __switch_to+0xdc/0x130 [16043.477959] 0xffff800016db3bc8 [16106.493004] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16106.493574] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=302355 [16106.494439] (detected by 1, t=913742 jiffies, g=1226929, q=23693) [16106.494998] Task dump for CPU 5: [16106.495293] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16106.496200] Call trace: [16106.496426] __switch_to+0xdc/0x130 [16106.496763] 0xffff800016db3bc8 [16169.511966] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16169.512534] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=308617 [16169.513398] (detected by 1, t=932647 jiffies, g=1226929, q=23881) [16169.513958] Task dump for CPU 5: [16169.514253] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16169.515160] Call trace: [16169.515386] __switch_to+0xdc/0x130 [16169.515720] 0xffff800016db3bc8 [16232.530953] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16232.531530] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=314840 [16232.532412] (detected by 1, t=951552 jiffies, g=1226929, q=24168) [16232.532981] Task dump for CPU 5: [16232.533284] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16232.534208] Call trace: [16232.534439] __switch_to+0xdc/0x130 [16232.534786] 0xffff800016db3bc8 [16295.549694] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16295.550260] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=321100 [16295.551122] (detected by 1, t=970457 jiffies, g=1226929, q=24344) [16295.551682] Task dump for CPU 5: [16295.551977] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16295.552883] Call trace: [16295.553109] __switch_to+0xdc/0x130 [16295.553444] 0xffff800016db3bc8 [16358.568692] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16358.569257] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=327311 [16358.570119] (detected by 1, t=989362 jiffies, g=1226929, q=24453) [16358.570677] Task dump for CPU 5: [16358.570973] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16358.571878] Call trace: [16358.572103] __switch_to+0xdc/0x130 [16358.572438] 0xffff800016db3bc8 [16421.587636] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16421.588203] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=333593 [16421.589064] (detected by 1, t=1008267 jiffies, g=1226929, q=24583) [16421.589631] Task dump for CPU 5: [16421.589926] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16421.590832] Call trace: [16421.591058] __switch_to+0xdc/0x130 [16421.591393] 0xffff800016db3bc8 [16484.606656] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16484.607238] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=339823 [16484.608120] (detected by 1, t=1027172 jiffies, g=1226929, q=24800) [16484.608697] Task dump for CPU 5: [16484.609001] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16484.609926] Call trace: [16484.610156] __switch_to+0xdc/0x130 [16484.610503] 0xffff800016db3bc8 [16547.625618] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16547.626182] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=346004 [16547.627043] (detected by 1, t=1046077 jiffies, g=1226929, q=24992) [16547.627609] Task dump for CPU 5: [16547.627905] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16547.628811] Call trace: [16547.629035] __switch_to+0xdc/0x130 [16547.629371] 0xffff800016db3bc8 [16610.644564] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16610.645128] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=352273 [16610.645990] (detected by 1, t=1064982 jiffies, g=1226929, q=26024) [16610.646556] Task dump for CPU 5: [16610.646851] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16610.647758] Call trace: [16610.647982] __switch_to+0xdc/0x130 [16610.648318] 0xffff800016db3bc8 [16673.663533] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16673.664098] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=358540 [16673.664960] (detected by 1, t=1083887 jiffies, g=1226929, q=27452) [16673.665526] Task dump for CPU 5: [16673.665822] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842539 flags:0x00000002[16673.666728] Call trace: [16673.666954] __switch_to+0xdc/0x130 [16673.667289] 0xffff800016db3bc8 [16736.682410] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [16736.682978] rcu: 5-...0: (1 GPs behind) idle=aaa/1/0x4000000000000000 softirq=981287/981290 fqs=364780 [16736.683840] (detected by 1, t=1102792 jiffies, g=1226929, q=28629) [16736.684407] Task dump for CPU 5: [16736.684702] task:pkgjson state:R running task stack: 0 pid:845641 ppid:842408 flags:0x00000003[16736.685608] Call trace: [16736.685834] __switch_to+0xdc/0x130 [16736.686169] 0xffff800016db3bc8