syzbot


INFO: task hung in __writeback_inodes_sb_nr (4)

Status: closed as invalid on 2022/02/08 10:10
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 356d, last: 302d
similar bugs (9):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in __writeback_inodes_sb_nr 53 1418d 1681d 0/24 closed as dup on 2018/09/08 15:33
android-49 INFO: task hung in __writeback_inodes_sb_nr 26 1515d 1658d 0/3 auto-closed as invalid on 2019/04/08 13:33
android-414 INFO: task hung in __writeback_inodes_sb_nr 1 1452d 1329d 0/1 auto-closed as invalid on 2019/06/09 16:55
upstream INFO: task hung in __writeback_inodes_sb_nr (5) C done 38 6d11h 294d 23/24 internal: reported C repro on 2022/02/12 04:17
linux-4.19 INFO: task hung in __writeback_inodes_sb_nr 1 65d 65d 0/1 upstream: reported on 2022/09/28 21:19
upstream INFO: task hung in __writeback_inodes_sb_nr (3) 2 568d 666d 0/24 auto-closed as invalid on 2021/08/11 17:49
linux-4.14 INFO: task hung in __writeback_inodes_sb_nr (2) 2 33d 35d 0/1 upstream: reported on 2022/10/29 04:06
upstream INFO: task hung in __writeback_inodes_sb_nr (2) 1 850d 850d 0/24 auto-closed as invalid on 2020/11/03 06:13
linux-4.14 INFO: task hung in __writeback_inodes_sb_nr 1 916d 916d 0/1 auto-closed as invalid on 2020/09/27 19:31

Sample crash report:
INFO: task syz-executor.1:19539 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:27144 pid:19539 ppid:  3633 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 wb_wait_for_completion+0x17e/0x240 fs/fs-writeback.c:190
 __writeback_inodes_sb_nr+0x1d7/0x280 fs/fs-writeback.c:2613
 try_to_writeback_inodes_sb+0x94/0xc0 fs/fs-writeback.c:2661
 ext4_nonda_switch+0x1aa/0x1f0 fs/ext4/inode.c:2911
 ext4_da_write_begin+0x176/0xad0 fs/ext4/inode.c:2938
 generic_perform_write+0x205/0x510 mm/filemap.c:3754
 ext4_buffered_write_iter+0x1ac/0x3b0 fs/ext4/file.c:269
 ext4_file_write_iter+0x423/0x14e0 fs/ext4/file.c:681
 call_write_iter include/linux/fs.h:2162 [inline]
 new_sync_write+0x429/0x660 fs/read_write.c:503
 vfs_write+0x7cd/0xae0 fs/read_write.c:590
 ksys_write+0x12d/0x250 fs/read_write.c:643
 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+0x44/0xae
RIP: 0033:0x7f1d54887e99
RSP: 002b:00007f1d531fd168 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f1d5499af60 RCX: 00007f1d54887e99
RDX: 00000000ffffff6a RSI: 0000000020000000 RDI: 0000000000000004
RBP: 00007f1d548e1ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffcf206409f R14: 00007f1d531fd300 R15: 0000000000022000
 </TASK>
INFO: task syz-executor.1:19541 blocked for more than 143 seconds.
      Not tainted 5.16.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:25080 pid:19541 ppid:  3633 flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4972 [inline]
 __schedule+0xa9a/0x4940 kernel/sched/core.c:6253
 schedule+0xd2/0x260 kernel/sched/core.c:6326
 rwsem_down_write_slowpath+0x634/0x1110 kernel/locking/rwsem.c:1151
 __down_write_common kernel/locking/rwsem.c:1268 [inline]
 __down_write_common kernel/locking/rwsem.c:1265 [inline]
 __down_write kernel/locking/rwsem.c:1277 [inline]
 down_write+0x135/0x150 kernel/locking/rwsem.c:1524
 inode_lock include/linux/fs.h:783 [inline]
 lock_two_nondirectories+0xec/0x110 fs/inode.c:1048
 ext4_move_extents+0x369/0x3ee0 fs/ext4/move_extent.c:603
 __ext4_ioctl+0x3a4e/0x4840 fs/ext4/ioctl.c:988
 ext4_ioctl+0x46/0x90 fs/ext4/ioctl.c:1279
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:874 [inline]
 __se_sys_ioctl fs/ioctl.c:860 [inline]
 __x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
 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+0x44/0xae
RIP: 0033:0x7f1d54887e99
RSP: 002b:00007f1d531dc168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f1d5499b030 RCX: 00007f1d54887e99
RDX: 0000000020000180 RSI: 00000000c028660f RDI: 0000000000000005
RBP: 00007f1d548e1ff1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffcf206409f R14: 00007f1d531dc300 R15: 0000000000022000
 </TASK>

Showing all locks held in the system:
2 locks held by kworker/u4:1/10:
 #0: ffff8880b9d39a98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:478
 #1: ffff8880b9d279c8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x3a6/0x490 kernel/sched/psi.c:880
1 lock held by khungtaskd/27:
 #0: ffffffff8bb83e20 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:6458
2 locks held by getty/3279:
 #0: ffff88814af0c098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x22/0x80 drivers/tty/tty_ldisc.c:252
 #1: ffffc90002b962e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xcf0/0x1230 drivers/tty/n_tty.c:2113
4 locks held by kworker/u4:6/3970:
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:635 [inline]
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:662 [inline]
 #0: ffff888013b8a138 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2269
 #1: ffffc9000473fdb0 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2273
 #2: ffff88807f10cbd8 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1ab/0x690 mm/page-writeback.c:2364
 #3: ffff8880b9c39a98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:478
