[v5.15] possible deadlock in __mod_timer

0 views
Skip to first unread message

syzbot

unread,
Apr 8, 2024, 11:59:33 AMApr 8
to syzkaller...@googlegroups.com
Hello,

syzbot found the following issue on:

HEAD commit: 9465fef4ae35 Linux 5.15.153
git tree: linux-5.15.y
console output: https://syzkaller.appspot.com/x/log.txt?x=118e81d3180000
kernel config: https://syzkaller.appspot.com/x/.config?x=176c746ee3348b33
dashboard link: https://syzkaller.appspot.com/bug?extid=77d73d9fcc34bdd32b00
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

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

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/2962c02652ce/disk-9465fef4.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/d0f5a1ce082d/vmlinux-9465fef4.xz
kernel image: https://storage.googleapis.com/syzbot-assets/86b5b1eea636/bzImage-9465fef4.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+77d73d...@syzkaller.appspotmail.com

------------[ cut here ]------------
======================================================
WARNING: possible circular locking dependency detected
5.15.153-syzkaller #0 Not tainted
------------------------------------------------------
kworker/1:9/3595 is trying to acquire lock:
ffffffff8c7fbf78 ((console_sem).lock){..-.}-{2:2}, at: down_trylock+0x1c/0xa0 kernel/locking/semaphore.c:138

but task is already holding lock:
ffff8880b9b28098 (&base->lock){-.-.}-{2:2}, at: __mod_timer+0x772/0xeb0 kernel/time/timer.c:1043

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&base->lock){-.-.}-{2:2}:
lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
lock_timer_base+0x120/0x260 kernel/time/timer.c:946
__mod_timer+0x1d6/0xeb0 kernel/time/timer.c:1019
queue_delayed_work_on+0x156/0x250 kernel/workqueue.c:1715
psi_enqueue kernel/sched/stats.h:104 [inline]
enqueue_task+0x2fe/0x3a0 kernel/sched/core.c:1973
activate_task kernel/sched/core.c:2005 [inline]
wake_up_new_task+0x515/0xb60 kernel/sched/core.c:4522
kernel_clone+0x44e/0x960 kernel/fork.c:2628
kernel_thread+0x168/0x1e0 kernel/fork.c:2656
rest_init+0x21/0x330 init/main.c:704
start_kernel+0x48c/0x535 init/main.c:1138
secondary_startup_64_no_verify+0xb1/0xbb

-> #2 (&rq->__lock){-.-.}-{2:2}:
lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
_raw_spin_lock_nested+0x2d/0x40 kernel/locking/spinlock.c:368
raw_spin_rq_lock_nested+0x26/0x140 kernel/sched/core.c:475
raw_spin_rq_lock kernel/sched/sched.h:1326 [inline]
rq_lock kernel/sched/sched.h:1621 [inline]
task_fork_fair+0x5d/0x350 kernel/sched/fair.c:11480
sched_cgroup_fork+0x2d3/0x330 kernel/sched/core.c:4466
copy_process+0x224a/0x3ef0 kernel/fork.c:2320
kernel_clone+0x210/0x960 kernel/fork.c:2604
kernel_thread+0x168/0x1e0 kernel/fork.c:2656
rest_init+0x21/0x330 init/main.c:704
start_kernel+0x48c/0x535 init/main.c:1138
secondary_startup_64_no_verify+0xb1/0xbb

-> #1 (&p->pi_lock){-.-.}-{2:2}:
lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
try_to_wake_up+0xae/0x1300 kernel/sched/core.c:4030
up+0x6e/0x90 kernel/locking/semaphore.c:190
__up_console_sem+0x11a/0x1e0 kernel/printk/printk.c:256
console_unlock+0x1145/0x12b0 kernel/printk/printk.c:2754
vprintk_emit+0xbf/0x150 kernel/printk/printk.c:2268
_printk+0xd1/0x111 kernel/printk/printk.c:2293
kauditd_printk_skb kernel/audit.c:549 [inline]
kauditd_hold_skb+0x1b5/0x200 kernel/audit.c:584
kauditd_send_queue+0x2a3/0x2f0 kernel/audit.c:769
kauditd_thread+0x6fb/0xae0 kernel/audit.c:893
kthread+0x3f6/0x4f0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298

