[v6.1] possible deadlock in lock_timer_base

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: ca87e77a2ef8 Linux 6.1.34
git tree: linux-6.1.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16fb45cf280000
kernel config: https://syzkaller.appspot.com/x/.config?x=143044f84cdceac2
dashboard link: https://syzkaller.appspot.com/bug?extid=1e90d72fb78c8c8fae1d
compiler: Debian clang version 15.0.7, GNU ld (GNU Binutils for Debian) 2.35.2
userspace arch: arm64
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=1589a137280000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/1141c37ce351/disk-ca87e77a.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/de1fca0d0bb4/vmlinux-ca87e77a.xz
kernel image: https://storage.googleapis.com/syzbot-assets/c3417b70e0bf/Image-ca87e77a.gz.xz

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

============================================
WARNING: possible recursive locking detected
6.1.34-syzkaller #0 Not tainted
--------------------------------------------
kworker/u4:0/4234 is trying to acquire lock:
ffff0001b45d0758 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x108/0x214 kernel/time/timer.c:999

but task is already holding lock:
ffff0001b45b0758 (&base->lock){-.-.}-{2:2}, at: __mod_timer+0x67c/0xd30 kernel/time/timer.c:1096

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&base->lock);
lock(&base->lock);

*** DEADLOCK ***

May be due to missing lock nesting notation

3 locks held by kworker/u4:0/4234:
#0: ffff0000d51c3938 ((wq_completion)bat_events){+.+.}-{0:0}, at: process_one_work+0x664/0x1404 kernel/workqueue.c:2262
#1: ffff80001da57c20 ((work_completion)(&(&bat_priv->orig_work)->work)){+.+.}-{0:0}, at: process_one_work+0x6a8/0x1404 kernel/workqueue.c:2264
#2: ffff0001b45b0758 (&base->lock){-.-.}-{2:2}, at: __mod_timer+0x67c/0xd30 kernel/time/timer.c:1096

stack backtrace:
CPU: 0 PID: 4234 Comm: kworker/u4:0 Not tainted 6.1.34-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 05/25/2023
Workqueue: bat_events batadv_purge_orig
Call trace:
dump_backtrace+0x1c8/0x1f4 arch/arm64/kernel/stacktrace.c:158
show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:165
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x108/0x170 lib/dump_stack.c:106
dump_stack+0x1c/0x58 lib/dump_stack.c:113
__lock_acquire+0x6310/0x764c kernel/locking/lockdep.c:5056
lock_acquire+0x26c/0x7cc kernel/locking/lockdep.c:5669
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x6c/0xb4 kernel/locking/spinlock.c:162
lock_timer_base+0x108/0x214 kernel/time/timer.c:999
__mod_timer+0x1b4/0xd30 kernel/time/timer.c:1072
add_timer+0x6c/0x88 kernel/time/timer.c:1197
__queue_delayed_work kernel/workqueue.c:1676 [inline]
queue_delayed_work_on+0x1f0/0x320 kernel/workqueue.c:1701
queue_delayed_work include/linux/workqueue.h:518 [inline]
schedule_delayed_work include/linux/workqueue.h:670 [inline]
__debug_check_no_obj_freed lib/debugobjects.c:1036 [inline]
debug_check_no_obj_freed+0xc8/0x50c lib/debugobjects.c:1043
free_pages_prepare mm/page_alloc.c:1466 [inline]
free_pcp_prepare mm/page_alloc.c:1510 [inline]
free_unref_page_prepare+0x450/0x1070 mm/page_alloc.c:3388
free_unref_page+0x80/0x444 mm/page_alloc.c:3484
free_the_page mm/page_alloc.c:770 [inline]
__free_pages+0x1a0/0x1cc mm/page_alloc.c:5648
free_pages+0xa0/0xb8 mm/page_alloc.c:5659
__stack_depot_save+0x3a0/0x4dc lib/stackdepot.c:506
kasan_save_stack mm/kasan/common.c:46 [inline]
kasan_set_track+0x64/0x80 mm/kasan/common.c:52
kasan_save_alloc_info+0x24/0x30 mm/kasan/generic.c:505
__kasan_slab_alloc+0x74/0x8c mm/kasan/common.c:328
kasan_slab_alloc include/linux/kasan.h:201 [inline]
slab_post_alloc_hook+0x74/0x458 mm/slab.h:737
slab_alloc_node mm/slub.c:3398 [inline]
slab_alloc mm/slub.c:3406 [inline]
__kmem_cache_alloc_lru mm/slub.c:3413 [inline]
kmem_cache_alloc+0x230/0x37c mm/slub.c:3422
kmem_cache_zalloc include/linux/slab.h:679 [inline]
fill_pool lib/debugobjects.c:168 [inline]
debug_objects_fill_pool+0x36c/0x7d4 lib/debugobjects.c:597
debug_object_activate+0x114/0x790 lib/debugobjects.c:693
debug_timer_activate kernel/time/timer.c:782 [inline]
__mod_timer+0x830/0xd30 kernel/time/timer.c:1103
add_timer+0x6c/0x88 kernel/time/timer.c:1197
__queue_delayed_work kernel/workqueue.c:1676 [inline]
queue_delayed_work_on+0x1f0/0x320 kernel/workqueue.c:1701
queue_delayed_work include/linux/workqueue.h:518 [inline]
batadv_purge_orig+0x60/0x70 net/batman-adv/originator.c:1273
process_one_work+0x7ac/0x1404 kernel/workqueue.c:2289
worker_thread+0x8e4/0xfec kernel/workqueue.c:2436
kthread+0x250/0x2d8 kernel/kthread.c:376
ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:860


---
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 bug is already fixed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.

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

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

If you want to undo deduplication, reply with:
#syz undup

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: d7543167affd Linux 6.1.82
git tree: linux-6.1.y
console output: https://syzkaller.appspot.com/x/log.txt?x=1310b9f1180000
kernel config: https://syzkaller.appspot.com/x/.config?x=59059e181681c079
dashboard link: https://syzkaller.appspot.com/bug?extid=1e90d72fb78c8c8fae1d
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=11ba66be180000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=15a0eaa5180000

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/a2421980b49a/disk-d7543167.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/52a6bb44161f/vmlinux-d7543167.xz
kernel image: https://storage.googleapis.com/syzbot-assets/9b3723bf43a9/bzImage-d7543167.xz

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

=====================================================
WARNING: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected
6.1.82-syzkaller #0 Not tainted
-----------------------------------------------------
kworker/1:1/26 [HC0[0]:SC0[2]:HE0:SE0] is trying to acquire:
ffff8880146e0820 (&htab->buckets[i].lock){+...}-{2:2}, at: sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932

and this task is already holding:
ffff8880b9928358 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x120/0x260 kernel/time/timer.c:999
which would create a new lock dependency:
(&base->lock){-.-.}-{2:2} -> (&htab->buckets[i].lock){+...}-{2:2}

but this new dependency connects a HARDIRQ-irq-safe lock:

(&base->lock){-.-.}-{2:2}

... which became HARDIRQ-irq-safe at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__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:999
add_timer_on+0x1eb/0x580 kernel/time/timer.c:1222
handle_irq_event_percpu kernel/irq/handle.c:195 [inline]
handle_irq_event+0xa9/0x1e0 kernel/irq/handle.c:210
handle_edge_irq+0x245/0xbf0 kernel/irq/chip.c:819
generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
handle_irq arch/x86/kernel/irq.c:231 [inline]
__common_interrupt+0xd7/0x1f0 arch/x86/kernel/irq.c:250
common_interrupt+0x9f/0xc0 arch/x86/kernel/irq.c:240
asm_common_interrupt+0x22/0x40 arch/x86/include/asm/idtentry.h:644
console_emit_next_record+0xc69/0xea0 kernel/printk/printk.c:2751
console_unlock+0x278/0x7c0 kernel/printk/printk.c:2871
vprintk_emit+0x523/0x740 kernel/printk/printk.c:2268
_printk+0xd1/0x111 kernel/printk/printk.c:2293
cpu_select_mitigations+0x38/0x8f arch/x86/kernel/cpu/bugs.c:147
arch_cpu_finalize_init+0xf/0x81 arch/x86/kernel/cpu/common.c:2446
start_kernel+0x423/0x53f init/main.c:1105
secondary_startup_64_no_verify+0xcf/0xdb

to a HARDIRQ-irq-unsafe lock:
(&htab->buckets[i].lock){+...}-{2:2}

... which became HARDIRQ-irq-unsafe at:
...
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_bh+0x31/0x40 kernel/locking/spinlock.c:178
sock_hash_free+0x160/0x820 net/core/sock_map.c:1149
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:307

other info that might help us debug this:

Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&htab->buckets[i].lock);
local_irq_disable();
lock(&base->lock);
lock(&htab->buckets[i].lock);
<Interrupt>

lock(&base->lock);

*** DEADLOCK ***

