[syzbot] [sound?] possible deadlock in snd_timer_close_locked

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: fe46a7dd189e Merge tag 'sound-6.9-rc1' of git://git.kernel..
git tree: upstream
console+strace: https://syzkaller.appspot.com/x/log.txt?x=14cd9bd6180000
kernel config: https://syzkaller.appspot.com/x/.config?x=4d90a36f0cab495a
dashboard link: https://syzkaller.appspot.com/bug?extid=f3bc6f8108108010a03d
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=149b2e86180000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13a304a5180000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/72ab73815344/disk-fe46a7dd.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/2d6d6b0d7071/vmlinux-fe46a7dd.xz
kernel image: https://storage.googleapis.com/syzbot-assets/48e275e5478b/bzImage-fe46a7dd.xz

The issue was bisected to:

commit beb45974dd49068b24788bbfc2abe20d50503761
Author: Takashi Iwai <ti...@suse.de>
Date: Tue Feb 27 08:52:45 2024 +0000

ALSA: timer: Use guard() for locking

bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=100427b6180000
final oops: https://syzkaller.appspot.com/x/report.txt?x=120427b6180000
console output: https://syzkaller.appspot.com/x/log.txt?x=140427b6180000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+f3bc6f...@syzkaller.appspotmail.com
Fixes: beb45974dd49 ("ALSA: timer: Use guard() for locking")

