[f2fs?] INFO: task hung in block_operations

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: c4215ee4771b Linux 4.14.302
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=13712718480000
kernel config: https://syzkaller.appspot.com/x/.config?x=4a9988fe055c9527
dashboard link: https://syzkaller.appspot.com/bug?extid=beafd78dc209cb57fc7f
compiler: gcc version 10.2.1 20210110 (Debian 10.2.1-6)

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/c93ba055d204/disk-c4215ee4.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/bfbc929a33c1/vmlinux-c4215ee4.xz
kernel image: https://storage.googleapis.com/syzbot-assets/444658051770/bzImage-c4215ee4.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+beafd7...@syzkaller.appspotmail.com

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

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


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.