Message-Id: <42BD15B5-3C6C-437E-BF52-E22E6F200513@m.fudan.edu.cn>
Date: Sun, 12 Jan 2025 18:00:24 +0800
From: Kun Hu <huk23@...udan.edu.cn>
To: jlayton@...hat.com,
 tytso@....edu,
 adilger.kernel@...ger.ca,
 david@...morbit.com,
 bfields@...hat.com,
 viro@...iv.linux.org.uk,
 christian.brauner@...ntu.com,
 hch@....de
Cc: linux-fsdevel@...r.kernel.org,
 linux-kernel@...r.kernel.org,
 jack@...e.cz,
 brauner@...nel.org,
 viro@...iv.linux.org.uk
Subject: Bug: INFO_ task hung in lock_two_nondirectories

Hello,

When using our customized fuzzer tool to fuzz the latest Linux kernel, the following crash (43s)
was triggered.

HEAD commit: 9d89551994a430b50c4fffcb1e617a057fa76e20
git tree: upstream
Console output: https://github.com/pghk13/Kernel-Bug/blob/main/0110_6.13rc6/43-INFO_%20task%20hung%20in%20lock_two_nondirectories/log0
Kernel config: https://github.com/pghk13/Kernel-Bug/blob/main/0110_6.13rc6/config.txt
C reproducer: https://github.com/pghk13/Kernel-Bug/blob/main/0110_6.13rc6/43-INFO_%20task%20hung%20in%20lock_two_nondirectories/12generated_program.c
Syzlang reproducer: https://github.com/pghk13/Kernel-Bug/blob/main/0110_6.13rc6/43-INFO_%20task%20hung%20in%20lock_two_nondirectories/12_repro.txt

We first found the issue without a stable C and Syzlang reproducers, but later I tried multiple rounds of replication and got the C and Syzlang reproducers.

I suspect the issue may stem from resource contention or synchronization delays, as indicated by functions like lock_two_nondirectories and vfs_rename. There could also be potential deadlocks or inconsistencies in file system state management (e.g., sb_writers or inode locks) within the bcachefs subsystem. Additionally, interactions between lock_rename and concurrent rename operations might be contributing factors.

Could you kindly help review these areas to narrow down the root cause? Your expertise would be greatly appreciated.

If you fix this issue, please add the following tag to the commit:
Reported-by: Kun Hu <huk23@...udan.edu.cn>, Jiaji Qin <jjtan24@...udan.edu.cn>

INFO: task syz.0.12:1823 blocked for more than 143 seconds.
      Tainted: G        W          6.13.0-rc6 #1
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz.0.12        state:D stack:25728 pid:1823  tgid:1714  ppid:442    flags:0x00000004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5369 [inline]
 __schedule+0xe60/0x4120 kernel/sched/core.c:6756
 __schedule_loop kernel/sched/core.c:6833 [inline]
 schedule+0xd4/0x210 kernel/sched/core.c:6848
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6905
 rwsem_down_write_slowpath+0x551/0x1660 kernel/locking/rwsem.c:1176
 __down_write_common kernel/locking/rwsem.c:1304 [inline]
 __down_write kernel/locking/rwsem.c:1313 [inline]
 down_write_nested+0x1db/0x210 kernel/locking/rwsem.c:1694
 inode_lock_nested include/linux/fs.h:853 [inline]
 lock_two_nondirectories+0x107/0x210 fs/inode.c:1283
 vfs_rename+0x14c7/0x2a20 fs/namei.c:5038
 do_renameat2+0xb81/0xc90 fs/namei.c:5224
 __do_sys_renameat2 fs/namei.c:5258 [inline]
 __se_sys_renameat2 fs/namei.c:5255 [inline]
 __x64_sys_renameat2+0xe4/0x120 fs/namei.c:5255
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xc3/0x1d0 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7fca967c071d
RSP: 002b:00007fca953f2ba8 EFLAGS: 00000246 ORIG_RAX: 000000000000013c
RAX: ffffffffffffffda RBX: 00007fca96983058 RCX: 00007fca967c071d
RDX: ffffffffffffff9c RSI: 0000000020000580 RDI: ffffffffffffff9c
RBP: 00007fca96835425 R08: 0000000000000000 R09: 0000000000000000
R10: 00000000200005c0 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fca96983064 R14: 00007fca969830f0 R15: 00007fca953f2d40
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/45:
 #0: ffffffff9fb1aea0 (rcu_read_lock){....}-{1:3}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
 #0: ffffffff9fb1aea0 (rcu_read_lock){....}-{1:3}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
 #0: ffffffff9fb1aea0 (rcu_read_lock){....}-{1:3}, at: debug_show_all_locks+0x75/0x340 kernel/locking/lockdep.c:6744