4 locks held by kworker/1:1/26:
#0: ffff888012472138 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x7a9/0x11d0 kernel/workqueue.c:2267
#1: ffffc90000a1fd20 ((work_completion)(&rew->rew_work)){+.+.}-{0:0}, at: process_one_work+0x7a9/0x11d0 kernel/workqueue.c:2267
#2: ffff8880b9928358 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x120/0x260 kernel/time/timer.c:999
#3: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:319 [inline]
#3: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:760 [inline]
#3: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: __bpf_trace_run kernel/trace/bpf_trace.c:2272 [inline]
#3: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: bpf_trace_run3+0x146/0x440 kernel/trace/bpf_trace.c:2313

the dependencies between HARDIRQ-irq-safe lock and the holding lock:
-> (&base->lock){-.-.}-{2:2} {
IN-HARDIRQ-W at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__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:999
add_timer_on+0x1eb/0x580 kernel/time/timer.c:1222
handle_irq_event_percpu kernel/irq/handle.c:195 [inline]
handle_irq_event+0xa9/0x1e0 kernel/irq/handle.c:210
handle_edge_irq+0x245/0xbf0 kernel/irq/chip.c:819
generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
handle_irq arch/x86/kernel/irq.c:231 [inline]
__common_interrupt+0xd7/0x1f0 arch/x86/kernel/irq.c:250
common_interrupt+0x9f/0xc0 arch/x86/kernel/irq.c:240
asm_common_interrupt+0x22/0x40 arch/x86/include/asm/idtentry.h:644
console_emit_next_record+0xc69/0xea0 kernel/printk/printk.c:2751
console_unlock+0x278/0x7c0 kernel/printk/printk.c:2871
vprintk_emit+0x523/0x740 kernel/printk/printk.c:2268
_printk+0xd1/0x111 kernel/printk/printk.c:2293
cpu_select_mitigations+0x38/0x8f arch/x86/kernel/cpu/bugs.c:147
arch_cpu_finalize_init+0xf/0x81 arch/x86/kernel/cpu/common.c:2446
start_kernel+0x423/0x53f init/main.c:1105
secondary_startup_64_no_verify+0xcf/0xdb
IN-SOFTIRQ-W at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_irq include/linux/spinlock_api_smp.h:119 [inline]
_raw_spin_lock_irq+0xcf/0x110 kernel/locking/spinlock.c:170
__run_timers+0x111/0x890 kernel/time/timer.c:1772
run_timer_softirq+0x63/0xf0 kernel/time/timer.c:1803
__do_softirq+0x2e9/0xa4c kernel/softirq.c:571
invoke_softirq kernel/softirq.c:445 [inline]
__irq_exit_rcu+0x155/0x240 kernel/softirq.c:650
irq_exit_rcu+0x5/0x20 kernel/softirq.c:662
common_interrupt+0xa4/0xc0 arch/x86/kernel/irq.c:240
asm_common_interrupt+0x22/0x40 arch/x86/include/asm/idtentry.h:644
console_emit_next_record+0xc69/0xea0 kernel/printk/printk.c:2751
console_unlock+0x278/0x7c0 kernel/printk/printk.c:2871
vprintk_emit+0x523/0x740 kernel/printk/printk.c:2268
_printk+0xd1/0x111 kernel/printk/printk.c:2293
md_clear_update_mitigation+0x3ac/0x4aa arch/x86/kernel/cpu/bugs.c:575
cpu_select_mitigations+0x56/0x8f arch/x86/kernel/cpu/bugs.c:163
arch_cpu_finalize_init+0xf/0x81 arch/x86/kernel/cpu/common.c:2446
start_kernel+0x423/0x53f init/main.c:1105
secondary_startup_64_no_verify+0xcf/0xdb
INITIAL USE at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__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:999
add_timer_on+0x1eb/0x580 kernel/time/timer.c:1222
handle_irq_event_percpu kernel/irq/handle.c:195 [inline]
handle_irq_event+0xa9/0x1e0 kernel/irq/handle.c:210
handle_edge_irq+0x245/0xbf0 kernel/irq/chip.c:819
generic_handle_irq_desc include/linux/irqdesc.h:158 [inline]
handle_irq arch/x86/kernel/irq.c:231 [inline]
__common_interrupt+0xd7/0x1f0 arch/x86/kernel/irq.c:250
common_interrupt+0x9f/0xc0 arch/x86/kernel/irq.c:240
asm_common_interrupt+0x22/0x40 arch/x86/include/asm/idtentry.h:644
console_emit_next_record+0xc69/0xea0 kernel/printk/printk.c:2751
console_unlock+0x278/0x7c0 kernel/printk/printk.c:2871
vprintk_emit+0x523/0x740 kernel/printk/printk.c:2268
_printk+0xd1/0x111 kernel/printk/printk.c:2293
cpu_select_mitigations+0x38/0x8f arch/x86/kernel/cpu/bugs.c:147
arch_cpu_finalize_init+0xf/0x81 arch/x86/kernel/cpu/common.c:2446
start_kernel+0x423/0x53f init/main.c:1105
secondary_startup_64_no_verify+0xcf/0xdb
}
... key at: [<ffffffff91cd3480>] init_timer_cpu.__key+0x0/0x20

