syzbot


possible deadlock in __mod_timer (2)

Status: upstream: reported on 2024/08/11 05:04
Reported-by: syzbot+1e175fa5b198b9e3206f@syzkaller.appspotmail.com
First crash: 102d, last: 18d
Similar bugs (4)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in __mod_timer (4) bpf trace C 4 49d 60d 0/28 upstream: reported C repro on 2024/09/22 06:39
upstream possible deadlock in __mod_timer kernel 35 712d 785d 0/28 auto-obsoleted due to no activity on 2023/04/09 11:04
linux-5.15 possible deadlock in __mod_timer 4 208d 227d 0/3 auto-obsoleted due to no activity on 2024/08/05 08:07
upstream possible deadlock in __mod_timer (2) kernel 1 561d 560d 22/28 fixed on 2023/07/01 16:05

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

but task is already holding lock:
ffff8880b9128098 (&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:1970
       activate_task kernel/sched/core.c:2002 [inline]
       wake_up_new_task+0x515/0xb60 kernel/sched/core.c:4519
       kernel_clone+0x44e/0x960 kernel/fork.c:2625
       kernel_thread+0x168/0x1e0 kernel/fork.c:2653
       rest_init+0x21/0x330 init/main.c:706
       start_kernel+0x48c/0x540 init/main.c:1140
       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:11484
       sched_cgroup_fork+0x2d3/0x330 kernel/sched/core.c:4463
       copy_process+0x224a/0x3ef0 kernel/fork.c:2317
       kernel_clone+0x210/0x960 kernel/fork.c:2601
       kernel_thread+0x168/0x1e0 kernel/fork.c:2653
       rest_init+0x21/0x330 init/main.c:706
       start_kernel+0x48c/0x540 init/main.c:1140
       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:4027
       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:2760
       vprintk_emit+0xbf/0x150 kernel/printk/printk.c:2274
       dev_vprintk_emit+0x2aa/0x330 drivers/base/core.c:4621
       dev_printk_emit+0xd9/0x120 drivers/base/core.c:4632
       _dev_info+0x11e/0x170 drivers/base/core.c:4690
       usb_get_langid drivers/usb/core/message.c:935 [inline]
       usb_string+0x487/0x790 drivers/usb/core/message.c:983
       usb_cache_string+0x79/0xf0 drivers/usb/core/message.c:1029
       usb_set_configuration+0x188c/0x2020 drivers/usb/core/message.c:2137
       usb_generic_driver_probe+0x84/0x140 drivers/usb/core/generic.c:238
       usb_probe_device+0x130/0x260 drivers/usb/core/driver.c:293
       really_probe+0x24e/0xb60 drivers/base/dd.c:595
       __driver_probe_device+0x1a2/0x3d0 drivers/base/dd.c:755
       driver_probe_device+0x50/0x420 drivers/base/dd.c:785
       __device_attach_driver+0x2b9/0x500 drivers/base/dd.c:907
       bus_for_each_drv+0x183/0x200 drivers/base/bus.c:429
       __device_attach+0x359/0x570 drivers/base/dd.c:979
       bus_probe_device+0xba/0x1e0 drivers/base/bus.c:489
       device_add+0xb48/0xfd0 drivers/base/core.c:3415
       usb_new_device+0xc17/0x18e0 drivers/usb/core/hub.c:2593
       hub_port_connect drivers/usb/core/hub.c:5455 [inline]
       hub_port_connect_change drivers/usb/core/hub.c:5595 [inline]
       port_event drivers/usb/core/hub.c:5741 [inline]
       hub_event+0x2cdf/0x54c0 drivers/usb/core/hub.c:5823
       process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
       worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
       kthread+0x3f6/0x4f0 kernel/kthread.c:334
       ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:287

-> #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:2575 [inline]
       console_trylock_spinning+0x8a/0x3f0 kernel/printk/printk.c:1867
       vprintk_emit+0xa6/0x150 kernel/printk/printk.c:2273
       _printk+0xd1/0x120 kernel/printk/printk.c:2299
       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:604
       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_1e8b16acb1dbd232+0x42/0xd34
       bpf_dispatcher_nop_func include/linux/bpf.h:790 [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:1878 [inline]
       bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1916
       __traceiter_timer_start+0x79/0xd0 include/trace/events/timer.h:52
       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:7039
       napi_poll net/core/dev.c:7106 [inline]
       net_rx_action+0x617/0xda0 net/core/dev.c:7196
       handle_softirqs+0x3a7/0x930 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:334
       ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:287

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:2/1107:
 #0: ffff888064234538 ((wq_completion)wg-crypt-wg2#4){+.+.}-{0:0}, at: process_one_work+0x78a/0x10c0 kernel/workqueue.c:2283
 #1: ffffc900042f7d20 ((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: ffffffff8c91fcc0 (rcu_read_lock_bh){....}-{1:2}, at: rcu_lock_acquire+0x5/0x30 include/linux/rcupdate.h:311
 #3: ffff8880b9128098 (&base->lock){-.-.}-{2:2}, at: __mod_timer+0x772/0xeb0 kernel/time/timer.c:1043
 #4: ffffffff8c91fc60 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x5/0x30 include/linux/rcupdate.h:311

stack backtrace:
CPU: 1 PID: 1107 Comm: kworker/1:2 Not tainted 5.15.170-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Workqueue: wg-crypt-wg2 wg_packet_decrypt_worker
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2d0 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:2575 [inline]
 console_trylock_spinning+0x8a/0x3f0 kernel/printk/printk.c:1867
 vprintk_emit+0xa6/0x150 kernel/printk/printk.c:2273
 _printk+0xd1/0x120 kernel/printk/printk.c:2299
 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:604
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 0b c7 d5 ff 48 c7 c0 f2 ff ff ff 5b 41 5c 41 5d 41 5e 41 5f 5d c3 e8 f4 c6 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:ffffc90000dd0748 EFLAGS: 00010046
RAX: ffffffff81aaaccc RBX: 0000000000000000 RCX: ffff888021323b80
RDX: 0000000000000100 RSI: 0000000000000000 RDI: 0000000000000000
RBP: dffffc0000000000 R08: ffffffff81aaabdd R09: fffffbfff20ec621
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000000
R13: 0000000000000008 R14: 0000000000000000 R15: ffffc90000dd07a8
 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_1e8b16acb1dbd232+0x42/0xd34
 bpf_dispatcher_nop_func include/linux/bpf.h:790 [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:1878 [inline]
 bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1916
 __traceiter_timer_start+0x79/0xd0 include/trace/events/timer.h:52
 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:7039
 napi_poll net/core/dev.c:7106 [inline]
 net_rx_action+0x617/0xda0 net/core/dev.c:7196
 handle_softirqs+0x3a7/0x930 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:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:287
 </TASK>
WARNING: CPU: 1 PID: 1107 at mm/maccess.c:226 copy_from_user_nofault+0x15c/0x1c0
Modules linked in:
CPU: 1 PID: 1107 Comm: kworker/1:2 Not tainted 5.15.170-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 09/13/2024
Workqueue: wg-crypt-wg2 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 0b c7 d5 ff 48 c7 c0 f2 ff ff ff 5b 41 5c 41 5d 41 5e 41 5f 5d c3 e8 f4 c6 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:ffffc90000dd0748 EFLAGS: 00010046
RAX: ffffffff81aaaccc RBX: 0000000000000000 RCX: ffff888021323b80
RDX: 0000000000000100 RSI: 0000000000000000 RDI: 0000000000000000
RBP: dffffc0000000000 R08: ffffffff81aaabdd R09: fffffbfff20ec621
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000000
R13: 0000000000000008 R14: 0000000000000000 R15: ffffc90000dd07a8
FS:  0000000000000000(0000) GS:ffff8880b9100000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000110c2c676d CR3: 000000001a7f7000 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_1e8b16acb1dbd232+0x42/0xd34
 bpf_dispatcher_nop_func include/linux/bpf.h:790 [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:1878 [inline]
 bpf_trace_run3+0x1d1/0x380 kernel/trace/bpf_trace.c:1916
 __traceiter_timer_start+0x79/0xd0 include/trace/events/timer.h:52
 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:7039
 napi_poll net/core/dev.c:7106 [inline]
 net_rx_action+0x617/0xda0 net/core/dev.c:7196
 handle_softirqs+0x3a7/0x930 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:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:287
 </TASK>

Crashes (5):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/11/03 12:30 linux-5.15.y 72244eab0dad f00eed24 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in __mod_timer
2024/10/26 10:38 linux-5.15.y 74cdd62cb470 65e8686b .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in __mod_timer
2024/10/22 02:04 linux-5.15.y 584a40a22cb9 f1e4447c .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in __mod_timer
2024/10/06 08:10 linux-5.15.y 3a5928702e71 d7906eff .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-perf possible deadlock in __mod_timer
2024/08/11 05:03 linux-5.15.y 7e89efd3ae1c 6f4edef4 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan possible deadlock in __mod_timer
* Struck through repros no longer work on HEAD.