syzbot


INFO: rcu detected stall in d_walk

Status: auto-closed as invalid on 2019/03/01 20:51
First crash: 2271d, last: 2271d
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in d_walk fs C 25680 2352d 2414d 8/28 fixed on 2018/07/09 18:05

Sample crash report:
binder: 12210:12213 got transaction to context manager from process owning it
binder: 12210:12213 transaction failed 29201/-22, size 24-0 line 3004
FAT-fs (loop0): codepage cp437 not found
INFO: rcu_preempt detected stalls on CPUs/tasks:
	(detected by 0, t=10502 jiffies, g=3970, c=3969, q=379)
All QSes seen, last rcu_preempt kthread activity 10502 (4294991162-4294980660), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor7   R  running task    26968  2301   2298 0x00000000
 ffff8801db607c98 ffffffff813f5a7f ffffffff813f5886 0000000100003434
 0000000100005d3a dffffc0000000000 ffff8801db621d40 ffffffff82ecd580
 ffff8801db607d68 ffffffff81401aa5 0000000000000000 ffff8801db607cd8
Call Trace:
 <IRQ> 
 [<ffffffff813f5a7f>] sched_show_task.cold.35+0x279/0x31f kernel/sched/core.c:5317
 [<ffffffff81401aa5>] print_other_cpu_stall kernel/rcu/tree.c:1403 [inline]
 [<ffffffff81401aa5>] check_cpu_stall kernel/rcu/tree.c:1520 [inline]
 [<ffffffff81401aa5>] __rcu_pending kernel/rcu/tree.c:3487 [inline]
 [<ffffffff81401aa5>] rcu_pending kernel/rcu/tree.c:3551 [inline]
 [<ffffffff81401aa5>] rcu_check_callbacks.cold.69+0xc70/0xd27 kernel/rcu/tree.c:2880
 [<ffffffff81261680>] update_process_times+0x30/0x70 kernel/time/timer.c:1629
 [<ffffffff8128ec7a>] tick_sched_handle.isra.5+0x4a/0xf0 kernel/time/tick-sched.c:151
 [<ffffffff8128ed96>] tick_sched_timer+0x76/0x130 kernel/time/tick-sched.c:1190
 [<ffffffff812643a7>] __run_hrtimer kernel/time/hrtimer.c:1255 [inline]
 [<ffffffff812643a7>] __hrtimer_run_queues+0x357/0xe30 kernel/time/hrtimer.c:1319
 [<ffffffff81266891>] hrtimer_interrupt+0x1b1/0x430 kernel/time/hrtimer.c:1353
 [<ffffffff8108f6c4>] local_apic_timer_interrupt+0x74/0xa0 arch/x86/kernel/apic/apic.c:937
 [<ffffffff8278ff1c>] smp_apic_timer_interrupt+0x7c/0xa0 arch/x86/kernel/apic/apic.c:961
 [<ffffffff8278d7ed>] apic_timer_interrupt+0x9d/0xb0 arch/x86/entry/entry_64.S:648
 <EOI> 
 [<ffffffff8278b454>] _raw_spin_lock_nested+0x44/0x50 kernel/locking/spinlock.c:362
 [<ffffffff81548219>] d_walk.part.10+0x1b9/0x710 fs/dcache.c:1241
 [<ffffffff815488f7>] d_walk fs/dcache.c:1212 [inline]
 [<ffffffff815488f7>] shrink_dcache_parent+0xd7/0x130 fs/dcache.c:1447
 [<ffffffff81529bd9>] vfs_rmdir2+0x1c9/0x410 fs/namei.c:3884
 [<ffffffff81533264>] do_rmdir+0x304/0x3b0 fs/namei.c:3951
 [<ffffffff81534d9a>] SYSC_rmdir fs/namei.c:3969 [inline]
 [<ffffffff81534d9a>] SyS_rmdir+0x1a/0x20 fs/namei.c:3967
 [<ffffffff8100554f>] do_syscall_64+0x19f/0x480 arch/x86/entry/common.c:282
 [<ffffffff8278c053>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
rcu_preempt kthread starved for 10502 jiffies! g3970 c3969 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x0
rcu_preempt     R  running task    29096     7      2 0x00000000
 ffff8801d9e197c0 ffff8801d983d280 ffff8801d0904200 ffff8801a04dc740
 ffff8801db6210d8 ffff8801d9e37a90 ffffffff8277cf52 ffff8801d9e37a58
 ffffffff81b58bab ffff8801d9e1a068 00ff8801d9e1a068 ffff8801db6219b0
Call Trace:
 [<ffffffff8277e47f>] schedule+0x7f/0x1b0 kernel/sched/core.c:3553
 [<ffffffff82788864>] schedule_timeout+0x4f4/0xe20 kernel/time/timer.c:1791
 [<ffffffff8124b82d>] rcu_gp_kthread+0xb9d/0x2110 kernel/rcu/tree.c:2227
 [<ffffffff811410dd>] kthread+0x26d/0x300 kernel/kthread.c:211
 [<ffffffff8278c21c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:373
INFO: task kworker/1:1:22 blocked for more than 140 seconds.
      Not tainted 4.9.124+ #33
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1     D26904    22      2 0x00000000
Workqueue: events xfrm_state_gc_task
 ffff8801d9fc0000 ffff8801bdb0dd80 ffff8801bdb0dd80 ffff8801d3f55f00
 ffff8801db7210d8 ffff8801d9fcf7a0 ffffffff8277cf52 ffff8801d9fcf838
 ffff8801d9fcfb18 ffff8801d9fcf748 00ffffff81b58cfc ffff8801db7219b0
Call Trace:
 [<ffffffff8277e47f>] schedule+0x7f/0x1b0 kernel/sched/core.c:3553
 [<ffffffff82788aa5>] schedule_timeout+0x735/0xe20 kernel/time/timer.c:1768
 [<ffffffff8277fea9>] do_wait_for_common kernel/sched/completion.c:75 [inline]
 [<ffffffff8277fea9>] __wait_for_common kernel/sched/completion.c:93 [inline]
 [<ffffffff8277fea9>] wait_for_common+0x2f9/0x400 kernel/sched/completion.c:101
 [<ffffffff8277ffc8>] wait_for_completion+0x18/0x20 kernel/sched/completion.c:122
 [<ffffffff8123e3f7>] __wait_rcu_gp+0x137/0x1b0 kernel/rcu/update.c:369
 [<ffffffff81246ada>] synchronize_rcu.part.55+0xfa/0x110 kernel/rcu/tree_plugin.h:684
 [<ffffffff81246b17>] synchronize_rcu+0x27/0x90 kernel/rcu/tree_plugin.h:685
 [<ffffffff825c2882>] xfrm_state_gc_task+0xd2/0x510 net/xfrm/xfrm_state.c:385
 [<ffffffff8112fcf1>] process_one_work+0x791/0x1470 kernel/workqueue.c:2092
 [<ffffffff81130aa6>] worker_thread+0xd6/0x10a0 kernel/workqueue.c:2226
 [<ffffffff811410dd>] kthread+0x26d/0x300 kernel/kthread.c:211
 [<ffffffff8278c21c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:373

Showing all locks held in the system:
2 locks held by kworker/1:1/22:
 #0:  ("events"){.+.+.+}, at: [<ffffffff8112fc00>] process_one_work+0x6a0/0x1470 kernel/workqueue.c:2085
 #1:  (xfrm_state_gc_work){+.+...}, at: [<ffffffff8112fc38>] process_one_work+0x6d8/0x1470 kernel/workqueue.c:2089
2 locks held by khungtaskd/24:
 #0:  (rcu_read_lock){......}, at: [<ffffffff8131401c>] check_hung_uninterruptible_tasks kernel/hung_task.c:168 [inline]
 #0:  (rcu_read_lock){......}, at: [<ffffffff8131401c>] watchdog+0x11c/0xa20 kernel/hung_task.c:239
 #1:  (tasklist_lock){.+.+..}, at: [<ffffffff813f99b9>] debug_show_all_locks+0x79/0x218 kernel/locking/lockdep.c:4336
2 locks held by getty/2216:
 #0:  (&tty->ldisc_sem){++++++}, at: [<ffffffff8278a122>] ldsem_down_read+0x32/0x40 drivers/tty/tty_ldsem.c:367
 #1:  (&ldata->atomic_read_lock){+.+...}, at: [<ffffffff81cde522>] n_tty_read+0x202/0x16e0 drivers/tty/n_tty.c:2142
1 lock held by syz-executor0/12150:
 #0:  (sb_writers#3){.+.+.+}, at: [<ffffffff81500b30>] file_start_write include/linux/fs.h:2640 [inline]
 #0:  (sb_writers#3){.+.+.+}, at: [<ffffffff81500b30>] do_sendfile+0xa80/0xc30 fs/read_write.c:1392
3 locks held by syz-executor0/12172:
 #0:  (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff815b63cb>] __blkdev_put+0xbb/0x840 fs/block_dev.c:1579
 #1:  (loop_index_mutex){+.+.+.}, at: [<ffffffff81d8dbbf>] lo_release+0x1f/0x1a0 drivers/block/loop.c:1606
 #2:  (&lo->lo_ctl_mutex#2){+.+.+.}, at: [<ffffffff81d8dc25>] __lo_release drivers/block/loop.c:1584 [inline]
 #2:  (&lo->lo_ctl_mutex#2){+.+.+.}, at: [<ffffffff81d8dc25>] lo_release+0x85/0x1a0 drivers/block/loop.c:1607
1 lock held by syz-executor4/12215:
 #0:  (event_mutex){+.+.+.}, at: [<ffffffff8135d1a8>] perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:234
1 lock held by syz-executor4/12231:
 #0:  (&type->s_umount_key#23){++++++}, at: [<ffffffff8156b9bc>] do_remount fs/namespace.c:2346 [inline]
 #0:  (&type->s_umount_key#23){++++++}, at: [<ffffffff8156b9bc>] do_mount+0xb3c/0x2790 fs/namespace.c:2850

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 24 Comm: khungtaskd Not tainted 4.9.124+ #33
 ffff8801d9497d08 ffffffff81af4b39 0000000000000000 0000000000000001
 0000000000000001 0000000000000001 ffffffff81096740 ffff8801d9497d40
 ffffffff81aff897 0000000000000001 0000000000000000 0000000000000003
Call Trace:
 [<ffffffff81af4b39>] __dump_stack lib/dump_stack.c:15 [inline]
 [<ffffffff81af4b39>] dump_stack+0xc1/0x128 lib/dump_stack.c:51
 [<ffffffff81aff897>] nmi_cpu_backtrace.cold.0+0x48/0x87 lib/nmi_backtrace.c:99
 [<ffffffff81aff82a>] nmi_trigger_cpumask_backtrace+0x12a/0x14f lib/nmi_backtrace.c:60
 [<ffffffff81096844>] arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:37
 [<ffffffff813145ad>] trigger_all_cpu_backtrace include/linux/nmi.h:58 [inline]
 [<ffffffff813145ad>] check_hung_task kernel/hung_task.c:125 [inline]
 [<ffffffff813145ad>] check_hung_uninterruptible_tasks kernel/hung_task.c:182 [inline]
 [<ffffffff813145ad>] watchdog+0x6ad/0xa20 kernel/hung_task.c:239
 [<ffffffff811410dd>] kthread+0x26d/0x300 kernel/kthread.c:211
 [<ffffffff8278c21c>] ret_from_fork+0x5c/0x70 arch/x86/entry/entry_64.S:373
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 2301 Comm: syz-executor7 Not tainted 4.9.124+ #33
task: ffff8801d26f97c0 task.stack: ffff8801b0628000
RIP: 0010:[<ffffffff81200c01>] c [<ffffffff81200c01>] hlock_class kernel/locking/lockdep.c:142 [inline]
RIP: 0010:[<ffffffff81200c01>] c [<ffffffff81200c01>] mark_lock+0x21/0x1290 kernel/locking/lockdep.c:3039
RSP: 0018:ffff8801b062f9b0  EFLAGS: 00000046
RAX: dffffc0000000000 RBX: ffff8801d26fa110 RCX: 0000000000000002
RDX: ffff8801d26fa130 RSI: ffff8801d26fa110 RDI: ffff8801d26f97c0
RBP: ffff8801b062f9c0 R08: ffff8801d26fa130 R09: 0000000000000000
R10: ffff8801d26f97c0 R11: 1ffff1003a4df421 R12: 0000000000000282
R13: 0000000000000004 R14: 0000000000000002 R15: ffff8801d26f97c0
FS:  0000000001fc2940(0000) GS:ffff8801db600000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffd42de2c6c CR3: 00000001b05b4000 CR4: 00000000001606b0
DR0: 0000000020000000 DR1: 0000000020000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
Stack:
 0000000000000000c ffff8801d26fa132c ffff8801b062fb78c ffffffff812035f0c
 ffff8801d26fa05cc ffff8801d26fa10ac ffff8801b062fa20c ffffffff81b58babc
 0000000600000007c 000060fe2460ee48c 1ffff100360c5f50c ffffffff82eb9940c
Call Trace:
 [<ffffffff812035f0>] mark_irqflags kernel/locking/lockdep.c:2937 [inline]
 [<ffffffff812035f0>] __lock_acquire+0x10b0/0x4a10 kernel/locking/lockdep.c:3302
 [<ffffffff81207a60>] lock_acquire+0x130/0x3e0 kernel/locking/lockdep.c:3756
 [<ffffffff8278b44c>] _raw_spin_lock_nested+0x3c/0x50 kernel/locking/spinlock.c:361
 [<ffffffff81548219>] d_walk.part.10+0x1b9/0x710 fs/dcache.c:1241
 [<ffffffff815488f7>] d_walk fs/dcache.c:1212 [inline]
 [<ffffffff815488f7>] shrink_dcache_parent+0xd7/0x130 fs/dcache.c:1447
 [<ffffffff81529bd9>] vfs_rmdir2+0x1c9/0x410 fs/namei.c:3884
 [<ffffffff81533264>] do_rmdir+0x304/0x3b0 fs/namei.c:3951
 [<ffffffff81534d9a>] SYSC_rmdir fs/namei.c:3969 [inline]
 [<ffffffff81534d9a>] SyS_rmdir+0x1a/0x20 fs/namei.c:3967
 [<ffffffff8100554f>] do_syscall_64+0x19f/0x480 arch/x86/entry/common.c:282
 [<ffffffff8278c053>] entry_SYSCALL_64_after_swapgs+0x5d/0xdb
Code: ca6 c56 c2e c00 ceb cd7 c0f c1f c40 c00 c55 c4c c8d c46 c20 c89 cd1 c48 cb8 c00 c00 c00 c00 c00 cfc cff cdf c48 c89 ce5 c41 c57 c49 c89 cff c41 c56 c41 c89 cd6 c4c c89 cc2 c<41> c55 c48 cc1 cea c03 c41 cbd c01 c00 c00 c00 c41 c54 c41 cd3 ce5 c53 c48 c89 cf3 c

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2018/09/02 20:48 https://android.googlesource.com/kernel/common android-4.9 a06ea261bc2a a4718693 .config console log report ci-android-49-kasan-gce-root
* Struck through repros no longer work on HEAD.