INFO: rcu_sched self-detected stall on CPU detected on Linux next 5.4.0-rc7-next-20191112 running on x86_64 device and continuously popped up kernel OTOH, arm64 juno device boot failed without generating any kernel boot log.
Steps to reproduce: 1. boot x86_64 with Linux next 5.4.0-rc7-next-20191112 2. Run "perf test -v"
x86_64 device: Running perf test cases perf test -v ... test child forked, pid 418 mmap size 528384B [ 74.040659] rcu: INFO: rcu_sched self-detected stall on CPU [ 74.046275] rcu: 0-....: (26000 ticks this GP) idle=25a/1/0x4000000000000002 softirq=7882/7882 fqs=6495 [ 74.055873] (t=26007 jiffies g=4793 q=1772) [ 74.060146] NMI backtrace for cpu 0 [ 74.063631] CPU: 0 PID: 418 Comm: perf Not tainted 5.4.0-rc7-next-20191112 #1 [ 74.070754] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 74.078224] Call Trace: [ 74.080669] <IRQ> [ 74.082682] dump_stack+0x7a/0xa5 [ 74.086000] nmi_cpu_backtrace+0x94/0xa0 [ 74.089917] ? lapic_can_unplug_cpu+0xa0/0xa0 [ 74.094270] nmi_trigger_cpumask_backtrace+0x97/0xd0 [ 74.099235] arch_trigger_cpumask_backtrace+0x19/0x20 [ 74.104288] rcu_dump_cpu_stacks+0xaa/0xda [ 74.108385] rcu_sched_clock_irq+0x602/0x890 [ 74.112659] ? raise_softirq+0x10e/0x150 [ 74.116585] update_process_times+0x28/0x50 [ 74.120769] tick_sched_handle+0x38/0x50 [ 74.124686] tick_sched_timer+0x3c/0x80 [ 74.128517] __hrtimer_run_queues+0x11c/0x450 [ 74.132867] ? tick_sched_do_timer+0x60/0x60 [ 74.137133] hrtimer_interrupt+0xe7/0x240 [ 74.141146] smp_apic_timer_interrupt+0x86/0x220 [ 74.145763] apic_timer_interrupt+0xf/0x20 [ 74.149853] </IRQ> [ 74.151951] RIP: 0010:irq_work_sync+0x51/0x60 [ 74.156301] Code: 10 08 00 00 85 c0 75 22 80 3d 22 4d 97 01 00 75 19 48 c7 c7 08 98 ba a2 c6 05 12 4d 97 01 01 e8 75 9f eb ff 0f 0b eb 02 f3 90 <8b> 03 a8 02 75 f8 5b 5d c3 66 0f 1f 44 00 00 55 48 89 e5 41 55 41 [ 74.175038] RSP: 0018:ffffab53c0807dc0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13 [ 74.182603] RAX: 0000000000000002 RBX: ffff93651688ac00 RCX: 0000000000000001 [ 74.189727] RDX: 0000000000000000 RSI: ffff93651688aa98 RDI: ffff93651688ac00 [ 74.196850] RBP: ffffab53c0807dc8 R08: 0000000000000000 R09: 0000000000000000 [ 74.203975] R10: ffffab53c0807df8 R11: 0000000000000000 R12: ffff93651688aa38 [ 74.211100] R13: ffffab53c0807b60 R14: ffff93651d17a3e0 R15: ffff93651688aab8 [ 74.218237] _free_event+0x16/0x2f0 [ 74.221732] put_event+0x15/0x20 [ 74.224958] perf_event_release_kernel+0x1f6/0x3e0 [ 74.229751] perf_release+0x10/0x20 [ 74.233242] __fput+0xd1/0x270 [ 74.236303] ____fput+0xe/0x10 [ 74.239360] task_work_run+0x90/0xc0 [ 74.242933] exit_to_usermode_loop+0xf0/0x100 [ 74.247290] do_syscall_64+0x18d/0x1d0 [ 74.251044] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 74.256096] RIP: 0033:0x7f8ad5fe1641 [ 74.259673] Code: f7 d8 64 89 02 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 8b 05 aa cd 20 00 85 c0 75 16 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 3f c3 66 0f 1f 44 00 00 53 89 fb 48 83 ec 10 [ 74.278409] RSP: 002b:00007fffb5490998 EFLAGS: 00000246 ORIG_RAX: 0000000000000003 [ 74.285967] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f8ad5fe1641 [ 74.293090] RDX: 0000000000000000 RSI: 0000000000041000 RDI: 000000000000000b [ 74.300215] RBP: 00007fffb54909d0 R08: 00007f8ad6fec468 R09: 00007f8ad6fec470 [ 74.307337] R10: 000000000000058d R11: 0000000000000246 R12: 00000000022a8fd0 [ 74.314464] R13: 0000000000000000 R14: 00000000022a7e50 R15: 0000000000000003 [ 78.449712] rcu: INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 26496 jiffies s: 217 root: 0x1/. [ 78.460269] rcu: blocking rcu_node structures: [ 78.464803] Task dump for CPU 0: [ 78.468051] perf R running task 14144 418 413 0x90000088 [ 78.475145] Call Trace: [ 78.477611] ? retint_kernel+0x10/0x10 [ 78.481418] ? irq_work_sync+0x51/0x60 [ 78.485217] ? _free_event+0x16/0x2f0 [ 78.488892] ? put_event+0x15/0x20 [ 78.492315] ? perf_event_release_kernel+0x1f6/0x3e0 [ 78.497300] ? perf_release+0x10/0x20 [ 78.501007] ? __fput+0xd1/0x270 [ 78.504260] ? ____fput+0xe/0x10 [ 78.507543] ? task_work_run+0x90/0xc0 [ 78.511348] ? exit_to_usermode_loop+0xf0/0x100 [ 78.515922] ? do_syscall_64+0x18d/0x1d0 [ 78.519866] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 89.200374] ------------[ cut here ]------------ [ 89.205050] NETDEV WATCHDOG: eth0 (igb): transmit queue 2 timed out [ 89.211363] WARNING: CPU: 1 PID: 0 at /usr/src/kernel/net/sched/sch_generic.c:443 dev_watchdog+0x2b7/0x2f0 [ 89.221013] Modules linked in: x86_pkg_temp_thermal fuse [ 89.226324] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.4.0-rc7-next-20191112 #1 [ 89.233709] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 89.241180] RIP: 0010:dev_watchdog+0x2b7/0x2f0 [ 89.245625] Code: 08 5e e9 5c ff ff ff 4c 89 ef c6 05 d1 54 02 01 01 e8 4d 5b fa ff 89 d9 48 89 c2 4c 89 ee 48 c7 c7 f8 66 cb a2 e8 a9 a5 56 ff <0f> 0b e9 3f ff ff ff e8 cd 58 5f ff 85 c0 75 c1 48 c7 c2 70 58 b9 [ 89.264369] RSP: 0018:ffffab53c003ce28 EFLAGS: 00010286 [ 89.269587] RAX: 0000000000000000 RBX: 0000000000000002 RCX: 0000000000000000 [ 89.276710] RDX: 0000000000000001 RSI: ffff93651fa96788 RDI: ffff93651fa96788 [ 89.283834] RBP: ffffab53c003ce58 R08: 0000000000000000 R09: 0000000000000000 [ 89.290957] R10: 0000000000000000 R11: 0000000000000000 R12: ffff93651b3fbb00 [ 89.298081] R13: ffff93651ac40000 R14: ffff93651ac404b8 R15: 0000000000000008 [ 89.305205] FS: 0000000000000000(0000) GS:ffff93651fa80000(0000) knlGS:0000000000000000 [ 89.313282] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 89.319020] CR2: 00005647ea459454 CR3: 000000020a210006 CR4: 00000000003606e0 [ 89.326143] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 89.333266] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 89.340403] Call Trace: [ 89.342853] <IRQ> [ 89.344867] ? qdisc_destroy+0x170/0x170 [ 89.348792] call_timer_fn+0x9d/0x2b0 [ 89.352459] ? qdisc_destroy+0x170/0x170 [ 89.356403] run_timer_softirq+0x482/0x550 [ 89.360499] ? __do_softirq+0x9b/0x43a [ 89.364254] __do_softirq+0xc7/0x43a [ 89.367830] ? hrtimer_interrupt+0x11a/0x240 [ 89.372097] irq_exit+0xb8/0xc0 [ 89.375239] smp_apic_timer_interrupt+0xa7/0x220 [ 89.379851] apic_timer_interrupt+0xf/0x20 [ 89.383948] </IRQ> [ 89.386046] RIP: 0010:cpuidle_enter_state+0xc9/0x430 [ 89.391005] Code: 00 00 31 ff e8 e8 0d 6c ff 80 7d d3 00 74 12 9c 58 f6 c4 02 0f 85 37 03 00 00 31 ff e8 30 50 73 ff e8 0b ae 79 ff fb 45 85 ed <0f> 88 cd 02 00 00 49 63 cd 4c 2b 7d c8 48 8d 14 cd 00 00 00 00 48 [ 89.409748] RSP: 0018:ffffab53c00a7e48 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 [ 89.417305] RAX: ffff93651dea1780 RBX: ffff93651bcf2c00 RCX: 0000000000000000 [ 89.424430] RDX: 0000000000000046 RSI: 0000000000000006 RDI: ffff93651dea1780 [ 89.431562] RBP: ffffab53c00a7e88 R08: 0000000000000002 R09: 0000000000000000 [ 89.438686] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffffa2f09ac0 [ 89.445809] R13: 0000000000000003 R14: ffffffffa2f09c28 R15: 00000014c4c17efb [ 89.452940] ? cpuidle_enter_state+0xc5/0x430 [ 89.457304] cpuidle_enter+0x2e/0x40 [ 89.460883] call_cpuidle+0x23/0x40 [ 89.464394] do_idle+0x1f0/0x270 [ 89.467625] cpu_startup_entry+0x1d/0x20 [ 89.471551] start_secondary+0x162/0x1b0 [ 89.475476] secondary_startup_64+0xb6/0xc0 [ 89.479665] irq event stamp: 3279897 [ 89.483241] hardirqs last enabled at (3279896): [<ffffffffa156f858>] console_unlock+0x458/0x5c0 [ 89.492018] hardirqs last disabled at (3279897): [<ffffffffa1401e2b>] trace_hardirqs_off_thunk+0x1a/0x1c [ 89.501483] softirqs last enabled at (3279872): [<ffffffffa14fe0a1>] _local_bh_enable+0x21/0x40 [ 89.510260] softirqs last disabled at (3279873): [<ffffffffa14fec08>] irq_exit+0xb8/0xc0 [ 89.518351] ---[ end trace 9005e5b88ce17ad7 ]---
full test log, https://lkft.validation.linaro.org/scheduler/job/1006507#L1330
Best regards Naresh Kamboju
On Tue, Nov 12, 2019 at 10:38:10PM +0530, Naresh Kamboju wrote:
INFO: rcu_sched self-detected stall on CPU detected on Linux next 5.4.0-rc7-next-20191112 running on x86_64 device and continuously popped up kernel OTOH, arm64 juno device boot failed without generating any kernel boot log.
Juno is booting fine in -next in KernelCI:
https://kernelci.org/boot/id/5dca98dd59b514e08a138e08/
Some config difference perhaps?
On Tue, 12 Nov 2019 at 22:48, Mark Brown broonie@kernel.org wrote:
On Tue, Nov 12, 2019 at 10:38:10PM +0530, Naresh Kamboju wrote:
INFO: rcu_sched self-detected stall on CPU detected on Linux next 5.4.0-rc7-next-20191112 running on x86_64 device and continuously popped up kernel OTOH, arm64 juno device boot failed without generating any kernel boot log.
Juno is booting fine in -next in KernelCI:
Thanks for confirming that.
https://kernelci.org/boot/id/5dca98dd59b514e08a138e08/Some config difference perhaps?
Yes. There are extra kernel config fragments from selftests, LTP, perf and few more.
Juno build metadata: git branch: master git repo: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git git commit: fc6d6db1df2cb11bbecc542d67885742e75b4b07 git describe: next-20191112 make_kernelversion: 5.4.0-rc7 kernel-config: http://snapshots.linaro.org/openembedded/lkft/lkft/sumo/juno/lkft/linux-next...
- Naresh
+CC x86@vger.kernel.org
On Tue, 12 Nov 2019 at 22:38, Naresh Kamboju naresh.kamboju@linaro.org wrote:
INFO: rcu_sched self-detected stall on CPU detected on Linux next 5.4.0-rc7-next-20191112 running on x86_64 device and continuously popped up kernel OTOH, arm64 juno device boot failed without generating any kernel boot log.
Steps to reproduce:
- boot x86_64 with Linux next 5.4.0-rc7-next-20191112
- Run "perf test -v"
x86_64 device: Running perf test cases perf test -v ... test child forked, pid 418 mmap size 528384B [ 74.040659] rcu: INFO: rcu_sched self-detected stall on CPU [ 74.046275] rcu: 0-....: (26000 ticks this GP) idle=25a/1/0x4000000000000002 softirq=7882/7882 fqs=6495 [ 74.055873] (t=26007 jiffies g=4793 q=1772) [ 74.060146] NMI backtrace for cpu 0 [ 74.063631] CPU: 0 PID: 418 Comm: perf Not tainted 5.4.0-rc7-next-20191112 #1 [ 74.070754] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 74.078224] Call Trace: [ 74.080669] <IRQ> [ 74.082682] dump_stack+0x7a/0xa5 [ 74.086000] nmi_cpu_backtrace+0x94/0xa0 [ 74.089917] ? lapic_can_unplug_cpu+0xa0/0xa0 [ 74.094270] nmi_trigger_cpumask_backtrace+0x97/0xd0 [ 74.099235] arch_trigger_cpumask_backtrace+0x19/0x20 [ 74.104288] rcu_dump_cpu_stacks+0xaa/0xda [ 74.108385] rcu_sched_clock_irq+0x602/0x890 [ 74.112659] ? raise_softirq+0x10e/0x150 [ 74.116585] update_process_times+0x28/0x50 [ 74.120769] tick_sched_handle+0x38/0x50 [ 74.124686] tick_sched_timer+0x3c/0x80 [ 74.128517] __hrtimer_run_queues+0x11c/0x450 [ 74.132867] ? tick_sched_do_timer+0x60/0x60 [ 74.137133] hrtimer_interrupt+0xe7/0x240 [ 74.141146] smp_apic_timer_interrupt+0x86/0x220 [ 74.145763] apic_timer_interrupt+0xf/0x20 [ 74.149853] </IRQ> [ 74.151951] RIP: 0010:irq_work_sync+0x51/0x60 [ 74.156301] Code: 10 08 00 00 85 c0 75 22 80 3d 22 4d 97 01 00 75 19 48 c7 c7 08 98 ba a2 c6 05 12 4d 97 01 01 e8 75 9f eb ff 0f 0b eb 02 f3 90 <8b> 03 a8 02 75 f8 5b 5d c3 66 0f 1f 44 00 00 55 48 89 e5 41 55 41 [ 74.175038] RSP: 0018:ffffab53c0807dc0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13 [ 74.182603] RAX: 0000000000000002 RBX: ffff93651688ac00 RCX: 0000000000000001 [ 74.189727] RDX: 0000000000000000 RSI: ffff93651688aa98 RDI: ffff93651688ac00 [ 74.196850] RBP: ffffab53c0807dc8 R08: 0000000000000000 R09: 0000000000000000 [ 74.203975] R10: ffffab53c0807df8 R11: 0000000000000000 R12: ffff93651688aa38 [ 74.211100] R13: ffffab53c0807b60 R14: ffff93651d17a3e0 R15: ffff93651688aab8 [ 74.218237] _free_event+0x16/0x2f0 [ 74.221732] put_event+0x15/0x20 [ 74.224958] perf_event_release_kernel+0x1f6/0x3e0 [ 74.229751] perf_release+0x10/0x20 [ 74.233242] __fput+0xd1/0x270 [ 74.236303] ____fput+0xe/0x10 [ 74.239360] task_work_run+0x90/0xc0 [ 74.242933] exit_to_usermode_loop+0xf0/0x100 [ 74.247290] do_syscall_64+0x18d/0x1d0 [ 74.251044] entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 74.256096] RIP: 0033:0x7f8ad5fe1641 [ 74.259673] Code: f7 d8 64 89 02 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 8b 05 aa cd 20 00 85 c0 75 16 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 3f c3 66 0f 1f 44 00 00 53 89 fb 48 83 ec 10 [ 74.278409] RSP: 002b:00007fffb5490998 EFLAGS: 00000246 ORIG_RAX: 0000000000000003 [ 74.285967] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f8ad5fe1641 [ 74.293090] RDX: 0000000000000000 RSI: 0000000000041000 RDI: 000000000000000b [ 74.300215] RBP: 00007fffb54909d0 R08: 00007f8ad6fec468 R09: 00007f8ad6fec470 [ 74.307337] R10: 000000000000058d R11: 0000000000000246 R12: 00000000022a8fd0 [ 74.314464] R13: 0000000000000000 R14: 00000000022a7e50 R15: 0000000000000003 [ 78.449712] rcu: INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 0-... } 26496 jiffies s: 217 root: 0x1/. [ 78.460269] rcu: blocking rcu_node structures: [ 78.464803] Task dump for CPU 0: [ 78.468051] perf R running task 14144 418 413 0x90000088 [ 78.475145] Call Trace: [ 78.477611] ? retint_kernel+0x10/0x10 [ 78.481418] ? irq_work_sync+0x51/0x60 [ 78.485217] ? _free_event+0x16/0x2f0 [ 78.488892] ? put_event+0x15/0x20 [ 78.492315] ? perf_event_release_kernel+0x1f6/0x3e0 [ 78.497300] ? perf_release+0x10/0x20 [ 78.501007] ? __fput+0xd1/0x270 [ 78.504260] ? ____fput+0xe/0x10 [ 78.507543] ? task_work_run+0x90/0xc0 [ 78.511348] ? exit_to_usermode_loop+0xf0/0x100 [ 78.515922] ? do_syscall_64+0x18d/0x1d0 [ 78.519866] ? entry_SYSCALL_64_after_hwframe+0x49/0xbe [ 89.200374] ------------[ cut here ]------------ [ 89.205050] NETDEV WATCHDOG: eth0 (igb): transmit queue 2 timed out [ 89.211363] WARNING: CPU: 1 PID: 0 at /usr/src/kernel/net/sched/sch_generic.c:443 dev_watchdog+0x2b7/0x2f0 [ 89.221013] Modules linked in: x86_pkg_temp_thermal fuse [ 89.226324] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.4.0-rc7-next-20191112 #1 [ 89.233709] Hardware name: Supermicro SYS-5019S-ML/X11SSH-F, BIOS 2.0b 07/27/2017 [ 89.241180] RIP: 0010:dev_watchdog+0x2b7/0x2f0 [ 89.245625] Code: 08 5e e9 5c ff ff ff 4c 89 ef c6 05 d1 54 02 01 01 e8 4d 5b fa ff 89 d9 48 89 c2 4c 89 ee 48 c7 c7 f8 66 cb a2 e8 a9 a5 56 ff <0f> 0b e9 3f ff ff ff e8 cd 58 5f ff 85 c0 75 c1 48 c7 c2 70 58 b9 [ 89.264369] RSP: 0018:ffffab53c003ce28 EFLAGS: 00010286 [ 89.269587] RAX: 0000000000000000 RBX: 0000000000000002 RCX: 0000000000000000 [ 89.276710] RDX: 0000000000000001 RSI: ffff93651fa96788 RDI: ffff93651fa96788 [ 89.283834] RBP: ffffab53c003ce58 R08: 0000000000000000 R09: 0000000000000000 [ 89.290957] R10: 0000000000000000 R11: 0000000000000000 R12: ffff93651b3fbb00 [ 89.298081] R13: ffff93651ac40000 R14: ffff93651ac404b8 R15: 0000000000000008 [ 89.305205] FS: 0000000000000000(0000) GS:ffff93651fa80000(0000) knlGS:0000000000000000 [ 89.313282] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 89.319020] CR2: 00005647ea459454 CR3: 000000020a210006 CR4: 00000000003606e0 [ 89.326143] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 89.333266] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 89.340403] Call Trace: [ 89.342853] <IRQ> [ 89.344867] ? qdisc_destroy+0x170/0x170 [ 89.348792] call_timer_fn+0x9d/0x2b0 [ 89.352459] ? qdisc_destroy+0x170/0x170 [ 89.356403] run_timer_softirq+0x482/0x550 [ 89.360499] ? __do_softirq+0x9b/0x43a [ 89.364254] __do_softirq+0xc7/0x43a [ 89.367830] ? hrtimer_interrupt+0x11a/0x240 [ 89.372097] irq_exit+0xb8/0xc0 [ 89.375239] smp_apic_timer_interrupt+0xa7/0x220 [ 89.379851] apic_timer_interrupt+0xf/0x20 [ 89.383948] </IRQ> [ 89.386046] RIP: 0010:cpuidle_enter_state+0xc9/0x430 [ 89.391005] Code: 00 00 31 ff e8 e8 0d 6c ff 80 7d d3 00 74 12 9c 58 f6 c4 02 0f 85 37 03 00 00 31 ff e8 30 50 73 ff e8 0b ae 79 ff fb 45 85 ed <0f> 88 cd 02 00 00 49 63 cd 4c 2b 7d c8 48 8d 14 cd 00 00 00 00 48 [ 89.409748] RSP: 0018:ffffab53c00a7e48 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff13 [ 89.417305] RAX: ffff93651dea1780 RBX: ffff93651bcf2c00 RCX: 0000000000000000 [ 89.424430] RDX: 0000000000000046 RSI: 0000000000000006 RDI: ffff93651dea1780 [ 89.431562] RBP: ffffab53c00a7e88 R08: 0000000000000002 R09: 0000000000000000 [ 89.438686] R10: 0000000000000000 R11: 0000000000000000 R12: ffffffffa2f09ac0 [ 89.445809] R13: 0000000000000003 R14: ffffffffa2f09c28 R15: 00000014c4c17efb [ 89.452940] ? cpuidle_enter_state+0xc5/0x430 [ 89.457304] cpuidle_enter+0x2e/0x40 [ 89.460883] call_cpuidle+0x23/0x40 [ 89.464394] do_idle+0x1f0/0x270 [ 89.467625] cpu_startup_entry+0x1d/0x20 [ 89.471551] start_secondary+0x162/0x1b0 [ 89.475476] secondary_startup_64+0xb6/0xc0 [ 89.479665] irq event stamp: 3279897 [ 89.483241] hardirqs last enabled at (3279896): [<ffffffffa156f858>] console_unlock+0x458/0x5c0 [ 89.492018] hardirqs last disabled at (3279897): [<ffffffffa1401e2b>] trace_hardirqs_off_thunk+0x1a/0x1c [ 89.501483] softirqs last enabled at (3279872): [<ffffffffa14fe0a1>] _local_bh_enable+0x21/0x40 [ 89.510260] softirqs last disabled at (3279873): [<ffffffffa14fec08>] irq_exit+0xb8/0xc0 [ 89.518351] ---[ end trace 9005e5b88ce17ad7 ]---
full test log, https://lkft.validation.linaro.org/scheduler/job/1006507#L1330
Best regards Naresh Kamboju
Hi Frederic,
FYI,
On Tue, 12 Nov 2019 at 22:38, Naresh Kamboju naresh.kamboju@linaro.org wrote:
INFO: rcu_sched self-detected stall on CPU detected on Linux next 5.4.0-rc7-next-20191112 running on x86_64 device and continuously popped up kernel.
Steps to reproduce:
- boot x86_64 with Linux next 5.4.0-rc7-next-20191112
- Run "perf test -v"
x86_64 device: Running perf test cases perf test -v ... test child forked, pid 418 mmap size 528384B [ 74.040659] rcu: INFO: rcu_sched self-detected stall on CPU [ 74.046275] rcu: 0-....: (26000 ticks this GP) idle=25a/1/0x4000000000000002 softirq=7882/7882 fqs=6495
[ 74.151951] RIP: 0010:irq_work_sync+0x51/0x60
Thanks for providing fix patch. [PATCH] irq_work: Fix IRQ_WORK_BUZY bit clearing
Applied this patch and tested perf test on x86_64 and reported issue is gone.
ref: https://lore.kernel.org/lkml/20191113171201.14032-1-frederic@kernel.org/T/#u
- Naresh
-
Mark Brown -
Naresh Kamboju