2021-11-21 18:39:25

by syzbot

[permalink] [raw]
Subject: [syzbot] possible deadlock in snd_timer_interrupt (2)

Hello,

syzbot found the following issue on:

HEAD commit: ee1703cda8dc Merge tag 'hyperv-fixes-signed-20211117' of g..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=167cc6fab00000
kernel config: https://syzkaller.appspot.com/x/.config?x=b7264d1cb8ba2795
dashboard link: https://syzkaller.appspot.com/bug?extid=1ee0910eca9c94f71f25
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

=====================================================
WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected
5.16.0-rc1-syzkaller #0 Not tainted
-----------------------------------------------------
syz-executor.0/25993 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
ffffffff8b80a098 (tasklist_lock){.+.+}-{2:2}, at: send_sigio+0xab/0x380 fs/fcntl.c:810

and this task is already holding:
ffff888042f5cbb8 (&f->f_owner.lock){...-}-{2:2}, at: send_sigio+0x24/0x380 fs/fcntl.c:796
which would create a new lock dependency:
(&f->f_owner.lock){...-}-{2:2} -> (tasklist_lock){.+.+}-{2:2}

but this new dependency connects a SOFTIRQ-irq-safe lock:
(&timer->lock){..-.}-{2:2}

... which became SOFTIRQ-irq-safe at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x675/0xa20 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:636
irq_exit_rcu+0x5/0x20 kernel/softirq.c:648
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
lock_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5685
lock_is_held include/linux/lockdep.h:283 [inline]
rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
trace_lock_release include/trace/events/lock.h:58 [inline]
lock_release+0x522/0x720 kernel/locking/lockdep.c:5648
rcu_lock_release include/linux/rcupdate.h:273 [inline]
rcu_read_unlock include/linux/rcupdate.h:721 [inline]
inet_twsk_purge+0x503/0x7d0 net/ipv4/inet_timewait_sock.c:299
ops_exit_list+0x10d/0x160 net/core/net_namespace.c:171
cleanup_net+0x4ea/0xb00 net/core/net_namespace.c:593
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

to a SOFTIRQ-irq-unsafe lock:
(tasklist_lock){.+.+}-{2:2}

... which became SOFTIRQ-irq-unsafe at:
...
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1511
kernel_wait+0x9c/0x150 kernel/exit.c:1701
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

other info that might help us debug this:

Chain exists of:
&timer->lock --> &f->f_owner.lock --> tasklist_lock

Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(tasklist_lock);
local_irq_disable();
lock(&timer->lock);
lock(&f->f_owner.lock);
<Interrupt>
lock(&timer->lock);

*** DEADLOCK ***

6 locks held by syz-executor.0/25993:
#0: ffff88814af6e460 (sb_writers#5){.+.+}-{0:0}, at: vfs_truncate+0xea/0x4b0 fs/open.c:83
#1: ffffffff8bd30930 (file_rwsem){.+.+}-{0:0}, at: break_lease include/linux/fs.h:2634 [inline]
#1: ffffffff8bd30930 (file_rwsem){.+.+}-{0:0}, at: break_lease include/linux/fs.h:2624 [inline]
#1: ffffffff8bd30930 (file_rwsem){.+.+}-{0:0}, at: vfs_truncate+0x31a/0x4b0 fs/open.c:104
#2: ffff88806c596a68 (&ctx->flc_lock){+.+.}-{2:2}, at: spin_lock include/linux/spinlock.h:349 [inline]
#2: ffff88806c596a68 (&ctx->flc_lock){+.+.}-{2:2}, at: __break_lease+0x208/0x1420 fs/locks.c:1422
#3: ffffffff8bb80f60 (rcu_read_lock){....}-{1:2}, at: kill_fasync+0x41/0x470 fs/fcntl.c:1033
#4: ffff88802aad5948 (&new->fa_lock){...-}-{2:2}, at: kill_fasync_rcu fs/fcntl.c:1014 [inline]
#4: ffff88802aad5948 (&new->fa_lock){...-}-{2:2}, at: kill_fasync fs/fcntl.c:1035 [inline]
#4: ffff88802aad5948 (&new->fa_lock){...-}-{2:2}, at: kill_fasync+0x136/0x470 fs/fcntl.c:1028
#5: ffff888042f5cbb8 (&f->f_owner.lock){...-}-{2:2}, at: send_sigio+0x24/0x380 fs/fcntl.c:796

