syzbot


INFO: task hung in writepage_delalloc (2)

Status: auto-obsoleted due to no activity on 2024/01/04 22:50
Reported-by: syzbot+a908279f0d4e40fc322c@syzkaller.appspotmail.com
First crash: 387d, last: 387d
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in writepage_delalloc btrfs 1 445d 445d 0/28 auto-obsoleted due to no activity on 2023/09/28 02:46
linux-5.15 INFO: task hung in writepage_delalloc 1 576d 576d 0/3 auto-obsoleted due to no activity on 2023/07/19 03:54
upstream INFO: task hung in writepage_delalloc (2) btrfs 1 351d 351d 0/28 auto-obsoleted due to no activity on 2024/01/30 19:55

Sample crash report:
INFO: task kworker/u4:27:20364 blocked for more than 143 seconds.
      Not tainted 5.15.133-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:27   state:D stack:20312 pid:20364 ppid:     2 flags:0x00004000
Workqueue: events_unbound btrfs_async_reclaim_metadata_space
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5026 [inline]
 __schedule+0x12c4/0x4590 kernel/sched/core.c:6372
 schedule+0x11b/0x1f0 kernel/sched/core.c:6455
 wait_on_state fs/btrfs/extent_io.c:868 [inline]
 wait_extent_bit+0x3f9/0x530 fs/btrfs/extent_io.c:906
 lock_extent_bits fs/btrfs/extent_io.c:1469 [inline]
 find_lock_delalloc_range+0x469/0x8f0 fs/btrfs/extent_io.c:2047
 writepage_delalloc+0x1a0/0x5a0 fs/btrfs/extent_io.c:3795
 __extent_writepage+0x57d/0xbc0 fs/btrfs/extent_io.c:4108
 extent_write_cache_pages fs/btrfs/extent_io.c:5030 [inline]
 extent_writepages+0xbbd/0x1590 fs/btrfs/extent_io.c:5157
 do_writepages+0x481/0x730 mm/page-writeback.c:2364
 filemap_fdatawrite_wbc+0x1d6/0x230 mm/filemap.c:400
 start_delalloc_inodes+0x7df/0xca0 fs/btrfs/inode.c:10071
 btrfs_start_delalloc_roots+0x72f/0xa70 fs/btrfs/inode.c:10150
 shrink_delalloc fs/btrfs/space-info.c:538 [inline]
 flush_space+0x650/0xd50 fs/btrfs/space-info.c:646
 btrfs_async_reclaim_metadata_space+0x29b/0x340 fs/btrfs/space-info.c:953
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
INFO: task syz-executor.1:31132 blocked for more than 144 seconds.
      Not tainted 5.15.133-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:22752 pid:31132 ppid:  3561 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5026 [inline]
 __schedule+0x12c4/0x4590 kernel/sched/core.c:6372
 schedule+0x11b/0x1f0 kernel/sched/core.c:6455
 io_schedule+0x88/0x100 kernel/sched/core.c:8480
 wait_on_page_bit_common+0xa13/0x1180 mm/filemap.c:1356
 lock_page include/linux/pagemap.h:625 [inline]
 set_page_dirty_lock+0xae/0xe0 mm/page-writeback.c:2633
 bio_set_pages_dirty+0x1f3/0x2c0 block/bio.c:1349
 iomap_dio_bio_iter+0xb8d/0x1540 fs/iomap/direct-io.c:338
 __iomap_dio_rw+0xf9f/0x1f40 fs/iomap/direct-io.c:586
 iomap_dio_rw+0x38/0x80 fs/iomap/direct-io.c:672
 btrfs_direct_read fs/btrfs/file.c:3788 [inline]
 btrfs_file_read_iter+0x3a1/0x6a0 fs/btrfs/file.c:3828
 do_iter_readv_writev+0x594/0x7a0
 do_iter_read+0x1ec/0x760 fs/read_write.c:790
 vfs_readv fs/read_write.c:910 [inline]
 do_preadv+0x211/0x350 fs/read_write.c:1002
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7f91c48ceae9
RSP: 002b:00007f91c2e500c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000147
RAX: ffffffffffffffda RBX: 00007f91c49edf80 RCX: 00007f91c48ceae9
RDX: 0000000000000001 RSI: 0000000020000100 RDI: 0000000000000005
RBP: 00007f91c491a47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007f91c49edf80 R15: 00007fffc0bb30e8
 </TASK>
