syzbot


INFO: task hung in evict

Status: auto-closed as invalid on 2022/09/22 02:36
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 155d, last: 155d

Sample crash report:
INFO: task syz-executor.0:3633 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-syzkaller-00048-gde5c208d533a #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:23200 pid: 3633 ppid:     1 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0xa00/0x4b50 kernel/sched/core.c:6458
 schedule+0xd2/0x1f0 kernel/sched/core.c:6530
 bit_wait+0x12/0xd0 kernel/sched/wait_bit.c:199
 __wait_on_bit+0x60/0x190 kernel/sched/wait_bit.c:49
 __inode_wait_for_writeback+0x153/0x1f0 fs/fs-writeback.c:1461
 inode_wait_for_writeback+0x22/0x30 fs/fs-writeback.c:1473
 evict+0x2b7/0x6b0 fs/inode.c:661
 iput_final fs/inode.c:1744 [inline]
 iput.part.0+0x562/0x820 fs/inode.c:1770
 iput+0x58/0x70 fs/inode.c:1760
 do_unlinkat+0x41b/0x650 fs/namei.c:4267
 __do_sys_unlink fs/namei.c:4308 [inline]
 __se_sys_unlink fs/namei.c:4306 [inline]
 __x64_sys_unlink+0xc6/0x110 fs/namei.c:4306
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f936fa88a47
RSP: 002b:00007ffc5e668428 EFLAGS: 00000206 ORIG_RAX: 0000000000000057
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f936fa88a47
RDX: 00007ffc5e668460 RSI: 00007ffc5e668460 RDI: 00007ffc5e6684f0
RBP: 00007ffc5e6684f0 R08: 0000000000000001 R09: 00007ffc5e6682c0
R10: 0000555556ecb8c3 R11: 0000000000000206 R12: 00007f936fae21c8
R13: 00007ffc5e6695f0 R14: 0000555556ecb850 R15: 00007ffc5e66a6f0
 </TASK>
INFO: task syz-executor.2:18010 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-syzkaller-00048-gde5c208d533a #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:27112 pid:18010 ppid:  3636 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0xa00/0x4b50 kernel/sched/core.c:6458
 schedule+0xd2/0x1f0 kernel/sched/core.c:6530
 wb_wait_for_completion+0x17e/0x240 fs/fs-writeback.c:191
 __writeback_inodes_sb_nr+0x1d7/0x280 fs/fs-writeback.c:2607
 try_to_writeback_inodes_sb+0x94/0xc0 fs/fs-writeback.c:2655
 ext4_nonda_switch+0x1aa/0x1f0 fs/ext4/inode.c:2932
 ext4_da_write_begin+0x16e/0xaf0 fs/ext4/inode.c:2959
 generic_perform_write+0x244/0x560 mm/filemap.c:3770
 ext4_buffered_write_iter+0x15b/0x330 fs/ext4/file.c:270
 ext4_file_write_iter+0x43c/0x1520 fs/ext4/file.c:679
 call_write_iter include/linux/fs.h:2058 [inline]
 new_sync_write+0x38a/0x560 fs/read_write.c:504
 vfs_write+0x7c0/0xac0 fs/read_write.c:591
 ksys_write+0x127/0x250 fs/read_write.c:644
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f6fea889109
RSP: 002b:00007f6feb97d168 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f6fea99bf60 RCX: 00007f6fea889109
RDX: 00000000fffffc41 RSI: 0000000020001440 RDI: 0000000000000003
RBP: 00007f6fea8e305d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe7f54ddaf R14: 00007f6feb97d300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor.5:18012 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-syzkaller-00048-gde5c208d533a #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.5  state:D stack:27112 pid:18012 ppid:  3634 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0xa00/0x4b50 kernel/sched/core.c:6458
 schedule+0xd2/0x1f0 kernel/sched/core.c:6530
 wb_wait_for_completion+0x17e/0x240 fs/fs-writeback.c:191
 __writeback_inodes_sb_nr+0x1d7/0x280 fs/fs-writeback.c:2607
 try_to_writeback_inodes_sb+0x94/0xc0 fs/fs-writeback.c:2655
 ext4_nonda_switch+0x1aa/0x1f0 fs/ext4/inode.c:2932
 ext4_da_write_begin+0x16e/0xaf0 fs/ext4/inode.c:2959
 generic_perform_write+0x244/0x560 mm/filemap.c:3770
 ext4_buffered_write_iter+0x15b/0x330 fs/ext4/file.c:270
 ext4_file_write_iter+0x43c/0x1520 fs/ext4/file.c:679
 call_write_iter include/linux/fs.h:2058 [inline]
 new_sync_write+0x38a/0x560 fs/read_write.c:504
 vfs_write+0x7c0/0xac0 fs/read_write.c:591
 ksys_write+0x127/0x250 fs/read_write.c:644
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f1bd8889109
RSP: 002b:00007f1bd9a36168 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f1bd899bf60 RCX: 00007f1bd8889109
RDX: 00000000fffffc41 RSI: 0000000020001440 RDI: 0000000000000003
RBP: 00007f1bd88e305d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffe9e89678f R14: 00007f1bd9a36300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
1 lock held by pr/ttyS0/16:
1 lock held by khungtaskd/29:
 #0: ffffffff8bd86ba0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6491
2 locks held by getty/3291:
 #0: ffff8880265fc098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:244
 #1: ffffc90002d232e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xe50/0x13c0 drivers/tty/n_tty.c:2124
1 lock held by syz-executor.0/3633:
 #0: ffff88814ac1a460 (sb_writers#4){.+.+}-{0:0}, at: do_unlinkat+0x17f/0x650 fs/namei.c:4239
