syzbot


INFO: task hung in block_operations

Status: upstream: reported on 2022/12/30 23:43
Subsystems: f2fs
[Documentation on labels]
Reported-by: syzbot+beafd78dc209cb57fc7f@syzkaller.appspotmail.com
First crash: 536d, last: 536d

Sample crash report:
audit: type=1804 audit(1672443769.425:44): pid=14741 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir1323447472/syzkaller.onC1HV/64/bus" dev="sda1" ino=14178 res=1
INFO: task kworker/u4:5:3554 blocked for more than 140 seconds.
      Not tainted 4.14.302-syzkaller #0
audit: type=1800 audit(1672443769.425:45): pid=14741 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="sda1" ino=14178 res=0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
audit: type=1804 audit(1672443770.305:46): pid=14742 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.3" name="/root/syzkaller-testdir966455737/syzkaller.cJ2Aqw/75/bus" dev="sda1" ino=14178 res=1
kworker/u4:5    D27216  3554      2 0x80000000
Workqueue: writeback wb_workfn (flush-7:2)
audit: type=1800 audit(1672443770.305:47): pid=14742 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.3" name="bus" dev="sda1" ino=14178 res=0
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
audit: type=1804 audit(1672443770.305:48): pid=14743 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.0" name="/root/syzkaller-testdir1338092284/syzkaller.93aPtr/135/bus" dev="sda1" ino=14147 res=1
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 __rwsem_down_write_failed_common kernel/locking/rwsem-xadd.c:588 [inline]
 rwsem_down_write_failed+0x343/0x6d0 kernel/locking/rwsem-xadd.c:617
audit: type=1800 audit(1672443770.305:49): pid=14743 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.0" name="bus" dev="sda1" ino=14147 res=0
audit: type=1804 audit(1672443771.195:50): pid=14756 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.2" name="/root/syzkaller-testdir2147019885/syzkaller.tyErJR/77/bus" dev="sda1" ino=14289 res=1
 call_rwsem_down_write_failed+0x13/0x20 arch/x86/lib/rwsem.S:105
 __down_write arch/x86/include/asm/rwsem.h:126 [inline]
 down_write+0x4f/0x90 kernel/locking/rwsem.c:56
 f2fs_lock_all fs/f2fs/f2fs.h:1457 [inline]
 block_operations+0xdd/0x6d0 fs/f2fs/checkpoint.c:1058
audit: type=1800 audit(1672443771.195:51): pid=14756 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.2" name="bus" dev="sda1" ino=14289 res=0
audit: type=1804 audit(1672443771.195:52): pid=14755 uid=0 auid=4294967295 ses=4294967295 op="invalid_pcr" cause="open_writers" comm="syz-executor.5" name="/root/syzkaller-testdir1323447472/syzkaller.onC1HV/65/bus" dev="sda1" ino=14305 res=1
 write_checkpoint+0x203/0x45f0 fs/f2fs/checkpoint.c:1377
audit: type=1800 audit(1672443771.195:53): pid=14755 uid=0 auid=4294967295 ses=4294967295 op="collect_data" cause="failed(directio)" comm="syz-executor.5" name="bus" dev="sda1" ino=14305 res=0
 f2fs_sync_fs+0x178/0x3f0 fs/f2fs/super.c:873
 f2fs_balance_fs_bg+0x3a6/0x830 fs/f2fs/segment.c:474
 f2fs_write_node_pages+0x109/0x990 fs/f2fs/node.c:1732
 do_writepages+0xc3/0x240 mm/page-writeback.c:2361
 __writeback_single_inode+0xda/0x1010 fs/fs-writeback.c:1382
 writeback_sb_inodes+0x48b/0xd30 fs/fs-writeback.c:1645
 __writeback_inodes_wb+0xbf/0x230 fs/fs-writeback.c:1716
 wb_writeback+0x710/0xb80 fs/fs-writeback.c:1822
 wb_check_old_data_flush fs/fs-writeback.c:1935 [inline]
 wb_do_writeback fs/fs-writeback.c:1959 [inline]
 wb_workfn+0x708/0xf50 fs/fs-writeback.c:1988
 process_one_work+0x793/0x14a0 kernel/workqueue.c:2117
 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:406

Showing all locks held in the system:
2 locks held by kworker/0:0/3:
 #0:  ("events"){+.+.}, at: [<ffffffff81366130>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&rew.rew_work)){+.+.}, at: [<ffffffff81366166>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
