* [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
@ 2025-03-01 2:37 syzbot
2025-03-01 7:53 ` Hillf Danton
0 siblings, 1 reply; 8+ messages in thread
From: syzbot @ 2025-03-01 2:37 UTC (permalink / raw)
To: linux-kernel, linux-sound, perex, syzkaller-bugs, tiwai
Hello,
syzbot found the following issue on:
HEAD commit: d082ecbc71e9 Linux 6.14-rc4
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
kernel config: https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
dashboard link: https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
Unfortunately, I don't have any reproducer for this issue yet.
Downloadable assets:
disk image (non-bootable): https://storage.googleapis.com/syzbot-assets/7feb34a89c2a/non_bootable_disk-d082ecbc.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/f7cfa9bd3468/vmlinux-d082ecbc.xz
kernel image: https://storage.googleapis.com/syzbot-assets/d47dd7c3fc5d/bzImage-d082ecbc.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+4cb9fad083898f54c517@syzkaller.appspotmail.com
BUG: sleeping function called from invalid context at kernel/locking/mutex.c:562
in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 1167, name: kworker/0:1H
preempt_count: 0, expected: 0
RCU nest depth: 0, expected: 0
2 locks held by kworker/0:1H/1167:
#0: ffff88801b089148 ((wq_completion)events_highpri){+.+.}-{0:0}, at: process_one_work+0x1293/0x1ba0 kernel/workqueue.c:3211
#1: ffffc900061f7d18 ((work_completion)(&timer->task_work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3212
irq event stamp: 1044
hardirqs last enabled at (1043): [<ffffffff8b59c523>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:159 [inline]
hardirqs last enabled at (1043): [<ffffffff8b59c523>] _raw_spin_unlock_irq+0x23/0x50 kernel/locking/spinlock.c:202
hardirqs last disabled at (1044): [<ffffffff8b59c2c2>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (1044): [<ffffffff8b59c2c2>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
softirqs last enabled at (204): [<ffffffff817c131b>] softirq_handle_end kernel/softirq.c:407 [inline]
softirqs last enabled at (204): [<ffffffff817c131b>] handle_softirqs+0x5bb/0x8f0 kernel/softirq.c:589
softirqs last disabled at (183): [<ffffffff817c17e9>] __do_softirq kernel/softirq.c:595 [inline]
softirqs last disabled at (183): [<ffffffff817c17e9>] invoke_softirq kernel/softirq.c:435 [inline]
softirqs last disabled at (183): [<ffffffff817c17e9>] __irq_exit_rcu+0x109/0x170 kernel/softirq.c:662
CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Not tainted 6.14.0-rc4-syzkaller #0
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
Workqueue: events_highpri snd_timer_work
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:94 [inline]
dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:120
__might_resched+0x3c0/0x5e0 kernel/sched/core.c:8767
__mutex_lock_common kernel/locking/mutex.c:562 [inline]
__mutex_lock+0x108/0xb10 kernel/locking/mutex.c:730
class_mutex_constructor include/linux/mutex.h:201 [inline]
snd_card_locked+0x1b/0x60 sound/core/init.c:399
snd_request_card+0x14/0x70 sound/core/sound.c:62
snd_seq_client_use_ptr+0x375/0x3c0 sound/core/seq/seq_clientmgr.c:152
get_event_dest_client sound/core/seq/seq_clientmgr.c:533 [inline]
snd_seq_deliver_single_event+0xdb/0x6e0 sound/core/seq/seq_clientmgr.c:663
snd_seq_deliver_event+0x291/0x4b0 sound/core/seq/seq_clientmgr.c:822
snd_seq_dispatch_event+0x117/0x580 sound/core/seq/seq_clientmgr.c:897
snd_seq_check_queue+0x248/0x510 sound/core/seq/seq_queue.c:256
snd_seq_timer_interrupt+0x2e3/0x390 sound/core/seq/seq_timer.c:153
snd_timer_process_callbacks+0x217/0x2e0 sound/core/timer.c:785
snd_timer_work+0xa9/0x100 sound/core/timer.c:815
process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
process_scheduled_works kernel/workqueue.c:3317 [inline]
worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
kthread+0x3af/0x750 kernel/kthread.c:464
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
</TASK>
================================
WARNING: inconsistent lock state
6.14.0-rc4-syzkaller #0 Tainted: G W
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
kworker/0:1H/1167 [HC0[0]:SC0[0]:HE1:SE1] takes:
ffff8880236dc148 (&timer->lock){?.-.}-{3:3}, at: spin_lock include/linux/spinlock.h:351 [inline]
ffff8880236dc148 (&timer->lock){?.-.}-{3:3}, at: snd_timer_process_callbacks+0x227/0x2e0 sound/core/timer.c:786
{IN-HARDIRQ-W} state was registered at:
lock_acquire.part.0+0x11b/0x380 kernel/locking/lockdep.c:5851
__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:559 [inline]
snd_hrtimer_callback+0x53/0x400 sound/core/hrtimer.c:38
__run_hrtimer kernel/time/hrtimer.c:1801 [inline]
__hrtimer_run_queues+0x20a/0xae0 kernel/time/hrtimer.c:1865
hrtimer_interrupt+0x392/0x8e0 kernel/time/hrtimer.c:1927
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1038 [inline]
__sysvec_apic_timer_interrupt+0x10f/0x400 arch/x86/kernel/apic/apic.c:1055
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1049 [inline]
sysvec_apic_timer_interrupt+0x9f/0xc0 arch/x86/kernel/apic/apic.c:1049
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
_raw_spin_unlock_irqrestore+0x31/0x80 kernel/locking/spinlock.c:194
class_raw_spinlock_irqsave_destructor include/linux/spinlock.h:551 [inline]
try_to_wake_up+0x949/0x1490 kernel/sched/core.c:4214
wake_up_process kernel/sched/core.c:4463 [inline]
wake_up_q+0x9c/0x160 kernel/sched/core.c:1075
raw_spin_unlock_irqrestore_wake include/linux/sched/wake_q.h:96 [inline]
__mutex_unlock_slowpath+0x231/0x6a0 kernel/locking/mutex.c:933
device_unlock include/linux/device.h:1045 [inline]
hub_event+0xc5f/0x4e10 drivers/usb/core/hub.c:5954
process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
process_scheduled_works kernel/workqueue.c:3317 [inline]
worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
kthread+0x3af/0x750 kernel/kthread.c:464
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
irq event stamp: 1197
hardirqs last enabled at (1197): [<ffffffff8b59c5b2>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
hardirqs last enabled at (1197): [<ffffffff8b59c5b2>] _raw_spin_unlock_irqrestore+0x52/0x80 kernel/locking/spinlock.c:194
hardirqs last disabled at (1196): [<ffffffff8b59c2c2>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (1196): [<ffffffff8b59c2c2>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
softirqs last enabled at (1156): [<ffffffff817c131b>] softirq_handle_end kernel/softirq.c:407 [inline]
softirqs last enabled at (1156): [<ffffffff817c131b>] handle_softirqs+0x5bb/0x8f0 kernel/softirq.c:589
softirqs last disabled at (1047): [<ffffffff817c17e9>] __do_softirq kernel/softirq.c:595 [inline]
softirqs last disabled at (1047): [<ffffffff817c17e9>] invoke_softirq kernel/softirq.c:435 [inline]
softirqs last disabled at (1047): [<ffffffff817c17e9>] __irq_exit_rcu+0x109/0x170 kernel/softirq.c:662
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(&timer->lock);
<Interrupt>
lock(&timer->lock);
*** DEADLOCK ***
2 locks held by kworker/0:1H/1167:
#0: ffff88801b089148 ((wq_completion)events_highpri){+.+.}-{0:0}, at: process_one_work+0x1293/0x1ba0 kernel/workqueue.c:3211
#1: ffffc900061f7d18 ((work_completion)(&timer->task_work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3212
stack backtrace:
CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Tainted: G W 6.14.0-rc4-syzkaller #0
Tainted: [W]=WARN
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
Workqueue: events_highpri snd_timer_work
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:94 [inline]
dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:120
print_usage_bug.part.0+0x3fb/0x680 kernel/locking/lockdep.c:4040
print_usage_bug kernel/locking/lockdep.c:4008 [inline]
valid_state kernel/locking/lockdep.c:4054 [inline]
mark_lock_irq kernel/locking/lockdep.c:4265 [inline]
mark_lock+0x92d/0xc60 kernel/locking/lockdep.c:4751
mark_usage kernel/locking/lockdep.c:4660 [inline]
__lock_acquire+0x98e/0x3c40 kernel/locking/lockdep.c:5182
lock_acquire.part.0+0x11b/0x380 kernel/locking/lockdep.c:5851
__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]
snd_timer_process_callbacks+0x227/0x2e0 sound/core/timer.c:786
snd_timer_work+0xa9/0x100 sound/core/timer.c:815
process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
process_scheduled_works kernel/workqueue.c:3317 [inline]
worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
kthread+0x3af/0x750 kernel/kthread.c:464
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
</TASK>
------------[ cut here ]------------
raw_local_irq_restore() called with IRQs enabled
WARNING: CPU: 0 PID: 1167 at kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x29/0x30 kernel/locking/irqflag-debug.c:10
Modules linked in:
CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Tainted: G W 6.14.0-rc4-syzkaller #0
Tainted: [W]=WARN
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
Workqueue: events_highpri snd_timer_work
RIP: 0010:warn_bogus_irq_restore+0x29/0x30 kernel/locking/irqflag-debug.c:10
Code: 90 f3 0f 1e fa 90 80 3d f9 a7 f3 04 00 74 06 90 c3 cc cc cc cc c6 05 ea a7 f3 04 01 90 48 c7 c7 c0 e6 6c 8b e8 58 df 22 f6 90 <0f> 0b 90 90 eb df 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90
RSP: 0018:ffffc900061f7c18 EFLAGS: 00010282
RAX: 0000000000000000 RBX: ffff8880236dc130 RCX: ffffffff817a1229
RDX: ffff888028238000 RSI: ffffffff817a1236 RDI: 0000000000000001
RBP: 0000000000000286 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 61636f6c5f776172 R12: ffff8880236dc000
R13: ffff8880236dc1b0 R14: 0000000000000000 R15: ffff88801b09d800
FS: 0000000000000000(0000) GS:ffff88806a600000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fecdd000218 CR3: 0000000031f9c000 CR4: 0000000000352ef0
DR0: 0000000000000002 DR1: fffffffffffffffb DR2: 0000000000010001
DR3: 0000000000000004 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
_raw_spin_unlock_irqrestore+0x74/0x80 kernel/locking/spinlock.c:194
spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
class_spinlock_irqsave_destructor include/linux/spinlock.h:572 [inline]
snd_timer_work+0xbe/0x100 sound/core/timer.c:814
process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
process_scheduled_works kernel/workqueue.c:3317 [inline]
worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
kthread+0x3af/0x750 kernel/kthread.c:464
ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
</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 syzkaller@googlegroups.com.
syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title
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
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 2:37 [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked syzbot
@ 2025-03-01 7:53 ` Hillf Danton
0 siblings, 0 replies; 8+ messages in thread
From: Hillf Danton @ 2025-03-01 7:53 UTC (permalink / raw)
To: syzbot; +Cc: linux-kernel, linux-sound, perex, syzkaller-bugs, tiwai
On Fri, 28 Feb 2025 18:37:25 -0800
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> kernel config: https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> dashboard link: https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> Downloadable assets:
> disk image (non-bootable): https://storage.googleapis.com/syzbot-assets/7feb34a89c2a/non_bootable_disk-d082ecbc.raw.xz
> vmlinux: https://storage.googleapis.com/syzbot-assets/f7cfa9bd3468/vmlinux-d082ecbc.xz
> kernel image: https://storage.googleapis.com/syzbot-assets/d47dd7c3fc5d/bzImage-d082ecbc.xz
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+4cb9fad083898f54c517@syzkaller.appspotmail.com
>
> BUG: sleeping function called from invalid context at kernel/locking/mutex.c:562
> in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 1167, name: kworker/0:1H
> preempt_count: 0, expected: 0
> RCU nest depth: 0, expected: 0
> 2 locks held by kworker/0:1H/1167:
> #0: ffff88801b089148 ((wq_completion)events_highpri){+.+.}-{0:0}, at: process_one_work+0x1293/0x1ba0 kernel/workqueue.c:3211
> #1: ffffc900061f7d18 ((work_completion)(&timer->task_work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3212
> irq event stamp: 1044
> hardirqs last enabled at (1043): [<ffffffff8b59c523>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:159 [inline]
> hardirqs last enabled at (1043): [<ffffffff8b59c523>] _raw_spin_unlock_irq+0x23/0x50 kernel/locking/spinlock.c:202
> hardirqs last disabled at (1044): [<ffffffff8b59c2c2>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
> hardirqs last disabled at (1044): [<ffffffff8b59c2c2>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
> softirqs last enabled at (204): [<ffffffff817c131b>] softirq_handle_end kernel/softirq.c:407 [inline]
> softirqs last enabled at (204): [<ffffffff817c131b>] handle_softirqs+0x5bb/0x8f0 kernel/softirq.c:589
> softirqs last disabled at (183): [<ffffffff817c17e9>] __do_softirq kernel/softirq.c:595 [inline]
> softirqs last disabled at (183): [<ffffffff817c17e9>] invoke_softirq kernel/softirq.c:435 [inline]
> softirqs last disabled at (183): [<ffffffff817c17e9>] __irq_exit_rcu+0x109/0x170 kernel/softirq.c:662
> CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Not tainted 6.14.0-rc4-syzkaller #0
> Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
> Workqueue: events_highpri snd_timer_work
> Call Trace:
> <TASK>
> __dump_stack lib/dump_stack.c:94 [inline]
> dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:120
> __might_resched+0x3c0/0x5e0 kernel/sched/core.c:8767
> __mutex_lock_common kernel/locking/mutex.c:562 [inline]
> __mutex_lock+0x108/0xb10 kernel/locking/mutex.c:730
> class_mutex_constructor include/linux/mutex.h:201 [inline]
> snd_card_locked+0x1b/0x60 sound/core/init.c:399
> snd_request_card+0x14/0x70 sound/core/sound.c:62
> snd_seq_client_use_ptr+0x375/0x3c0 sound/core/seq/seq_clientmgr.c:152
> get_event_dest_client sound/core/seq/seq_clientmgr.c:533 [inline]
> snd_seq_deliver_single_event+0xdb/0x6e0 sound/core/seq/seq_clientmgr.c:663
> snd_seq_deliver_event+0x291/0x4b0 sound/core/seq/seq_clientmgr.c:822
> snd_seq_dispatch_event+0x117/0x580 sound/core/seq/seq_clientmgr.c:897
> snd_seq_check_queue+0x248/0x510 sound/core/seq/seq_queue.c:256
> snd_seq_timer_interrupt+0x2e3/0x390 sound/core/seq/seq_timer.c:153
> snd_timer_process_callbacks+0x217/0x2e0 sound/core/timer.c:785
> snd_timer_work+0xa9/0x100 sound/core/timer.c:815
> process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
> process_scheduled_works kernel/workqueue.c:3317 [inline]
> worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
> kthread+0x3af/0x750 kernel/kthread.c:464
> ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
> ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
> </TASK>
>
> ================================
> WARNING: inconsistent lock state
> 6.14.0-rc4-syzkaller #0 Tainted: G W
> --------------------------------
> inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
> kworker/0:1H/1167 [HC0[0]:SC0[0]:HE1:SE1] takes:
> ffff8880236dc148 (&timer->lock){?.-.}-{3:3}, at: spin_lock include/linux/spinlock.h:351 [inline]
> ffff8880236dc148 (&timer->lock){?.-.}-{3:3}, at: snd_timer_process_callbacks+0x227/0x2e0 sound/core/timer.c:786
> {IN-HARDIRQ-W} state was registered at:
> lock_acquire.part.0+0x11b/0x380 kernel/locking/lockdep.c:5851
> __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:559 [inline]
> snd_hrtimer_callback+0x53/0x400 sound/core/hrtimer.c:38
> __run_hrtimer kernel/time/hrtimer.c:1801 [inline]
> __hrtimer_run_queues+0x20a/0xae0 kernel/time/hrtimer.c:1865
> hrtimer_interrupt+0x392/0x8e0 kernel/time/hrtimer.c:1927
Given irq context, this deadlock is false positive because of irq disabled.
> local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1038 [inline]
> __sysvec_apic_timer_interrupt+0x10f/0x400 arch/x86/kernel/apic/apic.c:1055
> instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1049 [inline]
> sysvec_apic_timer_interrupt+0x9f/0xc0 arch/x86/kernel/apic/apic.c:1049
> asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
> __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
> _raw_spin_unlock_irqrestore+0x31/0x80 kernel/locking/spinlock.c:194
> class_raw_spinlock_irqsave_destructor include/linux/spinlock.h:551 [inline]
> try_to_wake_up+0x949/0x1490 kernel/sched/core.c:4214
> wake_up_process kernel/sched/core.c:4463 [inline]
> wake_up_q+0x9c/0x160 kernel/sched/core.c:1075
> raw_spin_unlock_irqrestore_wake include/linux/sched/wake_q.h:96 [inline]
> __mutex_unlock_slowpath+0x231/0x6a0 kernel/locking/mutex.c:933
> device_unlock include/linux/device.h:1045 [inline]
> hub_event+0xc5f/0x4e10 drivers/usb/core/hub.c:5954
> process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
> process_scheduled_works kernel/workqueue.c:3317 [inline]
> worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
> kthread+0x3af/0x750 kernel/kthread.c:464
> ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
> ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
> irq event stamp: 1197
> hardirqs last enabled at (1197): [<ffffffff8b59c5b2>] __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
> hardirqs last enabled at (1197): [<ffffffff8b59c5b2>] _raw_spin_unlock_irqrestore+0x52/0x80 kernel/locking/spinlock.c:194
> hardirqs last disabled at (1196): [<ffffffff8b59c2c2>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
> hardirqs last disabled at (1196): [<ffffffff8b59c2c2>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
> softirqs last enabled at (1156): [<ffffffff817c131b>] softirq_handle_end kernel/softirq.c:407 [inline]
> softirqs last enabled at (1156): [<ffffffff817c131b>] handle_softirqs+0x5bb/0x8f0 kernel/softirq.c:589
> softirqs last disabled at (1047): [<ffffffff817c17e9>] __do_softirq kernel/softirq.c:595 [inline]
> softirqs last disabled at (1047): [<ffffffff817c17e9>] invoke_softirq kernel/softirq.c:435 [inline]
> softirqs last disabled at (1047): [<ffffffff817c17e9>] __irq_exit_rcu+0x109/0x170 kernel/softirq.c:662
>
> other info that might help us debug this:
> Possible unsafe locking scenario:
>
> CPU0
> ----
> lock(&timer->lock);
> <Interrupt>
> lock(&timer->lock);
>
> *** DEADLOCK ***
>
> 2 locks held by kworker/0:1H/1167:
> #0: ffff88801b089148 ((wq_completion)events_highpri){+.+.}-{0:0}, at: process_one_work+0x1293/0x1ba0 kernel/workqueue.c:3211
> #1: ffffc900061f7d18 ((work_completion)(&timer->task_work)){+.+.}-{0:0}, at: process_one_work+0x921/0x1ba0 kernel/workqueue.c:3212
>
> stack backtrace:
> CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Tainted: G W 6.14.0-rc4-syzkaller #0
> Tainted: [W]=WARN
> Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
> Workqueue: events_highpri snd_timer_work
> Call Trace:
> <TASK>
> __dump_stack lib/dump_stack.c:94 [inline]
> dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:120
> print_usage_bug.part.0+0x3fb/0x680 kernel/locking/lockdep.c:4040
> print_usage_bug kernel/locking/lockdep.c:4008 [inline]
> valid_state kernel/locking/lockdep.c:4054 [inline]
> mark_lock_irq kernel/locking/lockdep.c:4265 [inline]
> mark_lock+0x92d/0xc60 kernel/locking/lockdep.c:4751
> mark_usage kernel/locking/lockdep.c:4660 [inline]
> __lock_acquire+0x98e/0x3c40 kernel/locking/lockdep.c:5182
> lock_acquire.part.0+0x11b/0x380 kernel/locking/lockdep.c:5851
> __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]
> snd_timer_process_callbacks+0x227/0x2e0 sound/core/timer.c:786
> snd_timer_work+0xa9/0x100 sound/core/timer.c:815
> process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
> process_scheduled_works kernel/workqueue.c:3317 [inline]
> worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
> kthread+0x3af/0x750 kernel/kthread.c:464
> ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
> ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
> </TASK>
> ------------[ cut here ]------------
> raw_local_irq_restore() called with IRQs enabled
> WARNING: CPU: 0 PID: 1167 at kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x29/0x30 kernel/locking/irqflag-debug.c:10
> Modules linked in:
> CPU: 0 UID: 0 PID: 1167 Comm: kworker/0:1H Tainted: G W 6.14.0-rc4-syzkaller #0
> Tainted: [W]=WARN
> Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.3-debian-1.16.3-2~bpo12+1 04/01/2014
> Workqueue: events_highpri snd_timer_work
> RIP: 0010:warn_bogus_irq_restore+0x29/0x30 kernel/locking/irqflag-debug.c:10
> Code: 90 f3 0f 1e fa 90 80 3d f9 a7 f3 04 00 74 06 90 c3 cc cc cc cc c6 05 ea a7 f3 04 01 90 48 c7 c7 c0 e6 6c 8b e8 58 df 22 f6 90 <0f> 0b 90 90 eb df 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90
> RSP: 0018:ffffc900061f7c18 EFLAGS: 00010282
> RAX: 0000000000000000 RBX: ffff8880236dc130 RCX: ffffffff817a1229
> RDX: ffff888028238000 RSI: ffffffff817a1236 RDI: 0000000000000001
> RBP: 0000000000000286 R08: 0000000000000001 R09: 0000000000000000
> R10: 0000000000000000 R11: 61636f6c5f776172 R12: ffff8880236dc000
> R13: ffff8880236dc1b0 R14: 0000000000000000 R15: ffff88801b09d800
> FS: 0000000000000000(0000) GS:ffff88806a600000(0000) knlGS:0000000000000000
> CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 00007fecdd000218 CR3: 0000000031f9c000 CR4: 0000000000352ef0
> DR0: 0000000000000002 DR1: fffffffffffffffb DR2: 0000000000010001
> DR3: 0000000000000004 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Call Trace:
> <TASK>
> __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
> _raw_spin_unlock_irqrestore+0x74/0x80 kernel/locking/spinlock.c:194
> spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
> class_spinlock_irqsave_destructor include/linux/spinlock.h:572 [inline]
> snd_timer_work+0xbe/0x100 sound/core/timer.c:814
> process_one_work+0x9c5/0x1ba0 kernel/workqueue.c:3236
> process_scheduled_works kernel/workqueue.c:3317 [inline]
> worker_thread+0x6c8/0xf00 kernel/workqueue.c:3398
> kthread+0x3af/0x750 kernel/kthread.c:464
> ret_from_fork+0x45/0x80 arch/x86/kernel/process.c:148
> ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
> </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 syzkaller@googlegroups.com.
>
> syzbot will keep track of this issue. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
>
> If the report is already addressed, let syzbot know by replying with:
> #syz fix: exact-commit-title
>
> 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
>
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
@ 2025-03-01 9:25 Zhongqiu Han
2025-03-01 9:26 ` syzbot
2025-03-01 9:34 ` Takashi Iwai
0 siblings, 2 replies; 8+ messages in thread
From: Zhongqiu Han @ 2025-03-01 9:25 UTC (permalink / raw)
To: syzbot+4cb9fad083898f54c517
Cc: linux-kernel, linux-sound, perex, syzbot+4cb9fad083898f54c517,
syzkaller-bugs, tiwai
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> git tree: upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> kernel config:
https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> dashboard link:
https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
for Debian) 2.40
BUG: sleeping function called from invalid context and
raw_local_irq_restore() called with IRQs enabled seems can be
fixed by below change. if it is valid, will arise the PATCH.
#syz test:
diff --git a/sound/core/timer.c b/sound/core/timer.c
index fbada79380f9..5290c1b9f2b8 100644
--- a/sound/core/timer.c
+++ b/sound/core/timer.c
@@ -767,6 +767,7 @@ static void snd_timer_process_callbacks(struct
snd_timer *timer,
{
struct snd_timer_instance *ti;
unsigned long resolution, ticks;
+ unsigned long flags;
while (!list_empty(head)) {
ti = list_first_entry(head, struct snd_timer_instance,
@@ -780,10 +781,10 @@ static void snd_timer_process_callbacks(struct
snd_timer *timer,
ti->pticks = 0;
resolution = ti->resolution;
ti->flags |= SNDRV_TIMER_IFLG_CALLBACK;
- spin_unlock(&timer->lock);
+ spin_unlock_irqrestore(&timer->lock, flags);
if (ti->callback)
ti->callback(ti, resolution, ticks);
- spin_lock(&timer->lock);
+ spin_lock_irqsave(&timer->lock, flags);
ti->flags &= ~SNDRV_TIMER_IFLG_CALLBACK;
}
}
@@ -805,14 +806,16 @@ static void snd_timer_clear_callbacks(struct
snd_timer *timer,
static void snd_timer_work(struct work_struct *work)
{
struct snd_timer *timer = container_of(work, struct snd_timer,
task_work);
+ unsigned long flags;
if (timer->card && timer->card->shutdown) {
snd_timer_clear_callbacks(timer, &timer->sack_list_head);
return;
}
- guard(spinlock_irqsave)(&timer->lock);
+ spin_lock_irqsave(&timer->lock, flags);
snd_timer_process_callbacks(timer, &timer->sack_list_head);
+ spin_unlock_irqrestore(&timer->lock, flags);
}
/*
Thanks
Zhongqiu Han
^ permalink raw reply related [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 9:25 Zhongqiu Han
@ 2025-03-01 9:26 ` syzbot
2025-03-01 9:34 ` Takashi Iwai
1 sibling, 0 replies; 8+ messages in thread
From: syzbot @ 2025-03-01 9:26 UTC (permalink / raw)
To: quic_zhonhan
Cc: linux-kernel, linux-sound, perex, quic_zhonhan, syzkaller-bugs,
tiwai
> > Hello,
> >
> > syzbot found the following issue on:
> >
> > HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> > git tree: upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> > kernel config:
> https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> > dashboard link:
> https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> > compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
> for Debian) 2.40
>
>
> BUG: sleeping function called from invalid context and
> raw_local_irq_restore() called with IRQs enabled seems can be
> fixed by below change. if it is valid, will arise the PATCH.
>
> #syz test:
want either no args or 2 args (repo, branch), got 4
>
> diff --git a/sound/core/timer.c b/sound/core/timer.c
> index fbada79380f9..5290c1b9f2b8 100644
> --- a/sound/core/timer.c
> +++ b/sound/core/timer.c
> @@ -767,6 +767,7 @@ static void snd_timer_process_callbacks(struct
> snd_timer *timer,
> {
> struct snd_timer_instance *ti;
> unsigned long resolution, ticks;
> + unsigned long flags;
>
> while (!list_empty(head)) {
> ti = list_first_entry(head, struct snd_timer_instance,
> @@ -780,10 +781,10 @@ static void snd_timer_process_callbacks(struct
> snd_timer *timer,
> ti->pticks = 0;
> resolution = ti->resolution;
> ti->flags |= SNDRV_TIMER_IFLG_CALLBACK;
> - spin_unlock(&timer->lock);
> + spin_unlock_irqrestore(&timer->lock, flags);
> if (ti->callback)
> ti->callback(ti, resolution, ticks);
> - spin_lock(&timer->lock);
> + spin_lock_irqsave(&timer->lock, flags);
> ti->flags &= ~SNDRV_TIMER_IFLG_CALLBACK;
> }
> }
> @@ -805,14 +806,16 @@ static void snd_timer_clear_callbacks(struct
> snd_timer *timer,
> static void snd_timer_work(struct work_struct *work)
> {
> struct snd_timer *timer = container_of(work, struct snd_timer,
> task_work);
> + unsigned long flags;
>
> if (timer->card && timer->card->shutdown) {
> snd_timer_clear_callbacks(timer, &timer->sack_list_head);
> return;
> }
>
> - guard(spinlock_irqsave)(&timer->lock);
> + spin_lock_irqsave(&timer->lock, flags);
> snd_timer_process_callbacks(timer, &timer->sack_list_head);
> + spin_unlock_irqrestore(&timer->lock, flags);
> }
>
> /*
>
>
>
>
>
> Thanks
> Zhongqiu Han
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 9:25 Zhongqiu Han
2025-03-01 9:26 ` syzbot
@ 2025-03-01 9:34 ` Takashi Iwai
2025-03-01 9:50 ` Zhongqiu Han
1 sibling, 1 reply; 8+ messages in thread
From: Takashi Iwai @ 2025-03-01 9:34 UTC (permalink / raw)
To: Zhongqiu Han
Cc: syzbot+4cb9fad083898f54c517, linux-kernel, linux-sound, perex,
syzkaller-bugs, tiwai
On Sat, 01 Mar 2025 10:25:55 +0100,
Zhongqiu Han wrote:
>
> > Hello,
> >
> > syzbot found the following issue on:
> >
> > HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> > git tree: upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> > kernel config:
> https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> > dashboard link:
> https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> > compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
> for Debian) 2.40
>
>
> BUG: sleeping function called from invalid context and
> raw_local_irq_restore() called with IRQs enabled seems can be
> fixed by below change. if it is valid, will arise the PATCH.
snd_timer_process_callbacks() gets called from two places, one from
snd_timer_work() and another from snd_timer_interrupt() where both
caller cover already with guard(spinlock_irqsave). That is, it's a
nested lock, hence without _irqsave().
IMO, the question is rather why the check of "!in_interrupt()" in
snd_seq_client_use_ptr() passed in this call path.
thanks,
Takashi
>
> #syz test:
>
> diff --git a/sound/core/timer.c b/sound/core/timer.c
> index fbada79380f9..5290c1b9f2b8 100644
> --- a/sound/core/timer.c
> +++ b/sound/core/timer.c
> @@ -767,6 +767,7 @@ static void snd_timer_process_callbacks(struct
> snd_timer *timer,
> {
> struct snd_timer_instance *ti;
> unsigned long resolution, ticks;
> + unsigned long flags;
>
> while (!list_empty(head)) {
> ti = list_first_entry(head, struct snd_timer_instance,
> @@ -780,10 +781,10 @@ static void snd_timer_process_callbacks(struct
> snd_timer *timer,
> ti->pticks = 0;
> resolution = ti->resolution;
> ti->flags |= SNDRV_TIMER_IFLG_CALLBACK;
> - spin_unlock(&timer->lock);
> + spin_unlock_irqrestore(&timer->lock, flags);
> if (ti->callback)
> ti->callback(ti, resolution, ticks);
> - spin_lock(&timer->lock);
> + spin_lock_irqsave(&timer->lock, flags);
> ti->flags &= ~SNDRV_TIMER_IFLG_CALLBACK;
> }
> }
> @@ -805,14 +806,16 @@ static void snd_timer_clear_callbacks(struct
> snd_timer *timer,
> static void snd_timer_work(struct work_struct *work)
> {
> struct snd_timer *timer = container_of(work, struct snd_timer,
> task_work);
> + unsigned long flags;
>
> if (timer->card && timer->card->shutdown) {
> snd_timer_clear_callbacks(timer, &timer->sack_list_head);
> return;
> }
>
> - guard(spinlock_irqsave)(&timer->lock);
> + spin_lock_irqsave(&timer->lock, flags);
> snd_timer_process_callbacks(timer, &timer->sack_list_head);
> + spin_unlock_irqrestore(&timer->lock, flags);
> }
>
> /*
>
>
>
>
>
> Thanks
> Zhongqiu Han
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 9:34 ` Takashi Iwai
@ 2025-03-01 9:50 ` Zhongqiu Han
2025-03-01 10:22 ` Takashi Iwai
0 siblings, 1 reply; 8+ messages in thread
From: Zhongqiu Han @ 2025-03-01 9:50 UTC (permalink / raw)
To: Takashi Iwai
Cc: syzbot+4cb9fad083898f54c517, linux-kernel, linux-sound, perex,
syzkaller-bugs, tiwai
On 3/1/2025 5:34 PM, Takashi Iwai wrote:
> On Sat, 01 Mar 2025 10:25:55 +0100,
> Zhongqiu Han wrote:
>>
>>> Hello,
>>>
>>> syzbot found the following issue on:
>>>
>>> HEAD commit: d082ecbc71e9 Linux 6.14-rc4
>>> git tree: upstream
>>> console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
>>> kernel config:
>> https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
>>> dashboard link:
>> https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
>>> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
>> for Debian) 2.40
>>
>>
>> BUG: sleeping function called from invalid context and
>> raw_local_irq_restore() called with IRQs enabled seems can be
>> fixed by below change. if it is valid, will arise the PATCH.
>
> snd_timer_process_callbacks() gets called from two places, one from
> snd_timer_work() and another from snd_timer_interrupt() where both
> caller cover already with guard(spinlock_irqsave). That is, it's a
> nested lock, hence without _irqsave().
>
> IMO, the question is rather why the check of "!in_interrupt()" in
> snd_seq_client_use_ptr() passed in this call path.
>
>
> thanks,
>
> Takashi
>
Thanks Takashi for the discussion.
I have an initial check:
func snd_seq_check_queue is called from func snd_seq_timer_interrupt,
and the scoped_guard can not cover it. maybe this the reason of
!in_interrupt() check pass.
just like my patch shared, snd_timer_process_callbacks called
spin_unlock but not spin_unlock_irqrestore, which caused
irqs_disabled(): 1 , and then caused the BUG.
BUG: sleeping function called from invalid context at
kernel/locking/mutex.c:562
in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 1167, name:
kworker/0:1H
please feel free and kindly correct me if any misunderstanding.
>>
>> #syz test:
>>
>> diff --git a/sound/core/timer.c b/sound/core/timer.c
>> index fbada79380f9..5290c1b9f2b8 100644
>> --- a/sound/core/timer.c
>> +++ b/sound/core/timer.c
>> @@ -767,6 +767,7 @@ static void snd_timer_process_callbacks(struct
>> snd_timer *timer,
>> {
>> struct snd_timer_instance *ti;
>> unsigned long resolution, ticks;
>> + unsigned long flags;
>>
>> while (!list_empty(head)) {
>> ti = list_first_entry(head, struct snd_timer_instance,
>> @@ -780,10 +781,10 @@ static void snd_timer_process_callbacks(struct
>> snd_timer *timer,
>> ti->pticks = 0;
>> resolution = ti->resolution;
>> ti->flags |= SNDRV_TIMER_IFLG_CALLBACK;
>> - spin_unlock(&timer->lock);
>> + spin_unlock_irqrestore(&timer->lock, flags);
>> if (ti->callback)
>> ti->callback(ti, resolution, ticks);
>> - spin_lock(&timer->lock);
>> + spin_lock_irqsave(&timer->lock, flags);
>> ti->flags &= ~SNDRV_TIMER_IFLG_CALLBACK;
>> }
>> }
>> @@ -805,14 +806,16 @@ static void snd_timer_clear_callbacks(struct
>> snd_timer *timer,
>> static void snd_timer_work(struct work_struct *work)
>> {
>> struct snd_timer *timer = container_of(work, struct snd_timer,
>> task_work);
>> + unsigned long flags;
>>
>> if (timer->card && timer->card->shutdown) {
>> snd_timer_clear_callbacks(timer, &timer->sack_list_head);
>> return;
>> }
>>
>> - guard(spinlock_irqsave)(&timer->lock);
>> + spin_lock_irqsave(&timer->lock, flags);
>> snd_timer_process_callbacks(timer, &timer->sack_list_head);
>> + spin_unlock_irqrestore(&timer->lock, flags);
>> }
>>
>> /*
>>
>>
>>
>>
>>
>> Thanks
>> Zhongqiu Han
--
Thx and BRs,
Zhongqiu Han
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 9:50 ` Zhongqiu Han
@ 2025-03-01 10:22 ` Takashi Iwai
2025-03-01 10:43 ` Takashi Iwai
0 siblings, 1 reply; 8+ messages in thread
From: Takashi Iwai @ 2025-03-01 10:22 UTC (permalink / raw)
To: Zhongqiu Han
Cc: Takashi Iwai, syzbot+4cb9fad083898f54c517, linux-kernel,
linux-sound, perex, syzkaller-bugs, tiwai
On Sat, 01 Mar 2025 10:50:43 +0100,
Zhongqiu Han wrote:
>
> On 3/1/2025 5:34 PM, Takashi Iwai wrote:
> > On Sat, 01 Mar 2025 10:25:55 +0100,
> > Zhongqiu Han wrote:
> >>
> >>> Hello,
> >>>
> >>> syzbot found the following issue on:
> >>>
> >>> HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> >>> git tree: upstream
> >>> console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> >>> kernel config:
> >> https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> >>> dashboard link:
> >> https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> >>> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
> >> for Debian) 2.40
> >>
> >>
> >> BUG: sleeping function called from invalid context and
> >> raw_local_irq_restore() called with IRQs enabled seems can be
> >> fixed by below change. if it is valid, will arise the PATCH.
> >
> > snd_timer_process_callbacks() gets called from two places, one from
> > snd_timer_work() and another from snd_timer_interrupt() where both
> > caller cover already with guard(spinlock_irqsave). That is, it's a
> > nested lock, hence without _irqsave().
> >
> > IMO, the question is rather why the check of "!in_interrupt()" in
> > snd_seq_client_use_ptr() passed in this call path.
> >
> >
> > thanks,
> >
> > Takashi
> >
>
> Thanks Takashi for the discussion.
>
> I have an initial check:
> func snd_seq_check_queue is called from func snd_seq_timer_interrupt,
> and the scoped_guard can not cover it. maybe this the reason of
> !in_interrupt() check pass.
>
> just like my patch shared, snd_timer_process_callbacks called
> spin_unlock but not spin_unlock_irqrestore, which caused
> irqs_disabled(): 1 , and then caused the BUG.
>
>
> BUG: sleeping function called from invalid context at
> kernel/locking/mutex.c:562
> in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 1167, name:
> kworker/0:1H
>
>
> please feel free and kindly correct me if any misunderstanding.
Ah, no, the code in timer.c worked as expected; the lock in the caller
side is temporarily released intentionally for avoiding deadlock.
It's rather the problem in seq_clientmgr.c side, as I mentioned. The
check with !in_interrupt() is fragile in this case, and it's an
overkill to handle the module loading whenever it's referenced.
I'm going to submit the fix patch later.
thanks,
Takashi
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked
2025-03-01 10:22 ` Takashi Iwai
@ 2025-03-01 10:43 ` Takashi Iwai
0 siblings, 0 replies; 8+ messages in thread
From: Takashi Iwai @ 2025-03-01 10:43 UTC (permalink / raw)
To: Zhongqiu Han
Cc: syzbot+4cb9fad083898f54c517, linux-kernel, linux-sound, perex,
syzkaller-bugs, tiwai
On Sat, 01 Mar 2025 11:22:52 +0100,
Takashi Iwai wrote:
>
> On Sat, 01 Mar 2025 10:50:43 +0100,
> Zhongqiu Han wrote:
> >
> > On 3/1/2025 5:34 PM, Takashi Iwai wrote:
> > > On Sat, 01 Mar 2025 10:25:55 +0100,
> > > Zhongqiu Han wrote:
> > >>
> > >>> Hello,
> > >>>
> > >>> syzbot found the following issue on:
> > >>>
> > >>> HEAD commit: d082ecbc71e9 Linux 6.14-rc4
> > >>> git tree: upstream
> > >>> console output: https://syzkaller.appspot.com/x/log.txt?x=14e3d7a4580000
> > >>> kernel config:
> > >> https://syzkaller.appspot.com/x/.config?x=8f2f8fb6ad08b539
> > >>> dashboard link:
> > >> https://syzkaller.appspot.com/bug?extid=4cb9fad083898f54c517
> > >>> compiler: gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils
> > >> for Debian) 2.40
> > >>
> > >>
> > >> BUG: sleeping function called from invalid context and
> > >> raw_local_irq_restore() called with IRQs enabled seems can be
> > >> fixed by below change. if it is valid, will arise the PATCH.
> > >
> > > snd_timer_process_callbacks() gets called from two places, one from
> > > snd_timer_work() and another from snd_timer_interrupt() where both
> > > caller cover already with guard(spinlock_irqsave). That is, it's a
> > > nested lock, hence without _irqsave().
> > >
> > > IMO, the question is rather why the check of "!in_interrupt()" in
> > > snd_seq_client_use_ptr() passed in this call path.
> > >
> > >
> > > thanks,
> > >
> > > Takashi
> > >
> >
> > Thanks Takashi for the discussion.
> >
> > I have an initial check:
> > func snd_seq_check_queue is called from func snd_seq_timer_interrupt,
> > and the scoped_guard can not cover it. maybe this the reason of
> > !in_interrupt() check pass.
> >
> > just like my patch shared, snd_timer_process_callbacks called
> > spin_unlock but not spin_unlock_irqrestore, which caused
> > irqs_disabled(): 1 , and then caused the BUG.
> >
> >
> > BUG: sleeping function called from invalid context at
> > kernel/locking/mutex.c:562
> > in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 1167, name:
> > kworker/0:1H
> >
> >
> > please feel free and kindly correct me if any misunderstanding.
>
> Ah, no, the code in timer.c worked as expected; the lock in the caller
> side is temporarily released intentionally for avoiding deadlock.
>
> It's rather the problem in seq_clientmgr.c side, as I mentioned. The
> check with !in_interrupt() is fragile in this case, and it's an
> overkill to handle the module loading whenever it's referenced.
>
> I'm going to submit the fix patch later.
Below is the copy:
Takashi
-- 8< --
From: Takashi Iwai <tiwai@suse.de>
Subject: [PATCH] ALSA: seq: Avoid module auto-load handling at event delivery
snd_seq_client_use_ptr() is supposed to return the snd_seq_client
object for the given client ID, and it tries to handle the module
auto-loading when no matching object is found. Although the module
handling is performed only conditionally with "!in_interrupt()", this
condition may be fragile, e.g. when the code is called from the ALSA
timer callback where the spinlock is temporarily disabled while the
irq is disabled. Then his doesn't fit well and spews the error about
sleep from invalid context, as complained recently by syzbot.
Also, in general, handling the module-loading at each time if no
matching object is found is really an overkill. It can be still
useful when performed at the top-level ioctl or proc reads, but it
shouldn't be done at event delivery at all.
For addressing the issues above, this patch disables the module
handling in snd_seq_client_use_ptr() in normal cases like event
deliveries, but allow only in limited and safe situations.
A new function client_load_and_use_ptr() is used for the cases where
the module loading can be done safely, instead.
Reported-by: syzbot+4cb9fad083898f54c517@syzkaller.appspotmail.com
Closes: https://lore.kernel.org/67c272e5.050a0220.dc10f.0159.GAE@google.com
Cc: <stable@vger.kernel.org>
Signed-off-by: Takashi Iwai <tiwai@suse.de>
---
sound/core/seq/seq_clientmgr.c | 46 ++++++++++++++++++++++------------
1 file changed, 30 insertions(+), 16 deletions(-)
diff --git a/sound/core/seq/seq_clientmgr.c b/sound/core/seq/seq_clientmgr.c
index cb66ec42a3f8..706f53e39b53 100644
--- a/sound/core/seq/seq_clientmgr.c
+++ b/sound/core/seq/seq_clientmgr.c
@@ -106,7 +106,7 @@ static struct snd_seq_client *clientptr(int clientid)
return clienttab[clientid];
}
-struct snd_seq_client *snd_seq_client_use_ptr(int clientid)
+static struct snd_seq_client *client_use_ptr(int clientid, bool load_module)
{
unsigned long flags;
struct snd_seq_client *client;
@@ -126,7 +126,7 @@ struct snd_seq_client *snd_seq_client_use_ptr(int clientid)
}
spin_unlock_irqrestore(&clients_lock, flags);
#ifdef CONFIG_MODULES
- if (!in_interrupt()) {
+ if (load_module) {
static DECLARE_BITMAP(client_requested, SNDRV_SEQ_GLOBAL_CLIENTS);
static DECLARE_BITMAP(card_requested, SNDRV_CARDS);
@@ -168,6 +168,20 @@ struct snd_seq_client *snd_seq_client_use_ptr(int clientid)
return client;
}
+/* get snd_seq_client object for the given id quickly */
+struct snd_seq_client *snd_seq_client_use_ptr(int clientid)
+{
+ return client_use_ptr(clientid, false);
+}
+
+/* get snd_seq_client object for the given id;
+ * if not found, retry after loading the modules
+ */
+static struct snd_seq_client *client_load_and_use_ptr(int clientid)
+{
+ return client_use_ptr(clientid, IS_ENABLED(CONFIG_MODULES));
+}
+
/* Take refcount and perform ioctl_mutex lock on the given client;
* used only for OSS sequencer
* Unlock via snd_seq_client_ioctl_unlock() below
@@ -176,7 +190,7 @@ bool snd_seq_client_ioctl_lock(int clientid)
{
struct snd_seq_client *client;
- client = snd_seq_client_use_ptr(clientid);
+ client = client_load_and_use_ptr(clientid);
if (!client)
return false;
mutex_lock(&client->ioctl_mutex);
@@ -1195,7 +1209,7 @@ static int snd_seq_ioctl_running_mode(struct snd_seq_client *client, void *arg)
int err = 0;
/* requested client number */
- cptr = snd_seq_client_use_ptr(info->client);
+ cptr = client_load_and_use_ptr(info->client);
if (cptr == NULL)
return -ENOENT; /* don't change !!! */
@@ -1257,7 +1271,7 @@ static int snd_seq_ioctl_get_client_info(struct snd_seq_client *client,
struct snd_seq_client *cptr;
/* requested client number */
- cptr = snd_seq_client_use_ptr(client_info->client);
+ cptr = client_load_and_use_ptr(client_info->client);
if (cptr == NULL)
return -ENOENT; /* don't change !!! */
@@ -1396,7 +1410,7 @@ static int snd_seq_ioctl_get_port_info(struct snd_seq_client *client, void *arg)
struct snd_seq_client *cptr;
struct snd_seq_client_port *port;
- cptr = snd_seq_client_use_ptr(info->addr.client);
+ cptr = client_load_and_use_ptr(info->addr.client);
if (cptr == NULL)
return -ENXIO;
@@ -1503,10 +1517,10 @@ static int snd_seq_ioctl_subscribe_port(struct snd_seq_client *client,
struct snd_seq_client *receiver = NULL, *sender = NULL;
struct snd_seq_client_port *sport = NULL, *dport = NULL;
- receiver = snd_seq_client_use_ptr(subs->dest.client);
+ receiver = client_load_and_use_ptr(subs->dest.client);
if (!receiver)
goto __end;
- sender = snd_seq_client_use_ptr(subs->sender.client);
+ sender = client_load_and_use_ptr(subs->sender.client);
if (!sender)
goto __end;
sport = snd_seq_port_use_ptr(sender, subs->sender.port);
@@ -1871,7 +1885,7 @@ static int snd_seq_ioctl_get_client_pool(struct snd_seq_client *client,
struct snd_seq_client_pool *info = arg;
struct snd_seq_client *cptr;
- cptr = snd_seq_client_use_ptr(info->client);
+ cptr = client_load_and_use_ptr(info->client);
if (cptr == NULL)
return -ENOENT;
memset(info, 0, sizeof(*info));
@@ -1975,7 +1989,7 @@ static int snd_seq_ioctl_get_subscription(struct snd_seq_client *client,
struct snd_seq_client_port *sport = NULL;
result = -EINVAL;
- sender = snd_seq_client_use_ptr(subs->sender.client);
+ sender = client_load_and_use_ptr(subs->sender.client);
if (!sender)
goto __end;
sport = snd_seq_port_use_ptr(sender, subs->sender.port);
@@ -2006,7 +2020,7 @@ static int snd_seq_ioctl_query_subs(struct snd_seq_client *client, void *arg)
struct list_head *p;
int i;
- cptr = snd_seq_client_use_ptr(subs->root.client);
+ cptr = client_load_and_use_ptr(subs->root.client);
if (!cptr)
goto __end;
port = snd_seq_port_use_ptr(cptr, subs->root.port);
@@ -2073,7 +2087,7 @@ static int snd_seq_ioctl_query_next_client(struct snd_seq_client *client,
if (info->client < 0)
info->client = 0;
for (; info->client < SNDRV_SEQ_MAX_CLIENTS; info->client++) {
- cptr = snd_seq_client_use_ptr(info->client);
+ cptr = client_load_and_use_ptr(info->client);
if (cptr)
break; /* found */
}
@@ -2096,7 +2110,7 @@ static int snd_seq_ioctl_query_next_port(struct snd_seq_client *client,
struct snd_seq_client *cptr;
struct snd_seq_client_port *port = NULL;
- cptr = snd_seq_client_use_ptr(info->addr.client);
+ cptr = client_load_and_use_ptr(info->addr.client);
if (cptr == NULL)
return -ENXIO;
@@ -2193,7 +2207,7 @@ static int snd_seq_ioctl_client_ump_info(struct snd_seq_client *caller,
size = sizeof(struct snd_ump_endpoint_info);
else
size = sizeof(struct snd_ump_block_info);
- cptr = snd_seq_client_use_ptr(client);
+ cptr = client_load_and_use_ptr(client);
if (!cptr)
return -ENOENT;
@@ -2475,7 +2489,7 @@ int snd_seq_kernel_client_enqueue(int client, struct snd_seq_event *ev,
if (check_event_type_and_length(ev))
return -EINVAL;
- cptr = snd_seq_client_use_ptr(client);
+ cptr = client_load_and_use_ptr(client);
if (cptr == NULL)
return -EINVAL;
@@ -2707,7 +2721,7 @@ void snd_seq_info_clients_read(struct snd_info_entry *entry,
/* list the client table */
for (c = 0; c < SNDRV_SEQ_MAX_CLIENTS; c++) {
- client = snd_seq_client_use_ptr(c);
+ client = client_load_and_use_ptr(c);
if (client == NULL)
continue;
if (client->type == NO_CLIENT) {
^ permalink raw reply related [flat|nested] 8+ messages in thread
end of thread, other threads:[~2025-03-01 10:43 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-03-01 2:37 [syzbot] [sound?] BUG: sleeping function called from invalid context in snd_card_locked syzbot
2025-03-01 7:53 ` Hillf Danton
-- strict thread matches above, loose matches on Subject: below --
2025-03-01 9:25 Zhongqiu Han
2025-03-01 9:26 ` syzbot
2025-03-01 9:34 ` Takashi Iwai
2025-03-01 9:50 ` Zhongqiu Han
2025-03-01 10:22 ` Takashi Iwai
2025-03-01 10:43 ` Takashi Iwai
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox