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 for Android: free password hash cracker in your pocket
[<prev] [next>] [day] [month] [year] [list]
Date:   Thu, 19 Apr 2018 10:46:58 +0800
From:   Fengguang Wu <fengguang.wu@...el.com>
To:     dri-devel@...ts.freedesktop.org
Cc:     Daniel Vetter <daniel.vetter@...ll.ch>,
        David Airlie <airlied@...ux.ie>,
        Chris Wilson <chris@...is-wilson.co.uk>,
        linux-kernel@...r.kernel.org, lkp@...org
Subject: [test_drm_mm_init] watchdog: BUG: soft lockup - CPU#0 stuck for 22s!
 [swapper/0:1]

Hello,

FYI this happens in mainline kernel 4.17.0-rc1.
It dates back to at least v4.11 .

It occurs in 2 out of 3 boots.

[ 1043.919758] rcu-torture: Free-Block Circulation:  669 668 667 666 662 661 660 659 658 657 0
[ 1109.691598] rcu-torture: rtc: 000000003d6da35c ver: 685 tfle: 0 rta: 685 rtaf: 0 rtf: 674 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 29429 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=250) barrier: 0/0:0 cbflood: 129
[ 1109.739392] rcu-torture: Reader Pipe:  23942278 7 0 0 0 0 0 0 0 0 0
[ 1109.750932] rcu-torture: Reader Batch:  23895152 47133 0 0 0 0 0 0 0 0 0
[ 1109.763056] rcu-torture: Free-Block Circulation:  684 684 683 682 681 680 679 678 677 676 0
[ 1144.200304] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:1]
[ 1144.229662] irq event stamp: 14402106
[ 1144.229662] hardirqs last  enabled at (14402105): [<ffffffffb1400abd>] restore_regs_and_return_to_kernel+0x0/0x33:
						restore_regs_and_return_to_kernel at arch/x86/entry/entry_64.S:720
[ 1144.245638] hardirqs last disabled at (14402106): [<ffffffffb140098a>] interrupt_entry+0xea/0x120:
						interrupt_entry at arch/x86/entry/entry_64.S:627
[ 1144.261617] softirqs last  enabled at (14390978): [<ffffffffb1600495>] __do_softirq+0x495/0x550
[ 1144.277763] softirqs last disabled at (14390969): [<ffffffffae9304a0>] irq_exit+0xb1/0x29e:
						invoke_softirq at kernel/softirq.c:365
						 (inlined by) irq_exit at kernel/softirq.c:405
[ 1144.285635] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.17.0-rc1 #99
[ 1144.301610] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 1144.309648] RIP: 0010:rb_next+0xa3/0x118:
						rb_next at lib/rbtree.c:541
[ 1144.317646] RSP: 0000:ffff88001015f9d8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[ 1144.332748] RAX: dffffc0000000000 RBX: 0000000000000000 RCX: 0000000000000815
[ 1144.341594] RDX: 1ffff920002d9ee8 RSI: 0000000000000816 RDI: ffffc900016cf740
[ 1144.349636] RBP: ffff88001015f9f8 R08: 0000000000001b15 R09: 0000000000000000
[ 1144.365611] R10: 0000000000000000 R11: 00000000d9de409f R12: ffffc900016cf738
[ 1144.373584] R13: ffff88001015fc70 R14: ffff88001015faf8 R15: ffffc900017cce70
[ 1144.381688] FS:  0000000000000000(0000) GS:ffff880010600000(0000) knlGS:0000000000000000
[ 1144.397596] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1144.405598] CR2: 0000000000000000 CR3: 0000000015814001 CR4: 00000000000206b0
[ 1144.413673] Call Trace:
[ 1144.421640]  drm_mm_insert_node_in_range+0x3c7/0x917:
						next_hole at drivers/gpu/drm/drm_mm.c:358 (discriminator 1)
						 (inlined by) drm_mm_insert_node_in_range at drivers/gpu/drm/drm_mm.c:465 (discriminator 1)
[ 1144.429639]  ? drm_mm_reserve_node+0x4c7/0x4c7:
						drm_mm_insert_node_in_range at drivers/gpu/drm/drm_mm.c:451