6 locks held by kworker/u4:2/34:
 #0:  ("writeback"){+.+.}, at: [<ffffffff81366130>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&(&wb->dwork)->work)){+.+.}, at: [<ffffffff81366166>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&type->s_umount_key#71){.+.+}, at: [<ffffffff8187b4eb>] trylock_super+0x1b/0xe0 fs/super.c:402
 #3:  (&sbi->gc_mutex){+.+.}, at: [<ffffffff82c56b4b>] f2fs_sync_fs+0x16b/0x3f0 fs/f2fs/super.c:872
 #4:  (&sbi->cp_mutex){+.+.}, at: [<ffffffff82c79862>] write_checkpoint+0x62/0x45f0 fs/f2fs/checkpoint.c:1360
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] f2fs_lock_all fs/f2fs/f2fs.h:1457 [inline]
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] block_operations+0xdd/0x6d0 fs/f2fs/checkpoint.c:1058
6 locks held by kworker/u4:3/200:
 #0:  ("writeback"){+.+.}, at: [<ffffffff81366130>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&(&wb->dwork)->work)){+.+.}, at: [<ffffffff81366166>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&type->s_umount_key#71){.+.+}, at: [<ffffffff8187b4eb>] trylock_super+0x1b/0xe0 fs/super.c:402
 #3:  (&sbi->gc_mutex){+.+.}, at: [<ffffffff82c56b4b>] f2fs_sync_fs+0x16b/0x3f0 fs/f2fs/super.c:872
 #4:  (&sbi->cp_mutex){+.+.}, at: [<ffffffff82c79862>] write_checkpoint+0x62/0x45f0 fs/f2fs/checkpoint.c:1360
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] f2fs_lock_all fs/f2fs/f2fs.h:1457 [inline]
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] block_operations+0xdd/0x6d0 fs/f2fs/checkpoint.c:1058
1 lock held by khungtaskd/1533:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff8702b3a4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
6 locks held by kworker/u4:5/3554:
 #0:  ("writeback"){+.+.}, at: [<ffffffff81366130>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&(&wb->dwork)->work)){+.+.}, at: [<ffffffff81366166>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&type->s_umount_key#71){.+.+}, at: [<ffffffff8187b4eb>] trylock_super+0x1b/0xe0 fs/super.c:402
 #3:  (&sbi->gc_mutex){+.+.}, at: [<ffffffff82c56b4b>] f2fs_sync_fs+0x16b/0x3f0 fs/f2fs/super.c:872
 #4:  (&sbi->cp_mutex){+.+.}, at: [<ffffffff82c79862>] write_checkpoint+0x62/0x45f0 fs/f2fs/checkpoint.c:1360
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] f2fs_lock_all fs/f2fs/f2fs.h:1457 [inline]
 #5:  (&sbi->cp_rwsem){++++}, at: [<ffffffff82c7920d>] block_operations+0xdd/0x6d0 fs/f2fs/checkpoint.c:1058
1 lock held by syz-executor.0/7996:
 #0:  (rcu_preempt_state.exp_mutex){+.+.}, at: [<ffffffff81471452>] exp_funnel_lock kernel/rcu/tree_exp.h:272 [inline]
 #0:  (rcu_preempt_state.exp_mutex){+.+.}, at: [<ffffffff81471452>] _synchronize_rcu_expedited+0x2c2/0x770 kernel/rcu/tree_exp.h:596
1 lock held by syz-executor.2/11952:
 #0:  (rcu_preempt_state.exp_mutex){+.+.}, at: [<ffffffff814714bd>] exp_funnel_lock kernel/rcu/tree_exp.h:305 [inline]
 #0:  (rcu_preempt_state.exp_mutex){+.+.}, at: [<ffffffff814714bd>] _synchronize_rcu_expedited+0x32d/0x770 kernel/rcu/tree_exp.h:596

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

init_special_inode: bogus i_mode (11) for inode loop1:2
print_req_error: I/O error, dev loop1, sector 0
Buffer I/O error on dev loop1, logical block 0, async page read
print_req_error: I/O error, dev loop1, sector 6
Buffer I/O error on dev loop1, logical block 3, async page read
init_special_inode: bogus i_mode (11) for inode loop1:2
init_special_inode: bogus i_mode (11) for inode loop1:2
block nbd4: shutting down sockets

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

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2022/12/30 23:43 linux-4.14.y c4215ee4771b ab32d508 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-4-14 INFO: task hung in block_operations
* Struck through repros no longer work on HEAD.