powerpc 5.10-rcN boot failures with RCU_SCALE_TEST=m

Michael Ellerman mpe at ellerman.id.au
Thu Dec 3 01:03:32 AEDT 2020


Daniel Axtens <dja at axtens.net> writes:
> Hi all,
>
> I'm having some difficulty tracking down a bug.
>
> Some configurations of the powerpc kernel since somewhere in the 5.10
> merge window fail to boot on some ppc64 systems. They hang while trying
> to bring up SMP. It seems to depend on the RCU_SCALE/PERF_TEST option.
> (It was renamed in the 5.10 merge window.)
>
> I can reproduce it as follows with qemu tcg:
>
> make -j64 pseries_le_defconfig
> scripts/config -m RCU_SCALE_TEST
> scripts/config -m RCU_PERF_TEST
> make -j 64 vmlinux CC="ccache gcc"
>
> qemu-system-ppc64 -cpu power9 -M pseries -m 1G -nographic -vga none -smp 4 -kernel vmlinux
>
> ...
> [    0.036284][    T0] Mount-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
> [    0.036481][    T0] Mountpoint-cache hash table entries: 8192 (order: 0, 65536 bytes, linear)
> [    0.148168][    T1] POWER9 performance monitor hardware support registered
> [    0.151118][    T1] rcu: Hierarchical SRCU implementation.
> [    0.186660][    T1] smp: Bringing up secondary CPUs ...
> <hangs>

One does not simply hang :)

> I have no idea why RCU_SCALE/PERF_TEST would be causing this, but that
> seems to be what does it: if I don't set that, the kernel boots fine.

It seems to be TASKS_RCU that is the key.

I don't need RCU_SCALE_TEST enabled, I can trigger it just with the
following applied:

diff --git a/kernel/rcu/Kconfig b/kernel/rcu/Kconfig
index 0ebe15a84985..f3500c95d6a1 100644
--- a/kernel/rcu/Kconfig
+++ b/kernel/rcu/Kconfig
@@ -78,7 +78,7 @@ config TASKS_RCU_GENERIC
 	  task-based RCU implementations.  Not for manual selection.
 
 config TASKS_RCU
-	def_bool PREEMPTION
+	def_bool y
 	help
 	  This option enables a task-based RCU implementation that uses
 	  only voluntary context switch (not preemption!), idle, and


And bisect points to:
  36dadef23fcc ("kprobes: Init kprobes in early_initcall")

Which moved init_kprobes() prior to SMP bringup.


For some reason when it gets stuck sysrq doesn't work, but I was able to
get it into gdb and manually call handle_sysrq('t') to get the output
below.

The SMP bringup stalls because _cpu_up() is blocked trying to take
cpu_hotplug_lock for writing:

[  401.403132][    T0] task:swapper/0       state:D stack:12512 pid:    1 ppid:     0 flags:0x00000800
[  401.403502][    T0] Call Trace:
[  401.403907][    T0] [c0000000062c37d0] [c0000000062c3830] 0xc0000000062c3830 (unreliable)
[  401.404068][    T0] [c0000000062c39b0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.404189][    T0] [c0000000062c3a10] [c000000000b87228] __schedule+0x288/0x9b0
[  401.404257][    T0] [c0000000062c3ad0] [c000000000b879b8] schedule+0x68/0x120
[  401.404324][    T0] [c0000000062c3b00] [c000000000184ad4] percpu_down_write+0x164/0x170
[  401.404390][    T0] [c0000000062c3b50] [c000000000116b68] _cpu_up+0x68/0x280
[  401.404475][    T0] [c0000000062c3bb0] [c000000000116e70] cpu_up+0xf0/0x140
[  401.404546][    T0] [c0000000062c3c30] [c00000000011776c] bringup_nonboot_cpus+0xac/0xf0
[  401.404643][    T0] [c0000000062c3c80] [c000000000eea1b8] smp_init+0x40/0xcc
[  401.404727][    T0] [c0000000062c3ce0] [c000000000ec43dc] kernel_init_freeable+0x1e0/0x3a0
[  401.404799][    T0] [c0000000062c3db0] [c000000000011ec4] kernel_init+0x24/0x150
[  401.404958][    T0] [c0000000062c3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c

It can't get it because kprobe_optimizer() has taken it for read and is now
blocked waiting for synchronize_rcu_tasks():

[  401.418808][    T0] task:kworker/0:1     state:D stack:13392 pid:   12 ppid:     2 flags:0x00000800
[  401.418951][    T0] Workqueue: events kprobe_optimizer
[  401.419078][    T0] Call Trace:
[  401.419121][    T0] [c0000000062ef650] [c0000000062ef710] 0xc0000000062ef710 (unreliable)
[  401.419213][    T0] [c0000000062ef830] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.419281][    T0] [c0000000062ef890] [c000000000b87228] __schedule+0x288/0x9b0
[  401.419347][    T0] [c0000000062ef950] [c000000000b879b8] schedule+0x68/0x120
[  401.419415][    T0] [c0000000062ef980] [c000000000b8e664] schedule_timeout+0x2a4/0x340
[  401.419484][    T0] [c0000000062efa80] [c000000000b894ec] wait_for_completion+0x9c/0x170
[  401.419552][    T0] [c0000000062efae0] [c0000000001ac85c] __wait_rcu_gp+0x19c/0x210
[  401.419619][    T0] [c0000000062efb40] [c0000000001ac90c] synchronize_rcu_tasks_generic+0x3c/0x70
[  401.419690][    T0] [c0000000062efbe0] [c00000000022a3dc] kprobe_optimizer+0x1dc/0x470
[  401.419757][    T0] [c0000000062efc60] [c000000000136684] process_one_work+0x2f4/0x530
[  401.419823][    T0] [c0000000062efd20] [c000000000138d28] worker_thread+0x78/0x570
[  401.419891][    T0] [c0000000062efdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.419976][    T0] [c0000000062efe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c

But why is the synchronize_rcu_tasks() not completing?

Hopefully Paul can help there, otherwise I'll try and work out how to
dump some RCU state when it gets stuck.

Full sysrq-t output below.

cheers


[  401.402512][    T0] sysrq: Show State
[  401.403132][    T0] task:swapper/0       state:D stack:12512 pid:    1 ppid:     0 flags:0x00000800
[  401.403502][    T0] Call Trace:
[  401.403907][    T0] [c0000000062c37d0] [c0000000062c3830] 0xc0000000062c3830 (unreliable)
[  401.404068][    T0] [c0000000062c39b0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.404189][    T0] [c0000000062c3a10] [c000000000b87228] __schedule+0x288/0x9b0
[  401.404257][    T0] [c0000000062c3ad0] [c000000000b879b8] schedule+0x68/0x120
[  401.404324][    T0] [c0000000062c3b00] [c000000000184ad4] percpu_down_write+0x164/0x170
[  401.404390][    T0] [c0000000062c3b50] [c000000000116b68] _cpu_up+0x68/0x280
[  401.404475][    T0] [c0000000062c3bb0] [c000000000116e70] cpu_up+0xf0/0x140
[  401.404546][    T0] [c0000000062c3c30] [c00000000011776c] bringup_nonboot_cpus+0xac/0xf0
[  401.404643][    T0] [c0000000062c3c80] [c000000000eea1b8] smp_init+0x40/0xcc
[  401.404727][    T0] [c0000000062c3ce0] [c000000000ec43dc] kernel_init_freeable+0x1e0/0x3a0
[  401.404799][    T0] [c0000000062c3db0] [c000000000011ec4] kernel_init+0x24/0x150
[  401.404958][    T0] [c0000000062c3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.405221][    T0] task:kthreadd        state:S stack:13712 pid:    2 ppid:     0 flags:0x00000800
[  401.405326][    T0] Call Trace:
[  401.405380][    T0] [c0000000062c7a60] [c0000000062c7ac0] 0xc0000000062c7ac0 (unreliable)
[  401.405473][    T0] [c0000000062c7c40] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.405565][    T0] [c0000000062c7ca0] [c000000000b87228] __schedule+0x288/0x9b0
[  401.405639][    T0] [c0000000062c7d60] [c000000000b879b8] schedule+0x68/0x120
[  401.405720][    T0] [c0000000062c7d90] [c000000000143508] kthreadd+0x278/0x2f0
[  401.405798][    T0] [c0000000062c7e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.405908][    T0] task:rcu_gp          state:I stack:14576 pid:    3 ppid:     2 flags:0x00000800
[  401.407471][    T0] Call Trace:
[  401.407690][    T0] [c0000000062cba00] [c0000000062cba60] 0xc0000000062cba60 (unreliable)
[  401.407851][    T0] [c0000000062cbbe0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.407952][    T0] [c0000000062cbc40] [c000000000b87228] __schedule+0x288/0x9b0
[  401.408037][    T0] [c0000000062cbd00] [c000000000b879b8] schedule+0x68/0x120
[  401.408123][    T0] [c0000000062cbd30] [c000000000136ed4] rescuer_thread+0x2c4/0x3f0
[  401.408268][    T0] [c0000000062cbdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.408351][    T0] [c0000000062cbe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.408463][    T0] task:rcu_par_gp      state:I stack:14624 pid:    4 ppid:     2 flags:0x00000800
[  401.408629][    T0] Call Trace:
[  401.408725][    T0] [c0000000062cfa00] [c0000000062cfa60] 0xc0000000062cfa60 (unreliable)
[  401.408830][    T0] [c0000000062cfbe0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.408927][    T0] [c0000000062cfc40] [c000000000b87228] __schedule+0x288/0x9b0
[  401.409030][    T0] [c0000000062cfd00] [c000000000b879b8] schedule+0x68/0x120
[  401.409143][    T0] [c0000000062cfd30] [c000000000136ed4] rescuer_thread+0x2c4/0x3f0
[  401.409256][    T0] [c0000000062cfdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.409349][    T0] [c0000000062cfe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.409458][    T0] task:kworker/0:0     state:I stack:13888 pid:    5 ppid:     2 flags:0x00000800
[  401.409749][    T0] Workqueue:  0x0 (events)
[  401.409923][    T0] Call Trace:
[  401.409986][    T0] [c0000000062d39f0] [c0000000062d3a50] 0xc0000000062d3a50 (unreliable)
[  401.410125][    T0] [c0000000062d3bd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.410263][    T0] [c0000000062d3c30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.410371][    T0] [c0000000062d3cf0] [c000000000b879b8] schedule+0x68/0x120
[  401.410450][    T0] [c0000000062d3d20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.410567][    T0] [c0000000062d3db0] [c000000000142424] kthread+0x194/0x1a0
[  401.410671][    T0] [c0000000062d3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.410795][    T0] task:kworker/0:0H    state:I stack:14624 pid:    6 ppid:     2 flags:0x00000800
[  401.411024][    T0] Call Trace:
[  401.411117][    T0] [c0000000062d79f0] [c0000000062d7a50] 0xc0000000062d7a50 (unreliable)
[  401.411267][    T0] [c0000000062d7bd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.411401][    T0] [c0000000062d7c30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.411484][    T0] [c0000000062d7cf0] [c000000000b879b8] schedule+0x68/0x120
[  401.411575][    T0] [c0000000062d7d20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.411666][    T0] [c0000000062d7db0] [c000000000142424] kthread+0x194/0x1a0
[  401.411722][    T0] [c0000000062d7e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.411809][    T0] task:kworker/u8:0    state:I stack:14624 pid:    7 ppid:     2 flags:0x00000800
[  401.411923][    T0] Call Trace:
[  401.411969][    T0] [c0000000062db9f0] [c0000000062dba50] 0xc0000000062dba50 (unreliable)
[  401.412045][    T0] [c0000000062dbbd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.412143][    T0] [c0000000062dbc30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.413324][    T0] [c0000000062dbcf0] [c000000000b879b8] schedule+0x68/0x120
[  401.413402][    T0] [c0000000062dbd20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.413468][    T0] [c0000000062dbdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.413522][    T0] [c0000000062dbe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.413595][    T0] task:mm_percpu_wq    state:I stack:14624 pid:    8 ppid:     2 flags:0x00000800
[  401.413699][    T0] Call Trace:
[  401.413745][    T0] [c0000000062dfa00] [c0000000062dfa60] 0xc0000000062dfa60 (unreliable)
[  401.413826][    T0] [c0000000062dfbe0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.413894][    T0] [c0000000062dfc40] [c000000000b87228] __schedule+0x288/0x9b0
[  401.413960][    T0] [c0000000062dfd00] [c000000000b879b8] schedule+0x68/0x120
[  401.414025][    T0] [c0000000062dfd30] [c000000000136ed4] rescuer_thread+0x2c4/0x3f0
[  401.414105][    T0] [c0000000062dfdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.414185][    T0] [c0000000062dfe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.414275][    T0] task:ksoftirqd/0     state:S stack:14544 pid:    9 ppid:     2 flags:0x00000800
[  401.414506][    T0] Call Trace:
[  401.414729][    T0] [c0000000062e3a20] [c0000000062e3a80] 0xc0000000062e3a80 (unreliable)
[  401.415109][    T0] [c0000000062e3c00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.415651][    T0] [c0000000062e3c60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.415944][    T0] [c0000000062e3d20] [c000000000b879b8] schedule+0x68/0x120
[  401.416044][    T0] [c0000000062e3d50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.416104][    T0] [c0000000062e3db0] [c000000000142424] kthread+0x194/0x1a0
[  401.416177][    T0] [c0000000062e3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.416261][    T0] task:rcu_sched       state:I stack:12928 pid:   10 ppid:     2 flags:0x00000800
[  401.416378][    T0] Call Trace:
[  401.416423][    T0] [c0000000062e7990] [c0000000062e7a50] 0xc0000000062e7a50 (unreliable)
[  401.416501][    T0] [c0000000062e7b70] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.416569][    T0] [c0000000062e7bd0] [c000000000b87228] __schedule+0x288/0x9b0
[  401.416633][    T0] [c0000000062e7c90] [c000000000b879b8] schedule+0x68/0x120
[  401.416705][    T0] [c0000000062e7cc0] [c0000000001b7b54] rcu_gp_kthread+0xa94/0xc00
[  401.416798][    T0] [c0000000062e7db0] [c000000000142424] kthread+0x194/0x1a0
[  401.416871][    T0] [c0000000062e7e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.416965][    T0] task:migration/0     state:S stack:14496 pid:   11 ppid:     2 flags:0x00000800
[  401.417050][    T0] Call Trace:
[  401.417092][    T0] [c0000000062eba20] [c0000000062ebaa0] 0xc0000000062ebaa0 (unreliable)
[  401.417206][    T0] [c0000000062ebc00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.417397][    T0] [c0000000062ebc60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.417631][    T0] [c0000000062ebd20] [c000000000b879b8] schedule+0x68/0x120
[  401.417930][    T0] [c0000000062ebd50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.418251][    T0] [c0000000062ebdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.418520][    T0] [c0000000062ebe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.418808][    T0] task:kworker/0:1     state:D stack:13392 pid:   12 ppid:     2 flags:0x00000800
[  401.418951][    T0] Workqueue: events kprobe_optimizer
[  401.419078][    T0] Call Trace:
[  401.419121][    T0] [c0000000062ef650] [c0000000062ef710] 0xc0000000062ef710 (unreliable)
[  401.419213][    T0] [c0000000062ef830] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.419281][    T0] [c0000000062ef890] [c000000000b87228] __schedule+0x288/0x9b0
[  401.419347][    T0] [c0000000062ef950] [c000000000b879b8] schedule+0x68/0x120
[  401.419415][    T0] [c0000000062ef980] [c000000000b8e664] schedule_timeout+0x2a4/0x340
[  401.419484][    T0] [c0000000062efa80] [c000000000b894ec] wait_for_completion+0x9c/0x170
[  401.419552][    T0] [c0000000062efae0] [c0000000001ac85c] __wait_rcu_gp+0x19c/0x210
[  401.419619][    T0] [c0000000062efb40] [c0000000001ac90c] synchronize_rcu_tasks_generic+0x3c/0x70
[  401.419690][    T0] [c0000000062efbe0] [c00000000022a3dc] kprobe_optimizer+0x1dc/0x470
[  401.419757][    T0] [c0000000062efc60] [c000000000136684] process_one_work+0x2f4/0x530
[  401.419823][    T0] [c0000000062efd20] [c000000000138d28] worker_thread+0x78/0x570
[  401.419891][    T0] [c0000000062efdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.419976][    T0] [c0000000062efe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.420051][    T0] task:cpuhp/0         state:S stack:14544 pid:   13 ppid:     2 flags:0x00000800
[  401.420136][    T0] Call Trace:
[  401.420197][    T0] [c0000000062ffa20] [c0000000062ffa80] 0xc0000000062ffa80 (unreliable)
[  401.420342][    T0] [c0000000062ffc00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.420519][    T0] [c0000000062ffc60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.420704][    T0] [c0000000062ffd20] [c000000000b879b8] schedule+0x68/0x120
[  401.420904][    T0] [c0000000062ffd50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.421134][    T0] [c0000000062ffdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.421487][    T0] [c0000000062ffe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.421834][    T0] task:cpuhp/1         state:S stack:13584 pid:   14 ppid:     2 flags:0x00000800
[  401.422146][    T0] Call Trace:
[  401.422233][    T0] [c0000000063c3a20] [c0000000063c3a80] 0xc0000000063c3a80 (unreliable)
[  401.422314][    T0] [c0000000063c3c00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.422378][    T0] [c0000000063c3c60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.422444][    T0] [c0000000063c3d20] [c000000000b879b8] schedule+0x68/0x120
[  401.422511][    T0] [c0000000063c3d50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.422575][    T0] [c0000000063c3db0] [c000000000142424] kthread+0x194/0x1a0
[  401.422658][    T0] [c0000000063c3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.422742][    T0] task:migration/1     state:S stack:13472 pid:   15 ppid:     2 flags:0x00000800
[  401.422826][    T0] Call Trace:
[  401.422873][    T0] [c0000000063c7a20] [c0000000063c7aa0] 0xc0000000063c7aa0 (unreliable)
[  401.423195][    T0] [c0000000063c7c00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.423285][    T0] [c0000000063c7c60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.423354][    T0] [c0000000063c7d20] [c000000000b879b8] schedule+0x68/0x120
[  401.423421][    T0] [c0000000063c7d50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.423486][    T0] [c0000000063c7db0] [c000000000142424] kthread+0x194/0x1a0
[  401.423576][    T0] [c0000000063c7e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.423783][    T0] task:ksoftirqd/1     state:S stack:14544 pid:   16 ppid:     2 flags:0x00000800
[  401.424112][    T0] Call Trace:
[  401.424410][    T0] [c0000000063cba20] [c0000000063cba80] 0xc0000000063cba80 (unreliable)
[  401.424775][    T0] [c0000000063cbc00] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.425005][    T0] [c0000000063cbc60] [c000000000b87228] __schedule+0x288/0x9b0
[  401.425124][    T0] [c0000000063cbd20] [c000000000b879b8] schedule+0x68/0x120
[  401.425197][    T0] [c0000000063cbd50] [c000000000148774] smpboot_thread_fn+0x254/0x260
[  401.425299][    T0] [c0000000063cbdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.425398][    T0] [c0000000063cbe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.425504][    T0] task:kworker/1:0     state:I stack:14624 pid:   17 ppid:     2 flags:0x00000800
[  401.425684][    T0] Call Trace:
[  401.425748][    T0] [c0000000063cf9f0] [c0000000063cfa50] 0xc0000000063cfa50 (unreliable)
[  401.425845][    T0] [c0000000063cfbd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.425916][    T0] [c0000000063cfc30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.425983][    T0] [c0000000063cfcf0] [c000000000b879b8] schedule+0x68/0x120
[  401.426050][    T0] [c0000000063cfd20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.426123][    T0] [c0000000063cfdb0] [c000000000142424] kthread+0x194/0x1a0
[  401.426229][    T0] [c0000000063cfe20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.426327][    T0] task:kworker/1:0H    state:I stack:14320 pid:   18 ppid:     2 flags:0x00000800
[  401.426494][    T0] Call Trace:
[  401.426577][    T0] [c0000000063d39f0] [c0000000063d3ab0] 0xc0000000063d3ab0 (unreliable)
[  401.426685][    T0] [c0000000063d3bd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.426772][    T0] [c0000000063d3c30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.426868][    T0] [c0000000063d3cf0] [c000000000b879b8] schedule+0x68/0x120
[  401.426969][    T0] [c0000000063d3d20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.427082][    T0] [c0000000063d3db0] [c000000000142424] kthread+0x194/0x1a0
[  401.427244][    T0] [c0000000063d3e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.427403][    T0] task:kworker/0:2     state:I stack:14320 pid:   19 ppid:     2 flags:0x00000800
[  401.427624][    T0] Workqueue:  0x0 (events)
[  401.427768][    T0] Call Trace:
[  401.427840][    T0] [c0000000063d79f0] [c0000000063d7ab0] 0xc0000000063d7ab0 (unreliable)
[  401.427981][    T0] [c0000000063d7bd0] [c000000000019d70] __switch_to+0x2e0/0x4a0
[  401.428096][    T0] [c0000000063d7c30] [c000000000b87228] __schedule+0x288/0x9b0
[  401.428303][    T0] [c0000000063d7cf0] [c000000000b879b8] schedule+0x68/0x120
[  401.428394][    T0] [c0000000063d7d20] [c000000000138dac] worker_thread+0xfc/0x570
[  401.428470][    T0] [c0000000063d7db0] [c000000000142424] kthread+0x194/0x1a0
[  401.428575][    T0] [c0000000063d7e20] [c00000000000daf0] ret_from_kernel_thread+0x5c/0x6c
[  401.429454][    T0] Sched Debug Version: v0.11, 5.10.0-rc6-gcc-8.2.0-01356-ga1aeabd25a36-dirty #563
[  401.429604][    T0] ktime                                   : 383770.000000
[  401.429683][    T0] sched_clk                               : 401429.227980
[  401.429744][    T0] cpu_clk                                 : 401429.232778
[  401.429799][    T0] jiffies                                 : 4294975673
[  401.429926][    T0]
[  401.430003][    T0] sysctl_sched
[  401.430066][    T0]   .sysctl_sched_latency                    : 12.000000
[  401.430152][    T0]   .sysctl_sched_min_granularity            : 1.500000
[  401.430339][    T0]   .sysctl_sched_wakeup_granularity         : 2.000000
[  401.430524][    T0]   .sysctl_sched_child_runs_first           : 0
[  401.430688][    T0]   .sysctl_sched_features                   : 4139835
[  401.430900][    T0]   .sysctl_sched_tunable_scaling            : 1 (logarithmic)
[  401.431124][    T0]
[  401.431697][    T0] cpu#0
[  401.431766][    T0]   .nr_running                    : 0
[  401.431813][    T0]   .nr_switches                   : 1055
[  401.431865][    T0]   .nr_uninterruptible            : 2
[  401.432042][    T0]   .next_balance                  : 4294.937296
[  401.432103][    T0]   .curr->pid                     : 0
[  401.432195][    T0]   .clock                         : 401423.022270
[  401.432313][    T0]   .clock_task                    : 401423.022270
[  401.432415][    T0]   .avg_idle                      : 1000000
[  401.432488][    T0]   .max_idle_balance_cost         : 500000
[  401.432817][    T0]
[  401.433054][    T0] cfs_rq[0]:/
[  401.433196][    T0]   .exec_clock                    : 0.000000
[  401.433386][    T0]   .MIN_vruntime                  : 0.000001
[  401.433503][    T0]   .min_vruntime                  : 278.095255
[  401.433596][    T0]   .max_vruntime                  : 0.000001
[  401.433691][    T0]   .spread                        : 0.000000
[  401.433784][    T0]   .spread0                       : 0.000000
[  401.433886][    T0]   .nr_spread_over                : 0
[  401.433954][    T0]   .nr_running                    : 0
[  401.434039][    T0]   .load                          : 0
[  401.434127][    T0]   .load_avg                      : 0
[  401.434235][    T0]   .runnable_avg                  : 0
[  401.434341][    T0]   .util_avg                      : 0
[  401.434451][    T0]   .util_est_enqueued             : 0
[  401.434540][    T0]   .removed.load_avg              : 0
[  401.434611][    T0]   .removed.util_avg              : 0
[  401.434697][    T0]   .removed.runnable_avg          : 0
[  401.434811][    T0]   .tg_load_avg_contrib           : 0
[  401.434902][    T0]   .tg_load_avg                   : 0
[  401.435203][    T0]
[  401.435308][    T0] rt_rq[0]:
[  401.435394][    T0]   .rt_nr_running                 : 0
[  401.435481][    T0]   .rt_nr_migratory               : 0
[  401.435569][    T0]   .rt_throttled                  : 0
[  401.435678][    T0]   .rt_time                       : 0.000000
[  401.435772][    T0]   .rt_runtime                    : 950.000000
[  401.435942][    T0]
[  401.436017][    T0] dl_rq[0]:
[  401.436116][    T0]   .dl_nr_running                 : 0
[  401.436212][    T0]   .dl_nr_migratory               : 0
[  401.436301][    T0]   .dl_bw->bw                     : 996147
[  401.436386][    T0]   .dl_bw->total_bw               : 0
[  401.436476][    T0]
[  401.436560][    T0] runnable tasks:
[  401.436614][    T0]  S            task   PID         tree-key  switches  prio     wait-time             sum-exec        sum-sleep
[  401.436687][    T0] -------------------------------------------------------------------------------------------------------------
[  401.436875][    T0]  D       swapper/0     1        84.404220        26   120         0.000000        69.398526         0.000000 0 0 /
[  401.437357][    T0]  S        kthreadd     2        80.816484        18   120         0.000000        24.915098         0.000000 0 0 /
[  401.437554][    T0]  I          rcu_gp     3        26.218815         2   100         0.000000         1.771584         0.000000 0 0 /
[  401.437698][    T0]  I      rcu_par_gp     4        28.434004         2   100         0.000000         0.138216         0.000000 0 0 /
[  401.437853][    T0]  I     kworker/0:0     5        86.357041         8   120         0.000000         7.010072         0.000000 0 0 /
[  401.438002][    T0]  I    kworker/0:0H     6        32.481348         2   100         0.000000         0.097112         0.000000 0 0 /
[  401.438144][    T0]  I    kworker/u8:0     7        32.635000         2   120         0.000000         0.086604         0.000000 0 0 /
[  401.438368][    T0]  I    mm_percpu_wq     8        34.185643         2   100         0.000000         0.118036         0.000000 0 0 /
[  401.438544][    T0]  S     ksoftirqd/0     9        36.753489         3   120         0.000000         0.617720         0.000000 0 0 /
[  401.438686][    T0]  I       rcu_sched    10        79.402224         7   120         0.000000         9.592868         0.000000 0 0 /
[  401.438890][    T0]  S     migration/0    11         0.100901        98     0         0.000000        40.445210         0.000000 0 0 /
[  401.439041][    T0]  D     kworker/0:1    12        83.770462         4   120         0.000000         4.564404         0.000000 0 0 /
[  401.439230][    T0]  S         cpuhp/0    13        54.369911         3   120         0.000000         1.278230         0.000000 0 0 /
[  401.439412][    T0]  I     kworker/0:2    19       278.095255       384   120         0.000000       187.691038         0.000000 0 0 /
[  401.439939][    T0]
[  401.440140][    T0] cpu#1
[  401.440250][    T0]   .nr_running                    : 0
[  401.440331][    T0]   .nr_switches                   : 196
[  401.440434][    T0]   .nr_uninterruptible            : 0
[  401.440500][    T0]   .next_balance                  : 4294.937296
[  401.440552][    T0]   .curr->pid                     : 0
[  401.440631][    T0]   .clock                         : 401422.799786
[  401.440689][    T0]   .clock_task                    : 401422.799786
[  401.440777][    T0]   .avg_idle                      : 1000000
[  401.440865][    T0]   .max_idle_balance_cost         : 500000
[  401.440945][    T0]
[  401.441027][    T0] rt_rq[1]:
[  401.441076][    T0]   .rt_nr_running                 : 0
[  401.441127][    T0]   .rt_nr_migratory               : 0
[  401.441197][    T0]   .rt_throttled                  : 0
[  401.441255][    T0]   .rt_time                       : 0.000000
[  401.441315][    T0]   .rt_runtime                    : 950.000000
[  401.441395][    T0]
[  401.441445][    T0] dl_rq[1]:
[  401.441497][    T0]   .dl_nr_running                 : 0
[  401.441555][    T0]   .dl_nr_migratory               : 0
[  401.441609][    T0]   .dl_bw->bw                     : 996147
[  401.441665][    T0]   .dl_bw->total_bw               : 0
[  401.441717][    T0]
[  401.441755][    T0] runnable tasks:
[  401.441817][    T0]  S            task   PID         tree-key  switches  prio     wait-time             sum-exec        sum-sleep
[  401.441888][    T0] -------------------------------------------------------------------------------------------------------------
[  401.441995][    T0]  S         cpuhp/1    14         7.177520         3   120         0.000000        11.790932         0.000000 0 0 /
[  401.442211][    T0]  S     migration/1    15         0.000000        98     0         0.000000        39.188082         0.000000 0 0 /
[  401.442383][    T0]  S     ksoftirqd/1    16         0.312838         3   120         0.000000         3.826106         0.000000 0 0 /
[  401.442615][    T0]  I     kworker/1:0    17        -3.720346         3   120         0.000000         0.592222         0.000000 0 0 /
[  401.442879][    T0]  I    kworker/1:0H    18        -4.047847         3   100         0.000000         0.211754         0.000000 0 0 /
[  401.443037][    T0]
[  401.443407][    T0]
[  401.443407][    T0] Showing all locks held in the system:
[  401.443722][    T0] 2 locks held by swapper/0/1:
[  401.443859][    T0]  #0: c000000000f6be60 (cpu_add_remove_lock){....}-{3:3}, at: cpu_up+0xcc/0x140
[  401.444836][    T0]  #1: c000000000f6bdd0 (cpu_hotplug_lock){....}-{0:0}, at: _cpu_up+0x68/0x280
[  401.445096][    T0] 5 locks held by kworker/0:1/12:
[  401.445223][    T0]  #0: c000000006070138 ((wq_completion)events){....}-{0:0}, at: process_one_work+0x278/0x530
[  401.445408][    T0]  #1: c0000000062efcc0 ((optimizing_work).work){....}-{0:0}, at: process_one_work+0x278/0x530
[  401.445528][    T0]  #2: c00000000107de60 (kprobe_mutex){....}-{3:3}, at: kprobe_optimizer+0x50/0x470
[  401.445610][    T0]  #3: c000000000f6bdd0 (cpu_hotplug_lock){....}-{0:0}, at: kprobe_optimizer+0x58/0x470
[  401.445746][    T0]  #4: c000000000f6d018 (text_mutex){....}-{3:3}, at: kprobe_optimizer+0x70/0x470
[  401.445895][    T0]
[  401.445934][    T0] =============================================
[  401.445934][    T0]
[  401.446043][    T0] Showing busy workqueues and worker pools:
[  401.446139][    T0] workqueue events: flags=0x0
[  401.446275][    T0]   pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 refcnt=2
[  401.446602][    T0]     in-flight: 12:kprobe_optimizer
[  401.447083][    T0] pool 0: cpus=0 node=0 flags=0x0 nice=0 hung=0s workers=3 idle: 19 5



More information about the Linuxppc-dev mailing list