======================================================== WARNING: possible irq lock inversion dependency detected 5.14.0-rc7-syzkaller #0 Not tainted -------------------------------------------------------- kauditd/36 just changed the state of lock: ffff8881471c7148 (&timer->lock){..-.}-{2:2}, at: snd_timer_interrupt+0x210/0x1410 sound/core/timer.c:857 but this lock took another, SOFTIRQ-READ-unsafe lock in the past: (&new->fa_lock){.+.+}-{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(&new->fa_lock); local_irq_disable(); lock(&timer->lock); lock(&new->fa_lock); lock(&timer->lock); *** DEADLOCK *** 2 locks held by kauditd/36: #0: ffffffff8c5f4440 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x201/0x2f0 kernel/printk/printk.c:2173 #1: ffffc90000007be0 ((&priv->tlist)){+.-.}-{0:0}, at: lockdep_copy_map include/linux/lockdep.h:45 [inline] #1: ffffc90000007be0 ((&priv->tlist)){+.-.}-{0:0}, at: call_timer_fn+0xbd/0x210 kernel/time/timer.c:1411 the shortest dependencies between 2nd lock and 1st lock: -> (&new->fa_lock){.+.+}-{2:2} { HARDIRQ-ON-R at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline] _raw_read_lock+0x32/0x40 kernel/locking/spinlock.c:223 kill_fasync_rcu fs/fcntl.c:1012 [inline] kill_fasync+0x13b/0x430 fs/fcntl.c:1033 sock_wake_async+0x133/0x150 net/socket.c:1354 rcu_read_unlock include/linux/rcupdate.h:716 [inline] sk_wake_async+0x12e/0x200 include/net/sock.h:2328 unix_release_sock+0x47d/0x9f0 net/unix/af_unix.c:562 unix_release+0x4a/0x80 net/unix/af_unix.c:867 __sock_release net/socket.c:648 [inline] sock_close+0xd8/0x260 net/socket.c:1300 __fput+0x352/0x7b0 fs/file_table.c:280 task_work_run+0x146/0x1c0 kernel/task_work.c:164 get_signal+0x1fd9/0x2080 kernel/signal.c:2581 arch_do_signal_or_restart+0x8e/0x6d0 arch/x86/kernel/signal.c:865 handle_signal_work kernel/entry/common.c:148 [inline] exit_to_user_mode_loop kernel/entry/common.c:172 [inline] exit_to_user_mode_prepare+0x191/0x220 kernel/entry/common.c:209 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline] syscall_exit_to_user_mode+0x26/0x60 kernel/entry/common.c:302 do_syscall_64+0x4c/0xb0 arch/x86/entry/common.c:86 entry_SYSCALL_64_after_hwframe+0x44/0xae SOFTIRQ-ON-R at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline] _raw_read_lock+0x32/0x40 kernel/locking/spinlock.c:223 kill_fasync_rcu fs/fcntl.c:1012 [inline] kill_fasync+0x13b/0x430 fs/fcntl.c:1033 sock_wake_async+0x133/0x150 net/socket.c:1354 rcu_read_unlock include/linux/rcupdate.h:716 [inline] sk_wake_async+0x12e/0x200 include/net/sock.h:2328 unix_release_sock+0x47d/0x9f0 net/unix/af_unix.c:562 unix_release+0x4a/0x80 net/unix/af_unix.c:867 __sock_release net/socket.c:648 [inline] sock_close+0xd8/0x260 net/socket.c:1300 __fput+0x352/0x7b0 fs/file_table.c:280 task_work_run+0x146/0x1c0 kernel/task_work.c:164 get_signal+0x1fd9/0x2080 kernel/signal.c:2581 arch_do_signal_or_restart+0x8e/0x6d0 arch/x86/kernel/signal.c:865 handle_signal_work kernel/entry/common.c:148 [inline] exit_to_user_mode_loop kernel/entry/common.c:172 [inline] exit_to_user_mode_prepare+0x191/0x220 kernel/entry/common.c:209 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline] syscall_exit_to_user_mode+0x26/0x60 kernel/entry/common.c:302 do_syscall_64+0x4c/0xb0 arch/x86/entry/common.c:86 entry_SYSCALL_64_after_hwframe+0x44/0xae INITIAL USE at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_write_lock_irq include/linux/rwlock_api_smp.h:196 [inline] _raw_write_lock_irq+0xae/0xf0 kernel/locking/spinlock.c:311 fasync_remove_entry+0xff/0x1d0 fs/fcntl.c:890 __fput+0x65b/0x7b0 fs/file_table.c:277 task_work_run+0x146/0x1c0 kernel/task_work.c:164 tracehook_notify_resume include/linux/tracehook.h:189 [inline] exit_to_user_mode_loop kernel/entry/common.c:175 [inline] exit_to_user_mode_prepare+0x201/0x220 kernel/entry/common.c:209 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline] syscall_exit_to_user_mode+0x26/0x60 kernel/entry/common.c:302 do_syscall_64+0x4c/0xb0 arch/x86/entry/common.c:86 entry_SYSCALL_64_after_hwframe+0x44/0xae INITIAL READ USE at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline] _raw_read_lock+0x32/0x40 kernel/locking/spinlock.c:223 kill_fasync_rcu fs/fcntl.c:1012 [inline] kill_fasync+0x13b/0x430 fs/fcntl.c:1033 snd_timer_user_ccallback+0x3ee/0x710 sound/core/timer.c:1387 snd_timer_notify1+0x19e/0x340 sound/core/timer.c:516 snd_timer_start1+0x53d/0x640 sound/core/timer.c:578 snd_timer_start sound/core/timer.c:697 [inline] snd_timer_user_start sound/core/timer.c:1985 [inline] __snd_timer_user_ioctl+0xe18/0x5ed0 sound/core/timer.c:2108 snd_timer_user_ioctl+0x5d/0x80 sound/core/timer.c:2129 vfs_ioctl fs/ioctl.c:51 [inline] __do_sys_ioctl fs/ioctl.c:1069 [inline] __se_sys_ioctl+0xfb/0x170 fs/ioctl.c:1055 do_syscall_x64 arch/x86/entry/common.c:50 [inline] do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80 entry_SYSCALL_64_after_hwframe+0x44/0xae } ... key at: [] fasync_insert_entry.__key+0x0/0x40 ... acquired at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_read_lock include/linux/rwlock_api_smp.h:149 [inline] _raw_read_lock+0x32/0x40 kernel/locking/spinlock.c:223 kill_fasync_rcu fs/fcntl.c:1012 [inline] kill_fasync+0x13b/0x430 fs/fcntl.c:1033 snd_timer_user_ccallback+0x3ee/0x710 sound/core/timer.c:1387 snd_timer_notify1+0x19e/0x340 sound/core/timer.c:516 snd_timer_start1+0x53d/0x640 sound/core/timer.c:578 snd_timer_start sound/core/timer.c:697 [inline] snd_timer_user_start sound/core/timer.c:1985 [inline] __snd_timer_user_ioctl+0xe18/0x5ed0 sound/core/timer.c:2108 snd_timer_user_ioctl+0x5d/0x80 sound/core/timer.c:2129 vfs_ioctl fs/ioctl.c:51 [inline] __do_sys_ioctl fs/ioctl.c:1069 [inline] __se_sys_ioctl+0xfb/0x170 fs/ioctl.c:1055 do_syscall_x64 arch/x86/entry/common.c:50 [inline] do_syscall_64+0x3d/0xb0 arch/x86/entry/common.c:80 entry_SYSCALL_64_after_hwframe+0x44/0xae -> (&timer->lock){..-.}-{2:2} { IN-SOFTIRQ-W at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline] _raw_spin_lock_irqsave+0xb3/0x100 kernel/locking/spinlock.c:159 snd_timer_interrupt+0x210/0x1410 sound/core/timer.c:857 call_timer_fn+0xf6/0x210 kernel/time/timer.c:1421 expire_timers kernel/time/timer.c:1466 [inline] __run_timers+0x703/0x8f0 kernel/time/timer.c:1734 run_timer_softirq+0x63/0xf0 kernel/time/timer.c:1747 __do_softirq+0x372/0x783 kernel/softirq.c:558 invoke_softirq kernel/softirq.c:432 [inline] __irq_exit_rcu+0x21b/0x260 kernel/softirq.c:636 irq_exit_rcu+0x5/0x20 kernel/softirq.c:648 sysvec_apic_timer_interrupt+0x91/0xb0 arch/x86/kernel/apic/apic.c:1100 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638 console_unlock+0xb2b/0xec0 kernel/printk/printk.c:2653 vprintk_emit+0x21a/0x2f0 kernel/printk/printk.c:2174 vprintk+0x30d/0x370 kernel/printk/printk_safe.c:392 printk+0xc0/0x108 kernel/printk/printk.c:2216 kauditd_printk_skb kernel/audit.c:538 [inline] kauditd_hold_skb+0x131/0x190 kernel/audit.c:571 kauditd_send_queue+0x68/0x290 kernel/audit.c:734 kauditd_thread+0x650/0xaa0 kernel/audit.c:860 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295 INITIAL USE at: lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_spin_lock_irq include/linux/spinlock_api_smp.h:128 [inline] _raw_spin_lock_irq+0xae/0xf0 kernel/locking/spinlock.c:167 spin_lock_irq include/linux/spinlock.h:379 [inline] snd_pcm_detach_substream+0x14b/0x280 sound/core/pcm.c:995 snd_pcm_release+0xbd/0x160 sound/core/pcm_native.c:2818 __fput+0x352/0x7b0 fs/file_table.c:280 task_work_run+0x146/0x1c0 kernel/task_work.c:164 tracehook_notify_resume include/linux/tracehook.h:189 [inline] exit_to_user_mode_loop kernel/entry/common.c:175 [inline] exit_to_user_mode_prepare+0x201/0x220 kernel/entry/common.c:209 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline] syscall_exit_to_user_mode+0x26/0x60 kernel/entry/common.c:302 do_syscall_64+0x4c/0xb0 arch/x86/entry/common.c:86 entry_SYSCALL_64_after_hwframe+0x44/0xae } ... key at: [] snd_timer_new.__key+0x0/0x40 ... acquired at: mark_usage kernel/locking/lockdep.c:4488 [inline] __lock_acquire+0xca1/0x6100 kernel/locking/lockdep.c:4969 lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline] _raw_spin_lock_irqsave+0xb3/0x100 kernel/locking/spinlock.c:159 snd_timer_interrupt+0x210/0x1410 sound/core/timer.c:857 call_timer_fn+0xf6/0x210 kernel/time/timer.c:1421 expire_timers kernel/time/timer.c:1466 [inline] __run_timers+0x703/0x8f0 kernel/time/timer.c:1734 run_timer_softirq+0x63/0xf0 kernel/time/timer.c:1747 __do_softirq+0x372/0x783 kernel/softirq.c:558 invoke_softirq kernel/softirq.c:432 [inline] __irq_exit_rcu+0x21b/0x260 kernel/softirq.c:636 irq_exit_rcu+0x5/0x20 kernel/softirq.c:648 sysvec_apic_timer_interrupt+0x91/0xb0 arch/x86/kernel/apic/apic.c:1100 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638 console_unlock+0xb2b/0xec0 kernel/printk/printk.c:2653 vprintk_emit+0x21a/0x2f0 kernel/printk/printk.c:2174 vprintk+0x30d/0x370 kernel/printk/printk_safe.c:392 printk+0xc0/0x108 kernel/printk/printk.c:2216 kauditd_printk_skb kernel/audit.c:538 [inline] kauditd_hold_skb+0x131/0x190 kernel/audit.c:571 kauditd_send_queue+0x68/0x290 kernel/audit.c:734 kauditd_thread+0x650/0xaa0 kernel/audit.c:860 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295 stack backtrace: CPU: 0 PID: 36 Comm: kauditd Not tainted 5.14.0-rc7-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:88 [inline] dump_stack_lvl+0x1ae/0x29f lib/dump_stack.c:105 print_irq_inversion_bug+0xa58/0xda0 kernel/locking/lockdep.c:4000 check_usage_forwards kernel/locking/lockdep.c:2585 [inline] mark_lock_irq kernel/locking/lockdep.c:4163 [inline] mark_lock+0x1064/0x1eb0 kernel/locking/lockdep.c:4593 mark_usage kernel/locking/lockdep.c:4488 [inline] __lock_acquire+0xca1/0x6100 kernel/locking/lockdep.c:4969 lock_acquire+0x182/0x4a0 kernel/locking/lockdep.c:5625 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline] _raw_spin_lock_irqsave+0xb3/0x100 kernel/locking/spinlock.c:159 snd_timer_interrupt+0x210/0x1410 sound/core/timer.c:857 call_timer_fn+0xf6/0x210 kernel/time/timer.c:1421 expire_timers kernel/time/timer.c:1466 [inline] __run_timers+0x703/0x8f0 kernel/time/timer.c:1734 run_timer_softirq+0x63/0xf0 kernel/time/timer.c:1747 __do_softirq+0x372/0x783 kernel/softirq.c:558 invoke_softirq kernel/softirq.c:432 [inline] __irq_exit_rcu+0x21b/0x260 kernel/softirq.c:636 irq_exit_rcu+0x5/0x20 kernel/softirq.c:648 sysvec_apic_timer_interrupt+0x91/0xb0 arch/x86/kernel/apic/apic.c:1100 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638 RIP: 0010:console_unlock+0xb2b/0xec0 kernel/printk/printk.c:2653 Code: 75 1d e8 b8 ec 19 00 f6 44 24 0f 01 75 1e e8 ac ec 19 00 e9 54 f7 ff ff 0f 1f 80 00 00 00 00 e8 9b ec 19 00 fb f6 44 24 0f 01 <74> e2 e8 8e ec 19 00 48 c7 c7 aa 1f f9 8b be 5e 0a 00 00 31 d2 e8 RSP: 0018:ffffc90000e8f820 EFLAGS: 00000246 RAX: ffffffff81664b35 RBX: ffffc90000e8f9e0 RCX: ffff8880124d8000 RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 RBP: ffffc90000e8fa70 R08: ffffffff81664af4 R09: fffffbfff1f5e7b9 R10: fffffbfff1f5e7b9 R11: 0000000000000000 R12: dffffc0000000000 R13: 1ffffffff19f7b21 R14: 1ffffffff19f7b1a R15: ffffffff8cfbd908 vprintk_emit+0x21a/0x2f0 kernel/printk/printk.c:2174 vprintk+0x30d/0x370 kernel/printk/printk_safe.c:392 printk+0xc0/0x108 kernel/printk/printk.c:2216 kauditd_printk_skb kernel/audit.c:538 [inline] kauditd_hold_skb+0x131/0x190 kernel/audit.c:571 kauditd_send_queue+0x68/0x290 kernel/audit.c:734 kauditd_thread+0x650/0xaa0 kernel/audit.c:860 kthread+0x453/0x480 kernel/kthread.c:319 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295 ---------------- Code disassembly (best guess): 0: 75 1d jne 0x1f 2: e8 b8 ec 19 00 callq 0x19ecbf 7: f6 44 24 0f 01 testb $0x1,0xf(%rsp) c: 75 1e jne 0x2c e: e8 ac ec 19 00 callq 0x19ecbf 13: e9 54 f7 ff ff jmpq 0xfffff76c 18: 0f 1f 80 00 00 00 00 nopl 0x0(%rax) 1f: e8 9b ec 19 00 callq 0x19ecbf 24: fb sti 25: f6 44 24 0f 01 testb $0x1,0xf(%rsp) * 2a: 74 e2 je 0xe <-- trapping instruction 2c: e8 8e ec 19 00 callq 0x19ecbf 31: 48 c7 c7 aa 1f f9 8b mov $0xffffffff8bf91faa,%rdi 38: be 5e 0a 00 00 mov $0xa5e,%esi 3d: 31 d2 xor %edx,%edx 3f: e8 .byte 0xe8