the dependencies between SOFTIRQ-irq-safe lock and the holding lock:
-> (&timer->lock){..-.}-{2:2} {
IN-SOFTIRQ-W at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x675/0xa20 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:636
irq_exit_rcu+0x5/0x20 kernel/softirq.c:648
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
lock_is_held_type+0xff/0x140 kernel/locking/lockdep.c:5685
lock_is_held include/linux/lockdep.h:283 [inline]
rcu_read_lock_sched_held+0x3a/0x70 kernel/rcu/update.c:125
trace_lock_release include/trace/events/lock.h:58 [inline]
lock_release+0x522/0x720 kernel/locking/lockdep.c:5648
rcu_lock_release include/linux/rcupdate.h:273 [inline]
rcu_read_unlock include/linux/rcupdate.h:721 [inline]
inet_twsk_purge+0x503/0x7d0 net/ipv4/inet_timewait_sock.c:299
ops_exit_list+0x10d/0x160 net/core/net_namespace.c:171
cleanup_net+0x4ea/0xb00 net/core/net_namespace.c:593
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_notify sound/core/timer.c:1086 [inline]
snd_timer_notify+0x10c/0x3d0 sound/core/timer.c:1073
snd_pcm_timer_notify sound/core/pcm_native.c:595 [inline]
snd_pcm_post_stop+0x195/0x1f0 sound/core/pcm_native.c:1453
snd_pcm_action_single sound/core/pcm_native.c:1229 [inline]
snd_pcm_action+0x143/0x170 sound/core/pcm_native.c:1310
snd_pcm_stop sound/core/pcm_native.c:1476 [inline]
snd_pcm_drop+0x1ab/0x320 sound/core/pcm_native.c:2155
snd_pcm_kernel_ioctl+0x2af/0x310 sound/core/pcm_native.c:3382
snd_pcm_oss_sync+0x230/0x800 sound/core/oss/pcm_oss.c:1721
snd_pcm_oss_release+0x276/0x300 sound/core/oss/pcm_oss.c:2571
__fput+0x286/0x9f0 fs/file_table.c:280
task_work_run+0xdd/0x1a0 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+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90842da0>] __key.12+0x0/0x40
-> (&new->fa_lock){...-}-{2:2} {
IN-SOFTIRQ-R at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x45/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
sock_wake_async+0xd2/0x160 net/socket.c:1368
sk_wake_async include/net/sock.h:2400 [inline]
sk_wake_async include/net/sock.h:2396 [inline]
sock_def_error_report+0x34b/0x4e0 net/core/sock.c:3125
sk_error_report+0x35/0x310 net/core/sock.c:339
tcp_write_err net/ipv4/tcp_timer.c:71 [inline]
tcp_write_timeout net/ipv4/tcp_timer.c:276 [inline]
tcp_retransmit_timer+0x20c2/0x3320 net/ipv4/tcp_timer.c:512
tcp_write_timer_handler+0x5e6/0xbc0 net/ipv4/tcp_timer.c:622
tcp_write_timer+0xa2/0x2b0 net/ipv4/tcp_timer.c:642
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x675/0xa20 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
run_ksoftirqd kernel/softirq.c:920 [inline]
run_ksoftirqd+0x2d/0x60 kernel/softirq.c:912
smpboot_thread_fn+0x645/0x9c0 kernel/smpboot.c:164
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_write_lock_irq include/linux/rwlock_api_smp.h:194 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:316
fasync_remove_entry+0xb6/0x1f0 fs/fcntl.c:891
fasync_helper+0x9e/0xb0 fs/fcntl.c:994
lease_modify fs/locks.c:1315 [inline]
lease_modify+0x28a/0x370 fs/locks.c:1302
locks_remove_lease fs/locks.c:2558 [inline]
locks_remove_file+0x29c/0x570 fs/locks.c:2583
__fput+0x1b9/0x9f0 fs/file_table.c:272
task_work_run+0xdd/0x1a0 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+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
pipe_release+0x1ba/0x320 fs/pipe.c:728
__fput+0x286/0x9f0 fs/file_table.c:280
task_work_run+0xdd/0x1a0 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+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90537880>] __key.0+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&f->f_owner.lock){...-}-{2:2} {
IN-SOFTIRQ-R at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x45/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
sock_wake_async+0xd2/0x160 net/socket.c:1368
sk_wake_async include/net/sock.h:2400 [inline]
sk_wake_async include/net/sock.h:2396 [inline]
sock_def_error_report+0x34b/0x4e0 net/core/sock.c:3125
sk_error_report+0x35/0x310 net/core/sock.c:339
tcp_write_err net/ipv4/tcp_timer.c:71 [inline]
tcp_write_timeout net/ipv4/tcp_timer.c:276 [inline]
tcp_retransmit_timer+0x20c2/0x3320 net/ipv4/tcp_timer.c:512
tcp_write_timer_handler+0x5e6/0xbc0 net/ipv4/tcp_timer.c:622
tcp_write_timer+0xa2/0x2b0 net/ipv4/tcp_timer.c:642
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x675/0xa20 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
run_ksoftirqd kernel/softirq.c:920 [inline]
run_ksoftirqd+0x2d/0x60 kernel/softirq.c:912
smpboot_thread_fn+0x645/0x9c0 kernel/smpboot.c:164
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_write_lock_irq include/linux/rwlock_api_smp.h:194 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:316
f_modown+0x2a/0x390 fs/fcntl.c:91
generic_add_lease fs/locks.c:1735 [inline]
generic_setlease+0x11bc/0x1a60 fs/locks.c:1814
vfs_setlease+0xfd/0x120 fs/locks.c:1904
do_fcntl_add_lease fs/locks.c:1925 [inline]
fcntl_setlease+0x134/0x2c0 fs/locks.c:1947
do_fcntl+0x2b6/0x1210 fs/fcntl.c:419
__do_sys_fcntl fs/fcntl.c:472 [inline]
__se_sys_fcntl fs/fcntl.c:457 [inline]
__x64_sys_fcntl+0x165/0x1e0 fs/fcntl.c:457
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
pipe_release+0x1ba/0x320 fs/pipe.c:728
__fput+0x286/0x9f0 fs/file_table.c:280
task_work_run+0xdd/0x1a0 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+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90536aa0>] __key.5+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:159 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
pipe_release+0x1ba/0x320 fs/pipe.c:728
__fput+0x286/0x9f0 fs/file_table.c:280
task_work_run+0xdd/0x1a0 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+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae


the dependencies between the lock to be acquired
and SOFTIRQ-irq-unsafe lock:
-> (tasklist_lock){.+.+}-{2:2} {
HARDIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1511
kernel_wait+0x9c/0x150 kernel/exit.c:1701
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
SOFTIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1511
kernel_wait+0x9c/0x150 kernel/exit.c:1701
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_write_lock_irq include/linux/rwlock_api_smp.h:194 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:316
copy_process+0x36c8/0x75a0 kernel/fork.c:2311
kernel_clone+0xe7/0xab0 kernel/fork.c:2582
kernel_thread+0xb5/0xf0 kernel/fork.c:2634
rest_init+0x23/0x3e0 init/main.c:690
start_kernel+0x47a/0x49b init/main.c:1135
secondary_startup_64_no_verify+0xb0/0xbb
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1511
kernel_wait+0x9c/0x150 kernel/exit.c:1701
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
}
... key at: [<ffffffff8b80a098>] tasklist_lock+0x18/0x40
... acquired at:
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
send_sigio+0xab/0x380 fs/fcntl.c:810
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
lease_break_callback+0x1f/0x30 fs/locks.c:477
__break_lease+0x3d7/0x1420 fs/locks.c:1450
break_lease include/linux/fs.h:2634 [inline]
break_lease include/linux/fs.h:2624 [inline]
vfs_truncate+0x31a/0x4b0 fs/open.c:104
do_sys_truncate.part.0+0x11e/0x140 fs/open.c:133
do_sys_truncate fs/open.c:127 [inline]
__do_sys_truncate fs/open.c:145 [inline]
__se_sys_truncate fs/open.c:143 [inline]
__x64_sys_truncate+0x69/0x90 fs/open.c:143
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae


