linux-kernel - [rbtree_test_init] watchdog: BUG: soft lockup

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20171121111022.4petko2v2wnovzii@wfg-t540p.sh.intel.com>
Date:   Tue, 21 Nov 2017 19:10:22 +0800
From:   Fengguang Wu <fengguang.wu@...el.com>
To:     Davidlohr Bueso <dave@...olabs.net>
Cc:     Linus Torvalds <torvalds@...ux-foundation.org>,
        Andrew Morton <akpm@...ux-foundation.org>,
        linux-kernel@...r.kernel.org, lkp@...org
Subject: [rbtree_test_init] watchdog: BUG: soft lockup - CPU#0 stuck for 22s!
 [swapper:1]

Hello,

FYI this happens in mainline kernel 4.14.0-03453-ge37e0ee.
It at least dates back to v4.1 .

It occurs in 2 out of 2 boots.

[  112.204889]  -> test 1 (latency of nnodes insert+delete): 500735 cycles
[  112.209353] rcu-torture: rtc: ffffffff8708e420 ver: 1 tfle: 0 rta: 1 rtaf: 0 rtf: 0 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1 barrier: 0/0:0 cbflood: 1
[  112.209404] rcu-torture: Reader Pipe:  2 0 0 0 0 0 0 0 0 0 0
[  112.209467] rcu-torture: Reader Batch:  0 2 0 0 0 0 0 0 0 0 0
[  112.209530] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  140.043368] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper:1]
[  140.044140] CPU: 0 PID: 1 Comm: swapper Not tainted 4.14.0-03453-ge37e0ee #1
[  140.044140] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  140.044140] task: ffff880018538000 task.stack: ffff880018548000
[  140.044140] RIP: 0010:check_memory_region+0x7/0x1da:
check_memory_region_inline at mm/kasan/kasan.c:248
  (inlined by) check_memory_region at mm/kasan/kasan.c:267
[  140.044140] RSP: 0000:ffff88001854fd30 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff11
[  140.044140] RAX: 1ffff10001d87600 RBX: ffffffff85992f18 RCX: ffffffff8127c184
[  140.044140] RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff85a22f20
[  140.044140] RBP: 0000000000000002 R08: fffffbfff0be0d65 R09: fffffbfff0be0d64
[  140.044140] R10: fffffbfff0be0d64 R11: 0000000000000000 R12: 0000000000000000
[  140.044140] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000003
[  140.044140] FS:  0000000000000000(0000) GS:ffffffff83cad000(0000) knlGS:0000000000000000
[  140.044140] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  140.044140] CR2: 0000000000000000 CR3: 0000000003c1e000 CR4: 00000000000006b0
[  140.044140] Call Trace:
[  140.044140]  __asan_loadN+0x19/0x21
[  140.044140]  ftrace_likely_update+0x32/0xc3:
ftrace_likely_update at kernel/trace/trace_branch.c:209
[  140.044140]  ? augment_recompute+0x14b/0x14b:
augment_callbacks_rotate at lib/rbtree_test.c:97
[  140.044140]  __rb_insert_augmented+0x8d/0x639:
__rb_insert at lib/rbtree.c:110
  (inlined by) __rb_insert_augmented at lib/rbtree.c:495
[  140.044140]  rbtree_test_init+0xbfb/0x1407:
rb_insert_augmented_cached at include/linux/rbtree_augmented.h:70
  (inlined by) insert_augmented_cached at lib/rbtree_test.c:148
  (inlined by) rbtree_test_init at lib/rbtree_test.c:371
[  140.044140]  ? glob_init+0x23f/0x23f:
rbtree_test_init at lib/rbtree_test.c:245
[  140.044140]  do_one_initcall+0x1ef/0x4ab:
do_one_initcall at init/main.c:828
[  140.044140]  ? start_kernel+0xd4e/0xd4e:
do_one_initcall at init/main.c:817
[  140.044140]  kernel_init_freeable+0x2d3/0x4cd:
do_initcall_level at init/main.c:894
  (inlined by) do_initcalls at init/main.c:902
  (inlined by) do_basic_setup at init/main.c:920
  (inlined by) kernel_init_freeable at init/main.c:1068
[  140.044140]  ? rest_init+0x153/0x153:
kernel_init at init/main.c:992
[  140.044140]  kernel_init+0x13/0x2c4:
kernel_init at init/main.c:995
[  140.044140]  ? rest_init+0x153/0x153:
kernel_init at init/main.c:992
[  140.044140]  ret_from_fork+0x1f/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:443
[  140.044140] Code: 85 dc 05 48 89 c7 48 b8 00 00 00 00 00 ea ff ff 48 c1 e7 06 48 01 c7 e8 b1 ff ff ff 48 ff 05 db 85 dc 05 c3 48 ff 05 a3 86 dc 05 <48> 85 f6 0f 84 c9 01 00 00 48 b8 ff ff ff ff ff 7f ff ff 55 44
[  140.044140] Kernel panic - not syncing: softlockup: hung tasks
[  140.044140] CPU: 0 PID: 1 Comm: swapper Tainted: G             L  4.14.0-03453-ge37e0ee #1
[  140.044140] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  140.044140] Call Trace:
[  140.044140]  <IRQ>
[  140.044140]  show_stack+0x94/0x9d:
show_stack at arch/x86/kernel/dumpstack.c:178
[  140.044140]  dump_stack+0x2a/0x39:
__dump_stack at lib/dump_stack.c:17
  (inlined by) dump_stack at lib/dump_stack.c:63
[  140.044140]  panic+0x245/0x5c5:
panic at kernel/panic.c:192
[  140.044140]  ? from_kuid_munged+0x6d/0x6d
[  140.044140]  ? watchdog_timer_fn+0x454/0x4ab:
watchdog_timer_fn at kernel/watchdog.c:442
[  140.044140]  watchdog_timer_fn+0x47f/0x4ab:
watchdog_timer_fn at kernel/watchdog.c:444
[  140.044140]  ? watchdog+0x27/0x27:
watchdog_timer_fn at kernel/watchdog.c:340
[  140.044140]  hrtimer_run_queues+0x4a9/0x7fa:
__read_once_size at include/linux/compiler.h:178
  (inlined by) atomic_read at arch/x86/include/asm/atomic.h:27
  (inlined by) static_key_count at include/linux/jump_label.h:191
  (inlined by) static_key_false at include/linux/jump_label.h:201
  (inlined by) trace_hrtimer_expire_exit at include/trace/events/timer.h:255
  (inlined by) __run_hrtimer at kernel/time/hrtimer.c:1212
  (inlined by) __hrtimer_run_queues at kernel/time/hrtimer.c:1275
  (inlined by) hrtimer_run_queues at kernel/time/hrtimer.c:1414
[  140.044140]  ? hrtimer_cancel+0x6f/0x6f:
hrtimer_run_queues at kernel/time/hrtimer.c:1393
[  140.044140]  ? account_system_index_time+0x9d/0xab:
account_system_index_time at kernel/sched/cputime.c:175
[  140.044140]  ? account_system_time+0x137/0x147:
account_system_time at kernel/sched/cputime.c:203
[  140.044140]  run_local_timers+0x1a/0x111:
run_local_timers at kernel/time/timer.c:1694
[  140.044140]  update_process_times+0x30/0xad:
update_process_times at kernel/time/timer.c:1624
[  140.044140]  tick_nohz_handler+0x20c/0x2b2:
tick_nohz_handler at kernel/time/tick-sched.c:1068
[  140.044140]  ? tick_do_update_jiffies64+0x1cc/0x1cc:
tick_nohz_handler at kernel/time/tick-sched.c:1057
[  140.044140]  smp_apic_timer_interrupt+0x245/0x3e8:
local_apic_timer_interrupt at arch/x86/kernel/apic/apic.c:1025
  (inlined by) smp_apic_timer_interrupt at arch/x86/kernel/apic/apic.c:1050