========================================================
WARNING: possible irq lock inversion dependency detected
6.8.0-syzkaller-08951-gfe46a7dd189e #0 Not tainted
--------------------------------------------------------
syz-executor504/5058 just changed the state of lock:
ffff8880293a4148 (&timer->lock){+.+.}-{2:2}, at: spin_lock include/linux/spinlock.h:351 [inline]
ffff8880293a4148 (&timer->lock){+.+.}-{2:2}, at: class_spinlock_constructor include/linux/spinlock.h:561 [inline]
ffff8880293a4148 (&timer->lock){+.+.}-{2:2}, at: snd_timer_close_locked+0x53/0x8d0 sound/core/timer.c:412
but this lock was taken by another, SOFTIRQ-safe lock in the past:
(&group->lock#2){..-.}-{2:2}


and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&timer->lock);
local_irq_disable();
lock(&group->lock#2);
lock(&timer->lock);
<Interrupt>
lock(&group->lock#2);

*** DEADLOCK ***

3 locks held by syz-executor504/5058:
#0: ffffffff8f2d3228 (register_mutex#4){+.+.}-{3:3}, at: odev_release+0x4e/0x80 sound/core/seq/oss/seq_oss.c:143
#1: ffff88801f38f978 (&q->timer_mutex){+.+.}-{3:3}, at: queue_delete sound/core/seq/seq_queue.c:124 [inline]
#1: ffff88801f38f978 (&q->timer_mutex){+.+.}-{3:3}, at: snd_seq_queue_delete+0x5b/0xf0 sound/core/seq/seq_queue.c:188
#2: ffffffff8f2c1a68 (register_mutex){+.+.}-{3:3}, at: class_mutex_constructor include/linux/mutex.h:169 [inline]
#2: ffffffff8f2c1a68 (register_mutex){+.+.}-{3:3}, at: snd_timer_close+0xa3/0x130 sound/core/timer.c:463

the shortest dependencies between 2nd lock and 1st lock:
-> (&group->lock#2){..-.}-{2:2} {
IN-SOFTIRQ-W at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
class_pcm_stream_lock_irqsave_constructor include/sound/pcm.h:669 [inline]
snd_pcm_period_elapsed+0x21/0x50 sound/core/pcm_lib.c:1904
dummy_hrtimer_callback+0x7f/0x180 sound/drivers/dummy.c:385
__run_hrtimer kernel/time/hrtimer.c:1692 [inline]
__hrtimer_run_queues+0x595/0xd00 kernel/time/hrtimer.c:1756
hrtimer_run_softirq+0x19a/0x2c0 kernel/time/hrtimer.c:1773
__do_softirq+0x2bc/0x943 kernel/softirq.c:554
invoke_softirq kernel/softirq.c:428 [inline]
__irq_exit_rcu+0xf2/0x1c0 kernel/softirq.c:633
irq_exit_rcu+0x9/0x30 kernel/softirq.c:645
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
sysvec_apic_timer_interrupt+0xa6/0xc0 arch/x86/kernel/apic/apic.c:1043
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
native_safe_halt arch/x86/include/asm/irqflags.h:48 [inline]
arch_safe_halt arch/x86/include/asm/irqflags.h:86 [inline]
acpi_safe_halt+0x21/0x30 drivers/acpi/processor_idle.c:112
acpi_idle_enter+0xe4/0x140 drivers/acpi/processor_idle.c:707
cpuidle_enter_state+0x118/0x490 drivers/cpuidle/cpuidle.c:267
cpuidle_enter+0x5d/0xa0 drivers/cpuidle/cpuidle.c:388
call_cpuidle kernel/sched/idle.c:155 [inline]
cpuidle_idle_call kernel/sched/idle.c:236 [inline]
do_idle+0x375/0x5d0 kernel/sched/idle.c:332
cpu_startup_entry+0x42/0x60 kernel/sched/idle.c:430
rest_init+0x2e0/0x300 init/main.c:730
arch_call_rest_init+0xe/0x10 init/main.c:831
start_kernel+0x47a/0x500 init/main.c:1077
x86_64_start_reservations+0x2a/0x30 arch/x86/kernel/head64.c:509
x86_64_start_kernel+0x99/0xa0 arch/x86/kernel/head64.c:490
common_startup_64+0x13e/0x147
INITIAL USE at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock_irq include/linux/spinlock_api_smp.h:119 [inline]
_raw_spin_lock_irq+0xd3/0x120 kernel/locking/spinlock.c:170
spin_lock_irq include/linux/spinlock.h:376 [inline]
snd_pcm_group_lock_irq sound/core/pcm_native.c:97 [inline]
snd_pcm_stream_lock_irq sound/core/pcm_native.c:136 [inline]
class_pcm_stream_lock_irq_constructor include/sound/pcm.h:666 [inline]
snd_pcm_hw_params+0x201/0x1ea0 sound/core/pcm_native.c:740
snd_pcm_oss_change_params_locked+0x20d5/0x3e00 sound/core/oss/pcm_oss.c:965
snd_pcm_oss_make_ready_locked sound/core/oss/pcm_oss.c:1187 [inline]
snd_pcm_oss_read1 sound/core/oss/pcm_oss.c:1515 [inline]
snd_pcm_oss_read+0x24c/0x940 sound/core/oss/pcm_oss.c:2773
do_loop_readv_writev fs/read_write.c:761 [inline]
vfs_readv+0x68f/0xa50 fs/read_write.c:934
do_readv+0x1b1/0x350 fs/read_write.c:994
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75
}
... key at: [<ffffffff9485f200>] snd_pcm_group_init.__key+0x0/0x20
... acquired at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
class_spinlock_irqsave_constructor include/linux/spinlock.h:574 [inline]
snd_timer_notify+0x103/0x3d0 sound/core/timer.c:1040
snd_pcm_action sound/core/pcm_native.c:1370 [inline]
snd_pcm_start+0x3fa/0x4c0 sound/core/pcm_native.c:1478
__snd_pcm_lib_xfer+0x1af3/0x1e30 sound/core/pcm_lib.c:2301
snd_pcm_oss_read3+0x3ea/0x600 sound/core/oss/pcm_oss.c:1281
snd_pcm_plug_read_transfer+0x3a1/0x470 sound/core/oss/pcm_plugin.c:663
snd_pcm_oss_read2+0x296/0x430 sound/core/oss/pcm_oss.c:1482
snd_pcm_oss_read1 sound/core/oss/pcm_oss.c:1520 [inline]
snd_pcm_oss_read+0x45b/0x940 sound/core/oss/pcm_oss.c:2773
do_loop_readv_writev fs/read_write.c:761 [inline]
vfs_readv+0x68f/0xa50 fs/read_write.c:934
do_readv+0x1b1/0x350 fs/read_write.c:994
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75

-> (&timer->lock){+.+.}-{2:2} {
HARDIRQ-ON-W at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
class_spinlock_constructor include/linux/spinlock.h:561 [inline]
snd_timer_close_locked+0x53/0x8d0 sound/core/timer.c:412
snd_timer_close+0xae/0x130 sound/core/timer.c:464
snd_seq_timer_close+0xa9/0xe0 sound/core/seq/seq_timer.c:302
queue_delete sound/core/seq/seq_queue.c:126 [inline]
snd_seq_queue_delete+0x8f/0xf0 sound/core/seq/seq_queue.c:188
delete_seq_queue sound/core/seq/oss/seq_oss_init.c:371 [inline]
snd_seq_oss_release+0x1d3/0x310 sound/core/seq/oss/seq_oss_init.c:416
odev_release+0x56/0x80 sound/core/seq/oss/seq_oss.c:144
__fput+0x429/0x8a0 fs/file_table.c:422
task_work_run+0x24f/0x310 kernel/task_work.c:180
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xa1b/0x27e0 kernel/exit.c:878
do_group_exit+0x207/0x2c0 kernel/exit.c:1027
__do_sys_exit_group kernel/exit.c:1038 [inline]
__se_sys_exit_group kernel/exit.c:1036 [inline]
__x64_sys_exit_group+0x3f/0x40 kernel/exit.c:1036
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75
SOFTIRQ-ON-W at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
class_spinlock_constructor include/linux/spinlock.h:561 [inline]
snd_timer_close_locked+0x53/0x8d0 sound/core/timer.c:412
snd_timer_close+0xae/0x130 sound/core/timer.c:464
snd_seq_timer_close+0xa9/0xe0 sound/core/seq/seq_timer.c:302
queue_delete sound/core/seq/seq_queue.c:126 [inline]
snd_seq_queue_delete+0x8f/0xf0 sound/core/seq/seq_queue.c:188
delete_seq_queue sound/core/seq/oss/seq_oss_init.c:371 [inline]
snd_seq_oss_release+0x1d3/0x310 sound/core/seq/oss/seq_oss_init.c:416
odev_release+0x56/0x80 sound/core/seq/oss/seq_oss.c:144
__fput+0x429/0x8a0 fs/file_table.c:422
task_work_run+0x24f/0x310 kernel/task_work.c:180
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xa1b/0x27e0 kernel/exit.c:878
do_group_exit+0x207/0x2c0 kernel/exit.c:1027
__do_sys_exit_group kernel/exit.c:1038 [inline]
__se_sys_exit_group kernel/exit.c:1036 [inline]
__x64_sys_exit_group+0x3f/0x40 kernel/exit.c:1036
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75
INITIAL USE at:
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd5/0x120 kernel/locking/spinlock.c:162
class_spinlock_irqsave_constructor include/linux/spinlock.h:574 [inline]
snd_timer_notify+0x103/0x3d0 sound/core/timer.c:1040
snd_pcm_action sound/core/pcm_native.c:1370 [inline]
snd_pcm_start+0x3fa/0x4c0 sound/core/pcm_native.c:1478
__snd_pcm_lib_xfer+0x1af3/0x1e30 sound/core/pcm_lib.c:2301
snd_pcm_oss_read3+0x3ea/0x600 sound/core/oss/pcm_oss.c:1281
snd_pcm_plug_read_transfer+0x3a1/0x470 sound/core/oss/pcm_plugin.c:663
snd_pcm_oss_read2+0x296/0x430 sound/core/oss/pcm_oss.c:1482
snd_pcm_oss_read1 sound/core/oss/pcm_oss.c:1520 [inline]
snd_pcm_oss_read+0x45b/0x940 sound/core/oss/pcm_oss.c:2773
do_loop_readv_writev fs/read_write.c:761 [inline]
vfs_readv+0x68f/0xa50 fs/read_write.c:934
do_readv+0x1b1/0x350 fs/read_write.c:994
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75
}
... key at: [<ffffffff9485efe0>] snd_timer_new.__key+0x0/0x20
... acquired at:
mark_lock+0x223/0x350 kernel/locking/lockdep.c:4678
__lock_acquire+0x116e/0x1fd0 kernel/locking/lockdep.c:5091
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
class_spinlock_constructor include/linux/spinlock.h:561 [inline]
snd_timer_close_locked+0x53/0x8d0 sound/core/timer.c:412
snd_timer_close+0xae/0x130 sound/core/timer.c:464
snd_seq_timer_close+0xa9/0xe0 sound/core/seq/seq_timer.c:302
queue_delete sound/core/seq/seq_queue.c:126 [inline]
snd_seq_queue_delete+0x8f/0xf0 sound/core/seq/seq_queue.c:188
delete_seq_queue sound/core/seq/oss/seq_oss_init.c:371 [inline]
snd_seq_oss_release+0x1d3/0x310 sound/core/seq/oss/seq_oss_init.c:416
odev_release+0x56/0x80 sound/core/seq/oss/seq_oss.c:144
__fput+0x429/0x8a0 fs/file_table.c:422
task_work_run+0x24f/0x310 kernel/task_work.c:180
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xa1b/0x27e0 kernel/exit.c:878
do_group_exit+0x207/0x2c0 kernel/exit.c:1027
__do_sys_exit_group kernel/exit.c:1038 [inline]
__se_sys_exit_group kernel/exit.c:1036 [inline]
__x64_sys_exit_group+0x3f/0x40 kernel/exit.c:1036
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75


stack backtrace:
CPU: 0 PID: 5058 Comm: syz-executor504 Not tainted 6.8.0-syzkaller-08951-gfe46a7dd189e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x241/0x360 lib/dump_stack.c:114
mark_lock_irq+0x867/0xc20 kernel/locking/lockdep.c:4236
mark_lock+0x223/0x350 kernel/locking/lockdep.c:4678
__lock_acquire+0x116e/0x1fd0 kernel/locking/lockdep.c:5091
lock_acquire+0x1e4/0x530 kernel/locking/lockdep.c:5754
__raw_spin_lock include/linux/spinlock_api_smp.h:133 [inline]
_raw_spin_lock+0x2e/0x40 kernel/locking/spinlock.c:154
spin_lock include/linux/spinlock.h:351 [inline]
class_spinlock_constructor include/linux/spinlock.h:561 [inline]
snd_timer_close_locked+0x53/0x8d0 sound/core/timer.c:412
snd_timer_close+0xae/0x130 sound/core/timer.c:464
snd_seq_timer_close+0xa9/0xe0 sound/core/seq/seq_timer.c:302
queue_delete sound/core/seq/seq_queue.c:126 [inline]
snd_seq_queue_delete+0x8f/0xf0 sound/core/seq/seq_queue.c:188
delete_seq_queue sound/core/seq/oss/seq_oss_init.c:371 [inline]
snd_seq_oss_release+0x1d3/0x310 sound/core/seq/oss/seq_oss_init.c:416
odev_release+0x56/0x80 sound/core/seq/oss/seq_oss.c:144
__fput+0x429/0x8a0 fs/file_table.c:422
task_work_run+0x24f/0x310 kernel/task_work.c:180
exit_task_work include/linux/task_work.h:38 [inline]
do_exit+0xa1b/0x27e0 kernel/exit.c:878
do_group_exit+0x207/0x2c0 kernel/exit.c:1027
__do_sys_exit_group kernel/exit.c:1038 [inline]
__se_sys_exit_group kernel/exit.c:1036 [inline]
__x64_sys_exit_group+0x3f/0x40 kernel/exit.c:1036
do_syscall_64+0xfb/0x240
entry_SYSCALL_64_after_hwframe+0x6d/0x75
RIP: 0033:0x7f0910103b89
Code: Unable to access opcode bytes at 0x7f0910103b5f.
RSP: 002b:00007ffc7b2de668 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f0910103b89
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 00007f091017e290 R08: ffffffffffffffb8 R09: 0000000000000006
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f091017e290
R13: 0000000000000000 R14: 00007f091017ece0 R15: 00007f09100d4df0
</TASK>


---
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

[Takashi Iwai]

#syz dup: [syzbot] [sound?] possible deadlock in snd_pcm_period_elapsed (4)

[Hillf Danton]

On Fri, 15 Mar 2024 04:16:27 -0700

> syzbot found the following issue on:
>
> HEAD commit: fe46a7dd189e Merge tag 'sound-6.9-rc1' of git://git.kernel..
> git tree: upstream

> C reproducer: https://syzkaller.appspot.com/x/repro.c?x=13a304a5180000

#syz test https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master

--- x/sound/core/timer.c
+++ y/sound/core/timer.c
@@ -409,8 +409,9 @@ static void snd_timer_close_locked(struc
struct snd_timer *timer = timeri->timer;

if (timer) {
- guard(spinlock)(&timer->lock);
+ spin_lock_irq(&timer->lock);
timeri->flags |= SNDRV_TIMER_IFLG_DEAD;
+ spin_unlock_irq(&timer->lock);
}

if (!list_empty(&timeri->open_list)) {
--

[syzbot]

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

: registered new interface driver port100
[ 7.829002][ T1] usbcore: registered new interface driver nfcmrvl
[ 7.837538][ T1] Loading iSCSI transport class v2.0-870.
[ 7.856507][ T1] virtio_scsi virtio0: 1/0/0 default/read/poll queues
[ 7.866977][ T1] ------------[ cut here ]------------
[ 7.868232][ T1] refcount_t: decrement hit 0; leaking memory.
[ 7.869519][ T1] WARNING: CPU: 0 PID: 1 at lib/refcount.c:31 refcount_warn_saturate+0xfa/0x1d0
[ 7.870990][ T1] Modules linked in:
[ 7.871688][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.8.0-syzkaller-09791-ge5eb28f6d1af-dirty #0
[ 7.876326][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
[ 7.878700][ T1] RIP: 0010:refcount_warn_saturate+0xfa/0x1d0
[ 7.879754][ T1] Code: b2 00 00 00 e8 27 5a f7 fc 5b 5d c3 cc cc cc cc e8 1b 5a f7 fc c6 05 f6 81 d3 0a 01 90 48 c7 c7 e0 a7 fd 8b e8 47 2e ba fc 90 <0f> 0b 90 90 eb d9 e8 fb 59 f7 fc c6 05 d3 81 d3 0a 01 90 48 c7 c7
[ 7.882789][ T1] RSP: 0000:ffffc90000066e18 EFLAGS: 00010246
[ 7.884154][ T1] RAX: 427762defa97e000 RBX: ffff888020edeb2c RCX: ffff8880166c8000
[ 7.885354][ T1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 7.886832][ T1] RBP: 0000000000000004 R08: ffffffff8157cf32 R09: fffffbfff1bf9650
[ 7.888655][ T1] R10: dffffc0000000000 R11: fffffbfff1bf9650 R12: ffffea0000843dc0
[ 7.889916][ T1] R13: ffffea0000843dc8 R14: 1ffffd40001087b9 R15: 0000000000000000
[ 7.893126][ T1] FS: 0000000000000000(0000) GS:ffff8880b9400000(0000) knlGS:0000000000000000
[ 7.895114][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 7.896277][ T1] CR2: ffff88823ffff000 CR3: 000000000df32000 CR4: 00000000003506f0
[ 7.897638][ T1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 7.900434][ T1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 7.902939][ T1] Call Trace:
[ 7.904000][ T1] <TASK>
[ 7.904699][ T1] ? __warn+0x163/0x4b0
[ 7.905611][ T1] ? refcount_warn_saturate+0xfa/0x1d0
[ 7.906808][ T1] ? report_bug+0x2b3/0x500
[ 7.907725][ T1] ? refcount_warn_saturate+0xfa/0x1d0
[ 7.908788][ T1] ? handle_bug+0x3e/0x70
[ 7.909996][ T1] ? exc_invalid_op+0x1a/0x50
[ 7.910753][ T1] ? asm_exc_invalid_op+0x1a/0x20
[ 7.911517][ T1] ? __warn_printk+0x292/0x360
[ 7.912828][ T1] ? refcount_warn_saturate+0xfa/0x1d0
[ 7.914043][ T1] ? refcount_warn_saturate+0xf9/0x1d0
[ 7.914947][ T1] __free_pages_ok+0xc36/0xd60
[ 7.916124][ T1] make_alloc_exact+0xa3/0xf0
[ 7.917078][ T1] vring_alloc_queue_split+0x20a/0x600
[ 7.918018][ T1] ? __pfx_vring_alloc_queue_split+0x10/0x10
[ 7.919870][ T1] ? vp_find_vqs+0x4c/0x4e0
[ 7.920839][ T1] ? virtscsi_probe+0x3ea/0xf60
[ 7.921640][ T1] ? virtio_dev_probe+0x991/0xaf0
[ 7.922633][ T1] ? really_probe+0x29e/0xc50
[ 7.923595][ T1] ? driver_probe_device+0x50/0x430
[ 7.925027][ T1] vring_create_virtqueue_split+0xc6/0x310
[ 7.926040][ T1] ? ret_from_fork+0x4b/0x80
[ 7.927657][ T1] ? __pfx_vring_create_virtqueue_split+0x10/0x10
[ 7.929661][ T1] vring_create_virtqueue+0xca/0x110
[ 7.930785][ T1] ? __pfx_vp_notify+0x10/0x10
[ 7.931677][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 7.932523][ T1] setup_vq+0xe9/0x2d0
[ 7.933148][ T1] ? __pfx_vp_notify+0x10/0x10
[ 7.934298][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 7.936631][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 7.938514][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 7.939708][ T1] vp_setup_vq+0xbf/0x330
[ 7.940480][ T1] ? __pfx_vp_config_changed+0x10/0x10
[ 7.941952][ T1] ? ioread16+0x2f/0x90
[ 7.943383][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 7.945869][ T1] vp_find_vqs_msix+0x8b2/0xc80
[ 7.946930][ T1] vp_find_vqs+0x4c/0x4e0
[ 7.948366][ T1] virtscsi_init+0x8db/0xd00
[ 7.949444][ T1] ? __pfx_virtscsi_init+0x10/0x10
[ 7.950722][ T1] ? __pfx_default_calc_sets+0x10/0x10
[ 7.952485][ T1] ? scsi_host_alloc+0xa57/0xea0
[ 7.954177][ T1] ? vp_get+0xfd/0x140
[ 7.955309][ T1] virtscsi_probe+0x3ea/0xf60
[ 7.956670][ T1] ? __pfx_virtscsi_probe+0x10/0x10
[ 7.958350][ T1] ? virtqueue_dma_mapping_error+0xd/0x80
[ 7.960113][ T1] ? __pfx_vp_set_status+0x10/0x10
[ 7.961499][ T1] ? vp_set_status+0x1a/0x40
[ 7.962431][ T1] ? virtio_no_restricted_mem_acc+0x9/0x10
[ 7.964349][ T1] ? virtio_features_ok+0x10c/0x270
[ 7.965595][ T1] virtio_dev_probe+0x991/0xaf0
[ 7.966818][ T1] ? __pfx_virtio_dev_probe+0x10/0x10
[ 7.967921][ T1] really_probe+0x29e/0xc50
[ 7.968593][ T1] __driver_probe_device+0x1a2/0x3e0
[ 7.969535][ T1] driver_probe_device+0x50/0x430
[ 7.970634][ T1] __driver_attach+0x45f/0x710
[ 7.971732][ T1] ? __pfx___driver_attach+0x10/0x10
[ 7.973000][ T1] bus_for_each_dev+0x239/0x2b0
[ 7.974208][ T1] ? __pfx___driver_attach+0x10/0x10
[ 7.975425][ T1] ? __pfx_bus_for_each_dev+0x10/0x10
[ 7.976355][ T1] ? do_raw_spin_unlock+0x13c/0x8b0
[ 7.977543][ T1] bus_add_driver+0x347/0x620
[ 7.979682][ T1] driver_register+0x23a/0x320
[ 7.981056][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 7.982342][ T1] virtio_scsi_init+0x65/0xe0
[ 7.983870][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 7.985269][ T1] do_one_initcall+0x238/0x830
[ 7.986554][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 7.987867][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 7.989039][ T1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 7.990465][ T1] ? __pfx_parse_args+0x10/0x10
[ 7.991527][ T1] ? do_initcalls+0x1c/0x80
[ 7.992292][ T1] ? rcu_is_watching+0x15/0xb0
[ 7.993265][ T1] do_initcall_level+0x157/0x210
[ 7.994180][ T1] do_initcalls+0x3f/0x80
[ 7.994906][ T1] kernel_init_freeable+0x435/0x5d0
[ 7.995937][ T1] ? __pfx_kernel_init_freeable+0x10/0x10
[ 7.996856][ T1] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 7.997739][ T1] ? __pfx_kernel_init+0x10/0x10
[ 7.999001][ T1] ? __pfx_kernel_init+0x10/0x10
[ 7.999909][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.000823][ T1] kernel_init+0x1d/0x2b0
[ 8.001451][ T1] ret_from_fork+0x4b/0x80
[ 8.002268][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.003408][ T1] ret_from_fork_asm+0x1a/0x30
[ 8.004122][ T1] </TASK>
[ 8.005036][ T1] Kernel panic - not syncing: kernel: panic_on_warn set ...
[ 8.006846][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.8.0-syzkaller-09791-ge5eb28f6d1af-dirty #0
[ 8.009117][ T1] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
[ 8.011687][ T1] Call Trace:
[ 8.012892][ T1] <TASK>
[ 8.013386][ T1] dump_stack_lvl+0x241/0x360
[ 8.013386][ T1] ? __pfx_dump_stack_lvl+0x10/0x10
[ 8.013386][ T1] ? __pfx__printk+0x10/0x10
[ 8.013386][ T1] ? _printk+0xd5/0x120
[ 8.013386][ T1] ? vscnprintf+0x5d/0x90
[ 8.013386][ T1] panic+0x349/0x860
[ 8.013386][ T1] ? __warn+0x172/0x4b0
[ 8.013386][ T1] ? __pfx_panic+0x10/0x10
[ 8.013386][ T1] ? show_trace_log_lvl+0x4e6/0x520
[ 8.013386][ T1] ? ret_from_fork_asm+0x1a/0x30
[ 8.013386][ T1] __warn+0x31e/0x4b0
[ 8.013386][ T1] ? refcount_warn_saturate+0xfa/0x1d0
[ 8.013386][ T1] report_bug+0x2b3/0x500
[ 8.013386][ T1] ? refcount_warn_saturate+0xfa/0x1d0
[ 8.013386][ T1] handle_bug+0x3e/0x70
[ 8.013386][ T1] exc_invalid_op+0x1a/0x50
[ 8.013386][ T1] asm_exc_invalid_op+0x1a/0x20
[ 8.013386][ T1] RIP: 0010:refcount_warn_saturate+0xfa/0x1d0
[ 8.013386][ T1] Code: b2 00 00 00 e8 27 5a f7 fc 5b 5d c3 cc cc cc cc e8 1b 5a f7 fc c6 05 f6 81 d3 0a 01 90 48 c7 c7 e0 a7 fd 8b e8 47 2e ba fc 90 <0f> 0b 90 90 eb d9 e8 fb 59 f7 fc c6 05 d3 81 d3 0a 01 90 48 c7 c7
[ 8.013386][ T1] RSP: 0000:ffffc90000066e18 EFLAGS: 00010246
[ 8.013386][ T1] RAX: 427762defa97e000 RBX: ffff888020edeb2c RCX: ffff8880166c8000
[ 8.013386][ T1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 8.013386][ T1] RBP: 0000000000000004 R08: ffffffff8157cf32 R09: fffffbfff1bf9650
[ 8.013386][ T1] R10: dffffc0000000000 R11: fffffbfff1bf9650 R12: ffffea0000843dc0
[ 8.013386][ T1] R13: ffffea0000843dc8 R14: 1ffffd40001087b9 R15: 0000000000000000
[ 8.013386][ T1] ? __warn_printk+0x292/0x360
[ 8.013386][ T1] ? refcount_warn_saturate+0xf9/0x1d0
[ 8.013386][ T1] __free_pages_ok+0xc36/0xd60
[ 8.013386][ T1] make_alloc_exact+0xa3/0xf0
[ 8.013386][ T1] vring_alloc_queue_split+0x20a/0x600
[ 8.013386][ T1] ? __pfx_vring_alloc_queue_split+0x10/0x10
[ 8.013386][ T1] ? vp_find_vqs+0x4c/0x4e0
[ 8.013386][ T1] ? virtscsi_probe+0x3ea/0xf60
[ 8.013386][ T1] ? virtio_dev_probe+0x991/0xaf0
[ 8.013386][ T1] ? really_probe+0x29e/0xc50
[ 8.013386][ T1] ? driver_probe_device+0x50/0x430
[ 8.013386][ T1] vring_create_virtqueue_split+0xc6/0x310
[ 8.013386][ T1] ? ret_from_fork+0x4b/0x80
[ 8.063354][ T1] ? __pfx_vring_create_virtqueue_split+0x10/0x10
[ 8.063354][ T1] vring_create_virtqueue+0xca/0x110
[ 8.063354][ T1] ? __pfx_vp_notify+0x10/0x10
[ 8.063354][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 8.063354][ T1] setup_vq+0xe9/0x2d0
[ 8.063354][ T1] ? __pfx_vp_notify+0x10/0x10
[ 8.063354][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 8.063354][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 8.063354][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 8.063354][ T1] vp_setup_vq+0xbf/0x330
[ 8.063354][ T1] ? __pfx_vp_config_changed+0x10/0x10
[ 8.063354][ T1] ? ioread16+0x2f/0x90
[ 8.063354][ T1] ? __pfx_virtscsi_ctrl_done+0x10/0x10
[ 8.063354][ T1] vp_find_vqs_msix+0x8b2/0xc80
[ 8.063354][ T1] vp_find_vqs+0x4c/0x4e0
[ 8.063354][ T1] virtscsi_init+0x8db/0xd00
[ 8.063354][ T1] ? __pfx_virtscsi_init+0x10/0x10
[ 8.063354][ T1] ? __pfx_default_calc_sets+0x10/0x10
[ 8.063354][ T1] ? scsi_host_alloc+0xa57/0xea0
[ 8.063354][ T1] ? vp_get+0xfd/0x140
[ 8.063354][ T1] virtscsi_probe+0x3ea/0xf60
[ 8.063354][ T1] ? __pfx_virtscsi_probe+0x10/0x10
[ 8.063354][ T1] ? virtqueue_dma_mapping_error+0xd/0x80
[ 8.063354][ T1] ? __pfx_vp_set_status+0x10/0x10
[ 8.063354][ T1] ? vp_set_status+0x1a/0x40
[ 8.063354][ T1] ? virtio_no_restricted_mem_acc+0x9/0x10
[ 8.063354][ T1] ? virtio_features_ok+0x10c/0x270
[ 8.063354][ T1] virtio_dev_probe+0x991/0xaf0
[ 8.063354][ T1] ? __pfx_virtio_dev_probe+0x10/0x10
[ 8.063354][ T1] really_probe+0x29e/0xc50
[ 8.063354][ T1] __driver_probe_device+0x1a2/0x3e0
[ 8.063354][ T1] driver_probe_device+0x50/0x430
[ 8.063354][ T1] __driver_attach+0x45f/0x710
[ 8.063354][ T1] ? __pfx___driver_attach+0x10/0x10
[ 8.063354][ T1] bus_for_each_dev+0x239/0x2b0
[ 8.063354][ T1] ? __pfx___driver_attach+0x10/0x10
[ 8.063354][ T1] ? __pfx_bus_for_each_dev+0x10/0x10
[ 8.063354][ T1] ? do_raw_spin_unlock+0x13c/0x8b0
[ 8.063354][ T1] bus_add_driver+0x347/0x620
[ 8.063354][ T1] driver_register+0x23a/0x320
[ 8.063354][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 8.063354][ T1] virtio_scsi_init+0x65/0xe0
[ 8.063354][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 8.063354][ T1] do_one_initcall+0x238/0x830
[ 8.063354][ T1] ? __pfx_virtio_scsi_init+0x10/0x10
[ 8.063354][ T1] ? __pfx_do_one_initcall+0x10/0x10
[ 8.063354][ T1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 8.063354][ T1] ? __pfx_parse_args+0x10/0x10
[ 8.113373][ T1] ? do_initcalls+0x1c/0x80
[ 8.113373][ T1] ? rcu_is_watching+0x15/0xb0
[ 8.113373][ T1] do_initcall_level+0x157/0x210
[ 8.113373][ T1] do_initcalls+0x3f/0x80
[ 8.113373][ T1] kernel_init_freeable+0x435/0x5d0
[ 8.113373][ T1] ? __pfx_kernel_init_freeable+0x10/0x10
[ 8.113373][ T1] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 8.113373][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.113373][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.113373][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.113373][ T1] kernel_init+0x1d/0x2b0
[ 8.113373][ T1] ret_from_fork+0x4b/0x80
[ 8.113373][ T1] ? __pfx_kernel_init+0x10/0x10
[ 8.113373][ T1] ret_from_fork_asm+0x1a/0x30
[ 8.113373][ T1] </TASK>
[ 8.113373][ T1] Kernel Offset: disabled
[ 8.113373][ T1] Rebooting in 86400 seconds..


syzkaller build log:
go env (err=<nil>)
GO111MODULE='auto'
GOARCH='amd64'
GOBIN=''
GOCACHE='/syzkaller/.cache/go-build'
GOENV='/syzkaller/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/syzkaller/jobs/linux/gopath/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/syzkaller/jobs/linux/gopath'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.21.4'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/syzkaller/jobs/linux/gopath/src/github.com/google/syzkaller/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build2569298022=/tmp/go-build -gno-record-gcc-switches'

git status (err=<nil>)
HEAD detached at d615901c7
nothing to commit, working tree clean


tput: No value for $TERM and no -T specified
tput: No value for $TERM and no -T specified
Makefile:31: run command via tools/syz-env for best compatibility, see:
Makefile:32: https://github.com/google/syzkaller/blob/master/docs/contributing.md#using-syz-env
go list -f '{{.Stale}}' ./sys/syz-sysgen | grep -q false || go install ./sys/syz-sysgen
make .descriptions
tput: No value for $TERM and no -T specified
tput: No value for $TERM and no -T specified
Makefile:31: run command via tools/syz-env for best compatibility, see:
Makefile:32: https://github.com/google/syzkaller/blob/master/docs/contributing.md#using-syz-env
bin/syz-sysgen
touch .descriptions
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=d615901c739a765329b688494cee2f8e1b5037cb -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240314-145638'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-fuzzer github.com/google/syzkaller/syz-fuzzer
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=d615901c739a765329b688494cee2f8e1b5037cb -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240314-145638'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-execprog github.com/google/syzkaller/tools/syz-execprog
GOOS=linux GOARCH=amd64 go build "-ldflags=-s -w -X github.com/google/syzkaller/prog.GitRevision=d615901c739a765329b688494cee2f8e1b5037cb -X 'github.com/google/syzkaller/prog.gitRevisionDate=20240314-145638'" "-tags=syz_target syz_os_linux syz_arch_amd64 " -o ./bin/linux_amd64/syz-stress github.com/google/syzkaller/tools/syz-stress
mkdir -p ./bin/linux_amd64
gcc -o ./bin/linux_amd64/syz-executor executor/executor.cc \
-m64 -O2 -pthread -Wall -Werror -Wparentheses -Wunused-const-variable -Wframe-larger-than=16384 -Wno-stringop-overflow -Wno-array-bounds -Wno-format-overflow -Wno-unused-but-set-variable -Wno-unused-command-line-argument -static-pie -fpermissive -w -DGOOS_linux=1 -DGOARCH_amd64=1 \
-DHOSTGOOS_linux=1 -DGIT_REVISION=\"d615901c739a765329b688494cee2f8e1b5037cb\"


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=161a7959180000


Tested on:

commit: e5eb28f6 Merge tag 'mm-nonmm-stable-2024-03-14-09-36' ..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
kernel config: https://syzkaller.appspot.com/x/.config?x=839e3be5d86ffd1d

dashboard link: https://syzkaller.appspot.com/bug?extid=f3bc6f8108108010a03d
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

patch: https://syzkaller.appspot.com/x/patch.diff?x=13298231180000

[Hillf Danton]

#syz test https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git fe46a7dd189e

[syzbot]

Hello,

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

Reported-and-tested-by: syzbot+f3bc6f...@syzkaller.appspotmail.com

Tested on:

commit: fe46a7dd Merge tag 'sound-6.9-rc1' of git://git.kernel..
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
console output: https://syzkaller.appspot.com/x/log.txt?x=142f5185180000
kernel config: https://syzkaller.appspot.com/x/.config?x=4d90a36f0cab495a

dashboard link: https://syzkaller.appspot.com/bug?extid=f3bc6f8108108010a03d
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

patch: https://syzkaller.appspot.com/x/patch.diff?x=17ff06be180000

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