INFO: task syz-executor.1:31153 blocked for more than 144 seconds.
      Not tainted 5.15.133-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:27904 pid:31153 ppid:  3561 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5026 [inline]
 __schedule+0x12c4/0x4590 kernel/sched/core.c:6372
 schedule+0x11b/0x1f0 kernel/sched/core.c:6455
 rwsem_down_write_slowpath+0xebb/0x15c0 kernel/locking/rwsem.c:1157
 __down_write_common kernel/locking/rwsem.c:1284 [inline]
 __down_write kernel/locking/rwsem.c:1293 [inline]
 down_write+0x164/0x170 kernel/locking/rwsem.c:1542
 inode_lock include/linux/fs.h:787 [inline]
 btrfs_inode_lock+0x49/0xd0 fs/btrfs/inode.c:124
 btrfs_buffered_write+0x20f/0x1270 fs/btrfs/file.c:1679
 btrfs_direct_write fs/btrfs/file.c:2038 [inline]
 btrfs_file_write_iter+0x975/0xc60 fs/btrfs/file.c:2086
 call_write_iter include/linux/fs.h:2103 [inline]
 new_sync_write fs/read_write.c:507 [inline]
 vfs_write+0xacf/0xe50 fs/read_write.c:594
 ksys_write+0x1a2/0x2c0 fs/read_write.c:647
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7f91c48ceae9
RSP: 002b:00007f91bba0e0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f91c49ee120 RCX: 00007f91c48ceae9
RDX: 0000000000000128 RSI: 0000000020004400 RDI: 0000000000000005
RBP: 00007f91c491a47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f91c49ee120 R15: 00007fffc0bb30e8
 </TASK>
INFO: task syz-executor.1:31154 blocked for more than 145 seconds.
      Not tainted 5.15.133-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.1  state:D stack:29408 pid:31154 ppid:  3561 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5026 [inline]
 __schedule+0x12c4/0x4590 kernel/sched/core.c:6372
 schedule+0x11b/0x1f0 kernel/sched/core.c:6455
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6514
 __mutex_lock_common+0xe34/0x25a0 kernel/locking/mutex.c:669
 __mutex_lock kernel/locking/mutex.c:729 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:743
 __fdget_pos+0x2cb/0x380 fs/file.c:1088
 fdget_pos include/linux/file.h:75 [inline]
 ksys_write+0x7e/0x2c0 fs/read_write.c:638
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x61/0xcb
RIP: 0033:0x7f91c48ceae9
RSP: 002b:00007f91bb9ed0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007f91c49ee1f0 RCX: 00007f91c48ceae9
RDX: 0000000000000128 RSI: 0000000020004400 RDI: 0000000000000005
RBP: 00007f91c491a47a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f91c49ee1f0 R15: 00007fffc0bb30e8
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/26:
 #0: ffffffff8c91f0a0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/3272:
 #0: ffff88814b23d098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc900020a32e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6af/0x1db0 drivers/tty/n_tty.c:2158
1 lock held by syz-executor.5/3558:
3 locks held by syz-executor.4/22581:
 #0: ffff8880b9a39718 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x26/0x140 kernel/sched/core.c:475
 #1: ffff8880b9a27848 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x53d/0x810 kernel/sched/psi.c:891
 #2: ffffffff8c91f0a0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