2 locks held by syz-executor.5/19491:
2 locks held by syz-executor.1/19538:
 #0: ffff88807f10cbd8 (&sbi->s_writepages_rwsem){++++}-{0:0}, at: do_writepages+0x1ab/0x690 mm/page-writeback.c:2364
 #1: ffff8880b9d39a98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2b/0x120 kernel/sched/core.c:478
4 locks held by syz-executor.1/19539:
 #0: ffff888075052370 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:1034
 #1: ffff88807f10a460 (sb_writers#5){.+.+}-{0:0}, at: ksys_write+0x12d/0x250 fs/read_write.c:643
 #2: ffff888045ab35c8 (&sb->s_type->i_mutex_key#10){++++}-{3:3}, at: inode_lock include/linux/fs.h:783 [inline]
 #2: ffff888045ab35c8 (&sb->s_type->i_mutex_key#10){++++}-{3:3}, at: ext4_buffered_write_iter+0xb6/0x3b0 fs/ext4/file.c:263
 #3: ffff88807f10a0e0 (&type->s_umount_key#32){++++}-{3:3}, at: try_to_writeback_inodes_sb+0x1d/0xc0 fs/fs-writeback.c:2658
2 locks held by syz-executor.1/19541:
 #0: ffff88807f10a460 (sb_writers#5){.+.+}-{0:0}, at: __ext4_ioctl+0x2e30/0x4840 fs/ext4/ioctl.c:984
 #1: ffff888045ab35c8 (&sb->s_type->i_mutex_key#10){++++}-{3:3}, at: inode_lock include/linux/fs.h:783 [inline]
 #1: ffff888045ab35c8 (&sb->s_type->i_mutex_key#10){++++}-{3:3}, at: lock_two_nondirectories+0xec/0x110 fs/inode.c:1048
1 lock held by syz-executor.3/19553:

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.16.0-rc6-syzkaller #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+0x1b3/0x230 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xc1d/0xf50 kernel/hung_task.c:295
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3970 Comm: kworker/u4:6 Not tainted 5.16.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: writeback wb_workfn (flush-8:0)
RIP: 0010:mpage_process_page_bufs+0x180/0x7a0 fs/ext4/inode.c:2194
Code: 44 24 10 e8 92 68 66 ff be 08 00 00 00 48 89 df e8 e5 34 ad ff 48 89 d8 48 c1 e8 03 42 80 3c 20 00 0f 85 2b 05 00 00 48 8b 03 <31> ff 83 e0 04 49 89 c7 48 89 c6 e8 f0 6a 66 ff 4d 85 ff 0f 85 ea
RSP: 0018:ffffc9000473f1b8 EFLAGS: 00000246
RAX: 0000000000000113 RBX: ffff888046d85e80 RCX: ffffffff821139bb
RDX: ffffed1008db0bd1 RSI: 0000000000000008 RDI: ffff888046d85e80
RBP: 0000000000000b58 R08: 0000000000000000 R09: ffff888046d85e87
R10: ffffed1008db0bd0 R11: 0000000000000000 R12: dffffc0000000000
R13: ffffc9000473f5a8 R14: 0000000000000f1f R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000056218724a680 CR3: 0000000078a36000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 mpage_prepare_extent_to_map+0x94f/0xe60 fs/ext4/inode.c:2621
 ext4_writepages+0x12af/0x3b90 fs/ext4/inode.c:2793
 do_writepages+0x1ab/0x690 mm/page-writeback.c:2364
 __writeback_single_inode+0x126/0xff0 fs/fs-writeback.c:1616
 writeback_sb_inodes+0x53d/0xf30 fs/fs-writeback.c:1881
 wb_writeback+0x299/0xc30 fs/fs-writeback.c:2054
 wb_do_writeback fs/fs-writeback.c:2197 [inline]
 wb_workfn+0x2e8/0x12d0 fs/fs-writeback.c:2238
 process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
 worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
 kthread+0x405/0x4f0 kernel/kthread.c:327
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	44 24 10             	rex.R and $0x10,%al
   3:	e8 92 68 66 ff       	callq  0xff66689a
   8:	be 08 00 00 00       	mov    $0x8,%esi
   d:	48 89 df             	mov    %rbx,%rdi
  10:	e8 e5 34 ad ff       	callq  0xffad34fa
  15:	48 89 d8             	mov    %rbx,%rax
  18:	48 c1 e8 03          	shr    $0x3,%rax
  1c:	42 80 3c 20 00       	cmpb   $0x0,(%rax,%r12,1)
  21:	0f 85 2b 05 00 00    	jne    0x552
  27:	48 8b 03             	mov    (%rbx),%rax
* 2a:	31 ff                	xor    %edi,%edi <-- trapping instruction
  2c:	83 e0 04             	and    $0x4,%eax
  2f:	49 89 c7             	mov    %rax,%r15
  32:	48 89 c6             	mov    %rax,%rsi
  35:	e8 f0 6a 66 ff       	callq  0xff666b2a
  3a:	4d 85 ff             	test   %r15,%r15
  3d:	0f                   	.byte 0xf
  3e:	85 ea                	test   %ebp,%edx

Crashes (4):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-net-this-kasan-gce 2021/12/30 09:39 net f7397cd24c59 6cc879d4 .config log report info INFO: task hung in __writeback_inodes_sb_nr
ci-upstream-net-this-kasan-gce 2021/12/23 12:57 net d1652b70d07c 6caa12e4 .config log report info INFO: task hung in __writeback_inodes_sb_nr
ci-upstream-net-this-kasan-gce 2021/12/12 02:23 net ee60e626d536 49ca1f59 .config log report info INFO: task hung in __writeback_inodes_sb_nr
ci-upstream-net-kasan-gce 2022/02/04 12:07 net-next 41414c9bdbb8 a3e470b2 .config log report info INFO: task hung in __writeback_inodes_sb_nr
* Struck through repros no longer work on HEAD.