-> #0 ((console_sem).lock){..-.}-{2:2}:
check_prev_add kernel/locking/lockdep.c:3053 [inline]
check_prevs_add kernel/locking/lockdep.c:3172 [inline]
validate_chain+0x1649/0x5930 kernel/locking/lockdep.c:3788
__lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5012
lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
down_trylock+0x1c/0xa0 kernel/locking/semaphore.c:138
__down_trylock_console_sem+0x105/0x250 kernel/printk/printk.c:239
console_trylock kernel/printk/printk.c:2569 [inline]
console_trylock_spinning+0x8a/0x3f0 kernel/printk/printk.c:1867
vprintk_emit+0xa6/0x150 kernel/printk/printk.c:2267
_printk+0xd1/0x111 kernel/printk/printk.c:2293
report_bug+0x1e5/0x2e0 lib/bug.c:195
handle_bug+0x3d/0x70 arch/x86/kernel/traps.c:239
exc_invalid_op+0x16/0x40 arch/x86/kernel/traps.c:259
asm_exc_invalid_op+0x16/0x20 arch/x86/include/asm/idtentry.h:566
copy_from_user_nofault+0x15c/0x1c0
bpf_probe_read_user_common kernel/trace/bpf_trace.c:157 [inline]
____bpf_probe_read_user kernel/trace/bpf_trace.c:166 [inline]
bpf_probe_read_user+0x26/0x70 kernel/trace/bpf_trace.c:163
bpf_prog_7ea3c0fa2e27f655+0x37/0xb60
bpf_dispatcher_nop_func include/linux/bpf.h:785 [inline]
__bpf_prog_run include/linux/filter.h:628 [inline]
bpf_prog_run include/linux/filter.h:635 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:1880 [inline]
bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1918
trace_timer_start include/trace/events/timer.h:52 [inline]
enqueue_timer+0x3ae/0x540 kernel/time/timer.c:586
__mod_timer+0x9ca/0xeb0 kernel/time/timer.c:1060
mod_peer_timer+0x158/0x220 drivers/net/wireguard/timers.c:37
wg_packet_consume_data_done drivers/net/wireguard/receive.c:361 [inline]
wg_packet_rx_poll+0xd8f/0x2130 drivers/net/wireguard/receive.c:481
__napi_poll+0xc7/0x440 net/core/dev.c:7035
napi_poll net/core/dev.c:7102 [inline]
net_rx_action+0x617/0xda0 net/core/dev.c:7192
__do_softirq+0x3b3/0x93a kernel/softirq.c:558
do_softirq+0x162/0x240 kernel/softirq.c:459
__local_bh_enable_ip+0x1b1/0x1f0 kernel/softirq.c:383
spin_unlock_bh include/linux/spinlock.h:408 [inline]
ptr_ring_consume_bh include/linux/ptr_ring.h:367 [inline]
wg_packet_decrypt_worker+0xd49/0xde0 drivers/net/wireguard/receive.c:506
process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
kthread+0x3f6/0x4f0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298

other info that might help us debug this:

Chain exists of:
(console_sem).lock --> &rq->__lock --> &base->lock

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&base->lock);
lock(&rq->__lock);
lock(&base->lock);
lock((console_sem).lock);

*** DEADLOCK ***

5 locks held by kworker/1:9/3595:
#0: ffff888060367138 ((wq_completion)wg-crypt-wg1#5){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
#1: ffffc900032c7d20 ((work_completion)(&({ do { const void *__vpp_verify = (typeof((worker) + 0))((void *)0); (void)__vpp_verify; } while (0); ({ unsigned long __ptr; __ptr = (unsigned long) ((typeof(*((worker))) *)((worker))); (typeof((typeof(*((worker))) *)((worker)))) (__ptr + (((__per_cpu_offset[(cpu)])))); }); })->work)){+.+.}-{0:0}, at: process_one_work+0x7d0/0x10c0 kernel/workqueue.c:2285
#2: ffffffff8c91f780 (rcu_read_lock_bh){....}-{1:2}, at: rcu_lock_acquire+0x5/0x30 include/linux/rcupdate.h:311
#3: ffff8880b9b28098 (&base->lock){-.-.}-{2:2}, at: __mod_timer+0x772/0xeb0 kernel/time/timer.c:1043
#4: ffffffff8c91f720 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x5/0x30 include/linux/rcupdate.h:311