stack backtrace:
CPU: 0 PID: 25993 Comm: syz-executor.0 Not tainted 5.16.0-rc1-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
print_bad_irq_dependency kernel/locking/lockdep.c:2577 [inline]
check_irq_usage.cold+0x4c1/0x6b0 kernel/locking/lockdep.c:2816
check_prev_add kernel/locking/lockdep.c:3067 [inline]
check_prevs_add kernel/locking/lockdep.c:3186 [inline]
validate_chain kernel/locking/lockdep.c:3801 [inline]
__lock_acquire+0x2a1f/0x54a0 kernel/locking/lockdep.c:5027
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
send_sigio+0xab/0x380 fs/fcntl.c:810
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
lease_break_callback+0x1f/0x30 fs/locks.c:477
__break_lease+0x3d7/0x1420 fs/locks.c:1450
break_lease include/linux/fs.h:2634 [inline]
break_lease include/linux/fs.h:2624 [inline]
vfs_truncate+0x31a/0x4b0 fs/open.c:104
do_sys_truncate.part.0+0x11e/0x140 fs/open.c:133
do_sys_truncate fs/open.c:127 [inline]
__do_sys_truncate fs/open.c:145 [inline]
__se_sys_truncate fs/open.c:143 [inline]
__x64_sys_truncate+0x69/0x90 fs/open.c:143
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f7b8fe43ae9
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f7b8d3b9188 EFLAGS: 00000246 ORIG_RAX: 000000000000004c
RAX: ffffffffffffffda RBX: 00007f7b8ff56f60 RCX: 00007f7b8fe43ae9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000020000000
RBP: 00007f7b8fe9df6d R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007ffc1688ebaf R14: 00007f7b8d3b9300 R15: 0000000000022000
</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 [email protected].

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.


2022-02-04 19:00:28

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] possible deadlock in snd_timer_interrupt (2)

syzbot has found a reproducer for the following issue on:

HEAD commit: 1f2cfdd349b7 printk: Fix incorrect __user type in proc_doi..
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=146fce24700000
kernel config: https://syzkaller.appspot.com/x/.config?x=b4a89edfcc8f7c74
dashboard link: https://syzkaller.appspot.com/bug?extid=1ee0910eca9c94f71f25
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1007e462700000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

========================================================
WARNING: possible irq lock inversion dependency detected
5.17.0-rc2-syzkaller-00071-g1f2cfdd349b7 #0 Not tainted
--------------------------------------------------------
syz-executor.3/4250 just changed the state of lock:
ffff88814a62e148 (&timer->lock){..-.}-{2:2}, at: snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
but this lock took another, SOFTIRQ-READ-unsafe lock in the past:
(tasklist_lock){.+.+}-{2:2}


and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
Chain exists of:
&timer->lock --> &new->fa_lock --> tasklist_lock

Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(tasklist_lock);
local_irq_disable();
lock(&timer->lock);
lock(&new->fa_lock);
<Interrupt>
lock(&timer->lock);

*** DEADLOCK ***

2 locks held by syz-executor.3/4250:
#0: ffff88807efef828 (&mm->mmap_lock#2){++++}-{3:3}, at: __might_fault+0xa1/0x170 mm/memory.c:5271
#1: ffffc90000dc0d70 ((&priv->tlist)){+.-.}-{0:0}, at: lockdep_copy_map include/linux/lockdep.h:35 [inline]
#1: ffffc90000dc0d70 ((&priv->tlist)){+.-.}-{0:0}, at: call_timer_fn+0xd5/0x6b0 kernel/time/timer.c:1411

the shortest dependencies between 2nd lock and 1st lock:
-> (tasklist_lock){.+.+}-{2:2} {
HARDIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
SOFTIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
copy_process+0x47da/0x7300 kernel/fork.c:2284
kernel_clone+0xe7/0xab0 kernel/fork.c:2555
kernel_thread+0xb5/0xf0 kernel/fork.c:2607
rest_init+0x23/0x3e0 init/main.c:690
start_kernel+0x47a/0x49b init/main.c:1138
secondary_startup_64_no_verify+0xc3/0xcb
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
}
... key at: [<ffffffff8b80a098>] tasklist_lock+0x18/0x40
... acquired at:
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
send_sigio+0xab/0x380 fs/fcntl.c:810
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
sock_wake_async+0xd2/0x160 net/socket.c:1372
sk_wake_async include/net/sock.h:2444 [inline]
sk_wake_async include/net/sock.h:2440 [inline]
sock_def_readable+0x349/0x4e0 net/core/sock.c:3149
unix_dgram_sendmsg+0xf30/0x1a10 net/unix/af_unix.c:2029
sock_sendmsg_nosec net/socket.c:705 [inline]
sock_sendmsg+0xcf/0x120 net/socket.c:725
____sys_sendmsg+0x331/0x810 net/socket.c:2413
___sys_sendmsg+0xf3/0x170 net/socket.c:2467
__sys_sendmmsg+0x195/0x470 net/socket.c:2553
__do_sys_sendmmsg net/socket.c:2582 [inline]
__se_sys_sendmmsg net/socket.c:2579 [inline]
__x64_sys_sendmmsg+0x99/0x100 net/socket.c:2579
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&f->f_owner.lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
f_modown+0x2a/0x390 fs/fcntl.c:91
__f_setown fs/fcntl.c:110 [inline]
f_setown+0xd7/0x230 fs/fcntl.c:138
sock_ioctl+0x37e/0x640 net/socket.c:1182
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff9057ea40>] __key.5+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&new->fa_lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
fasync_remove_entry+0xb6/0x1f0 fs/fcntl.c:891
fasync_helper+0x9e/0xb0 fs/fcntl.c:994
__fput+0x846/0x9f0 fs/file_table.c:308
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
tracehook_notify_resume include/linux/tracehook.h:188 [inline]
exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff9057f820>] __key.0+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&timer->lock){..-.}-{2:2} {
IN-SOFTIRQ-W at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
kasan_check_range+0x0/0x180 mm/kasan/generic.c:349
instrument_atomic_read include/linux/instrumented.h:71 [inline]
test_bit include/asm-generic/bitops/instrumented-non-atomic.h:134 [inline]
cpumask_test_cpu include/linux/cpumask.h:379 [inline]
cpu_online include/linux/cpumask.h:921 [inline]
trace_lock_release include/trace/events/lock.h:58 [inline]
lock_release+0xa1/0x720 kernel/locking/lockdep.c:5650
__might_fault mm/memory.c:5272 [inline]
__might_fault+0x142/0x170 mm/memory.c:5257
_copy_from_user+0x27/0x180 lib/usercopy.c:13
copy_from_user include/linux/uaccess.h:192 [inline]
snd_seq_oss_write+0x38b/0x780 sound/core/seq/oss/seq_oss_rw.c:93
odev_write+0x55/0x90 sound/core/seq/oss/seq_oss.c:168
vfs_write+0x28e/0xae0 fs/read_write.c:588
ksys_write+0x12d/0x250 fs/read_write.c:643
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_resolution+0x55/0x100 sound/core/timer.c:489
snd_timer_user_params.isra.0+0x18e/0x8c0 sound/core/timer.c:1851
__snd_timer_user_ioctl.isra.0+0x1020/0x2490 sound/core/timer.c:2100
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff9087d3c0>] __key.12+0x0/0x40
... acquired at:
mark_usage kernel/locking/lockdep.c:4500 [inline]
__lock_acquire+0x11d2/0x5470 kernel/locking/lockdep.c:4981
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
kasan_check_range+0x0/0x180 mm/kasan/generic.c:349
instrument_atomic_read include/linux/instrumented.h:71 [inline]
test_bit include/asm-generic/bitops/instrumented-non-atomic.h:134 [inline]
cpumask_test_cpu include/linux/cpumask.h:379 [inline]
cpu_online include/linux/cpumask.h:921 [inline]
trace_lock_release include/trace/events/lock.h:58 [inline]
lock_release+0xa1/0x720 kernel/locking/lockdep.c:5650
__might_fault mm/memory.c:5272 [inline]
__might_fault+0x142/0x170 mm/memory.c:5257
_copy_from_user+0x27/0x180 lib/usercopy.c:13
copy_from_user include/linux/uaccess.h:192 [inline]
snd_seq_oss_write+0x38b/0x780 sound/core/seq/oss/seq_oss_rw.c:93
odev_write+0x55/0x90 sound/core/seq/oss/seq_oss.c:168
vfs_write+0x28e/0xae0 fs/read_write.c:588
ksys_write+0x12d/0x250 fs/read_write.c:643
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae


stack backtrace:
CPU: 1 PID: 4250 Comm: syz-executor.3 Not tainted 5.17.0-rc2-syzkaller-00071-g1f2cfdd349b7 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106

2022-03-04 19:34:10

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] possible deadlock in snd_timer_interrupt (2)

syzbot has found a reproducer for the following issue on:

HEAD commit: 38f80f42147f MAINTAINERS: Remove dead patchwork link
git tree: upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=161736d6700000
kernel config: https://syzkaller.appspot.com/x/.config?x=4e9585407e09f75f
dashboard link: https://syzkaller.appspot.com/bug?extid=1ee0910eca9c94f71f25
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11b6ad85700000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=12527ef1700000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: [email protected]

========================================================
WARNING: possible irq lock inversion dependency detected
5.17.0-rc6-syzkaller-00184-g38f80f42147f #0 Not tainted
--------------------------------------------------------
syz-executor301/4486 just changed the state of lock:
ffff88814a78a948 (&timer->lock){..-.}-{2:2}, at: snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
but this lock took another, SOFTIRQ-READ-unsafe lock in the past:
(tasklist_lock){.+.+}-{2:2}


and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
Chain exists of:
&timer->lock --> &new->fa_lock --> tasklist_lock

Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(tasklist_lock);
local_irq_disable();
lock(&timer->lock);
lock(&new->fa_lock);
<Interrupt>
lock(&timer->lock);

*** DEADLOCK ***

1 lock held by syz-executor301/4486:
#0: ffffc90000007d70 ((&priv->tlist)){+.-.}-{0:0}, at: lockdep_copy_map include/linux/lockdep.h:35 [inline]
#0: ffffc90000007d70 ((&priv->tlist)){+.-.}-{0:0}, at: call_timer_fn+0xd5/0x6b0 kernel/time/timer.c:1411