3 locks held by kworker/u4:7/3719:
4 locks held by syz-executor.2/18010:
 #0: ffff88801c7a2868 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe3/0x100 fs/file.c:1036
 #1: ffff88814ac1a460 (sb_writers#4){.+.+}-{0:0}, at: ksys_write+0x127/0x250 fs/read_write.c:644
 #2: ffff88803032ac20 (&sb->s_type->i_mutex_key#9){++++}-{3:3}, at: inode_lock include/linux/fs.h:741 [inline]
 #2: ffff88803032ac20 (&sb->s_type->i_mutex_key#9){++++}-{3:3}, at: ext4_buffered_write_iter+0xb0/0x330 fs/ext4/file.c:264
 #3: ffff88814ac1a0e0 (&type->s_umount_key#32){++++}-{3:3}, at: try_to_writeback_inodes_sb+0x1d/0xc0 fs/fs-writeback.c:2652
4 locks held by syz-executor.5/18012:
 #0: ffff888084a625e8 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe3/0x100 fs/file.c:1036
 #1: ffff88814ac1a460 (sb_writers#4){.+.+}-{0:0}, at: ksys_write+0x127/0x250 fs/read_write.c:644
 #2: ffff888032690e08 (&sb->s_type->i_mutex_key#9){++++}-{3:3}, at: inode_lock include/linux/fs.h:741 [inline]
 #2: ffff888032690e08 (&sb->s_type->i_mutex_key#9){++++}-{3:3}, at: ext4_buffered_write_iter+0xb0/0x330 fs/ext4/file.c:264
 #3: ffff88814ac1a0e0 (&type->s_umount_key#32){++++}-{3:3}, at: try_to_writeback_inodes_sb+0x1d/0xc0 fs/fs-writeback.c:2652

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

NMI backtrace for cpu 1
CPU: 1 PID: 29 Comm: khungtaskd Not tainted 5.19.0-rc3-syzkaller-00048-gde5c208d533a #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1e6/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:220 [inline]
 watchdog+0xc22/0xf90 kernel/hung_task.c:378
 kthread+0x2e9/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:302
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 2960 Comm: syslogd Not tainted 5.19.0-rc3-syzkaller-00048-gde5c208d533a #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:vfs_read+0x2/0x5d0 fs/read_write.c:463
Code: ff 84 d2 0f 84 63 ff ff ff e8 aa 11 f2 ff e9 59 ff ff ff 4c 89 f7 e8 ad 11 f2 ff e9 a0 fe ff ff 0f 1f 84 00 00 00 00 00 41 57 <41> 56 41 55 49 89 cd 41 54 55 48 89 d5 53 48 89 fb 4c 8d 73 7c 48
RSP: 0018:ffffc90002d3fe98 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffff888022294f00 RCX: 0000000000000000
RDX: 00000000000000ff RSI: 00005562a589a950 RDI: ffff888022294f00
RBP: ffff888022294f00 R08: 0000000000000005 R09: 0000000000000000
R10: 0000000000200000 R11: 0000000000000001 R12: 1ffff920005a7fd5
R13: 00005562a589a950 R14: 0000000000200000 R15: 00000000000000ff
FS:  00007f7705862800(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c010c898f0 CR3: 000000007e407000 CR4: 0000000000350ef0
Call Trace:
 <TASK>
 ksys_read+0x1e8/0x250 fs/read_write.c:620
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x7f77059ee8fe
Code: c0 e9 e6 fe ff ff 50 48 8d 3d 0e c7 09 00 e8 c9 cf 01 00 66 0f 1f 84 00 00 00 00 00 64 8b 04 25 18 00 00 00 85 c0 75 14 0f 05 <48> 3d 00 f0 ff ff 77 5a c3 66 0f 1f 84 00 00 00 00 00 48 83 ec 28
RSP: 002b:00007ffe31947258 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f77059ee8fe
RDX: 00000000000000ff RSI: 00005562a589a950 RDI: 0000000000000000
RBP: 00005562a589a910 R08: 00007f7705a7e040 R09: 00007f7705a7e0c0
R10: 00007f7705a7dfc0 R11: 0000000000000246 R12: 00005562a589a9a4
R13: 00005562a589a950 R14: 0000000000000000 R15: 0000000000000000
 </TASK>
----------------
Code disassembly (best guess), 1 bytes skipped:
   0:	84 d2                	test   %dl,%dl
   2:	0f 84 63 ff ff ff    	je     0xffffff6b
   8:	e8 aa 11 f2 ff       	callq  0xfff211b7
   d:	e9 59 ff ff ff       	jmpq   0xffffff6b
  12:	4c 89 f7             	mov    %r14,%rdi
  15:	e8 ad 11 f2 ff       	callq  0xfff211c7
  1a:	e9 a0 fe ff ff       	jmpq   0xfffffebf
  1f:	0f 1f 84 00 00 00 00 	nopl   0x0(%rax,%rax,1)
  26:	00
  27:	41 57                	push   %r15
* 29:	41 56                	push   %r14 <-- trapping instruction
  2b:	41 55                	push   %r13
  2d:	49 89 cd             	mov    %rcx,%r13
  30:	41 54                	push   %r12
  32:	55                   	push   %rbp
  33:	48 89 d5             	mov    %rdx,%rbp
  36:	53                   	push   %rbx
  37:	48 89 fb             	mov    %rdi,%rbx
  3a:	4c 8d 73 7c          	lea    0x7c(%rbx),%r14
  3e:	48                   	rex.W

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-root 2022/06/24 02:28 upstream de5c208d533a 912f5df7 .config log report info INFO: task hung in evict
* Struck through repros no longer work on HEAD.