[ 1144.437652]  ? rcu_dynticks_curr_cpu_in_eqs+0x35/0x79:
						__read_once_size at include/linux/compiler.h:188
						 (inlined by) arch_atomic_read at arch/x86/include/asm/atomic.h:31
						 (inlined by) atomic_read at include/asm-generic/atomic-instrumented.h:22
						 (inlined by) rcu_dynticks_curr_cpu_in_eqs at kernel/rcu/tree.c:349
[ 1144.445752]  ? retint_kernel+0x10/0x10:
						restore_regs_and_return_to_kernel at arch/x86/entry/entry_64.S:720
[ 1144.445752]  expect_insert+0x6d/0x118:
						drm_mm_insert_node_generic at include/drm/drm_mm.h:403
						 (inlined by) expect_insert at drivers/gpu/drm/selftests/test-drm_mm.c:530
[ 1144.457609]  igt_color_evict+0x1fa/0x7bb:
						igt_color_evict at drivers/gpu/drm/selftests/test-drm_mm.c:2113
[ 1144.457609]  ? igt_color_evict_range+0x7b3/0x7b3:
						igt_color_evict at drivers/gpu/drm/selftests/test-drm_mm.c:2083
[ 1144.465551]  ? igt_color+0xa16/0xa64:
						igt_color at drivers/gpu/drm/selftests/test-drm_mm.c:1857
[ 1144.473560]  ? igt_init+0x299/0x299:
						igt_color at drivers/gpu/drm/selftests/test-drm_mm.c:1857
[ 1144.481561]  ? drm_dp_aux_dev_exit+0x40/0x40:
						separate_adjacent_colors at drivers/gpu/drm/selftests/test-drm_mm.c:1833
[ 1144.489569]  ? kasan_check_read+0x1e/0x28:
						kasan_check_read at mm/kasan/kasan.c:272
[ 1144.497602]  ? next_prime_number+0x3e5/0x3fa:
						rcu_lock_release at include/linux/rcupdate.h:251
						 (inlined by) rcu_read_unlock at include/linux/rcupdate.h:688
						 (inlined by) next_prime_number at lib/prime_numbers.c:203
[ 1144.504733]  test_drm_mm_init+0x2ad/0x3b8:
						run_selftests at drivers/gpu/drm/selftests/drm_selftest.c:76
						 (inlined by) test_drm_mm_init at drivers/gpu/drm/selftests/test-drm_mm.c:2294
[ 1144.513642]  ? drm_fb_helper_modinit+0x37/0x37:
						test_drm_mm_init at drivers/gpu/drm/selftests/test-drm_mm.c:2286
[ 1144.521580]  do_one_initcall+0x188/0x3ef:
						do_one_initcall at init/main.c:883
[ 1144.528710]  ? start_kernel+0x14ca/0x14ca:
						do_one_initcall at init/main.c:874
[ 1144.529615]  ? reacquire_held_locks+0x29f/0x29f:
						lock_release at kernel/locking/lockdep.c:3929
[ 1144.537620]  kernel_init_freeable+0x504/0x68d:
						do_initcall_level at init/main.c:951
						 (inlined by) do_initcalls at init/main.c:959
						 (inlined by) do_basic_setup at init/main.c:977
						 (inlined by) kernel_init_freeable at init/main.c:1127
[ 1144.545629]  ? rest_init+0x37d/0x37d:
						kernel_init at init/main.c:1050
[ 1144.553601]  kernel_init+0x13/0x1c6:
						kernel_init at init/main.c:1053
[ 1144.553601]  ? rest_init+0x37d/0x37d:
						kernel_init at init/main.c:1050
[ 1144.561661]  ret_from_fork+0x3a/0x50:
						ret_from_fork at arch/x86/entry/entry_64.S:418
