syzbot


INFO: task hung in flush_async_commits

Status: upstream: reported on 2024/06/02 16:31
Reported-by: syzbot+d48fd243eb2da02cf623@syzkaller.appspotmail.com
First crash: 135d, last: 70d
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 INFO: task hung in flush_async_commits 1 12d 12d 0/3 upstream: reported on 2024/10/03 20:44
upstream INFO: task hung in flush_async_commits (2) reiserfs 3 382d 450d 0/28 auto-obsoleted due to no activity on 2023/12/28 15:52
upstream INFO: task hung in flush_async_commits reiserfs 4 619d 669d 0/28 auto-obsoleted due to no activity on 2023/05/05 20:14

Sample crash report:
INFO: task kworker/1:3:3588 blocked for more than 143 seconds.
      Not tainted 5.15.164-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:3     state:D stack:24288 pid: 3588 ppid:     2 flags:0x00004000
Workqueue: reiserfs/loop0 flush_async_commits
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_preempt_disabled+0xf/0x20 kernel/sched/core.c:6518
 __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
 reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
 flush_async_commits+0x42/0xc0 fs/reiserfs/journal.c:3547
 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:287
 </TASK>
INFO: task kworker/1:7:3617 blocked for more than 144 seconds.
      Not tainted 5.15.164-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:7     state:D stack:23576 pid: 3617 ppid:     2 flags:0x00004000
Workqueue: events_long flush_old_commits
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_preempt_disabled+0xf/0x20 kernel/sched/core.c:6518
 __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
 reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
 reiserfs_sync_fs fs/reiserfs/super.c:76 [inline]
 flush_old_commits+0x1df/0x2e0 fs/reiserfs/super.c:111
 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:287
 </TASK>
INFO: task syz.3.160:4249 blocked for more than 144 seconds.
      Not tainted 5.15.164-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz.3.160       state:D stack:27136 pid: 4249 ppid:  3569 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_preempt_disabled+0xf/0x20 kernel/sched/core.c:6518
 __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
 reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
 reiserfs_sync_fs+0x9c/0x140 fs/reiserfs/super.c:76
 iterate_supers+0x127/0x1e0 fs/super.c:705
 ksys_sync+0xd7/0x1c0 fs/sync.c:104
 __do_sys_sync+0xa/0x10 fs/sync.c:113
 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:0x7efd711079f9
RSP: 002b:00007efd6f565048 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00007efd71296058 RCX: 00007efd711079f9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007efd711758ee R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007efd71296058 R15: 00007fffc8ed61a8
 </TASK>
INFO: task syz.1.191:4369 blocked for more than 144 seconds.
      Not tainted 5.15.164-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz.1.191       state:D stack:28160 pid: 4369 ppid:  3568 flags:0x00004004
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_preempt_disabled+0xf/0x20 kernel/sched/core.c:6518
 __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
 reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
 reiserfs_sync_fs+0x9c/0x140 fs/reiserfs/super.c:76
 iterate_supers+0x127/0x1e0 fs/super.c:705
 ksys_sync+0xc8/0x1c0 fs/sync.c:103
 __do_sys_sync+0xa/0x10 fs/sync.c:113
 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:0x7f272a1559f9
RSP: 002b:00007f27285b3048 EFLAGS: 00000246 ORIG_RAX: 00000000000000a2
RAX: ffffffffffffffda RBX: 00007f272a2e4058 RCX: 00007f272a1559f9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 00007f272a1c38ee R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007f272a2e4058 R15: 00007ffd00ee10f8
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/27:
 #0: ffffffff8c91fb20 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
2 locks held by getty/3328:
 #0: ffff88814ae4b098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:252
 #1: ffffc9000229b2e8 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6af/0x1db0 drivers/tty/n_tty.c:2158
3 locks held by kworker/1:3/3588:
 #0: ffff888061703938 ((wq_completion)reiserfs/loop0){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90002ee7d20 ((work_completion)(&(&journal->j_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
3 locks held by kworker/1:4/3613:
 #0: ffff888011c70938 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90003067d20 ((work_completion)(&pwq->unbound_release_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
4 locks held by kworker/1:7/3617:
 #0: ffff888011c71138 ((wq_completion)events_long){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900030a7d20 ((work_completion)(&(&sbi->old_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
 #2: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: flush_old_commits+0xc7/0x2e0 fs/reiserfs/super.c:97
 #3: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
3 locks held by kworker/0:15/4157:
 #0: ffff888011c70938 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900033c7d20 ((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.0.153/4248:
2 locks held by syz.3.160/4249:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
2 locks held by syz.1.191/4369:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
2 locks held by kworker/1:9/4385:
 #0: ffff888011c72138 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc90002fa7d20 ((work_completion)(&rew.rew_work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