the shortest dependencies between 2nd lock and 1st lock:
-> (tasklist_lock){.+.+}-{2:2} {
HARDIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
SOFTIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
copy_process+0x486a/0x7250 kernel/fork.c:2295
kernel_clone+0xe7/0xab0 kernel/fork.c:2565
kernel_thread+0xb5/0xf0 kernel/fork.c:2617
rest_init+0x23/0x3e0 init/main.c:690
start_kernel+0x47a/0x49b init/main.c:1138
secondary_startup_64_no_verify+0xc3/0xcb
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
}
... key at: [<ffffffff8b80a098>] tasklist_lock+0x18/0x40
... acquired at:
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
send_sigio+0xab/0x380 fs/fcntl.c:810
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_stop1+0x496/0x860 sound/core/timer.c:657
snd_timer_stop sound/core/timer.c:710 [inline]
snd_timer_close_locked+0x20f/0xbb0 sound/core/timer.c:408
snd_timer_close+0x87/0xf0 sound/core/timer.c:463
__snd_timer_user_ioctl.isra.0+0x10e2/0x2490 sound/core/timer.c:1762
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&f->f_owner.lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
f_modown+0x2a/0x390 fs/fcntl.c:91
__f_setown fs/fcntl.c:110 [inline]
f_setown+0xd7/0x230 fs/fcntl.c:138
do_fcntl+0x749/0x1210 fs/fcntl.c:393
__do_sys_fcntl fs/fcntl.c:472 [inline]
__se_sys_fcntl fs/fcntl.c:457 [inline]
__x64_sys_fcntl+0x165/0x1e0 fs/fcntl.c:457
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90585a40>] __key.5+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&new->fa_lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
fasync_remove_entry+0xb6/0x1f0 fs/fcntl.c:891
fasync_helper+0x9e/0xb0 fs/fcntl.c:994
__fput+0x846/0x9f0 fs/file_table.c:314
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0xb29/0x2a30 kernel/exit.c:806
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90586820>] __key.0+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1386
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1984
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&timer->lock){..-.}-{2:2} {
IN-SOFTIRQ-W at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
bytes_is_nonzero mm/kasan/generic.c:85 [inline]
memory_is_nonzero mm/kasan/generic.c:102 [inline]
memory_is_poisoned_n mm/kasan/generic.c:128 [inline]
memory_is_poisoned mm/kasan/generic.c:159 [inline]
check_region_inline mm/kasan/generic.c:180 [inline]
kasan_check_range+0xde/0x180 mm/kasan/generic.c:189
instrument_atomic_read include/linux/instrumented.h:71 [inline]
atomic_long_read include/linux/atomic/atomic-instrumented.h:1265 [inline]
filp_close+0x22/0x170 fs/open.c:1318
close_files fs/file.c:403 [inline]
put_files_struct fs/file.c:418 [inline]
put_files_struct+0x1d0/0x350 fs/file.c:415
exit_files+0x7e/0xa0 fs/file.c:435
do_exit+0xaf2/0x2a30 kernel/exit.c:801
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_stop1+0x5c/0x860 sound/core/timer.c:626
snd_timer_stop sound/core/timer.c:710 [inline]
snd_timer_user_start.isra.0+0x8b/0x260 sound/core/timer.c:1981
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2107
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2128
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff908843c0>] __key.12+0x0/0x40
... acquired at:
mark_lock kernel/locking/lockdep.c:4569 [inline]
mark_usage kernel/locking/lockdep.c:4500 [inline]
__lock_acquire+0x11e3/0x56c0 kernel/locking/lockdep.c:4981
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
bytes_is_nonzero mm/kasan/generic.c:85 [inline]
memory_is_nonzero mm/kasan/generic.c:102 [inline]
memory_is_poisoned_n mm/kasan/generic.c:128 [inline]
memory_is_poisoned mm/kasan/generic.c:159 [inline]
check_region_inline mm/kasan/generic.c:180 [inline]
kasan_check_range+0xde/0x180 mm/kasan/generic.c:189
instrument_atomic_read include/linux/instrumented.h:71 [inline]
atomic_long_read include/linux/atomic/atomic-instrumented.h:1265 [inline]
filp_close+0x22/0x170 fs/open.c:1318
close_files fs/file.c:403 [inline]
put_files_struct fs/file.c:418 [inline]
put_files_struct+0x1d0/0x350 fs/file.c:415
exit_files+0x7e/0xa0 fs/file.c:435
do_exit+0xaf2/0x2a30 kernel/exit.c:801
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae


stack backtrace:
CPU: 0 PID: 4486 Comm: syz-executor301 Not tainted 5.17.0-rc6-syzkaller-00184-g38f80f42147f #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
print_irq_inversion_bug kernel/locking/lockdep.c:194 [inline]
check_usage_forwards kernel/locking/lockdep.c:4043 [inline]
mark_lock_irq kernel/locking/lockdep.c:4175 [inline]
mark_lock.part.0.cold+0x86/0xd8 kernel/locking/lockdep.c:4605
mark_lock kernel/locking/lockdep.c:4569 [inline]
mark_usage kernel/locking/lockdep.c:4500 [inline]
__lock_acquire+0x11e3/0x56c0 kernel/locking/lockdep.c:4981
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x34/0xcf0 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1154 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1154
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:bytes_is_nonzero mm/kasan/generic.c:85 [inline]
RIP: 0010:memory_is_nonzero mm/kasan/generic.c:102 [inline]
RIP: 0010:memory_is_poisoned_n mm/kasan/generic.c:128 [inline]
RIP: 0010:memory_is_poisoned mm/kasan/generic.c:159 [inline]
RIP: 0010:check_region_inline mm/kasan/generic.c:180 [inline]
RIP: 0010:kasan_check_range+0xde/0x180 mm/kasan/generic.c:189
Code: 74 f2 48 89 c2 b8 01 00 00 00 48 85 d2 75 56 5b 5d 41 5c c3 48 85 d2 74 5e 48 01 ea eb 09 48 83 c0 01 48 39 d0 74 50 80 38 00 <74> f2 eb d4 41 bc 08 00 00 00 48 89 ea 45 29 dc 4d 8d 1c 2c eb 0c
RSP: 0018:ffffc9000376fd30 EFLAGS: 00000246
RAX: ffffed100f1d3d9f RBX: ffffed100f1d3da0 RCX: ffffffff81cb24b2
RDX: ffffed100f1d3da0 RSI: 0000000000000008 RDI: ffff888078e9ecf8
RBP: ffffed100f1d3d9f R08: 0000000000000000 R09: ffff888078e9ecff
R10: ffffed100f1d3d9f R11: 0000000000000000 R12: ffff88807ee70f00
R13: ffff888078e9ecf8 R14: ffff88807ee70f00 R15: ffff88807ee71028
instrument_atomic_read include/linux/instrumented.h:71 [inline]
atomic_long_read include/linux/atomic/atomic-instrumented.h:1265 [inline]
filp_close+0x22/0x170 fs/open.c:1318
close_files fs/file.c:403 [inline]
put_files_struct fs/file.c:418 [inline]
put_files_struct+0x1d0/0x350 fs/file.c:415
exit_files+0x7e/0xa0 fs/file.c:435
do_exit+0xaf2/0x2a30 kernel/exit.c:801
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7ff95f986c99
Code: Unable to access opcode bytes at RIP 0x7ff95f986c6f.
RSP: 002b:00007ffecd4a5e98 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007ff95f9fb330 RCX: 00007ff95f986c99
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 0000000000000001 R11: 0000000000000246 R12: 00007ff95f9fb330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>
----------------
Code disassembly (best guess):
0: 74 f2 je 0xfffffff4
2: 48 89 c2 mov %rax,%rdx
5: b8 01 00 00 00 mov $0x1,%eax
a: 48 85 d2 test %rdx,%rdx
d: 75 56 jne 0x65
f: 5b pop %rbx
10: 5d pop %rbp
11: 41 5c pop %r12
13: c3 retq
14: 48 85 d2 test %rdx,%rdx
17: 74 5e je 0x77
19: 48 01 ea add %rbp,%rdx
1c: eb 09 jmp 0x27
1e: 48 83 c0 01 add $0x1,%rax
22: 48 39 d0 cmp %rdx,%rax
25: 74 50 je 0x77
27: 80 38 00 cmpb $0x0,(%rax)
* 2a: 74 f2 je 0x1e <-- trapping instruction
2c: eb d4 jmp 0x2
2e: 41 bc 08 00 00 00 mov $0x8,%r12d
34: 48 89 ea mov %rbp,%rdx
37: 45 29 dc sub %r11d,%r12d
3a: 4d 8d 1c 2c lea (%r12,%rbp,1),%r11
3e: eb 0c jmp 0x4c