stack backtrace:
CPU: 1 PID: 3595 Comm: kworker/1:9 Not tainted 5.15.153-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Workqueue: wg-crypt-wg1 wg_packet_decrypt_worker
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
check_noncircular+0x2f8/0x3b0 kernel/locking/lockdep.c:2133
check_prev_add kernel/locking/lockdep.c:3053 [inline]
check_prevs_add kernel/locking/lockdep.c:3172 [inline]
validate_chain+0x1649/0x5930 kernel/locking/lockdep.c:3788
__lock_acquire+0x1295/0x1ff0 kernel/locking/lockdep.c:5012
lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
down_trylock+0x1c/0xa0 kernel/locking/semaphore.c:138
__down_trylock_console_sem+0x105/0x250 kernel/printk/printk.c:239
console_trylock kernel/printk/printk.c:2569 [inline]
console_trylock_spinning+0x8a/0x3f0 kernel/printk/printk.c:1867
vprintk_emit+0xa6/0x150 kernel/printk/printk.c:2267
_printk+0xd1/0x111 kernel/printk/printk.c:2293
report_bug+0x1e5/0x2e0 lib/bug.c:195
handle_bug+0x3d/0x70 arch/x86/kernel/traps.c:239
exc_invalid_op+0x16/0x40 arch/x86/kernel/traps.c:259
asm_exc_invalid_op+0x16/0x20 arch/x86/include/asm/idtentry.h:566
RIP: 0010:copy_from_user_nofault+0x15c/0x1c0 mm/maccess.c:226
Code: db 48 c7 c0 f2 ff ff ff 48 0f 44 c5 eb 0c e8 6b dc d5 ff 48 c7 c0 f2 ff ff ff 5b 41 5c 41 5d 41 5e 41 5f 5d c3 e8 54 dc d5 ff <0f> 0b e9 1e ff ff ff 89 d9 80 e1 07 80 c1 03 38 c1 0f 8c ef fe ff
RSP: 0018:ffffc90000dd0788 EFLAGS: 00010046
RAX: ffffffff81aa5d5c RBX: 0000000000000000 RCX: ffff88801917d940
RDX: 0000000080000303 RSI: 0000000000000000 RDI: 0000000000000000
RBP: dffffc0000000000 R08: ffffffff81aa5c6d R09: fffffbfff1f7a019
R10: 0000000000000000 R11: dffffc0000000001 R12: ffffffffe5000000
R13: 0000000000000000 R14: ffffffffe5000000 R15: ffffc90000dd07e8
bpf_probe_read_user_common kernel/trace/bpf_trace.c:157 [inline]
____bpf_probe_read_user kernel/trace/bpf_trace.c:166 [inline]
bpf_probe_read_user+0x26/0x70 kernel/trace/bpf_trace.c:163
bpf_prog_7ea3c0fa2e27f655+0x37/0xb60
bpf_dispatcher_nop_func include/linux/bpf.h:785 [inline]
__bpf_prog_run include/linux/filter.h:628 [inline]
bpf_prog_run include/linux/filter.h:635 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:1880 [inline]
bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1918
trace_timer_start include/trace/events/timer.h:52 [inline]
enqueue_timer+0x3ae/0x540 kernel/time/timer.c:586
__mod_timer+0x9ca/0xeb0 kernel/time/timer.c:1060
mod_peer_timer+0x158/0x220 drivers/net/wireguard/timers.c:37
wg_packet_consume_data_done drivers/net/wireguard/receive.c:361 [inline]
wg_packet_rx_poll+0xd8f/0x2130 drivers/net/wireguard/receive.c:481
__napi_poll+0xc7/0x440 net/core/dev.c:7035
napi_poll net/core/dev.c:7102 [inline]
net_rx_action+0x617/0xda0 net/core/dev.c:7192
__do_softirq+0x3b3/0x93a kernel/softirq.c:558
do_softirq+0x162/0x240 kernel/softirq.c:459
</IRQ>
<TASK>
__local_bh_enable_ip+0x1b1/0x1f0 kernel/softirq.c:383
spin_unlock_bh include/linux/spinlock.h:408 [inline]
ptr_ring_consume_bh include/linux/ptr_ring.h:367 [inline]
wg_packet_decrypt_worker+0xd49/0xde0 drivers/net/wireguard/receive.c:506
process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
kthread+0x3f6/0x4f0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</TASK>
WARNING: CPU: 1 PID: 3595 at mm/maccess.c:226 copy_from_user_nofault+0x15c/0x1c0
Modules linked in:
CPU: 1 PID: 3595 Comm: kworker/1:9 Not tainted 5.15.153-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Workqueue: wg-crypt-wg1 wg_packet_decrypt_worker
RIP: 0010:copy_from_user_nofault+0x15c/0x1c0 mm/maccess.c:226
Code: db 48 c7 c0 f2 ff ff ff 48 0f 44 c5 eb 0c e8 6b dc d5 ff 48 c7 c0 f2 ff ff ff 5b 41 5c 41 5d 41 5e 41 5f 5d c3 e8 54 dc d5 ff <0f> 0b e9 1e ff ff ff 89 d9 80 e1 07 80 c1 03 38 c1 0f 8c ef fe ff
RSP: 0018:ffffc90000dd0788 EFLAGS: 00010046
RAX: ffffffff81aa5d5c RBX: 0000000000000000 RCX: ffff88801917d940
RDX: 0000000080000303 RSI: 0000000000000000 RDI: 0000000000000000
RBP: dffffc0000000000 R08: ffffffff81aa5c6d R09: fffffbfff1f7a019
R10: 0000000000000000 R11: dffffc0000000001 R12: ffffffffe5000000
R13: 0000000000000000 R14: ffffffffe5000000 R15: ffffc90000dd07e8
FS: 0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001b2f225000 CR3: 000000006248c000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<IRQ>
bpf_probe_read_user_common kernel/trace/bpf_trace.c:157 [inline]
____bpf_probe_read_user kernel/trace/bpf_trace.c:166 [inline]
bpf_probe_read_user+0x26/0x70 kernel/trace/bpf_trace.c:163
bpf_prog_7ea3c0fa2e27f655+0x37/0xb60
bpf_dispatcher_nop_func include/linux/bpf.h:785 [inline]
__bpf_prog_run include/linux/filter.h:628 [inline]
bpf_prog_run include/linux/filter.h:635 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:1880 [inline]
bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1918
trace_timer_start include/trace/events/timer.h:52 [inline]
enqueue_timer+0x3ae/0x540 kernel/time/timer.c:586
__mod_timer+0x9ca/0xeb0 kernel/time/timer.c:1060
mod_peer_timer+0x158/0x220 drivers/net/wireguard/timers.c:37
wg_packet_consume_data_done drivers/net/wireguard/receive.c:361 [inline]
wg_packet_rx_poll+0xd8f/0x2130 drivers/net/wireguard/receive.c:481
__napi_poll+0xc7/0x440 net/core/dev.c:7035
napi_poll net/core/dev.c:7102 [inline]
net_rx_action+0x617/0xda0 net/core/dev.c:7192
__do_softirq+0x3b3/0x93a kernel/softirq.c:558
do_softirq+0x162/0x240 kernel/softirq.c:459
</IRQ>
<TASK>
__local_bh_enable_ip+0x1b1/0x1f0 kernel/softirq.c:383
spin_unlock_bh include/linux/spinlock.h:408 [inline]
ptr_ring_consume_bh include/linux/ptr_ring.h:367 [inline]
wg_packet_decrypt_worker+0xd49/0xde0 drivers/net/wireguard/receive.c:506
process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
kthread+0x3f6/0x4f0 kernel/kthread.c:319
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
</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 syzk...@googlegroups.com.

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

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup
Reply all
Reply to author
Forward
0 new messages