2 locks held by syz.4.219/4505:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
3 locks held by kworker/0:19/4506:
 #0: ffff888011c70938 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900046d7d20 ((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
2 locks held by syz.3.258/4686:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
2 locks held by kworker/u4:15/4871:
2 locks held by syz.2.304/4884:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
1 lock held by udevd/5026:
 #0: ffff88801b62c118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_get_by_dev+0x14d/0xa50 block/bdev.c:817
2 locks held by syz.0.319/5101:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
2 locks held by syz.4.343/5316:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
3 locks held by kworker/u4:23/5333:
2 locks held by syz.2.452/6144:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27
2 locks held by syz-executor/6236:
 #0: ffff88801b62c118 (&disk->open_mutex){+.+.}-{3:3}, at: blkdev_put+0xfb/0x790 block/bdev.c:912
 #1: ffff88801b50d468 (&lo->lo_mutex){+.+.}-{3:3}, at: __loop_clr_fd+0xa9/0xbe0 drivers/block/loop.c:1365
2 locks held by syz.0.523/6273:
 #0: ffff88807d2b60e0 (&type->s_umount_key#88){.+.+}-{3:3}, at: iterate_supers+0xac/0x1e0 fs/super.c:703
 #1: ffff888062a8e090 (&sbi->lock){+.+.}-{3:3}, at: reiserfs_write_lock+0x76/0xd0 fs/reiserfs/lock.c:27

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

NMI backtrace for cpu 0
CPU: 0 PID: 27 Comm: khungtaskd Not tainted 5.15.164-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/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:287
 </TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3028 Comm: udevd Not tainted 5.15.164-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/27/2024
RIP: 0010:preempt_latency_start kernel/sched/core.c:5473 [inline]
RIP: 0010:preempt_count_add+0xb8/0x180 kernel/sched/core.c:5496
Code: 00 85 c0 74 0a 45 31 f6 31 ff e8 83 8e 0c 00 65 48 8b 1d 9b 05 ab 7e 48 81 c3 e8 14 00 00 48 89 d8 48 c1 e8 03 42 80 3c 38 00 <74> 08 48 89 df e8 7e cb 72 00 4c 89 33 5b 41 5e 41 5f c3 e8 90 72
RSP: 0018:ffffc900022e77a8 EFLAGS: 00000246
RAX: 1ffff1100fc5cdc5 RBX: ffff88807e2e6e28 RCX: ffffffff8a3cb100
RDX: dffffc0000000000 RSI: ffffffff8a8b3ca0 RDI: ffffffff8a3bd173
RBP: ffff8880764e3c38 R08: dffffc0000000000 R09: fffffbfff1f8e01a
R10: 0000000000000000 R11: dffffc0000000001 R12: dffffc0000000000
R13: ffff8880764322f0 R14: ffffffff8a3bd173 R15: dffffc0000000000
FS:  00007fa9e56bcc80(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000110c435e65 CR3: 0000000023302000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 __down_read_common kernel/locking/rwsem.c:1237 [inline]
 __down_read kernel/locking/rwsem.c:1252 [inline]
 down_read+0x53/0x2e0 kernel/locking/rwsem.c:1500
 kernfs_dop_revalidate+0x87/0x4a0 fs/kernfs/dir.c:1090
 d_revalidate fs/namei.c:856 [inline]
 lookup_fast+0x37b/0x7b0 fs/namei.c:1624
 open_last_lookups fs/namei.c:3501 [inline]
 path_openat+0x6ae/0x2f20 fs/namei.c:3739
 do_filp_open+0x21c/0x460 fs/namei.c:3769
 do_sys_openat2+0x13b/0x4f0 fs/open.c:1253
 do_sys_open fs/open.c:1269 [inline]
 __do_sys_openat fs/open.c:1285 [inline]
 __se_sys_openat fs/open.c:1280 [inline]
 __x64_sys_openat+0x243/0x290 fs/open.c:1280
 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:0x7fa9e57e79a4
Code: 24 20 48 8d 44 24 30 48 89 44 24 28 64 8b 04 25 18 00 00 00 85 c0 75 2c 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 76 60 48 8b 15 55 a4 0d 00 f7 d8 64 89 02 48 83
RSP: 002b:00007ffec406fb10 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00007fa9e57e79a4
RDX: 0000000000080000 RSI: 00007ffec406fc48 RDI: 00000000ffffff9c
RBP: 00007ffec406fc48 R08: 0000000000000008 R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000080000
R13: 0000555a0ef15b42 R14: 0000000000000001 R15: 0000000000000000
 </TASK>

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/08/06 00:00 linux-5.15.y 7e89efd3ae1c e35c337f .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in flush_async_commits
2024/06/02 16:30 linux-5.15.y c61bd26ae81a 3113787f .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: task hung in flush_async_commits
* Struck through repros no longer work on HEAD.