[syzbot] [block?] [trace?] INFO: task hung in blk_trace_ioctl (4)

Hello,

syzbot found the following issue on:

HEAD commit: 8c9660f65153 Add linux-next specific files for 20231124
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=1006f178e80000
kernel config: https://syzkaller.appspot.com/x/.config?x=ca1e8655505e280
dashboard link: https://syzkaller.appspot.com/bug?extid=ed812ed461471ab17a0c
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=14ec6e62e80000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=11964f7ce80000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/345ed4af3a0d/disk-8c9660f6.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/191053c69d57/vmlinux-8c9660f6.xz
kernel image: https://storage.googleapis.com/syzbot-assets/aac7ee5e55e0/bzImage-8c9660f6.xz

The issue was bisected to:

commit 0d345996e4cb573f8cc81d49b3ee9a7fd2035bef
Author: Pengfei Xu <pengf...@intel.com>
Date: Mon Jul 31 03:04:18 2023 +0000

x86/kernel: increase kcov coverage under arch/x86/kernel folder

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=14782eaae80000
final oops: https://syzkaller.appspot.com/x/report.txt?x=16782eaae80000
console output: https://syzkaller.appspot.com/x/log.txt?x=12782eaae80000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+ed812e...@syzkaller.appspotmail.com
Fixes: 0d345996e4cb ("x86/kernel: increase kcov coverage under arch/x86/kernel folder")

INFO: task syz-executor216:5234 blocked for more than 143 seconds.
Not tainted 6.7.0-rc2-next-20231124-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor216 state:D stack:29104 pid:5234 tgid:5232 ppid:5106 flags:0x00004006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5399 [inline]
__schedule+0xf15/0x5c00 kernel/sched/core.c:6726
__schedule_loop kernel/sched/core.c:6801 [inline]
schedule+0xe7/0x270 kernel/sched/core.c:6816
schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6873
__mutex_lock_common kernel/locking/mutex.c:679 [inline]
__mutex_lock+0x5b4/0x9c0 kernel/locking/mutex.c:747
blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
blkdev_common_ioctl+0x1575/0x1ce0 block/ioctl.c:562
blkdev_ioctl+0x249/0x770 block/ioctl.c:627
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:871 [inline]
__se_sys_ioctl fs/ioctl.c:857 [inline]
__x64_sys_ioctl+0x18f/0x210 fs/ioctl.c:857
do_syscall_x64 arch/x86/entry/common.c:51 [inline]
do_syscall_64+0x40/0x110 arch/x86/entry/common.c:82
entry_SYSCALL_64_after_hwframe+0x62/0x6a
RIP: 0033:0x7f914d80ca89
RSP: 002b:00007f914cfa3168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f914d89c1d8 RCX: 00007f914d80ca89
RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000004
RBP: 00007f914d89c1d0 R08: 00007ffdb3560fd7 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f914d89c1dc
R13: 000000000000006e R14: 00007ffdb3560ef0 R15: 00007ffdb3560fd8
</TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/29:
#0: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:301 [inline]
#0: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:747 [inline]
#0: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x75/0x340 kernel/locking/lockdep.c:6613
1 lock held by klogd/4501:
#0: ffff8880b993c718 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:558
2 locks held by getty/4815:
#0: ffff8880273ee0a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x24/0x80 drivers/tty/tty_ldisc.c:243
#1: ffffc90002f062f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xfc4/0x1490 drivers/tty/n_tty.c:2201
2 locks held by kworker/0:5/5180:
2 locks held by syz-executor216/5233:
1 lock held by syz-executor216/5234:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5240:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5241:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5245:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5246:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5248:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5249:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5251:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5252:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5254:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736
1 lock held by syz-executor216/5255:
#0: ffff888142f94490 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:736

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

NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: khungtaskd Not tainted 6.7.0-rc2-next-20231124-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xd9/0x1b0 lib/dump_stack.c:106
nmi_cpu_backtrace+0x277/0x390 lib/nmi_backtrace.c:113
nmi_trigger_cpumask_backtrace+0x299/0x300 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
watchdog+0xf86/0x1210 kernel/hung_task.c:379
kthread+0x2c1/0x3a0 kernel/kthread.c:389
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:242
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 5233 Comm: syz-executor216 Not tainted 6.7.0-rc2-next-20231124-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 11/10/2023
RIP: 0010:__sanitizer_cov_trace_switch+0x4f/0x90 kernel/kcov.c:341
Code: 83 f8 10 75 2f 41 bd 03 00 00 00 4c 8b 75 00 31 db 4d 85 f6 74 1e 48 8b 74 dd 10 4c 89 e2 4c 89 ef 48 83 c3 01 48 8b 4c 24 28 <e8> 2c fe ff ff 49 39 de 75 e2 5b 5d 41 5c 41 5d 41 5e c3 48 83 f8
RSP: 0018:ffffc90003fdf3a0 EFLAGS: 00000202
RAX: 0000000000000008 RBX: 0000000000000001 RCX: ffffffff813a44c8
RDX: 0000000000000001 RSI: 0000000000000000 RDI: 0000000000000001
RBP: ffffffff8ac9d800 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000001 R11: dffffc0000000000 R12: 0000000000000001
R13: 0000000000000001 R14: 0000000000000003 R15: 0000000000000001
FS: 00007f914cfc46c0(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f914d899f18 CR3: 00000000a0ad4000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<NMI>
</NMI>
<TASK>
unwind_next_frame+0xea8/0x2390 arch/x86/kernel/unwind_orc.c:641
arch_stack_walk+0xfa/0x170 arch/x86/kernel/stacktrace.c:25
stack_trace_save+0x95/0xd0 kernel/stacktrace.c:122
save_stack+0x15e/0x1f0 mm/page_owner.c:130
__set_page_owner+0x1f/0x60 mm/page_owner.c:196
set_page_owner include/linux/page_owner.h:31 [inline]
post_alloc_hook+0x2d0/0x350 mm/page_alloc.c:1533
prep_new_page mm/page_alloc.c:1540 [inline]
get_page_from_freelist+0xa16/0x3690 mm/page_alloc.c:3344
__alloc_pages+0x22d/0x2400 mm/page_alloc.c:4600
alloc_pages_mpol+0x258/0x5f0 mm/mempolicy.c:2133
relay_alloc_buf kernel/relay.c:121 [inline]
relay_create_buf kernel/relay.c:162 [inline]
relay_open_buf.part.0+0x27d/0xba0 kernel/relay.c:384
relay_open_buf kernel/relay.c:536 [inline]
relay_open+0x641/0xab0 kernel/relay.c:517
do_blk_trace_setup+0x4a9/0xaa0 kernel/trace/blktrace.c:591
__blk_trace_setup+0xd8/0x180 kernel/trace/blktrace.c:631
blk_trace_ioctl+0x163/0x290 kernel/trace/blktrace.c:741
blkdev_ioctl+0x111/0x770 block/ioctl.c:622
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:871 [inline]
__se_sys_ioctl fs/ioctl.c:857 [inline]
__x64_sys_ioctl+0x18f/0x210 fs/ioctl.c:857
do_syscall_x64 arch/x86/entry/common.c:51 [inline]
do_syscall_64+0x40/0x110 arch/x86/entry/common.c:82
entry_SYSCALL_64_after_hwframe+0x62/0x6a
RIP: 0033:0x7f914d80ca89
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 e1 1c 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f914cfc4168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f914d89c1c8 RCX: 00007f914d80ca89
RDX: 0000000020000380 RSI: 00000000c0481273 RDI: 0000000000000004
RBP: 00007f914d89c1c0 R08: 00007f914cfc46c0 R09: 0000000000000000
R10: 00007f914cfc46c0 R11: 0000000000000246 R12: 00007f914d89c1cc
R13: 000000000000000b R14: 00007ffdb3560ef0 R15: 00007ffdb3560fd8
</TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 2.100 msecs


---
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.
For information about bisection process see: https://goo.gl/tpsmEJ#bisection

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

Hi,
Thanks for your report!
I reverted the commit 0d345996e4cb573f8cc81d49b3ee9a7fd2035bef on top of
v6.3-rc7 mainline kernel, this issue was still reproduced.
Anyway, it's an interesting problem, I will update the email if I find
more clue of the problem.

Best Regards,
Thanks!

please test task hung in blk_trace_ioctl

#syz test https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git 8c9660f65153

diff --git a/kernel/trace/blktrace.c b/kernel/trace/blktrace.c
index d5d94510af..54ade89a1a 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -588,8 +588,10 @@ static int do_blk_trace_setup(struct request_queue *q, char *name, dev_t dev,
debugfs_create_file("dropped", 0444, dir, bt, &blk_dropped_fops);
debugfs_create_file("msg", 0222, dir, bt, &blk_msg_fops);

+ mutex_unlock(&q->debugfs_mutex);
bt->rchan = relay_open("trace", dir, buts->buf_size,
buts->buf_nr, &blk_relay_callbacks, bt);
+ mutex_lock(&q->debugfs_mutex);
if (!bt->rchan)
goto err;

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
INFO: task hung in relay_open

INFO: task syz-executor.0:6090 blocked for more than 143 seconds.
Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
task:syz-executor.0 state:D stack:28464 pid:6090 tgid:6089 ppid:6031 flags:0x00004006
relay_open+0x38f/0xab0 kernel/relay.c:515
do_blk_trace_setup+0x4c1/0xaf0 kernel/trace/blktrace.c:592
__blk_trace_setup+0xd8/0x180 kernel/trace/blktrace.c:633
blk_trace_ioctl+0x163/0x290 kernel/trace/blktrace.c:743
RIP: 0033:0x7efdb9e7cae9
RSP: 002b:00007efdbac5e0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007efdb9f9bf80 RCX: 00007efdb9e7cae9
RBP: 00007efdb9ec847a R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000000b R14: 00007efdb9f9bf80 R15: 00007fff425d3c28
3 locks held by kworker/0:0/8:
#0: ffff888013074d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc900000d7d80 ((linkwatch_work).work){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
#2: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: linkwatch_event+0x51/0xc0 net/core/link_watch.c:277
3 locks held by kworker/u4:3/48:
#0: ffff8880b983c718 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:558
#1: ffff8880b9828888 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x2d9/0x900 kernel/sched/psi.c:988
#2: ffff88802eb58768 (&rdev->wiphy.mtx){+.+.}-{3:3}, at: wiphy_lock include/net/cfg80211.h:5870 [inline]
#2: ffff88802eb58768 (&rdev->wiphy.mtx){+.+.}-{3:3}, at: cfg80211_wiphy_work+0x2b/0x330 net/wireless/core.c:422
3 locks held by kworker/1:2/55:
#0: ffff888013074d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffff8880b9928888 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x2d9/0x900 kernel/sched/psi.c:988
#2: ffffffff8da73fd8 (pool_rwlock){----}-{2:2}, at: stack_depot_save_flags+0x169/0x740 lib/stackdepot.c:508
3 locks held by kworker/u4:4/59:
2 locks held by kworker/1:3/924:
#0: ffff888013076938 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc900052b7d80 ((work_completion)(&rew->rew_work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
2 locks held by getty/4816:
#0: ffff88802b3f20a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x24/0x80 drivers/tty/tty_ldisc.c:243
#1: ffffc900015d02f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xfc4/0x1490 drivers/tty/n_tty.c:2201
3 locks held by kworker/0:4/5077:
#0: ffff88814c053938 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc9000488fd80 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
#2: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: addrconf_dad_work+0xcf/0x14b0 net/ipv6/addrconf.c:4137
2 locks held by kworker/0:5/5078:
1 lock held by syz-executor.0/5959:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: do_blk_trace_setup+0x4eb/0xaf0 kernel/trace/blktrace.c:594
1 lock held by syz-executor.1/5971:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: do_blk_trace_setup+0x4eb/0xaf0 kernel/trace/blktrace.c:594
1 lock held by syz-executor.4/5991:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: do_blk_trace_setup+0x4eb/0xaf0 kernel/trace/blktrace.c:594
1 lock held by syz-executor.2/6004:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: do_blk_trace_setup+0x4eb/0xaf0 kernel/trace/blktrace.c:594
1 lock held by syz-executor.3/6038:
1 lock held by syz-executor.0/6090:
#0: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_open+0x38f/0xab0 kernel/relay.c:515
1 lock held by syz-executor.1/6094:
#0: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_open+0x38f/0xab0 kernel/relay.c:515
1 lock held by syz-executor.4/6123:
#0: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_open+0x38f/0xab0 kernel/relay.c:515
1 lock held by syz-executor.2/6126:
#0: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_open+0x38f/0xab0 kernel/relay.c:515
1 lock held by syz-executor.5/6129:
#0: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_open+0x38f/0xab0 kernel/relay.c:515
2 locks held by syz-executor.3/6151:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
#1: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_close kernel/relay.c:760 [inline]
#1: ffffffff8d01c1e8 (relay_channels_mutex){+.+.}-{3:3}, at: relay_close+0x36/0x5d0 kernel/relay.c:752
1 lock held by syz-executor.0/6174:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.0/6175:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.1/6184:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.1/6185:
#0: ffff888143343340
(&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.4/6225:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.4/6226:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.2/6241:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.2/6243:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.5/6245:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.5/6246:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.3/6268:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.3/6269:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.0/6299:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.0/6300:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.1/6307:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.1/6308:
#0: ffff888143343340 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0xc9/0x290 kernel/trace/blktrace.c:738
1 lock held by syz-executor.4/6310:
#0: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
#0: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x372/0xe00 net/core/rtnetlink.c:6555
8 locks held by syz-executor.2/6323:
#0: ffff88807d52c420 (sb_writers#8){.+.+}-{0:0}, at: ksys_write+0x12f/0x250 fs/read_write.c:637
#1: ffff8881bf4f1c88 (&of->mutex){+.+.}-{3:3}, at: kernfs_fop_write_iter+0x27d/0x500 fs/kernfs/file.c:325
#2: ffff888144379e88 (kn->active#50){.+.+}-{0:0}, at: kernfs_fop_write_iter+0x2a0/0x500 fs/kernfs/file.c:326
#3: ffffffff8e145528 (nsim_bus_dev_list_lock){+.+.}-{3:3}, at: del_device_store+0xd2/0x4b0 drivers/net/netdevsim/bus.c:216
#4: ffff88806460a0e8 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:992 [inline]
#4: ffff88806460a0e8 (&dev->mutex){....}-{3:3}, at: __device_driver_lock drivers/base/dd.c:1095 [inline]
#4: ffff88806460a0e8 (&dev->mutex){....}-{3:3}, at: device_release_driver_internal+0xa4/0x610 drivers/base/dd.c:1292
#5: ffff88806460b250 (&devlink->lock_key#24){+.+.}-{3:3}, at: nsim_drv_remove+0x4a/0x1d0 drivers/net/netdevsim/dev.c:1672
#6: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: nsim_destroy+0x39/0x190 drivers/net/netdevsim/netdev.c:411
#7: ffffffff8cfb8938 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:293 [inline]
#7: ffffffff8cfb8938 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x6b1/0x800 kernel/rcu/tree_exp.h:996
1 lock held by syz-executor.5/6341:
#0: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
#0: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x372/0xe00 net/core/rtnetlink.c:6555

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

NMI backtrace for cpu 1
CPU: 1 PID: 29 Comm: khungtaskd Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
Sending NMI from CPU 1 to CPUs 0:
CPU: 0 PID: 59 Comm: kworker/u4:4 Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
Workqueue: bat_events batadv_nc_worker
RIP: 0010:validate_chain kernel/locking/lockdep.c:3835 [inline]
RIP: 0010:__lock_acquire+0xcf1/0x3b10 kernel/locking/lockdep.c:5136
Code: 31 d1 89 ca 29 ce 01 c8 c1 c2 04 89 c0 31 f2 48 c1 e2 20 48 09 c2 48 b8 00 00 00 00 00 fc ff df 48 89 54 24 08 48 8b 54 24 40 <48> c1 ea 03 0f b6 04 02 84 c0 74 08 3c 03 0f 8e dc 29 00 00 41 8b
RSP: 0018:ffffc900015a7968 EFLAGS: 00000082
RAX: dffffc0000000000 RBX: 0000000066e96c45 RCX: 000000001a14bb59
RDX: ffff888018e86470 RSI: 000000004cd4b0ec RDI: ffffffff91f26720
RBP: ffffffff91f7bf20 R08: 0000000000000000 R09: fffffbfff23e49e8
R10: ffffffff91f24f47 R11: 0000000000000002 R12: 0000000000004018
R13: 0000000000000018 R14: ffff888018e86450 R15: 0000000000000004
FS: 0000000000000000(0000) GS:ffff8880b9800000(0000) knlGS:0000000000000000
CR2: 00007ffa7f3c6866 CR3: 000000008768f000 CR4: 00000000003506f0
lock_acquire kernel/locking/lockdep.c:5753 [inline]
lock_acquire+0x1b1/0x530 kernel/locking/lockdep.c:5718
rcu_lock_acquire include/linux/rcupdate.h:301 [inline]
rcu_read_lock include/linux/rcupdate.h:747 [inline]
batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:408 [inline]
batadv_nc_worker+0x16e/0x10e0 net/batman-adv/network-coding.c:719
process_one_work+0x8a4/0x15f0 kernel/workqueue.c:2633
process_scheduled_works kernel/workqueue.c:2706 [inline]
worker_thread+0x8b6/0x1290 kernel/workqueue.c:2787
Tested on:

commit: 8c9660f6 Add linux-next specific files for 20231124
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git
console output: https://syzkaller.appspot.com/x/log.txt?x=156484e2e80000
kernel config: https://syzkaller.appspot.com/x/.config?x=6eff11e3e3c25a4f
patch: https://syzkaller.appspot.com/x/patch.diff?x=16ca43aae80000

index 54ade89a1ad2..a1b341722693 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -735,7 +735,10 @@ int blk_trace_ioctl(struct block_device *bdev, unsigned cmd, char __user *arg)
int ret, start = 0;
char b[BDEVNAME_SIZE];

- mutex_lock(&q->debugfs_mutex);
+ if (cmd == BLKTRACESETUP)
+ mutex_lock_nested(&q->debugfs_mutex, 0);
+ else
+ mutex_lock_nested(&q->debugfs_mutex, 1);

switch (cmd) {
case BLKTRACESETUP:

INFO: task hung in blk_trace_ioctl

INFO: task syz-executor.5:5691 blocked for more than 143 seconds.
task:syz-executor.5 state:D stack:29344 pid:5691 tgid:5688 ppid:5438 flags:0x00000006
blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
RIP: 0033:0x7f0bacc7cae9
RSP: 002b:00007f0bada690c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f0bacd9c050 RCX: 00007f0bacc7cae9
RBP: 00007f0baccc847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007f0bacd9c050 R15: 00007ffdfd91ff58
</TASK>
INFO: task syz-executor.4:5694 blocked for more than 144 seconds.
task:syz-executor.4 state:D stack:28464 pid:5694 tgid:5692 ppid:5446 flags:0x00004006
blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
RIP: 0033:0x7fd308c7cae9
RSP: 002b:00007fd3099650c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fd308d9bf80 RCX: 00007fd308c7cae9
RBP: 00007fd308cc847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007fd308d9bf80 R15: 00007ffdef910b18
</TASK>
INFO: task syz-executor.4:5695 blocked for more than 145 seconds.
task:syz-executor.4 state:D stack:29536 pid:5695 tgid:5692 ppid:5446 flags:0x00000006
blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
RIP: 0033:0x7fd308c7cae9
RSP: 002b:00007fd3099440c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fd308d9c050 RCX: 00007fd308c7cae9
RBP: 00007fd308cc847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007fd308d9c050 R15: 00007ffdef910b18
</TASK>
INFO: task syz-executor.2:5699 blocked for more than 145 seconds.
task:syz-executor.2 state:D stack:28464 pid:5699 tgid:5698 ppid:5433 flags:0x00004006
blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
RIP: 0033:0x7f06c0a7cae9
RSP: 002b:00007f06c17260c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f06c0b9bf80 RCX: 00007f06c0a7cae9
RBP: 00007f06c0ac847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007f06c0b9bf80 R15: 00007ffd778555b8
</TASK>
INFO: task syz-executor.2:5702 blocked for more than 146 seconds.
task:syz-executor.2 state:D stack:28880 pid:5702 tgid:5698 ppid:5433 flags:0x00004006
blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
RIP: 0033:0x7f06c0a7cae9
RSP: 002b:00007f06c17050c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f06c0b9c050 RCX: 00007f06c0a7cae9
RBP: 00007f06c0ac847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007f06c0b9c050 R15: 00007ffd778555b8
3 locks held by kworker/0:1/9:
#2: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:301 [inline]
#2: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:747 [inline]
#2: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: led_trigger_event drivers/leds/led-triggers.c:389 [inline]
#2: ffffffff8cfacf60 (rcu_read_lock){....}-{1:2}, at: led_trigger_event+0x44/0x240 drivers/leds/led-triggers.c:381
2 locks held by kworker/u4:11/4345:
2 locks held by getty/4820:
#0: ffff8880270240a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x24/0x80 drivers/tty/tty_ldisc.c:243
#1: ffffc90002f062f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0xfc4/0x1490 drivers/tty/n_tty.c:2201
3 locks held by kworker/1:4/5079:
#1: ffffc900040afd80 ((work_completion)(&data->fib_event_work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
#2: ffff8881670a0240 (&data->fib_lock){+.+.}-{3:3}, at: nsim_fib_event_work+0x1bb/0x26e0 drivers/net/netdevsim/fib.c:1489
3 locks held by kworker/0:6/5550:
#0: ffff88802668fd38 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc90005657d80 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
2 locks held by syz-executor.5/5689:
1 lock held by syz-executor.5/5691:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.4/5694:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.4/5695:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.2/5699:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.2/5702:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.3/5896:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.3/5897:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.1/5951:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.1/5952:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.0/5983:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.0/5984:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.5/5986:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.5/5987:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.4/5989:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
#0: ffff88814435bbe8
(&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.2/5993:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.2/5994:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.3/6013:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.3/6014:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.1/6041:
#0:
ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.1/6042:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
2 locks held by syz-executor.2/6063:
#0: ffffffff8eb482b0 (cb_lock){++++}-{3:3}, at: genl_rcv+0x19/0x40 net/netlink/genetlink.c:1075
#1: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: nl80211_pre_doit+0xb4/0xb10 net/wireless/nl80211.c:16329
3 locks held by syz-executor.4/6064:
1 lock held by syz-executor.0/6100:
#0:
ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.0/6102:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.3/6113:
1 lock held by syz-executor.5/6116:
#0: ffff88814435bbe8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.5/6117:
#0: ffff88814435bbe8 (&q->debugfs_mutex/1){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
CPU: 0 PID: 1252 Comm: kworker/u4:7 Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
Workqueue: events_unbound cfg80211_wiphy_work
RIP: 0010:printk_get_next_message+0x2bc/0x7c0 kernel/printk/printk.c:2828
Code: 24 84 c0 74 3a e8 54 e7 1c 00 0f b6 74 24 1f 31 ff e8 78 e2 1c 00 45 84 e4 0f 85 c1 00 00 00 e8 3a e7 1c 00 8b 35 64 09 16 11 <4c> 89 ff 0f b6 15 7a 76 80 0b 83 e6 01 e8 32 9d ff ff 41 89 c6 e8
RSP: 0018:ffffc900055575c8 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 1ffff92000aaaebd RCX: ffffffff816b2ac8
RDX: ffff888020b98000 RSI: 0000000000000000 RDI: 0000000000000001
RBP: ffffc900055577d0 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000005010 R12: 0000000000000000
R13: 0000000000000001 R14: 0000000000000006 R15: ffffc90005557608
CR2: 0000555555db3938 CR3: 000000000cd78000 CR4: 00000000003506f0
console_emit_next_record kernel/printk/printk.c:2868 [inline]
console_flush_all+0x3af/0xd60 kernel/printk/printk.c:2967
console_unlock+0x10c/0x260 kernel/printk/printk.c:3036
vprintk_emit+0x17f/0x5f0 kernel/printk/printk.c:2303
vprintk+0x7b/0x90 kernel/printk/printk_safe.c:45
_printk+0xc8/0x100 kernel/printk/printk.c:2328
ieee80211_sta_find_ibss net/mac80211/ibss.c:1447 [inline]
ieee80211_ibss_work+0xbb0/0x14c0 net/mac80211/ibss.c:1666
ieee80211_iface_work+0xbeb/0xda0 net/mac80211/iface.c:1665
cfg80211_wiphy_work+0x24e/0x330 net/wireless/core.c:435
console output: https://syzkaller.appspot.com/x/log.txt?x=104c7d64e80000
patch: https://syzkaller.appspot.com/x/patch.diff?x=10f7e752e80000

index 54ade89a1ad2..f5d3576ef3ed 100644
+ mutex_lock(&q->debugfs_mutex);
+ else
+ mutex_lock_nested(&q->debugfs_mutex, 2);

switch (cmd) {
case BLKTRACESETUP:

index 54ade89a1ad2..34e5bce42b1e 100644
--- a/kernel/trace/blktrace.c
+++ b/kernel/trace/blktrace.c
@@ -735,7 +735,8 @@ int blk_trace_ioctl(struct block_device *bdev, unsigned cmd, char __user *arg)
+ if (!mutex_trylock(&q->debugfs_mutex))
+ return -EBUSY;

switch (cmd) {
case BLKTRACESETUP:

INFO: task syz-executor.5:5690 blocked for more than 143 seconds.
task:syz-executor.5 state:D stack:29344 pid:5690 tgid:5688 ppid:5422 flags:0x00000006
RIP: 0033:0x7f74daa7cae9
RSP: 002b:00007f74db6f50c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f74dab9c050 RCX: 00007f74daa7cae9
RBP: 00007f74daac847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007f74dab9c050 R15: 00007ffe5d9903a8
</TASK>
INFO: task syz-executor.3:5697 blocked for more than 144 seconds.
task:syz-executor.3 state:D stack:28240 pid:5697 tgid:5695 ppid:5424 flags:0x00000006
RIP: 0033:0x7fdf0727cae9
RSP: 002b:00007fdf07fce0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fdf0739bf80 RCX: 00007fdf0727cae9
RBP: 00007fdf072c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007fdf0739bf80 R15: 00007fffd6989178
</TASK>
INFO: task syz-executor.3:5700 blocked for more than 144 seconds.
task:syz-executor.3 state:D stack:29536 pid:5700 tgid:5695 ppid:5424 flags:0x00004006
RIP: 0033:0x7fdf0727cae9
RSP: 002b:00007fdf07fad0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fdf0739c050 RCX: 00007fdf0727cae9
RBP: 00007fdf072c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007fdf0739c050 R15: 00007fffd6989178
task:syz-executor.2 state:D stack:28464 pid:5699 tgid:5698 ppid:5432 flags:0x00000006
RIP: 0033:0x7fe49b47cae9
RSP: 002b:00007fe49c22b0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fe49b59bf80 RCX: 00007fe49b47cae9
RBP: 00007fe49b4c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007fe49b59bf80 R15: 00007ffcc7430b68
</TASK>
INFO: task syz-executor.2:5701 blocked for more than 146 seconds.
task:syz-executor.2 state:D stack:29536 pid:5701 tgid:5698 ppid:5432 flags:0x00000006
RIP: 0033:0x7fe49b47cae9
RSP: 002b:00007fe49c20a0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fe49b59c050 RCX: 00007fe49b47cae9
RBP: 00007fe49b4c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007fe49b59c050 R15: 00007ffcc7430b68
4 locks held by kworker/1:0/23:
#1: ffffc900001d7d80 ((work_completion)(&data->fib_event_work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
#2: ffff888040930240 (&data->fib_lock){+.+.}-{3:3}, at: nsim_fib_event_work+0x1bb/0x26e0 drivers/net/netdevsim/fib.c:1489
#3: ffff8880b993c718 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:558
2 locks held by kworker/u4:5/127:
#0: ffff888013075938 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc90002d9fd80 ((work_completion)(&sub_info->work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
2 locks held by kworker/u4:11/3621:
2 locks held by getty/4809:
#0: ffff88814d2a80a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x24/0x80 drivers/tty/tty_ldisc.c:243
3 locks held by kworker/0:3/5057:
#0: ffff8880265d5938 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc90003bdfd80 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
2 locks held by kworker/1:6/5530:
#0: ffff888013076938 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc90004d1fd80 ((work_completion)(&rew->rew_work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
3 locks held by kworker/1:8/5567:
#0: ffff8880265d5938 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x78c/0x15f0 kernel/workqueue.c:2608
#1: ffffc900057efd80 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x7f6/0x15f0 kernel/workqueue.c:2609
4 locks held by syz-executor.5/5689:
1 lock held by syz-executor.5/5690:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.3/5697:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.3/5700:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.2/5701:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.1/5889:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.1/5891:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.0/5957:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.0/5959:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.4/5967:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.4/5968:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.5/5983:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.5/5984:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.2/5986:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.2/5987:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.3/5989:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.3/5990:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.1/6010:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.1/6011:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
1 lock held by syz-executor.5/6050:
1 lock held by syz-executor.0/6054:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.0/6056:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
3 locks held by syz-executor.2/6057:
#1: ffff8880200ad3e8 (&wg->device_update_lock){+.+.}-{3:3}, at: wg_open+0x203/0x4e0 drivers/net/wireguard/device.c:50
#2: ffffffff8cfb8938 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:293 [inline]
#2: ffffffff8cfb8938 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x6b1/0x800 kernel/rcu/tree_exp.h:996
1 lock held by syz-executor.3/6059:
1 lock held by syz-executor.4/6091:
#0: ffff88801e502a98 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x216/0x2b0 kernel/trace/blktrace.c:737
1 lock held by syz-executor.4/6093:
#0: ffff88801e502a98 (&q->debugfs_mutex/2){+.+.}-{3:3}, at: blk_trace_ioctl+0xe9/0x2b0 kernel/trace/blktrace.c:739
2 locks held by syz-executor.1/6108:
#0: ffffffff8ea96f90 (pernet_ops_rwsem){++++}-{3:3}, at: copy_net_ns+0x2d4/0x670 net/core/net_namespace.c:487
#1: ffffffff8eaac528 (rtnl_mutex){+.+.}-{3:3}, at: ip_tunnel_init_net+0x225/0x5e0 net/ipv4/ip_tunnel.c:1090

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

NMI backtrace for cpu 0
CPU: 0 PID: 29 Comm: khungtaskd Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
Sending NMI from CPU 0 to CPUs 1:
CPU: 1 PID: 5530 Comm: kworker/1:6 Not tainted 6.7.0-rc2-next-20231124-syzkaller-dirty #0
Workqueue: wg-kex-wg2 wg_packet_handshake_receive_worker
RIP: 0010:__lock_acquire+0xe75/0x3b10 kernel/locking/lockdep.c:5008
Code: 01 0f 87 ae f2 ff ff 45 89 f7 0f 87 60 1f 00 00 4b 8d 7c fc 08 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 <0f> 85 7d 1f 00 00 4b 8b 44 fc 08 48 85 c0 0f 85 95 f2 ff ff e9 72
RSP: 0018:ffffc90004d1f770 EFLAGS: 00000046
RAX: dffffc0000000000 RBX: 0000000000000001 RCX: 0000000000000000
RDX: 1ffffffff1b4e7fc RSI: ffff888020b03b80 RDI: ffffffff8da73fe0
RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000001
R10: ffffffff8f193397 R11: 0000000000000004 R12: ffffffff8da73fd8
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
FS: 0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CR2: 00007f8eed404440 CR3: 0000000151079000 CR4: 00000000003506f0
__raw_write_lock_irqsave include/linux/rwlock_api_smp.h:186 [inline]
_raw_write_lock_irqsave+0x3a/0x50 kernel/locking/spinlock.c:318
stack_depot_put lib/stackdepot.c:621 [inline]
stack_depot_put+0x24/0x110 lib/stackdepot.c:613
qlink_free mm/kasan/quarantine.c:151 [inline]
qlist_free_all+0x5e/0x1e0 mm/kasan/quarantine.c:201
kasan_quarantine_reduce+0x18e/0x1d0 mm/kasan/quarantine.c:308
__kasan_slab_alloc+0x65/0x90 mm/kasan/common.c:307
kasan_slab_alloc include/linux/kasan.h:188 [inline]
slab_post_alloc_hook mm/slab.h:763 [inline]
slab_alloc_node mm/slub.c:3452 [inline]
__kmem_cache_alloc_node+0x195/0x310 mm/slub.c:3491
kmalloc_trace+0x25/0x60 mm/slab_common.c:1098
kmalloc include/linux/slab.h:600 [inline]
kzalloc include/linux/slab.h:721 [inline]
keypair_create drivers/net/wireguard/noise.c:100 [inline]
wg_noise_handshake_begin_session+0xe1/0xe70 drivers/net/wireguard/noise.c:827
wg_receive_handshake_packet+0x73c/0xbc0 drivers/net/wireguard/receive.c:176
wg_packet_handshake_receive_worker+0x17f/0x3a0 drivers/net/wireguard/receive.c:213
console output: https://syzkaller.appspot.com/x/log.txt?x=112e2b52e80000
patch: https://syzkaller.appspot.com/x/patch.diff?x=16e6004ae80000

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger any issue:

Reported-and-tested-by: syzbot+ed812e...@syzkaller.appspotmail.com
console output: https://syzkaller.appspot.com/x/log.txt?x=125ebdaae80000
patch: https://syzkaller.appspot.com/x/patch.diff?x=11cd5352e80000

Note: testing is done by a robot and is best-effort only.

The reproducer involves running test programs on multiple processors separately,
in order to enter blkdev_ioctl() and ultimately reach blk_trace_ioctl() through
two different paths, triggering an AA deadlock.

CPU0 CPU1
--- ---
mutex_lock(&q->debugfs_mutex) mutex_lock(&q->debugfs_mutex)
mutex_lock(&q->debugfs_mutex) mutex_lock(&q->debugfs_mutex)


The first path:
blkdev_ioctl()->
blk_trace_ioctl()->
mutex_lock(&q->debugfs_mutex)

The second path:
blkdev_ioctl()->
blkdev_common_ioctl()->
blk_trace_ioctl()->
mutex_lock(&q->debugfs_mutex)

The solution I have proposed is to exit blk_trace_ioctl() to avoid AA locks if
a task has already obtained debugfs_mutex.
Reported-and-tested-by: syzbot+ed812e...@syzkaller.appspotmail.com
Signed-off-by: Edward Adam Davis <ead...@qq.com>
---
kernel/trace/blktrace.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
--
2.43.0

Hi,
I still don't understand how this AA deadlock is triggered, does the
'debugfs_mutex' already held before calling blk_trace_ioctl()?
This is absolutely not a proper fix, a lot of user case will fail after
this patch.

Thanks,
Kuai

>
> switch (cmd) {
> case BLKTRACESETUP:
>

Hi,

On 2023-12-03 at 06:07:43 +0800, Steven Rostedt wrote:
> Right, I don't see where the mutex is taken twice. You don't need two
> paths for an AA lock, you only need one.
> How does it fix the above? I don't see how the above is even related to this.

I bisected this issue and the following fix information is more accurate:
"
Fixes: f2c2e717642c ("usb: gadget: add raw-gadget interface")
"

All the bisected info is in link: https://github.com/xupengfe/syzkaller_logs/tree/main/231203_140738_blk_trace_ioctl

Acked-by: Pengfei Xu <pengf...@intel.com>

Thanks!

>
> -- Steve

syz test: git://git.kernel.dk/linux btrace-fault

--
Jens Axboe

(minus most people and mailing lists)
It should begin with a # :)

#syz test: git://git.kernel.dk/linux btrace-fault

--
Aleksandr

>
> --
> Jens Axboe
>
> --

hah thanks, I always have to click the link to remember what to type.
Guess even with that I messed it up...

--
Jens Axboe

FYI we've begun to include a small cheatsheet of the main syzbot
commands at the bottom of each syzbot report. So for the newer reports
you can just copy-paste the commands directly from the emails.

On 10/11/24 1:41 PM, Aleksandr Nogikh wrote:
Ok question then - if I just include the patch inline in the email, what
do I type? Or does that not work?

--
Jens Axboe

Hello,
INFO: task hung in blk_trace_setup

INFO: task syz-executor.0:5945 blocked for more than 143 seconds.
Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
task:syz-executor.0 state:D stack:27360 pid:5945 tgid:5944 ppid:5899 flags:0x00000006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5322 [inline]
__schedule+0x1895/0x4b30 kernel/sched/core.c:6682
__schedule_loop kernel/sched/core.c:6759 [inline]
schedule+0x14b/0x320 kernel/sched/core.c:6774
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6831
__mutex_lock_common kernel/locking/mutex.c:684 [inline]
__mutex_lock+0x6a7/0xd70 kernel/locking/mutex.c:752
blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
blk_trace_ioctl+0x182/0x830 kernel/trace/blktrace.c:730
blkdev_ioctl+0x45f/0x6f0 block/ioctl.c:682
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl+0xf9/0x170 fs/ioctl.c:893
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f0ebba7cae9
RSP: 002b:00007f0ebc7b30c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f0ebbb9bf80 RCX: 00007f0ebba7cae9
RBP: 00007f0ebbac847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007f0ebbb9bf80 R15: 00007fff4cbbb418
</TASK>
INFO: task syz-executor.0:5946 blocked for more than 145 seconds.
Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
task:syz-executor.0 state:D stack:28752 pid:5946 tgid:5944 ppid:5899 flags:0x00000006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5322 [inline]
__schedule+0x1895/0x4b30 kernel/sched/core.c:6682
__schedule_loop kernel/sched/core.c:6759 [inline]
schedule+0x14b/0x320 kernel/sched/core.c:6774
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6831
__mutex_lock_common kernel/locking/mutex.c:684 [inline]
__mutex_lock+0x6a7/0xd70 kernel/locking/mutex.c:752
blk_trace_remove kernel/trace/blktrace.c:406 [inline]
blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
blkdev_common_ioctl+0xe7b/0x2480 block/ioctl.c:622
blkdev_ioctl+0x51d/0x6f0 block/ioctl.c:687
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl+0xf9/0x170 fs/ioctl.c:893
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f0ebba7cae9
RSP: 002b:00007f0ebc7920c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f0ebbb9c050 RCX: 00007f0ebba7cae9
RBP: 00007f0ebbac847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007f0ebbb9c050 R15: 00007fff4cbbb418
</TASK>
INFO: task syz-executor.4:5948 blocked for more than 146 seconds.
Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
task:syz-executor.4 state:D stack:27360 pid:5948 tgid:5947 ppid:5901 flags:0x00004006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5322 [inline]
__schedule+0x1895/0x4b30 kernel/sched/core.c:6682
__schedule_loop kernel/sched/core.c:6759 [inline]
schedule+0x14b/0x320 kernel/sched/core.c:6774
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6831
__mutex_lock_common kernel/locking/mutex.c:684 [inline]
__mutex_lock+0x6a7/0xd70 kernel/locking/mutex.c:752
blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
blk_trace_ioctl+0x182/0x830 kernel/trace/blktrace.c:730
blkdev_ioctl+0x45f/0x6f0 block/ioctl.c:682
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl+0xf9/0x170 fs/ioctl.c:893
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f1da087cae9
RSP: 002b:00007f1da03ff0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f1da099bf80 RCX: 00007f1da087cae9
RBP: 00007f1da08c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000000b R14: 00007f1da099bf80 R15: 00007fff0c43a168
</TASK>
INFO: task syz-executor.4:5949 blocked for more than 146 seconds.
Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
task:syz-executor.4 state:D stack:28032 pid:5949 tgid:5947 ppid:5901 flags:0x00000006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5322 [inline]
__schedule+0x1895/0x4b30 kernel/sched/core.c:6682
__schedule_loop kernel/sched/core.c:6759 [inline]
schedule+0x14b/0x320 kernel/sched/core.c:6774
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6831
__mutex_lock_common kernel/locking/mutex.c:684 [inline]
__mutex_lock+0x6a7/0xd70 kernel/locking/mutex.c:752
blk_trace_remove kernel/trace/blktrace.c:406 [inline]
blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
blkdev_common_ioctl+0xe7b/0x2480 block/ioctl.c:622
blkdev_ioctl+0x51d/0x6f0 block/ioctl.c:687
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:907 [inline]
__se_sys_ioctl+0xf9/0x170 fs/ioctl.c:893
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f1da087cae9
RSP: 002b:00007f1da03de0c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f1da099c050 RCX: 00007f1da087cae9
RBP: 00007f1da08c847a R08: 0000000000000000 R09: 0000000000000000
R13: 000000000000006e R14: 00007f1da099c050 R15: 00007fff0c43a168
1 lock held by khungtaskd/30:
#0: ffffffff8e73a660 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:337 [inline]
#0: ffffffff8e73a660 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:849 [inline]
#0: ffffffff8e73a660 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x2a0 kernel/locking/lockdep.c:6720
3 locks held by kworker/u8:5/1271:
#0: ffff88814bf99948 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
#0: ffff88814bf99948 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_scheduled_works+0x98b/0x18f0 kernel/workqueue.c:3310
#1: ffffc90004737d00 ((work_completion)(&(&net->ipv6.addr_chk_work)->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
#1: ffffc90004737d00 ((work_completion)(&(&net->ipv6.addr_chk_work)->work)){+.+.}-{0:0}, at: process_scheduled_works+0x9c6/0x18f0 kernel/workqueue.c:3310
#2: ffffffff8fa498c8 (rtnl_mutex){+.+.}-{3:3}, at: addrconf_verify_work+0x19/0x30 net/ipv6/addrconf.c:4736
2 locks held by kworker/u8:8/2844:
3 locks held by kworker/u9:1/4493:
#0: ffff88809896c148 ((wq_completion)hci5){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
#0: ffff88809896c148 ((wq_completion)hci5){+.+.}-{0:0}, at: process_scheduled_works+0x98b/0x18f0 kernel/workqueue.c:3310
#1: ffffc9000db1fd00 ((work_completion)(&hdev->cmd_sync_work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
#1: ffffc9000db1fd00 ((work_completion)(&hdev->cmd_sync_work)){+.+.}-{0:0}, at: process_scheduled_works+0x9c6/0x18f0 kernel/workqueue.c:3310
#2: ffff88802c874d80 (&hdev->req_lock){+.+.}-{3:3}, at: hci_cmd_sync_work+0x1ec/0x400 net/bluetooth/hci_sync.c:327
4 locks held by klogd/4537:
#0: ffff8880b913ea98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2a/0x140 kernel/sched/core.c:593
#1: ffffffff8e84ce60 (mmu_notifier_invalidate_range_start){+.+.}-{0:0}, at: raw_spin_rq_lock_nested+0x2a/0x140 kernel/sched/core.c:593
#2: ffff88807e2cc618 (&p->pi_lock){-.-.}-{2:2}, at: class_raw_spinlock_irqsave_constructor include/linux/spinlock.h:551 [inline]
#2: ffff88807e2cc618 (&p->pi_lock){-.-.}-{2:2}, at: try_to_wake_up+0xbe/0x14b0 kernel/sched/core.c:4160
#3: ffff8880b913ea98 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x2a/0x140 kernel/sched/core.c:593
2 locks held by getty/4852:
#0: ffff88802a4b80a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
#1: ffffc90002f062f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x616/0x1770 drivers/tty/n_tty.c:2211
3 locks held by kworker/1:5/5500:
#0: ffff888015480948 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3204 [inline]
#0: ffff888015480948 ((wq_completion)events){+.+.}-{0:0}, at: process_scheduled_works+0x98b/0x18f0 kernel/workqueue.c:3310
#1: ffffc90004d17d00 (drain_vmap_work){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3205 [inline]
#1: ffffc90004d17d00 (drain_vmap_work){+.+.}-{0:0}, at: process_scheduled_works+0x9c6/0x18f0 kernel/workqueue.c:3310
#2: ffffffff8e8373c8 (vmap_purge_lock){+.+.}-{3:3}, at: drain_vmap_area_work+0x17/0x40 mm/vmalloc.c:2321
3 locks held by syz-executor.5/5929:
1 lock held by syz-executor.0/5945:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.0/5946:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.4/5948:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.4/5949:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.1/5967:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.1/5968:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.2/5985:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.3/6003:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.3/6004:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.5/6037:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.5/6038:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.0/6064:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.4/6066:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.4/6067:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.1/6087:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.1/6088:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.2/6106:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.2/6107:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.3/6125:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.3/6126:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by syz-executor.5/6147:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.5/6148:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
2 locks held by syz-executor.4/6165:
#0: ffffffff8fa498c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:79 [inline]
#0: ffffffff8fa498c8 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0x6e6/0xcf0 net/core/rtnetlink.c:6672
#1: ffffffff8e73fc38 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:329 [inline]
#1: ffffffff8e73fc38 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x451/0x820 kernel/rcu/tree_exp.h:976
1 lock held by syz-executor.0/6168:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xfb/0x1f0 kernel/trace/blktrace.c:630
1 lock held by syz-executor.0/6169:
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove kernel/trace/blktrace.c:406 [inline]
#0: ffff888142b6ad90 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_ioctl+0x1b8/0x830 kernel/trace/blktrace.c:745
1 lock held by dhcpcd/6177:
#0: ffff888065d3ca08 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:815 [inline]
#0: ffff888065d3ca08 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: __sock_release net/socket.c:657 [inline]
#0: ffff888065d3ca08 (&sb->s_type->i_mutex_key#10){+.+.}-{3:3}, at: sock_close+0x90/0x240 net/socket.c:1426
CPU: 0 UID: 0 PID: 30 Comm: khungtaskd Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:94 [inline]
dump_stack_lvl+0x241/0x360 lib/dump_stack.c:120
nmi_cpu_backtrace+0x49c/0x4d0 lib/nmi_backtrace.c:113
nmi_trigger_cpumask_backtrace+0x198/0x320 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:162 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:223 [inline]
watchdog+0xff4/0x1040 kernel/hung_task.c:379
kthread+0x2f0/0x390 kernel/kthread.c:389
ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
CPU: 1 UID: 0 PID: 2844 Comm: kworker/u8:8 Not tainted 6.12.0-rc2-syzkaller-00206-g3ae400ee2cd9 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Workqueue: bat_events batadv_nc_worker
RIP: 0010:debug_lockdep_rcu_enabled+0x2a/0x40 kernel/rcu/update.c:321
Code: f3 0f 1e fa 31 c0 83 3d 9f 8e 50 04 00 74 1e 83 3d f6 bd 50 04 00 74 15 65 48 8b 0c 25 c0 d7 03 00 31 c0 83 b9 dc 0a 00 00 00 <0f> 94 c0 c3 cc cc cc cc 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00
RSP: 0018:ffffc90009de7b50 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffff888023995a80 RCX: ffff88802902bc00
RDX: dffffc0000000000 RSI: ffffffff8bead560 RDI: ffffffff8c4159e0
RBP: ffff888166c393b0 R08: ffffffff934ac807 R09: 1ffffffff2695900
R10: dffffc0000000000 R11: fffffbfff2695901 R12: ffff88816d91ccc0
R13: 0000000000000276 R14: ffff888023995a80 R15: dffffc0000000000
FS: 0000000000000000(0000) GS:ffff8880b9100000(0000) knlGS:0000000000000000
CR2: 00007efecd242040 CR3: 000000007b8e8000 CR4: 00000000003526f0
rcu_read_lock include/linux/rcupdate.h:850 [inline]
batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:408 [inline]
batadv_nc_worker+0xf5/0x610 net/batman-adv/network-coding.c:719
process_one_work kernel/workqueue.c:3229 [inline]
process_scheduled_works+0xabe/0x18f0 kernel/workqueue.c:3310
worker_thread+0x870/0xd30 kernel/workqueue.c:3391
kthread+0x2f0/0x390 kernel/kthread.c:389
ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
</TASK>


Tested on:

commit: 3ae400ee blktrace: move user copies out of q->debugfs_..
git tree: git://git.kernel.dk/linux btrace-fault
console output: https://syzkaller.appspot.com/x/log.txt?x=17995fd0580000
kernel config: https://syzkaller.appspot.com/x/.config?x=ac04e079248cbf6c
dashboard link: https://syzkaller.appspot.com/bug?extid=ed812ed461471ab17a0c
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

Note: no patches were applied.

Hi Jens,
< ... >
You'd need to type the exact same command. If there's no patch, syzbot
will just build the kernel from the specified repository and run the
reproducer on it. If you paste the git patch below the `syz test`
command, it will apply that patch before building the kernel.