INFO: task hung in hfs_mdb_commit

Status: upstream: reported C repro on 2023/01/25 02:58
Labels: hfs (incorrect?)
First crash: 135d, last: 135d

Fix bisection: failed (error log, bisect log)
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in hfs_mdb_commit hfs C error 12 17d 144d 0/24 upstream: reported C repro on 2023/01/16 13:34
linux-6.1 INFO: task hung in hfs_mdb_commit 1 17d 17d 0/3 upstream: reported on 2023/05/23 05:52

Sample crash report:
INFO: task kworker/0:0:8176 blocked for more than 140 seconds.
      Not tainted 4.19.211-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:0     D28808  8176      2 0x80000000
Workqueue: events_long flush_mdb
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 io_schedule+0xb5/0x120 kernel/sched/core.c:5181
 bit_wait_io+0x12/0x90 kernel/sched/wait_bit.c:207
 __wait_on_bit_lock+0xb5/0x170 kernel/sched/wait_bit.c:89
 out_of_line_wait_on_bit_lock+0xd2/0x100 kernel/sched/wait_bit.c:116
 wait_on_bit_lock_io include/linux/wait_bit.h:208 [inline]
 __lock_buffer+0x52/0x60 fs/buffer.c:65
 lock_buffer include/linux/buffer_head.h:374 [inline]
 hfs_mdb_commit+0x55e/0x11e0 fs/hfs/mdb.c:319
 process_one_work+0x864/0x1570 kernel/workqueue.c:2153
 worker_thread+0x64c/0x1130 kernel/workqueue.c:2296
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Showing all locks held in the system:
1 lock held by khungtaskd/1570:
 #0: 000000002e56a843 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4441
1 lock held by systemd-journal/4679:
 #0: 00000000b9c69cdb (&rq->lock){-.-.}, at: idle_balance kernel/sched/fair.c:9702 [inline]
 #0: 00000000b9c69cdb (&rq->lock){-.-.}, at: pick_next_task_fair+0x556/0x1570 kernel/sched/fair.c:6841
1 lock held by in:imklog/7806:
 #0: 00000000eadc87c2 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
2 locks held by kworker/0:0/8176:
 #0: 0000000053c54be6 ((wq_completion)"events_long"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2124
 #1: 00000000f22088ba ((work_completion)(&(&sbi->mdb_work)->work)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2128
2 locks held by syz-executor295/15193:
 #0: 00000000e77b2216 (&type->i_mutex_dir_key#7){+.+.}, at: inode_lock include/linux/fs.h:748 [inline]
 #0: 00000000e77b2216 (&type->i_mutex_dir_key#7){+.+.}, at: lock_mount+0xcc/0x4a0 fs/namespace.c:2075
 #1: 00000000cd5ad5e7 (rcu_preempt_state.exp_mutex){+.+.}, at: exp_funnel_lock kernel/rcu/tree_exp.h:297 [inline]
 #1: 00000000cd5ad5e7 (rcu_preempt_state.exp_mutex){+.+.}, at: _synchronize_rcu_expedited+0x4dc/0x6f0 kernel/rcu/tree_exp.h:667


NMI backtrace for cpu 0
CPU: 0 PID: 1570 Comm: khungtaskd Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2ef lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1a6/0x1f0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
 watchdog+0x991/0xe60 kernel/hung_task.c:287
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 10 Comm: rcu_preempt Not tainted 4.19.211-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/12/2023
RIP: 0010:lookup_chain_cache kernel/locking/lockdep.c:2318 [inline]
RIP: 0010:lookup_chain_cache_add kernel/locking/lockdep.c:2337 [inline]
RIP: 0010:validate_chain kernel/locking/lockdep.c:2391 [inline]
RIP: 0010:__lock_acquire+0xbed/0x3ff0 kernel/locking/lockdep.c:3416
Code: db 74 55 48 83 eb 08 74 4f 48 bd 00 00 00 00 00 fc ff df eb 06 48 83 eb 08 74 3d 48 8d 7b 18 48 89 f8 48 c1 e8 03 80 3c 28 00 <0f> 85 8c 1e 00 00 4c 3b 63 18 0f 84 f1 fc ff ff 48 8d 7b 08 48 89
RSP: 0018:ffff8880b5a679e0 EFLAGS: 00000046
RAX: 1ffffffff18e2a5b RBX: ffffffff8c7152c0 RCX: 0000000000005d11
RDX: 1ffffffff19a8bb9 RSI: 00000000f59a8c27 RDI: ffffffff8c7152d8
RBP: dffffc0000000000 R08: ffffffff8cd45dc8 R09: 0000000000000000
R10: ffff8880b5a4eb08 R11: 0000000000000000 R12: 577f4c272808619f
R13: ffff8880b5a4e280 R14: ffff8880b5a4eb20 R15: 0000000000000001
FS:  0000000000000000(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f1fd89c4000 CR3: 00000000a1986000 CR4: 00000000003406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3908
 del_timer_sync+0xab/0x270 kernel/time/timer.c:1295
 schedule_timeout+0x4d7/0xfe0 kernel/time/timer.c:1819
 rcu_gp_kthread+0xdad/0x21c0 kernel/rcu/tree.c:2202
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets Manager Title
2023/01/25 02:58 linux-4.19.y 3f8a27f9e27b 9dfcf09c .config console log report syz C [disk image] [vmlinux] [mounted in repro] ci2-linux-4-19 INFO: task hung in hfs_mdb_commit
* Struck through repros no longer work on HEAD.