syzbot


INFO: task hung in f2fs_issue_checkpoint

Status: upstream: reported on 2024/04/02 10:19
Reported-by: syzbot+d685021e4fad21571354@syzkaller.appspotmail.com
First crash: 35d, last: 7d19h
Similar bugs (1)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in f2fs_issue_checkpoint f2fs C error inconclusive 86 173d 554d 0/26 auto-obsoleted due to no activity on 2024/02/10 19:41

Sample crash report:
INFO: task syz-executor.4:5563 blocked for more than 143 seconds.
      Not tainted 5.15.157-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4  state:D stack:22176 pid: 5563 ppid:  4132 flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5030 [inline]
 __schedule+0x12c4/0x45b0 kernel/sched/core.c:6376
 schedule+0x11b/0x1f0 kernel/sched/core.c:6459
 schedule_timeout+0xac/0x300 kernel/time/timer.c:1890
 do_wait_for_common+0x2d9/0x480 kernel/sched/completion.c:85
 __wait_for_common kernel/sched/completion.c:106 [inline]
 wait_for_common kernel/sched/completion.c:117 [inline]
 wait_for_completion+0x48/0x60 kernel/sched/completion.c:138
 f2fs_issue_checkpoint+0x35f/0x4c0
 f2fs_rename fs/f2fs/namei.c:1108 [inline]
 f2fs_rename2+0x22ee/0x2790 fs/f2fs/namei.c:1315
 vfs_rename+0xd32/0x10f0 fs/namei.c:4832
 do_renameat2+0xe0f/0x1700 fs/namei.c:4985
 __do_sys_rename fs/namei.c:5031 [inline]
 __se_sys_rename fs/namei.c:5029 [inline]
 __x64_sys_rename+0x82/0x90 fs/namei.c:5029
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x3b/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x66/0xd0
RIP: 0033:0x7fbd28897ea9
RSP: 002b:00007fbd26e0a0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000052
RAX: ffffffffffffffda RBX: 00007fbd289c5f80 RCX: 00007fbd28897ea9
RDX: 0000000000000000 RSI: 0000000020000100 RDI: 00000000200002c0
RBP: 00007fbd288e44a4 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007fbd289c5f80 R15: 00007fff63963078
 </TASK>

Showing all locks held in the system:
4 locks held by kworker/u4:0/9:
2 locks held by kworker/1:0/21:
 #0: ffff888011c72138 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90000db7d20 ((work_completion)(&rew.rew_work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
1 lock held by khungtaskd/27:
 #0: ffffffff8c91fb20 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
3 locks held by kworker/u4:1/144:
 #0: ffff8881423b4938 ((wq_completion)writeback){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900010bfd20 ((work_completion)(&(&wb->dwork)->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffff88807dcd80e0 (&type->s_umount_key#76){++++}-{3:3}, at: trylock_super+0x1b/0xf0 fs/super.c:418
2 locks held by getty/3260:
 #0: ffff8880248a4098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc90002bab2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6af/0x1db0 drivers/tty/n_tty.c:2158
1 lock held by syz-fuzzer/3693:
 #0: ffff8880b9a3a358 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x26/0x140 kernel/sched/core.c:475
3 locks held by kworker/1:11/3652:
 #0: ffff888011c70938 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90004c07d20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffffffff8c9240e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:290 [inline]
 #2: ffffffff8c9240e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x280/0x740 kernel/rcu/tree_exp.h:845
3 locks held by kworker/1:18/3659:
 #0: ffff888011c70938 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90004597d20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffffffff8c923ff0 (rcu_state.barrier_mutex){+.+.}-{3:3}, at: rcu_barrier+0x9c/0x4e0 kernel/rcu/tree.c:4039
5 locks held by syz-executor.4/5563:
 #0: ffff88807dcd8460 (sb_writers#25){.+.+}-{0:0}, at: mnt_want_write+0x3b/0x80 fs/namespace.c:377
 #1: ffff88807dcd8748 (&type->s_vfs_rename_key#2){+.+.}-{3:3}, at: lock_rename fs/namei.c:3016 [inline]
 #1: ffff88807dcd8748 (&type->s_vfs_rename_key#2){+.+.}-{3:3}, at: do_renameat2+0x5b7/0x1700 fs/namei.c:4924
 #2: ffff88806ffa43d0 (&type->i_mutex_dir_key#14/1){+.+.}-{3:3}, at: lock_rename fs/namei.c:3017 [inline]
 #2: ffff88806ffa43d0 (&type->i_mutex_dir_key#14/1){+.+.}-{3:3}, at: do_renameat2+0x644/0x1700 fs/namei.c:4924
 #3: ffff88806ffa6050 (&type->i_mutex_dir_key#14/5){+.+.}-{3:3}, at: do_renameat2+0x67e/0x1700 fs/namei.c:4924
 #4: ffff88806ffa4d50 (&sb->s_type->i_mutex_key#32/4){+.+.}-{3:3}, at: vfs_rename+0x7e4/0x10f0 fs/namei.c:4803