3 locks held by kworker/u4:21/20358:
2 locks held by kworker/u4:22/20359:
4 locks held by kworker/u4:27/20364:
 #0: ffff888011c79138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900047c7d20 ((work_completion)(&fs_info->async_reclaim_work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffff888077af8eb0 (&fs_info->delalloc_root_mutex){+.+.}-{3:3}, at: btrfs_start_delalloc_roots+0x1c6/0xa70 fs/btrfs/inode.c:10131
 #3: ffff88807a432750 (&root->delalloc_mutex){+.+.}-{3:3}, at: start_delalloc_inodes+0x1a8/0xca0 fs/btrfs/inode.c:10036
3 locks held by kworker/u4:28/20365:
 #0: ffff888142388138 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900047d7d20 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffff88807ee100e0 (&type->s_umount_key#94){++++}-{3:3}, at: trylock_super+0x1b/0xf0 fs/super.c:418
1 lock held by syz-executor.1/31132:
 #0: ffff888075dd19b0 (&sb->s_type->i_mutex_key#32){++++}-{3:3}, at: inode_lock_shared include/linux/fs.h:797 [inline]
 #0: ffff888075dd19b0 (&sb->s_type->i_mutex_key#32){++++}-{3:3}, at: btrfs_inode_lock+0x5c/0xd0 fs/btrfs/inode.c:116
3 locks held by syz-executor.1/31153:
 #0: ffff888065450370 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2cb/0x380 fs/file.c:1088
 #1: ffff88807ee10460 (sb_writers#26){.+.+}-{0:0}, at: vfs_write+0x29a/0xe50 fs/read_write.c:590
 #2: ffff888075dd19b0 (&sb->s_type->i_mutex_key#32){++++}-{3:3}, at: inode_lock include/linux/fs.h:787 [inline]
 #2: ffff888075dd19b0 (&sb->s_type->i_mutex_key#32){++++}-{3:3}, at: btrfs_inode_lock+0x49/0xd0 fs/btrfs/inode.c:124
1 lock held by syz-executor.1/31154:
 #0: ffff888065450370 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2cb/0x380 fs/file.c:1088
2 locks held by syz-executor.3/4109:
 #0: ffffffff9179d478 (nfnl_subsys_ipset){+.+.}-{3:3}, at: nfnl_lock net/netfilter/nfnetlink.c:93 [inline]
 #0: ffffffff9179d478 (nfnl_subsys_ipset){+.+.}-{3:3}, at: nfnetlink_rcv_msg+0x9e4/0x1090 net/netfilter/nfnetlink.c:290
 #1: ffffffff8c923570 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x9c/0x4e0 kernel/rcu/tree.c:4018

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

NMI backtrace for cpu 0
CPU: 0 PID: 26 Comm: khungtaskd Not tainted 5.15.133-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/04/2023
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 nmi_cpu_backtrace+0x46a/0x4a0 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x181/0x2a0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:210 [inline]
 watchdog+0xe72/0xeb0 kernel/hung_task.c:295
 kthread+0x3f6/0x4f0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 10046 Comm: syz-fuzzer Not tainted 5.15.133-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 08/04/2023
RIP: 0033:0x54f9ac
Code: 40 48 8b 49 30 48 8b 44 24 70 0f b6 5c 24 3b ff d1 48 89 44 24 48 48 89 5c 24 78 48 8b 8c 24 98 00 00 00 48 8b 89 b8 00 00 00 <48> 8b 84 24 e8 00 00 00 ff d1 89 44 24 3c 48 8d 05 5f 93 4c 00 e8
RSP: 002b:000000c03745ef20 EFLAGS: 00000246
RAX: 0000000000cecaf0 RBX: 000000c03a09c680 RCX: 000000000057bf40
RDX: 000000c039bf5f00 RSI: 0000000000000001 RDI: 0000000000000000
RBP: 000000c03745efe8 R08: 0000000000000020 R09: 000000c03a09c600
R10: 00000000601d04e3 R11: 000000000000a333 R12: ffffffffffffffff
R13: 0000000000000014 R14: 000000c0000061a0 R15: 0000000000010000
FS:  000000c03f921090 GS:  0000000000000000

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/09/26 22:50 linux-5.15.y b911329317b4 0b6a67ac .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in writepage_delalloc
* Struck through repros no longer work on HEAD.