2022-03-07 09:36:04

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] possible deadlock in snd_timer_interrupt (2)

Hello,

syzbot has tested the proposed patch but the reproducer is still triggering an issue:
possible deadlock in snd_timer_interrupt

========================================================
WARNING: possible irq lock inversion dependency detected
5.17.0-rc6-syzkaller-00184-g38f80f42147f-dirty #0 Not tainted
--------------------------------------------------------
syz-executor295/5049 just changed the state of lock:
ffff888021a6f948 (&timer->lock){..-.}-{2:2}, at: snd_timer_interrupt.part.0+0x33/0xe80 sound/core/timer.c:856
but this lock took another, SOFTIRQ-READ-unsafe lock in the past:
(tasklist_lock){.+.+}-{2:2}


and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
Chain exists of:
&timer->lock --> &new->fa_lock --> tasklist_lock

Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(tasklist_lock);
local_irq_disable();
lock(&timer->lock);
lock(&new->fa_lock);
<Interrupt>
lock(&timer->lock);

*** DEADLOCK ***

2 locks held by syz-executor295/5049:
#0: ffff88801bbbc028 (&mm->mmap_lock#2){++++}-{3:3}, at: mmap_write_lock include/linux/mmap_lock.h:71 [inline]
#0: ffff88801bbbc028 (&mm->mmap_lock#2){++++}-{3:3}, at: exit_mmap+0x10d/0x6a0 mm/mmap.c:3160
#1: ffffc90000dc0d70 ((&priv->tlist)){+.-.}-{0:0}, at: lockdep_copy_map include/linux/lockdep.h:35 [inline]
#1: ffffc90000dc0d70 ((&priv->tlist)){+.-.}-{0:0}, at: call_timer_fn+0xd5/0x6b0 kernel/time/timer.c:1411

the shortest dependencies between 2nd lock and 1st lock:
-> (tasklist_lock){.+.+}-{2:2} {
HARDIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
SOFTIRQ-ON-R at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
copy_process+0x486a/0x7250 kernel/fork.c:2295
kernel_clone+0xe7/0xab0 kernel/fork.c:2565
kernel_thread+0xb5/0xf0 kernel/fork.c:2617
rest_init+0x23/0x3e0 init/main.c:690
start_kernel+0x47a/0x49b init/main.c:1138
secondary_startup_64_no_verify+0xc3/0xcb
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
do_wait+0x284/0xce0 kernel/exit.c:1518
kernel_wait+0x9c/0x150 kernel/exit.c:1708
call_usermodehelper_exec_sync kernel/umh.c:139 [inline]
call_usermodehelper_exec_work+0xf5/0x180 kernel/umh.c:166
process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
worker_thread+0x657/0x1110 kernel/workqueue.c:2454
kthread+0x2e9/0x3a0 kernel/kthread.c:377
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
}
... key at: [<ffffffff8b80a098>] tasklist_lock+0x18/0x40
... acquired at:
__raw_read_lock include/linux/rwlock_api_smp.h:150 [inline]
_raw_read_lock+0x5b/0x70 kernel/locking/spinlock.c:228
send_sigio+0xab/0x380 fs/fcntl.c:810
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1393
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_stop1+0x496/0x860 sound/core/timer.c:657
snd_timer_stop sound/core/timer.c:710 [inline]
snd_timer_close_locked+0x20f/0xbb0 sound/core/timer.c:408
snd_timer_close+0x87/0xf0 sound/core/timer.c:463
__snd_timer_user_ioctl.isra.0+0x10e2/0x2490 sound/core/timer.c:1769
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2135
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&f->f_owner.lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
f_modown+0x2a/0x390 fs/fcntl.c:91
__f_setown fs/fcntl.c:110 [inline]
f_setown+0xd7/0x230 fs/fcntl.c:138
do_fcntl+0x749/0x1210 fs/fcntl.c:393
__do_sys_fcntl fs/fcntl.c:472 [inline]
__se_sys_fcntl fs/fcntl.c:457 [inline]
__x64_sys_fcntl+0x165/0x1e0 fs/fcntl.c:457
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1393
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1991
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2114
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2135
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90585a40>] __key.5+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
send_sigio+0x24/0x380 fs/fcntl.c:796
kill_fasync_rcu fs/fcntl.c:1021 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x1f8/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1393
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1991
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2114
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2135
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&new->fa_lock){....}-{2:2} {
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_write_lock_irq include/linux/rwlock_api_smp.h:195 [inline]
_raw_write_lock_irq+0x32/0x50 kernel/locking/spinlock.c:326
fasync_remove_entry+0xb6/0x1f0 fs/fcntl.c:891
fasync_helper+0x9e/0xb0 fs/fcntl.c:994
__fput+0x846/0x9f0 fs/file_table.c:314
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0xb29/0x2a30 kernel/exit.c:806
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL READ USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1393
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1991
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2114
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2135
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff90586820>] __key.0+0x0/0x40
... acquired at:
__raw_read_lock_irqsave include/linux/rwlock_api_smp.h:160 [inline]
_raw_read_lock_irqsave+0x70/0x90 kernel/locking/spinlock.c:236
kill_fasync_rcu fs/fcntl.c:1014 [inline]
kill_fasync fs/fcntl.c:1035 [inline]
kill_fasync+0x136/0x470 fs/fcntl.c:1028
snd_timer_user_ccallback+0x298/0x330 sound/core/timer.c:1393
snd_timer_notify1+0x11c/0x3b0 sound/core/timer.c:516
snd_timer_start1+0x4d4/0x800 sound/core/timer.c:578
snd_timer_start sound/core/timer.c:696 [inline]
snd_timer_start sound/core/timer.c:689 [inline]
snd_timer_user_start.isra.0+0x1e3/0x260 sound/core/timer.c:1991
__snd_timer_user_ioctl.isra.0+0xda8/0x2490 sound/core/timer.c:2114
snd_timer_user_ioctl+0x77/0xb0 sound/core/timer.c:2135
vfs_ioctl fs/ioctl.c:51 [inline]
__do_sys_ioctl fs/ioctl.c:874 [inline]
__se_sys_ioctl fs/ioctl.c:860 [inline]
__x64_sys_ioctl+0x193/0x200 fs/ioctl.c:860
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae

-> (&timer->lock){..-.}-{2:2} {
IN-SOFTIRQ-W at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x33/0xe80 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1161 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1161
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
native_save_fl arch/x86/include/asm/irqflags.h:29 [inline]
arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
arch_local_irq_save arch/x86/include/asm/irqflags.h:106 [inline]
lock_is_held_type+0x51/0x140 kernel/locking/lockdep.c:5678
lock_is_held include/linux/lockdep.h:283 [inline]
__might_resched+0x3a/0x2c0 kernel/sched/core.c:9547
down_write+0x6c/0x150 kernel/locking/rwsem.c:1513
i_mmap_lock_write include/linux/fs.h:492 [inline]
unlink_file_vma+0x7d/0x110 mm/mmap.c:170
free_pgtables+0x1b3/0x2f0 mm/memory.c:428
exit_mmap+0x210/0x6a0 mm/mmap.c:3179
__mmput+0x122/0x4b0 kernel/fork.c:1114
mmput+0x56/0x60 kernel/fork.c:1135
exit_mm kernel/exit.c:507 [inline]
do_exit+0xa3c/0x2a30 kernel/exit.c:793
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
INITIAL USE at:
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_notify sound/core/timer.c:1093 [inline]
snd_timer_notify+0x10c/0x3d0 sound/core/timer.c:1080
snd_pcm_timer_notify sound/core/pcm_native.c:608 [inline]
snd_pcm_post_stop+0x195/0x1f0 sound/core/pcm_native.c:1466
snd_pcm_action_single sound/core/pcm_native.c:1242 [inline]
snd_pcm_action+0x143/0x170 sound/core/pcm_native.c:1323
snd_pcm_stop sound/core/pcm_native.c:1489 [inline]
snd_pcm_drop+0x1ab/0x320 sound/core/pcm_native.c:2168
snd_pcm_kernel_ioctl+0x2af/0x310 sound/core/pcm_native.c:3395
snd_pcm_oss_sync+0x230/0x800 sound/core/oss/pcm_oss.c:1734
snd_pcm_oss_release+0x276/0x300 sound/core/oss/pcm_oss.c:2584
__fput+0x286/0x9f0 fs/file_table.c:317
task_work_run+0xdd/0x1a0 kernel/task_work.c:164
tracehook_notify_resume include/linux/tracehook.h:188 [inline]
exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
}
... key at: [<ffffffff908843c0>] __key.12+0x0/0x40
... acquired at:
mark_lock kernel/locking/lockdep.c:4569 [inline]
mark_usage kernel/locking/lockdep.c:4500 [inline]
__lock_acquire+0x11e3/0x56c0 kernel/locking/lockdep.c:4981
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x33/0xe80 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1161 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1161
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
native_save_fl arch/x86/include/asm/irqflags.h:29 [inline]
arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
arch_local_irq_save arch/x86/include/asm/irqflags.h:106 [inline]
lock_is_held_type+0x51/0x140 kernel/locking/lockdep.c:5678
lock_is_held include/linux/lockdep.h:283 [inline]
__might_resched+0x3a/0x2c0 kernel/sched/core.c:9547
down_write+0x6c/0x150 kernel/locking/rwsem.c:1513
i_mmap_lock_write include/linux/fs.h:492 [inline]
unlink_file_vma+0x7d/0x110 mm/mmap.c:170
free_pgtables+0x1b3/0x2f0 mm/memory.c:428
exit_mmap+0x210/0x6a0 mm/mmap.c:3179
__mmput+0x122/0x4b0 kernel/fork.c:1114
mmput+0x56/0x60 kernel/fork.c:1135
exit_mm kernel/exit.c:507 [inline]
do_exit+0xa3c/0x2a30 kernel/exit.c:793
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae


stack backtrace:
CPU: 1 PID: 5049 Comm: syz-executor295 Not tainted 5.17.0-rc6-syzkaller-00184-g38f80f42147f-dirty #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
print_irq_inversion_bug kernel/locking/lockdep.c:194 [inline]
check_usage_forwards kernel/locking/lockdep.c:4043 [inline]
mark_lock_irq kernel/locking/lockdep.c:4175 [inline]
mark_lock.part.0.cold+0x86/0xd8 kernel/locking/lockdep.c:4605
mark_lock kernel/locking/lockdep.c:4569 [inline]
mark_usage kernel/locking/lockdep.c:4500 [inline]
__lock_acquire+0x11e3/0x56c0 kernel/locking/lockdep.c:4981
lock_acquire kernel/locking/lockdep.c:5639 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x39/0x50 kernel/locking/spinlock.c:162
snd_timer_interrupt.part.0+0x33/0xe80 sound/core/timer.c:856
snd_timer_interrupt sound/core/timer.c:1161 [inline]
snd_timer_s_function+0x14b/0x200 sound/core/timer.c:1161
call_timer_fn+0x1a5/0x6b0 kernel/time/timer.c:1421
expire_timers kernel/time/timer.c:1466 [inline]
__run_timers.part.0+0x67c/0xa30 kernel/time/timer.c:1734
__run_timers kernel/time/timer.c:1715 [inline]
run_timer_softirq+0xb3/0x1d0 kernel/time/timer.c:1747
__do_softirq+0x29b/0x9c2 kernel/softirq.c:558
invoke_softirq kernel/softirq.c:432 [inline]
__irq_exit_rcu+0x123/0x180 kernel/softirq.c:637
irq_exit_rcu+0x5/0x20 kernel/softirq.c:649
sysvec_apic_timer_interrupt+0x93/0xc0 arch/x86/kernel/apic/apic.c:1097
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:native_save_fl arch/x86/include/asm/irqflags.h:29 [inline]
RIP: 0010:arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
RIP: 0010:arch_local_irq_save arch/x86/include/asm/irqflags.h:106 [inline]
RIP: 0010:lock_is_held_type+0x51/0x140 kernel/locking/lockdep.c:5678
Code: b6 76 85 c0 0f 85 ca 00 00 00 65 4c 8b 24 25 00 70 02 00 41 8b 94 24 5c 0a 00 00 85 d2 0f 85 b1 00 00 00 48 89 fd 41 89 f6 9c <8f> 04 24 fa 48 c7 c7 e0 60 ac 89 31 db e8 fd 0d 00 00 41 8b 84 24
RSP: 0018:ffffc9000333fb08 EFLAGS: 00000246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffffffff8bb84520
RBP: ffffffff8bb84520 R08: 0000000000000000 R09: ffffffff8ffc4977
R10: 0000000000000001 R11: 0000000000000000 R12: ffff888022f40000
R13: 00000000ffffffff R14: 00000000ffffffff R15: 0000000000000000
lock_is_held include/linux/lockdep.h:283 [inline]
__might_resched+0x3a/0x2c0 kernel/sched/core.c:9547
down_write+0x6c/0x150 kernel/locking/rwsem.c:1513
i_mmap_lock_write include/linux/fs.h:492 [inline]
unlink_file_vma+0x7d/0x110 mm/mmap.c:170
free_pgtables+0x1b3/0x2f0 mm/memory.c:428
exit_mmap+0x210/0x6a0 mm/mmap.c:3179
__mmput+0x122/0x4b0 kernel/fork.c:1114
mmput+0x56/0x60 kernel/fork.c:1135
exit_mm kernel/exit.c:507 [inline]
do_exit+0xa3c/0x2a30 kernel/exit.c:793
do_group_exit+0xd2/0x2f0 kernel/exit.c:935
__do_sys_exit_group kernel/exit.c:946 [inline]
__se_sys_exit_group kernel/exit.c:944 [inline]
__x64_sys_exit_group+0x3a/0x50 kernel/exit.c:944
do_syscall_x64 arch/x86/entry/common.c:50 [inline]
do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fa5e94ccc89
Code: Unable to access opcode bytes at RIP 0x7fa5e94ccc5f.
RSP: 002b:00007ffe3ea446b8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: 00007fa5e9541330 RCX: 00007fa5e94ccc89
RDX: 000000000000003c RSI: 00000000000000e7 RDI: 0000000000000000
RBP: 0000000000000000 R08: ffffffffffffffc0 R09: 0000000000000001
R10: 0000000000000001 R11: 0000000000000246 R12: 00007fa5e9541330
R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000001
</TASK>
----------------
Code disassembly (best guess):
0: b6 76 mov $0x76,%dh
2: 85 c0 test %eax,%eax
4: 0f 85 ca 00 00 00 jne 0xd4
a: 65 4c 8b 24 25 00 70 mov %gs:0x27000,%r12
11: 02 00
13: 41 8b 94 24 5c 0a 00 mov 0xa5c(%r12),%edx
1a: 00
1b: 85 d2 test %edx,%edx
1d: 0f 85 b1 00 00 00 jne 0xd4
23: 48 89 fd mov %rdi,%rbp
26: 41 89 f6 mov %esi,%r14d
29: 9c pushfq
* 2a: 8f 04 24 popq (%rsp) <-- trapping instruction
2d: fa cli
2e: 48 c7 c7 e0 60 ac 89 mov $0xffffffff89ac60e0,%rdi
35: 31 db xor %ebx,%ebx
37: e8 fd 0d 00 00 callq 0xe39
3c: 41 rex.B
3d: 8b .byte 0x8b
3e: 84 .byte 0x84
3f: 24 .byte 0x24


Tested on:

commit: 38f80f42 MAINTAINERS: Remove dead patchwork link
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/
console output: https://syzkaller.appspot.com/x/log.txt?x=17ec0c11700000
kernel config: https://syzkaller.appspot.com/x/.config?x=4e9585407e09f75f
dashboard link: https://syzkaller.appspot.com/bug?extid=1ee0910eca9c94f71f25
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=15000f85700000

2022-03-07 09:44:28

by Takashi Iwai

[permalink] [raw]
Subject: Re: [syzbot] possible deadlock in snd_timer_interrupt (2)

On Mon, 07 Mar 2022 09:05:20 +0100,
Hillf Danton wrote:
>
> Walk around the deadlock by trying to lock tasklist_lock for write on
> timer irq and scheduling workqueue work if any lock owner detected.

Oh no, that's toooo ugly.

And the problem isn't only here; take a look at commits f671a691e299
and 2f488f698fda. There are other users of kill_fasync() with the
hard-IRQ disabled, too.

So, IMO, the handling of tasklist_lock around kill_fasync() looks
broken and the fix should be needed there (or other core part),
instead of messing round each caller's code.


thanks,

Takashi

>
> Only for thoughts now.
>
> Hillf
>
> #syz test: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/ 38f80f42147f
>
> --- x/sound/core/timer.c
> +++ y/sound/core/timer.c
> @@ -916,7 +916,14 @@ void snd_timer_interrupt(struct snd_time
> }
>
> /* now process all fast callbacks */
> - snd_timer_process_callbacks(timer, &timer->ack_list_head);
> + if (write_trylock(&tasklist_lock)) {
> + write_unlock(&tasklist_lock);
> + snd_timer_process_callbacks(timer, &timer->ack_list_head);
> + } else {
> + /* go the slow path to avoid deadlock by calling kill_fasync() */
> + list_splice_init(&timer->ack_list_head,
> + &timer->sack_list_head);
> + }
>
> /* do we have any slow callbacks? */
> use_work = !list_empty(&timer->sack_list_head);
> --
>

2022-03-07 20:54:03

by syzbot

[permalink] [raw]
Subject: Re: [syzbot] possible deadlock in snd_timer_interrupt (2)

Hello,

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

Reported-and-tested-by: [email protected]

Tested on:

commit: 38f80f42 MAINTAINERS: Remove dead patchwork link
git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/
kernel config: https://syzkaller.appspot.com/x/.config?x=4e9585407e09f75f
dashboard link: https://syzkaller.appspot.com/bug?extid=1ee0910eca9c94f71f25
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch: https://syzkaller.appspot.com/x/patch.diff?x=16c1baa1700000

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