2 locks held by f2fs_ckpt-7:4/5606:
1 lock held by syz-executor.0/7009:
 #0: ffffffff8c9240e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:322 [inline]
 #0: ffffffff8c9240e8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x350/0x740 kernel/rcu/tree_exp.h:845
1 lock held by syz-executor.4/7140:
 #0: ffff8880b9b3a358 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x26/0x140 kernel/sched/core.c:475
2 locks held by syz-executor.3/7850:
 #0: ffff888147228118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff88814721a468 (&lo->lo_mutex){+.+.}-{3:3}, at: lo_release+0x4d/0x1f0 drivers/block/loop.c:2070
2 locks held by syz-executor.2/7853:
 #0: ffff88801b6b3918 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff88801b6a7468 (&lo->lo_mutex){+.+.}-{3:3}, at: lo_release+0x4d/0x1f0 drivers/block/loop.c:2070
1 lock held by syz-executor.1/7870:
 #0: ffff888021bee0e0 (&type->s_umount_key#58/1){+.+.}-{3:3}, at: alloc_super+0x210/0x940 fs/super.c:229

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

NMI backtrace for cpu 1
CPU: 1 PID: 27 Comm: khungtaskd Not tainted 5.15.157-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2d0 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:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 7465 Comm: kworker/u4:15 Not tainted 5.15.157-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Workqueue: loop2 loop_workfn
RIP: 0010:_find_first_zero_bit+0x92/0xf0 lib/find_bit.c:101
Code: 78 fd 45 31 f6 4c 89 f0 eb 6f 49 83 c7 08 41 bc 40 00 00 00 4d 89 fd 4c 89 e7 4c 89 f6 e8 06 7a 78 fd 4d 39 f4 73 31 4c 89 e8 <48> c1 e8 03 80 3c 28 00 74 08 4c 89 ef e8 1c 50 c2 fd 49 8b 1f 48
RSP: 0018:ffffc900033c6fe8 EFLAGS: 00000083
RAX: ffffffff8faad390 RBX: ffffffffffffffff RCX: ffff88801e339dc0
RDX: 0000000000000000 RSI: 0000000000040000 RDI: 0000000000001e80
RBP: dffffc0000000000 R08: ffffffff8407e4ba R09: 0000000000000003
R10: ffffffffffffffff R11: dffffc0000000001 R12: 0000000000001e80
R13: ffffffff8faad390 R14: 0000000000040000 R15: ffffffff8faad390
FS:  0000000000000000(0000) GS:ffff8880b9a00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f0c09385000 CR3: 000000006077d000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 find_first_zero_bit include/asm-generic/bitops/find.h:140 [inline]
 alloc_lock_chain kernel/locking/lockdep.c:3598 [inline]
 add_chain_cache kernel/locking/lockdep.c:3630 [inline]
 lookup_chain_cache_add kernel/locking/lockdep.c:3735 [inline]
 validate_chain+0x2a7/0x5930 kernel/locking/lockdep.c:3756
 __lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5012
 lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
 _raw_spin_lock_nested+0x2d/0x40 kernel/locking/spinlock.c:368
 raw_spin_rq_lock_nested+0x26/0x140 kernel/sched/core.c:475
 raw_spin_rq_lock kernel/sched/sched.h:1326 [inline]
 rq_lock kernel/sched/sched.h:1621 [inline]
 __schedule+0x2f2/0x45b0 kernel/sched/core.c:6290
 preempt_schedule_common+0x83/0xd0 kernel/sched/core.c:6552
 preempt_schedule+0xd9/0xe0 kernel/sched/core.c:6577
 preempt_schedule_thunk+0x16/0x18 arch/x86/entry/thunk_64.S:34
 blk_mq_raise_softirq block/blk-mq.c:653 [inline]
 blk_mq_complete_request_remote+0x518/0x640 block/blk-mq.c:673
 blk_mq_complete_request+0x15/0xa0 block/blk-mq.c:689
 loop_handle_cmd drivers/block/loop.c:2251 [inline]
 loop_process_work+0x19f1/0x2af0 drivers/block/loop.c:2274
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/04/29 22:27 linux-5.15.y b925f60c6ee7 f10afd69 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in f2fs_issue_checkpoint
2024/04/29 15:30 linux-5.15.y b925f60c6ee7 27e33c58 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in f2fs_issue_checkpoint
2024/04/02 10:18 linux-5.15.y 9465fef4ae35 6baf5069 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 INFO: task hung in f2fs_issue_checkpoint
* Struck through repros no longer work on HEAD.