the dependencies between the lock to be acquired
and HARDIRQ-irq-unsafe lock:
-> (&htab->buckets[i].lock){+...}-{2:2} {
HARDIRQ-ON-W at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_bh+0x31/0x40 kernel/locking/spinlock.c:178
sock_hash_free+0x160/0x820 net/core/sock_map.c:1149
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:307
INITIAL USE at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_bh+0x31/0x40 kernel/locking/spinlock.c:178
sock_hash_free+0x160/0x820 net/core/sock_map.c:1149
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:307
}
... key at: [<ffffffff920af300>] sock_hash_alloc.__key+0x0/0x20
... acquired at:
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_bh+0x31/0x40 kernel/locking/spinlock.c:178
sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932
bpf_prog_2c29ac5cdc6b1842+0x3a/0x3e
bpf_dispatcher_nop_func include/linux/bpf.h:989 [inline]
__bpf_prog_run include/linux/filter.h:600 [inline]
bpf_prog_run include/linux/filter.h:607 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:2273 [inline]
bpf_trace_run3+0x231/0x440 kernel/trace/bpf_trace.c:2313
trace_timer_start include/trace/events/timer.h:53 [inline]
enqueue_timer+0x440/0x600 kernel/time/timer.c:609
__mod_timer+0x92b/0xee0
schedule_timeout+0x1b4/0x300 kernel/time/timer.c:1934
synchronize_rcu_expedited_wait_once kernel/rcu/tree_exp.h:570 [inline]
synchronize_rcu_expedited_wait kernel/rcu/tree_exp.h:621 [inline]
rcu_exp_wait_wake kernel/rcu/tree_exp.h:689 [inline]
rcu_exp_sel_wait_wake+0x764/0x1d50 kernel/rcu/tree_exp.h:723
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:307


stack backtrace:
CPU: 1 PID: 26 Comm: kworker/1:1 Not tainted 6.1.82-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Workqueue: rcu_gp wait_rcu_exp_gp
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
print_bad_irq_dependency kernel/locking/lockdep.c:2604 [inline]
check_irq_usage kernel/locking/lockdep.c:2843 [inline]
check_prev_add kernel/locking/lockdep.c:3094 [inline]
check_prevs_add kernel/locking/lockdep.c:3209 [inline]
validate_chain+0x4d16/0x5950 kernel/locking/lockdep.c:3825
__lock_acquire+0x125b/0x1f80 kernel/locking/lockdep.c:5049
lock_acquire+0x1f8/0x5a0 kernel/locking/lockdep.c:5662
__raw_spin_lock_bh include/linux/spinlock_api_smp.h:126 [inline]
_raw_spin_lock_bh+0x31/0x40 kernel/locking/spinlock.c:178
sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932
bpf_prog_2c29ac5cdc6b1842+0x3a/0x3e
bpf_dispatcher_nop_func include/linux/bpf.h:989 [inline]
__bpf_prog_run include/linux/filter.h:600 [inline]
bpf_prog_run include/linux/filter.h:607 [inline]
__bpf_trace_run kernel/trace/bpf_trace.c:2273 [inline]
bpf_trace_run3+0x231/0x440 kernel/trace/bpf_trace.c:2313
trace_timer_start include/trace/events/timer.h:53 [inline]
enqueue_timer+0x440/0x600 kernel/time/timer.c:609
__mod_timer+0x92b/0xee0
schedule_timeout+0x1b4/0x300 kernel/time/timer.c:1934
synchronize_rcu_expedited_wait_once kernel/rcu/tree_exp.h:570 [inline]
synchronize_rcu_expedited_wait kernel/rcu/tree_exp.h:621 [inline]
rcu_exp_wait_wake kernel/rcu/tree_exp.h:689 [inline]
rcu_exp_sel_wait_wake+0x764/0x1d50 kernel/rcu/tree_exp.h:723
process_one_work+0x8a9/0x11d0 kernel/workqueue.c:2292
worker_thread+0xa47/0x1200 kernel/workqueue.c:2439
kthread+0x28d/0x320 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:307
</TASK>


---