[rbtree_test_init] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper:1]
From: Fengguang Wu
Date: Mon Nov 06 2017 - 23:50:33 EST
Hi Davidlohr,
Here's a warning in v4.14-rc8 -- it's not necessarily a new bug.
[ 103.655201] xz_dec_test: module loaded
[ 103.655994] xz_dec_test: Create a device node with 'mknod xz_dec_test c 249 0' and write .xz files to it.
[ 103.796051] atomic64_test: passed for i386+ platform with CX8 and with SSE
[ 103.812439] glob: 64 self-tests passed, 0 failed
[ 103.814253] rbtree testing
[ 128.874612] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [swapper:1]
[ 128.874612] CPU: 0 PID: 1 Comm: swapper Not tainted 4.14.0-rc8 #202
[ 128.874612] task: 91a34d40 task.stack: 91a36000
[ 128.874612] EIP: rb_erase+0xf0/0x320
[ 128.874612] EFLAGS: 00200216 CPU: 0
[ 128.874612] EAX: 91a7d784 EBX: 00000000 ECX: 91a7d3ac EDX: 91a7d574
[ 128.874612] ESI: 00000000 EDI: 91a7d85c EBP: 91a37f00 ESP: 91a37eec
[ 128.874612] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 128.874612] CR0: 80050033 CR2: 00000000 CR3: 01c69000 CR4: 00000690
[ 128.874612] Call Trace:
[ 128.874612] rbtree_test_init+0xc7/0x802
[ 128.874612] ? glob_init+0x96/0xab
[ 128.874612] ? irq_poll_setup+0x44/0x44
[ 128.874612] do_one_initcall+0x7e/0x14c
[ 128.874612] ? parse_args+0x120/0x2b0
[ 128.874612] ? kernel_init_freeable+0xdc/0x16f
[ 128.874612] kernel_init_freeable+0xfc/0x16f
[ 128.874612] ? rest_init+0xc0/0xc0
[ 128.874612] kernel_init+0xd/0xf0
[ 128.874612] ret_from_fork+0x19/0x30
[ 128.874612] Code: e2 fc 0f 84 1f 02 00 00 3b 42 08 0f 84 20 02 00 00 89 7a 04 eb ac 90 8d 74 26 00 8b 01 89 19 a8 01 74 9f 31 c9 eb 6f 8d 74 26 00 <f6> 00 01 75 2d 8b 58 08 89 d1 83 c9 01 89 5a 04 89 50 08 89 0b
[ 128.874612] Kernel panic - not syncing: softlockup: hung tasks
[ 128.874612] CPU: 0 PID: 1 Comm: swapper Tainted: G L 4.14.0-rc8 #202
[ 128.874612] Call Trace:
[ 128.874612] dump_stack+0x16/0x1b
[ 128.874612] panic+0x90/0x1cd
[ 128.874612] watchdog_timer_fn+0x1fd/0x200
[ 128.874612] hrtimer_run_queues+0x145/0x310
[ 128.874612] ? watchdog+0x30/0x30
[ 128.874612] run_local_timers+0xd/0x50
[ 128.874612] update_process_times+0x20/0x50
[ 128.874612] tick_nohz_handler+0xa1/0x170
[ 128.874612] smp_apic_timer_interrupt+0x62/0x130
[ 128.874612] apic_timer_interrupt+0x3a/0x40
[ 128.874612] EIP: rb_erase+0xf0/0x320
[ 128.874612] EFLAGS: 00200216 CPU: 0
[ 128.874612] EAX: 91a7d784 EBX: 00000000 ECX: 91a7d3ac EDX: 91a7d574
[ 128.874612] ESI: 00000000 EDI: 91a7d85c EBP: 91a37f00 ESP: 91a37eec
[ 128.874612] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 128.874612] rbtree_test_init+0xc7/0x802
[ 128.874612] ? glob_init+0x96/0xab
[ 128.874612] ? irq_poll_setup+0x44/0x44
[ 128.874612] do_one_initcall+0x7e/0x14c
[ 128.874612] ? parse_args+0x120/0x2b0
[ 128.874612] ? kernel_init_freeable+0xdc/0x16f
[ 128.874612] kernel_init_freeable+0xfc/0x16f
[ 128.874612] ? rest_init+0xc0/0xc0
[ 128.874612] kernel_init+0xd/0xf0
[ 128.874612] ret_from_fork+0x19/0x30
[ 128.874612] Kernel Offset: disabled
[ 56.196198] -> test 3 (latency of inorder traversal): 43214 cycles
[ 56.236854] -> test 4 (latency to fetch first node)
[ 56.238085] non-cached: 417 cycles
[ 56.241088] cached: 58 cycles
[ 57.770508] augmented rbtree testing
[ 80.910049] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper:1]
[ 80.910049] Modules linked in:
[ 80.910049] CPU: 0 PID: 1 Comm: swapper Not tainted 4.14.0-rc8 #65
[ 80.910049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 80.910049] task: ffff880000390040 task.stack: ffff880000398000
[ 80.910049] RIP: 0010:__asan_load4+0x0/0x7e
[ 80.910049] RSP: 0000:ffff88000039fd70 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
[ 80.910049] RAX: 00000000ffffffff RBX: ffff8800188dcd38 RCX: ffff880000390040
[ 80.910049] RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffff8800188dc888
[ 80.910049] RBP: ffff8800188dc890 R08: fffffbfff680f2d4 R09: fffffbfff680f2d3
[ 80.910049] R10: fffffbfff680f2d3 R11: 0000000000000000 R12: 0000000000000000
[ 80.910049] R13: 000000002494b5f1 R14: 0000000030d4b3e4 R15: 00000000ade321a5
[ 80.910049] FS: 0000000000000000(0000) GS:ffffffffb344f000(0000) knlGS:0000000000000000
[ 80.910049] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 80.910049] CR2: 0000000000000000 CR3: 0000000008020000 CR4: 00000000000006b0
[ 80.910049] Call Trace:
[ 80.910049] insert_augmented+0xa7/0x15d
[ 80.910049] rbtree_test_init+0x87c/0x1288
[ 80.910049] ? sg_pool_init+0x317/0x317
[ 80.910049] do_one_initcall+0x14d/0x30f
[ 80.910049] ? initcall_blacklisted+0x1a7/0x1a7
[ 80.910049] ? lock_downgrade+0x279/0x279
[ 80.910049] kernel_init_freeable+0x24a/0x3f6
[ 80.910049] ? rest_init+0x10d/0x10d
[ 80.910049] kernel_init+0x11/0x244
[ 80.910049] ? rest_init+0x10d/0x10d
[ 80.910049] ret_from_fork+0x25/0x30
[ 80.910049] Code: 44 d0 83 e2 01 eb 10 48 c1 e8 03 8a 04 30 84 c0 74 18 38 d0 0f 9e c2 84 d2 74 0f ba 01 00 00 00 be 02 00 00 00 e9 bb 11 00 00 c3 <48> b8 ff ff ff ff ff 7f ff ff 48 8b 0c 24 48 39 c7 76 5e 48 8d
[ 80.910049] Kernel panic - not syncing: softlockup: hung tasks
[ 80.910049] CPU: 0 PID: 1 Comm: swapper Tainted: G L 4.14.0-rc8 #65
[ 80.910049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 80.910049] Call Trace:
[ 80.910049] <IRQ>
[ 80.910049] panic+0x1f4/0x4ab
[ 80.910049] ? __warn+0x1e1/0x1e1
[ 80.910049] ? watchdog+0x1a/0x1a
[ 80.910049] watchdog_timer_fn+0x3c0/0x3ef
[ 80.910049] __hrtimer_run_queues+0x351/0x59e
[ 80.910049] ? __hrtimer_get_remaining+0x8d/0x8d
[ 80.910049] ? read_seqcount_retry+0x2e/0x33
[ 80.910049] ? ktime_get_update_offsets_now+0x178/0x18a
[ 80.910049] hrtimer_interrupt+0xbc/0x2be
[ 80.910049] ? hrtimer_get_next_event+0x94/0x94
[ 80.910049] smp_apic_timer_interrupt+0x199/0x2c1
[ 80.910049] apic_timer_interrupt+0x89/0x90
[ 80.910049] </IRQ>
[ 80.910049] RIP: 0010:__asan_load4+0x0/0x7e
[ 80.910049] RSP: 0000:ffff88000039fd70 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
[ 80.910049] RAX: 00000000ffffffff RBX: ffff8800188dcd38 RCX: ffff880000390040
[ 80.910049] RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffff8800188dc888
[ 80.910049] RBP: ffff8800188dc890 R08: fffffbfff680f2d4 R09: fffffbfff680f2d3
[ 80.910049] R10: fffffbfff680f2d3 R11: 0000000000000000 R12: 0000000000000000
[ 80.910049] R13: 000000002494b5f1 R14: 0000000030d4b3e4 R15: 00000000ade321a5
[ 80.910049] insert_augmented+0xa7/0x15d
[ 80.910049] rbtree_test_init+0x87c/0x1288
[ 80.910049] ? sg_pool_init+0x317/0x317
[ 80.910049] do_one_initcall+0x14d/0x30f
[ 80.910049] ? initcall_blacklisted+0x1a7/0x1a7
[ 80.910049] ? lock_downgrade+0x279/0x279
[ 80.910049] kernel_init_freeable+0x24a/0x3f6
[ 80.910049] ? rest_init+0x10d/0x10d
[ 80.910049] kernel_init+0x11/0x244
[ 80.910049] ? rest_init+0x10d/0x10d
[ 80.910049] ret_from_fork+0x25/0x30
[ 80.910049] Kernel Offset: 0x30600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
Thanks,
Fengguang