syzbot


inconsistent lock state in snd_timer_interrupt (3)

Status: fixed on 2024/04/22 10:23
Subsystems: sound
[Documentation on labels]
Reported-by: syzbot+0a26629966fddb6d4760@syzkaller.appspotmail.com
Fix commit: 587d67fd929a ALSA: timer: Fix missing irq-disable at closing
First crash: 175d, last: 171d
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [sound?] inconsistent lock state in snd_timer_interrupt (3) 1 (3) 2024/04/18 07:37
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream inconsistent lock state in snd_timer_interrupt sound C 1927 177d 199d 25/28 fixed on 2024/04/10 03:59
upstream inconsistent lock state in snd_timer_interrupt (2) sound C done 208 175d 177d 25/28 fixed on 2024/04/11 14:16

Sample crash report:
================================
WARNING: inconsistent lock state
6.8.0-syzkaller-08951-gfe46a7dd189e #0 Not tainted
--------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/1/0 [HC0[0]:SC1[1]:HE0:SE0] takes:
ffff888029e8d948 (&timer->lock){+.?.}-{2:2}, at: class_spinlock_irqsave_constructor include/linux/spinlock.h:574 [inline]
ffff888029e8d948 (&timer->lock){+.?.}-{2:2}, at: snd_timer_interrupt.part.0+0x31/0xd80 sound/core/timer.c:818
{SOFTIRQ-ON-W} state was registered at:
  lock_acquire kernel/locking/lockdep.c:5754 [inline]
  lock_acquire+0x1b1/0x540 kernel/locking/lockdep.c:5719
  __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+0x65/0xbd0 sound/core/timer.c:412
  snd_timer_close+0x8b/0xf0 sound/core/timer.c:464
  snd_timer_user_release+0x91/0x260 sound/core/timer.c:1468
  __fput+0x270/0xb80 fs/file_table.c:422
  task_work_run+0x14e/0x250 kernel/task_work.c:180
  exit_task_work include/linux/task_work.h:38 [inline]
  do_exit+0xa7d/0x2be0 kernel/exit.c:878
  do_group_exit+0xd3/0x2a0 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+0x3e/0x50 kernel/exit.c:1036
  do_syscall_x64 arch/x86/entry/common.c:52 [inline]
  do_syscall_64+0xd2/0x260 arch/x86/entry/common.c:83
  entry_SYSCALL_64_after_hwframe+0x6d/0x75
irq event stamp: 171005
hardirqs last  enabled at (171004): [<ffffffff8ad60263>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:159 [inline]
hardirqs last  enabled at (171004): [<ffffffff8ad60263>] _raw_spin_unlock_irq+0x23/0x50 kernel/locking/spinlock.c:202
hardirqs last disabled at (171005): [<ffffffff8ad60002>] __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:108 [inline]
hardirqs last disabled at (171005): [<ffffffff8ad60002>] _raw_spin_lock_irqsave+0x52/0x60 kernel/locking/spinlock.c:162
softirqs last  enabled at (170994): [<ffffffff8ad63156>] softirq_handle_end kernel/softirq.c:400 [inline]
softirqs last  enabled at (170994): [<ffffffff8ad63156>] __do_softirq+0x596/0x8de kernel/softirq.c:583
softirqs last disabled at (171001): [<ffffffff8151a149>] invoke_softirq kernel/softirq.c:428 [inline]
softirqs last disabled at (171001): [<ffffffff8151a149>] __irq_exit_rcu kernel/softirq.c:633 [inline]
softirqs last disabled at (171001): [<ffffffff8151a149>] irq_exit_rcu+0xb9/0x120 kernel/softirq.c:645

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

       CPU0
       ----
  lock(&timer->lock);
  <Interrupt>
    lock(&timer->lock);

 *** DEADLOCK ***

1 lock held by swapper/1/0:
 #0: ffffc90000a08cb0 ((&priv->tlist)){+.-.}-{0:0}, at: call_timer_fn+0x11a/0x5b0 kernel/time/timer.c:1789

stack backtrace:
CPU: 1 PID: 0 Comm: swapper/1 Not tainted 6.8.0-syzkaller-08951-gfe46a7dd189e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:114
 print_usage_bug kernel/locking/lockdep.c:3971 [inline]
 valid_state kernel/locking/lockdep.c:4013 [inline]
 mark_lock_irq kernel/locking/lockdep.c:4216 [inline]
 mark_lock+0x923/0xc60 kernel/locking/lockdep.c:4678
 mark_usage kernel/locking/lockdep.c:4567 [inline]
 __lock_acquire+0x13d4/0x3b30 kernel/locking/lockdep.c:5091
 lock_acquire kernel/locking/lockdep.c:5754 [inline]
 lock_acquire+0x1b1/0x540 kernel/locking/lockdep.c:5719
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x3a/0x60 kernel/locking/spinlock.c:162
 class_spinlock_irqsave_constructor include/linux/spinlock.h:574 [inline]
 snd_timer_interrupt.part.0+0x31/0xd80 sound/core/timer.c:818
 snd_timer_interrupt sound/core/timer.c:1107 [inline]
 snd_timer_s_function+0x14f/0x200 sound/core/timer.c:1107
 call_timer_fn+0x1a0/0x5b0 kernel/time/timer.c:1792
 expire_timers kernel/time/timer.c:1843 [inline]
 __run_timers+0x74b/0xab0 kernel/time/timer.c:2408
 __run_timer_base kernel/time/timer.c:2419 [inline]
 __run_timer_base kernel/time/timer.c:2412 [inline]
 run_timer_base+0x111/0x190 kernel/time/timer.c:2428
 run_timer_softirq+0x1a/0x40 kernel/time/timer.c:2438
 __do_softirq+0x218/0x8de kernel/softirq.c:554
 invoke_softirq kernel/softirq.c:428 [inline]
 __irq_exit_rcu kernel/softirq.c:633 [inline]
 irq_exit_rcu+0xb9/0x120 kernel/softirq.c:645
 instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
 sysvec_apic_timer_interrupt+0x95/0xb0 arch/x86/kernel/apic/apic.c:1043
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:native_irq_disable arch/x86/include/asm/irqflags.h:37 [inline]
RIP: 0010:arch_local_irq_disable arch/x86/include/asm/irqflags.h:72 [inline]
RIP: 0010:acpi_safe_halt+0x1a/0x20 drivers/acpi/processor_idle.c:113
Code: 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 65 48 8b 05 d8 60 31 75 48 8b 00 a8 08 75 0c 66 90 0f 00 2d c8 73 a7 00 fb f4 <fa> c3 cc cc cc cc 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90
RSP: 0018:ffffc90000197d58 EFLAGS: 00000246
RAX: 0000000000004000 RBX: 0000000000000001 RCX: ffffffff8ad255f9
RDX: 0000000000000001 RSI: ffff88801bef0800 RDI: ffff88801bef0864
RBP: ffff88801bef0864 R08: 0000000000000001 R09: ffffed10172a6fdd
R10: ffff8880b9537eeb R11: 0000000000000000 R12: ffff888017bbe000
R13: ffffffff8e31fbc0 R14: 0000000000000001 R15: 0000000000000000
 acpi_idle_enter+0xc5/0x160 drivers/acpi/processor_idle.c:707
 cpuidle_enter_state+0x85/0x510 drivers/cpuidle/cpuidle.c:267
 cpuidle_enter+0x4e/0xa0 drivers/cpuidle/cpuidle.c:388
 cpuidle_idle_call kernel/sched/idle.c:236 [inline]
 do_idle+0x313/0x3f0 kernel/sched/idle.c:332
 cpu_startup_entry+0x4f/0x60 kernel/sched/idle.c:430
 start_secondary+0x220/0x2b0 arch/x86/kernel/smpboot.c:313
 common_startup_64+0x13e/0x148
 </TASK>
----------------
Code disassembly (best guess):
   0:	90                   	nop
   1:	90                   	nop
   2:	90                   	nop
   3:	90                   	nop
   4:	90                   	nop
   5:	90                   	nop
   6:	90                   	nop
   7:	90                   	nop
   8:	90                   	nop
   9:	90                   	nop
   a:	90                   	nop
   b:	90                   	nop
   c:	90                   	nop
   d:	90                   	nop
   e:	90                   	nop
   f:	90                   	nop
  10:	65 48 8b 05 d8 60 31 	mov    %gs:0x753160d8(%rip),%rax        # 0x753160f0
  17:	75
  18:	48 8b 00             	mov    (%rax),%rax
  1b:	a8 08                	test   $0x8,%al
  1d:	75 0c                	jne    0x2b
  1f:	66 90                	xchg   %ax,%ax
  21:	0f 00 2d c8 73 a7 00 	verw   0xa773c8(%rip)        # 0xa773f0
  28:	fb                   	sti
  29:	f4                   	hlt
* 2a:	fa                   	cli <-- trapping instruction
  2b:	c3                   	ret
  2c:	cc                   	int3
  2d:	cc                   	int3
  2e:	cc                   	int3
  2f:	cc                   	int3
  30:	90                   	nop
  31:	90                   	nop
  32:	90                   	nop
  33:	90                   	nop
  34:	90                   	nop
  35:	90                   	nop
  36:	90                   	nop
  37:	90                   	nop
  38:	90                   	nop
  39:	90                   	nop
  3a:	90                   	nop
  3b:	90                   	nop
  3c:	90                   	nop
  3d:	90                   	nop
  3e:	90                   	nop
  3f:	90                   	nop

Crashes (710):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/04/11 17:02 upstream fe46a7dd189e 478efa7f .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/11 17:25 upstream fe46a7dd189e 478efa7f .config console log report syz [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 18:33 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 17:29 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 16:39 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 15:05 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 14:36 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 13:14 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 12:43 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 11:26 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 10:43 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 09:05 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 08:02 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 07:00 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in snd_timer_interrupt
2024/04/15 06:39 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 05:12 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in snd_timer_interrupt
2024/04/15 04:32 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 03:24 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 02:05 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 01:21 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/15 00:21 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 23:17 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 22:09 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 21:06 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 21:03 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 20:00 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 18:48 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 18:12 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 17:11 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 16:09 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 14:57 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 14:39 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 13:34 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 13:33 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in snd_timer_interrupt
2024/04/14 12:16 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 11:13 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 10:11 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 09:30 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 07:54 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 06:51 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 05:50 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 05:14 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 04:12 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 03:19 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in snd_timer_interrupt
2024/04/14 02:18 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/14 01:59 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/11 16:08 upstream fe46a7dd189e 478efa7f .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
2024/04/11 14:19 upstream fe46a7dd189e 478efa7f .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in snd_timer_interrupt
* Struck through repros no longer work on HEAD.