syzbot


INFO: rcu detected stall in snd_timer_user_release (3)

Status: upstream: reported C repro on 2024/04/29 18:46
Subsystems: sound
[Documentation on labels]
Reported-by: syzbot+43120c2af6ca2938cc38@syzkaller.appspotmail.com
Fix commit: ALSA: timer: Set lower bound of start tick time
Patched on: [ci-upstream-linux-next-kasan-gce-root], missing on: [ci-qemu-upstream ci-qemu-upstream-386 ci-qemu2-arm32 ci-qemu2-arm64 ci-qemu2-arm64-compat ci-qemu2-arm64-mte ci-qemu2-riscv64 ci-upstream-bpf-kasan-gce ci-upstream-bpf-next-kasan-gce ci-upstream-gce-arm64 ci-upstream-gce-leak ci-upstream-kasan-badwrites-root ci-upstream-kasan-gce ci-upstream-kasan-gce-386 ci-upstream-kasan-gce-root ci-upstream-kasan-gce-selinux-root ci-upstream-kasan-gce-smack-root ci-upstream-kmsan-gce-386-root ci-upstream-kmsan-gce-root ci-upstream-net-kasan-gce ci-upstream-net-this-kasan-gce ci2-upstream-fs ci2-upstream-kcsan-gce ci2-upstream-net-next-test-gce ci2-upstream-usb]
First crash: 25d, last: 12d
Cause bisection: the issue happens on the oldest tested release (bisect log)
Crash: INFO: rcu detected stall in snd_timer_user_release (log)
Repro: C syz .config
  
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [sound?] INFO: rcu detected stall in snd_timer_user_release (3) 1 (3) 2024/04/30 00:21
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in snd_timer_user_release (2) sound C 7 29d 42d 26/26 fixed on 2024/04/22 10:23
upstream INFO: rcu detected stall in snd_timer_user_release sound 1 208d 208d 0/26 auto-obsoleted due to no activity on 2024/01/24 03:14
Last patch testing requests (1)
Created Duration User Patch Repo Result
2024/04/29 23:35 23m hdanton@sina.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git e88c4cfcb7b8 OK log

Sample crash report:
rcu: INFO: rcu_preempt detected expedited stalls on CPUs/tasks: { 1-...D } 2683 jiffies s: 365 root: 0x2/.
rcu: blocking rcu_node structures (internal RCU debug):
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 5639 Comm: syz-executor147 Not tainted 6.9.0-rc7-syzkaller-00012-gdccb07f2914c #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
RIP: 0010:__lock_acquire+0x2e6/0x1fd0 kernel/locking/lockdep.c:5070
Code: 48 8b 44 24 50 4c 8d 80 d8 0a 00 00 83 fa 31 4c 89 44 24 08 0f 83 9f 19 00 00 4c 8d 34 92 4b 8d 5c f0 20 48 89 d8 48 c1 e8 03 <48> 89 44 24 20 0f b6 04 30 84 c0 0f 85 2e 14 00 00 48 8b ac 24 d0
RSP: 0018:ffffc90000a08a90 EFLAGS: 00000802
RAX: 1ffff11005bde8e9 RBX: ffff88802def4748 RCX: ffffffff9472d603
RDX: 0000000000000002 RSI: dffffc0000000000 RDI: 0000000000000654
RBP: 1ffff11005bde8e4 R08: ffff88802def46d8 R09: 0000000000000001
R10: dffffc0000000000 R11: fffffbfff1f51ef6 R12: ffff888029e61148
R13: 0000000000000654 R14: 000000000000000a R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff8880b9500000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffe7bcc5eb8 CR3: 000000006989c000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <IRQ>
 lock_acquire+0x1ed/0x550 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_hrtimer_callback+0x54/0x370 sound/core/hrtimer.c:38
 __run_hrtimer kernel/time/hrtimer.c:1692 [inline]
 __hrtimer_run_queues+0x5a5/0xd50 kernel/time/hrtimer.c:1756
 hrtimer_interrupt+0x396/0x990 kernel/time/hrtimer.c:1818
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1032 [inline]
 __sysvec_apic_timer_interrupt+0x110/0x3f0 arch/x86/kernel/apic/apic.c:1049
 instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
 sysvec_apic_timer_interrupt+0xa1/0xc0 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:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0xd8/0x140 kernel/locking/spinlock.c:194
Code: 9c 8f 44 24 20 42 80 3c 23 00 74 08 4c 89 f7 e8 de b8 6f f6 f6 44 24 21 02 75 52 41 f7 c7 00 02 00 00 74 01 fb bf 01 00 00 00 <e8> d3 b4 da f5 65 8b 05 74 d8 78 74 85 c0 74 43 48 c7 04 24 0e 36
RSP: 0018:ffffc900046df940 EFLAGS: 00000206
RAX: 735440de6f4b3300 RBX: 1ffff920008dbf2c RCX: ffffffff8172f77a
RDX: dffffc0000000000 RSI: ffffffff8bcab8a0 RDI: 0000000000000001
RBP: ffffc900046df9d0 R08: ffffffff92f35587 R09: 1ffffffff25e6ab0
R10: dffffc0000000000 R11: fffffbfff25e6ab1 R12: dffffc0000000000
R13: 1ffff920008dbf28 R14: ffffc900046df960 R15: 0000000000000246
 spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
 class_spinlock_irqsave_destructor include/linux/spinlock.h:574 [inline]
 snd_timer_stop1+0x7e6/0x950 sound/core/timer.c:634
 snd_timer_stop sound/core/timer.c:679 [inline]
 snd_timer_close_locked+0x223/0x8d0 sound/core/timer.c:423
 snd_timer_close sound/core/timer.c:464 [inline]
 snd_timer_user_release+0x138/0x2e0 sound/core/timer.c:1468
 __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_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x240 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f6871b47db9
Code: Unable to access opcode bytes at 0x7f6871b47d8f.
RSP: 002b:00007ffe7bcc5f58 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f6871b47db9
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 00007f6871bc22b0 R08: ffffffffffffffb8 R09: 00000000000000a0
R10: 00000000000000a0 R11: 0000000000000246 R12: 00007f6871bc22b0
R13: 0000000000000000 R14: 00007f6871bc2d20 R15: 00007f6871b18f50
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 1.599 msecs

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/05/08 10:44 upstream dccb07f2914c 4cf3f9b3 .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce INFO: rcu detected stall in snd_timer_user_release
2024/04/28 20:41 upstream 2c8159388952 07b455f9 .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce INFO: rcu detected stall in snd_timer_user_release
2024/04/25 18:37 upstream e88c4cfcb7b8 8bdc0f22 .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce INFO: rcu detected stall in snd_timer_user_release
* Struck through repros no longer work on HEAD.