[  140.044140]  apic_timer_interrupt+0x89/0x90:
apic_timer_interrupt at arch/x86/entry/entry_64.S:791
[  140.044140]  </IRQ>
[  140.044140] RIP: 0010:check_memory_region+0x7/0x1da:
check_memory_region_inline at mm/kasan/kasan.c:248
  (inlined by) check_memory_region at mm/kasan/kasan.c:267
[  140.044140] RSP: 0000:ffff88001854fd30 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff11
[  140.044140] RAX: 1ffff10001d87600 RBX: ffffffff85992f18 RCX: ffffffff8127c184
[  140.044140] RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff85a22f20
[  140.044140] RBP: 0000000000000002 R08: fffffbfff0be0d65 R09: fffffbfff0be0d64
[  140.044140] R10: fffffbfff0be0d64 R11: 0000000000000000 R12: 0000000000000000
[  140.044140] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000003
[  140.044140]  ? ftrace_likely_update+0x32/0xc3:
ftrace_likely_update at kernel/trace/trace_branch.c:209
[  140.044140]  __asan_loadN+0x19/0x21
[  140.044140]  ftrace_likely_update+0x32/0xc3:
ftrace_likely_update at kernel/trace/trace_branch.c:209
[  140.044140]  ? augment_recompute+0x14b/0x14b:
augment_callbacks_rotate at lib/rbtree_test.c:97
[  140.044140]  __rb_insert_augmented+0x8d/0x639:
__rb_insert at lib/rbtree.c:110
  (inlined by) __rb_insert_augmented at lib/rbtree.c:495
[  140.044140]  rbtree_test_init+0xbfb/0x1407:
rb_insert_augmented_cached at include/linux/rbtree_augmented.h:70
  (inlined by) insert_augmented_cached at lib/rbtree_test.c:148
  (inlined by) rbtree_test_init at lib/rbtree_test.c:371
[  140.044140]  ? glob_init+0x23f/0x23f:
rbtree_test_init at lib/rbtree_test.c:245
[  140.044140]  do_one_initcall+0x1ef/0x4ab:
do_one_initcall at init/main.c:828
[  140.044140]  ? start_kernel+0xd4e/0xd4e:
do_one_initcall at init/main.c:817
[  140.044140]  kernel_init_freeable+0x2d3/0x4cd:
do_initcall_level at init/main.c:894
  (inlined by) do_initcalls at init/main.c:902
  (inlined by) do_basic_setup at init/main.c:920
  (inlined by) kernel_init_freeable at init/main.c:1068
[  140.044140]  ? rest_init+0x153/0x153:
kernel_init at init/main.c:992
[  140.044140]  kernel_init+0x13/0x2c4:
kernel_init at init/main.c:995
[  140.044140]  ? rest_init+0x153/0x153:
kernel_init at init/main.c:992
[  140.044140]  ret_from_fork+0x1f/0x30:
ret_from_fork at arch/x86/entry/entry_64.S:443
[  140.044140] Kernel Offset: disabled

Attached the full dmesg, kconfig and reproduce scripts.

Thanks,
Fengguang

View attachment "dmesg-vm-vp-quantal-x86_64-43:20171115101550:x86_64-randconfig-ne0-11021012:4.14.0-03453-ge37e0ee:1" of type "text/plain" (39378 bytes)

View attachment ".config" of type "text/plain" (103884 bytes)

View attachment "job-script" of type "text/plain" (3895 bytes)

View attachment "reproduce-vm-vp-quantal-x86_64-43:20171115101550:x86_64-randconfig-ne0-11021012:4.14.0-03453-ge37e0ee:1" of type "text/plain" (1811 bytes)