[ 1144.569633] Code: 8d 7b 10 48 89 f8 48 c1 e8 03 42 80 3c 20 00 74 05 e8 60 3f a0 fd 48 8b 43 10 48 85 c0 74 75 48 ff 05 08 32 ba 05 48 89 c3 eb d4 <48> ff 05 04 32 ba 05 49 be 00 00 00 00 00 fc ff df 4c 89 e0 48
[ 1144.601626] Kernel panic - not syncing: softlockup: hung tasks
[ 1144.609656] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G             L    4.17.0-rc1 #99
[ 1144.617569] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 1144.633606] Call Trace:
[ 1144.640711]  <IRQ>
[ 1144.641612]  dump_stack+0x10f/0x19b:
						__dump_stack at lib/dump_stack.c:77
						 (inlined by) dump_stack at lib/dump_stack.c:113
[ 1144.649590]  panic+0x20d/0x46b:
						panic at kernel/panic.c:195
[ 1144.649590]  ? refcount_error_report+0x268/0x268:
						panic at kernel/panic.c:136
[ 1144.657617]  ? kasan_check_write+0x22/0x2b:
						kasan_check_write at mm/kasan/kasan.c:279
[ 1144.673626]  ? do_raw_spin_unlock+0x74/0x1fa:
						__read_once_size at include/linux/compiler.h:188
						 (inlined by) arch_atomic_read at arch/x86/include/asm/atomic.h:31
						 (inlined by) atomic_read at include/asm-generic/atomic-instrumented.h:22
						 (inlined by) queued_spin_is_locked at include/asm-generic/qspinlock.h:36
						 (inlined by) debug_spin_unlock at kernel/locking/spinlock_debug.c:98
						 (inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 1144.681566]  ? do_raw_spin_unlock+0x74/0x1fa:
						__read_once_size at include/linux/compiler.h:188
						 (inlined by) arch_atomic_read at arch/x86/include/asm/atomic.h:31
						 (inlined by) atomic_read at include/asm-generic/atomic-instrumented.h:22
						 (inlined by) queued_spin_is_locked at include/asm-generic/qspinlock.h:36
						 (inlined by) debug_spin_unlock at kernel/locking/spinlock_debug.c:98
						 (inlined by) do_raw_spin_unlock at kernel/locking/spinlock_debug.c:134
[ 1144.689539]  watchdog_timer_fn+0x335/0x366:
						watchdog_timer_fn at kernel/watchdog.c:444
[ 1144.689539]  __hrtimer_run_queues+0x2a9/0x3f8:
						__run_hrtimer at kernel/time/hrtimer.c:1388
						 (inlined by) __hrtimer_run_queues at kernel/time/hrtimer.c:1448
[ 1144.697609]  ? watchdog+0x29/0x29:
						watchdog_timer_fn at kernel/watchdog.c:340
[ 1144.705614]  ? __remove_hrtimer+0x296/0x296:
						__hrtimer_run_queues at kernel/time/hrtimer.c:1418
[ 1144.713590]  ? ktime_get_update_offsets_now+0x255/0x44d:
						timekeeping_get_delta at kernel/time/timekeeping.c:229
						 (inlined by) timekeeping_get_ns at kernel/time/timekeeping.c:367
						 (inlined by) ktime_get_update_offsets_now at kernel/time/timekeeping.c:2218
[ 1144.721656]  ? kasan_check_write+0x22/0x2b:
						kasan_check_write at mm/kasan/kasan.c:279
[ 1144.729594]  hrtimer_run_queues+0x1be/0x1ef:
						hrtimer_run_queues at kernel/time/hrtimer.c:1621
[ 1144.737601]  run_local_timers+0x29/0xd7:
						run_local_timers at kernel/time/timer.c:1706
[ 1144.737601]  update_process_times+0x30/0x87:
						update_process_times at kernel/time/timer.c:1636
[ 1144.745600]  tick_nohz_handler+0x338/0x40b:
						tick_sched_handle at kernel/time/tick-sched.c:174
						 (inlined by) tick_nohz_handler at kernel/time/tick-sched.c:1182
[ 1144.753609]  smp_apic_timer_interrupt+0x103/0x12a:
						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
[ 1144.761608]  apic_timer_interrupt+0xf/0x20:
						apic_timer_interrupt at arch/x86/entry/entry_64.S:863