1 lock held by in:imklog/329:
5 locks held by syz.0.12/1715:
 #0: ff1100003ff8c420 (sb_writers#20){.+.+}-{0:0}, at: do_open fs/namei.c:3821 [inline]
 #0: ff1100003ff8c420 (sb_writers#20){.+.+}-{0:0}, at: path_openat+0x1577/0x2970 fs/namei.c:3987
 #1: ff110000415c1780 (&sb->s_type->i_mutex_key#21){++++}-{4:4}, at: inode_lock include/linux/fs.h:818 [inline]
 #1: ff110000415c1780 (&sb->s_type->i_mutex_key#21){++++}-{4:4}, at: do_truncate+0x131/0x200 fs/open.c:63
 #2: ff11000047780a38 (&c->snapshot_create_lock){.+.+}-{4:4}, at: bch2_truncate+0x145/0x260 fs/bcachefs/io_misc.c:292
 #3: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_lock_acquire include/linux/srcu.h:158 [inline]
 #3: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_read_lock include/linux/srcu.h:249 [inline]
 #3: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: __bch2_trans_get+0x625/0xf60 fs/bcachefs/btree_iter.c:3228
 #4: ff110000477a66d0 (&c->gc_lock){.+.+}-{4:4}, at: bch2_btree_update_start+0xb18/0x2010 fs/bcachefs/btree_update_interior.c:1197
3 locks held by syz.0.12/1823:
 #0: ff1100003ff8c420 (sb_writers#20){.+.+}-{0:0}, at: do_renameat2+0x3ea/0xc90 fs/namei.c:5154
 #1: ff110000415c0148 (&sb->s_type->i_mutex_key#21/1){+.+.}-{4:4}, at: inode_lock_nested include/linux/fs.h:853 [inline]
 #1: ff110000415c0148 (&sb->s_type->i_mutex_key#21/1){+.+.}-{4:4}, at: lock_rename fs/namei.c:3215 [inline]
 #1: ff110000415c0148 (&sb->s_type->i_mutex_key#21/1){+.+.}-{4:4}, at: lock_rename+0xa5/0xc0 fs/namei.c:3212
 #2: ff110000415c1780 (&sb->s_type->i_mutex_key#21/4){+.+.}-{4:4}, at: inode_lock_nested include/linux/fs.h:853 [inline]
 #2: ff110000415c1780 (&sb->s_type->i_mutex_key#21/4){+.+.}-{4:4}, at: lock_two_nondirectories+0x107/0x210 fs/inode.c:1283
4 locks held by bch-reclaim/loo/1811:
 #0: ff110000477cb0a8 (&j->reclaim_lock){+.+.}-{4:4}, at: bch2_journal_reclaim_thread+0x101/0x560 fs/bcachefs/journal_reclaim.c:739
 #1: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_lock_acquire include/linux/srcu.h:158 [inline]
 #1: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: srcu_read_lock include/linux/srcu.h:249 [inline]
 #1: ff11000047784398 (&c->btree_trans_barrier){.+.+}-{0:0}, at: __bch2_trans_get+0x625/0xf60 fs/bcachefs/btree_iter.c:3228
 #2: ff11000047784740 (&wb->flushing.lock){+.+.}-{4:4}, at: btree_write_buffer_flush_seq+0x69f/0xa40 fs/bcachefs/btree_write_buffer.c:516
 #3: ff110000477a66d0 (&c->gc_lock){.+.+}-{4:4}, at: bch2_btree_update_start+0xb18/0x2010 fs/bcachefs/btree_update_interior.c:1197
1 lock held by syz-executor/5484:
2 locks held by syz.1.1333/8755:
1 lock held by syz.7.1104/8876:
 #0: ffffffff9fb27ef8 (rcu_state.exp_mutex){+.+.}-{4:4}, at: exp_funnel_lock+0x29f/0x3d0 kernel/rcu/tree_exp.h:297
2 locks held by syz.8.1367/8889:

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

---------------
thanks,
Kun Hu

Powered by blists - more mailing lists