[ 1144.769588]  </IRQ>
[ 1144.769588] RIP: 0010:rb_next+0xa3/0x118:
						rb_next at lib/rbtree.c:541
[ 1144.777587] RSP: 0000:ffff88001015f9d8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[ 1144.792716] RAX: dffffc0000000000 RBX: 0000000000000000 RCX: 0000000000000815
[ 1144.801661] RDX: 1ffff920002d9ee8 RSI: 0000000000000816 RDI: ffffc900016cf740
[ 1144.809546] RBP: ffff88001015f9f8 R08: 0000000000001b15 R09: 0000000000000000
[ 1144.825546] R10: 0000000000000000 R11: 00000000d9de409f R12: ffffc900016cf738
[ 1144.833521] R13: ffff88001015fc70 R14: ffff88001015faf8 R15: ffffc900017cce70
[ 1144.857566]  drm_mm_insert_node_in_range+0x3c7/0x917:
						next_hole at drivers/gpu/drm/drm_mm.c:358 (discriminator 1)
						 (inlined by) drm_mm_insert_node_in_range at drivers/gpu/drm/drm_mm.c:465 (discriminator 1)
[ 1144.865544]  ? drm_mm_reserve_node+0x4c7/0x4c7:
						drm_mm_insert_node_in_range at drivers/gpu/drm/drm_mm.c:451
[ 1144.873515]  ? rcu_dynticks_curr_cpu_in_eqs+0x35/0x79:
						__read_once_size at include/linux/compiler.h:188
						 (inlined by) arch_atomic_read at arch/x86/include/asm/atomic.h:31
						 (inlined by) atomic_read at include/asm-generic/atomic-instrumented.h:22
						 (inlined by) rcu_dynticks_curr_cpu_in_eqs at kernel/rcu/tree.c:349
[ 1144.880731]  ? retint_kernel+0x10/0x10:
						restore_regs_and_return_to_kernel at arch/x86/entry/entry_64.S:720
[ 1144.881545]  expect_insert+0x6d/0x118:
						drm_mm_insert_node_generic at include/drm/drm_mm.h:403
						 (inlined by) expect_insert at drivers/gpu/drm/selftests/test-drm_mm.c:530
[ 1144.889525]  igt_color_evict+0x1fa/0x7bb:
						igt_color_evict at drivers/gpu/drm/selftests/test-drm_mm.c:2113
[ 1144.897558]  ? igt_color_evict_range+0x7b3/0x7b3:
						igt_color_evict at drivers/gpu/drm/selftests/test-drm_mm.c:2083
[ 1144.905559]  ? igt_color+0xa16/0xa64:
						igt_color at drivers/gpu/drm/selftests/test-drm_mm.c:1857
[ 1144.912716]  ? igt_init+0x299/0x299:
						igt_color at drivers/gpu/drm/selftests/test-drm_mm.c:1857
[ 1144.913534]  ? drm_dp_aux_dev_exit+0x40/0x40:
						separate_adjacent_colors at drivers/gpu/drm/selftests/test-drm_mm.c:1833
[ 1144.921507]  ? kasan_check_read+0x1e/0x28:
						kasan_check_read at mm/kasan/kasan.c:272
[ 1144.929545]  ? next_prime_number+0x3e5/0x3fa:
						rcu_lock_release at include/linux/rcupdate.h:251
						 (inlined by) rcu_read_unlock at include/linux/rcupdate.h:688
						 (inlined by) next_prime_number at lib/prime_numbers.c:203
[ 1144.937549]  test_drm_mm_init+0x2ad/0x3b8:
						run_selftests at drivers/gpu/drm/selftests/drm_selftest.c:76
						 (inlined by) test_drm_mm_init at drivers/gpu/drm/selftests/test-drm_mm.c:2294
[ 1144.946133]  ? drm_fb_helper_modinit+0x37/0x37:
						test_drm_mm_init at drivers/gpu/drm/selftests/test-drm_mm.c:2286
[ 1144.946973]  do_one_initcall+0x188/0x3ef:
						do_one_initcall at init/main.c:883
[ 1144.946973]  ? start_kernel+0x14ca/0x14ca:
						do_one_initcall at init/main.c:874
[ 1144.959316]  ? reacquire_held_locks+0x29f/0x29f:
						lock_release at kernel/locking/lockdep.c:3929
[ 1144.965543]  kernel_init_freeable+0x504/0x68d:
						do_initcall_level at init/main.c:951
						 (inlined by) do_initcalls at init/main.c:959
						 (inlined by) do_basic_setup at init/main.c:977
						 (inlined by) kernel_init_freeable at init/main.c:1127
[ 1144.973548]  ? rest_init+0x37d/0x37d:
						kernel_init at init/main.c:1050
[ 1144.981577]  kernel_init+0x13/0x1c6:
						kernel_init at init/main.c:1053
[ 1144.981577]  ? rest_init+0x37d/0x37d:
						kernel_init at init/main.c:1050
[ 1144.991308]  ret_from_fork+0x3a/0x50:
						ret_from_fork at arch/x86/entry/entry_64.S:418
[ 1144.997523] Kernel Offset: 0x2d800000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

Attached the full dmesg, kconfig and reproduce scripts.

In v4.11, the call trace looks like this.

[  761.821640] rcu-torture: Reader Batch:  0 2 0 0 0 0 0 0 0 0 0
[  761.838883] rcu-torture: Free-Block Circulation:  0 0 0 0 0 0 0 0 0 0 0
[  761.857673] ??? Writer stall state RTWS_STUTTER(8) g6933 c6933 f0x2 ->state 0x1
[  761.880200] rcu_sched: wait state: 1 ->state: 0x1
[  761.894293] rcu_bh: wait state: 1 ->state: 0x1
[  818.124874] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:1]
[  818.191670] Modules linked in:
[  818.199151] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.11.0 #2
[  818.211527] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  818.229772] task: ffff880031a48000 task.stack: ffffc90000194000
[  818.242156] RIP: 0010:drm_mm_insert_node_in_range+0x254/0x670
[  818.254147] RSP: 0018:ffffc90000197c10 EFLAGS: 00000213 ORIG_RAX: ffffffffffffff10
[  818.271281] RAX: 0000000000000000 RBX: 000000000000296e RCX: ffffc90000197c70
[  818.285576] RDX: 000000000000296d RSI: 0000000000001f49 RDI: ffffc90001fd6d20
[  818.299937] RBP: ffffc90000197ca0 R08: 00000000000014b6 R09: 0000000000000000
[  818.317851] R10: 0000000000000000 R11: 000000000000296e R12: ffffc90001fd6d20
[  818.332694] R13: 000000000000296d R14: 0000000000000000 R15: 0000000000000000
[  818.348222] FS:  0000000000000000(0000) GS:ffff880033200000(0000) knlGS:0000000000000000
[  818.367047] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  818.379622] CR2: 00007fffc9805b88 CR3: 0000000002211000 CR4: 00000000000006b0
[  818.396438] Call Trace:
[  818.403050]  expect_insert+0x37/0xc0
[  818.413030]  igt_color_evict+0x149/0x530
[  818.422724]  ? drm_dp_aux_dev_exit+0x30/0x30
[  818.434163]  ? do_early_param+0xbb/0xbb
[  818.443424]  test_drm_mm_init+0xab/0x15a
[  818.452118]  ? drm_kms_helper_init+0x1c/0x1c
[  818.460570]  ? do_early_param+0xbb/0xbb
[  818.470427]  do_one_initcall+0x68/0x220
[  818.478688]  ? do_early_param+0xbb/0xbb
[  818.487569]  kernel_init_freeable+0x140/0x200

Thanks,
Fengguang

View attachment "dmesg-vm-lkp-wsx03-quantal-x86_64-28:20180417032459:x86_64-randconfig-s0-04170223:4.17.0-rc1:99" of type "text/plain" (52432 bytes)

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

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

View attachment "reproduce-vm-lkp-wsx03-quantal-x86_64-28:20180417032459:x86_64-randconfig-s0-04170223:4.17.0-rc1:99" of type "text/plain" (1857 bytes)

Powered by blists - more mailing lists