syzbot


possible deadlock in lock_timer_base

Status: upstream: reported syz repro on 2023/05/25 21:57
Bug presence: origin:lts-only
[Documentation on labels]
Reported-by: syzbot+557afc3253b6c451257a@syzkaller.appspotmail.com
First crash: 189d, last: 180d
Fix bisection: failed (error log, bisect log)
  
Bug presence (2)
Date Name Commit Repro Result
2023/05/26 linux-5.15.y (ToT) 1fe619a7d252 C [report] possible deadlock in lock_timer_base
2023/05/26 upstream (ToT) 0d85b27b0cc6 C Didn't crash
Similar bugs (2)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 possible deadlock in lock_timer_base origin:lts-only syz inconclusive 3 36d 166d 0/3 upstream: reported syz repro on 2023/06/17 18:14
upstream possible deadlock in lock_timer_base batman 14 177d 1062d 1/25 upstream: reported on 2021/01/03 06:59
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2023/10/30 17:37 0m fix candidate upstream error job log (0)
2023/10/14 07:00 0m bisect fix linux-5.15.y error job log (0)

Sample crash report:
FAULT_INJECTION: forcing a failure.
name failslab, interval 1, probability 0, space 0, times 0
======================================================
WARNING: possible circular locking dependency detected
5.15.113-syzkaller #0 Not tainted
------------------------------------------------------
syz-executor.0/4086 is trying to acquire lock:
ffff80001498f7f8 ((console_sem).lock){....}-{2:2}, at: down_trylock+0x28/0xd8 kernel/locking/semaphore.c:138

but task is already holding lock:
ffff0001b47fc498 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x108/0x214 kernel/time/timer.c:946

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&base->lock){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0xc4/0x14c kernel/locking/spinlock.c:162
       lock_timer_base+0x108/0x214 kernel/time/timer.c:946
       __mod_timer+0x1b4/0xd30 kernel/time/timer.c:1019
       add_timer+0x6c/0x88 kernel/time/timer.c:1144
       __queue_delayed_work kernel/workqueue.c:1687 [inline]
       queue_delayed_work_on+0x1f4/0x330 kernel/workqueue.c:1712
       queue_delayed_work include/linux/workqueue.h:517 [inline]
       schedule_delayed_work include/linux/workqueue.h:621 [inline]
       psi_group_change+0xd50/0x12a0 kernel/sched/psi.c:758
       psi_task_change+0x1dc/0x2e8 kernel/sched/psi.c:826
       psi_enqueue kernel/sched/stats.h:104 [inline]
       enqueue_task kernel/sched/core.c:1973 [inline]
       activate_task+0x268/0x2d0 kernel/sched/core.c:2005
       wake_up_new_task+0x314/0x964 kernel/sched/core.c:4518
       kernel_clone+0x47c/0xa58 kernel/fork.c:2625
       kernel_thread+0x148/0x1bc kernel/fork.c:2653
       rest_init+0x2c/0x38c init/main.c:701
       arch_call_rest_init+0x14/0x20 init/main.c:889
       start_kernel+0x444/0x604 init/main.c:1144
       __primary_switched+0xa8/0xb0 arch/arm64/kernel/head.S:468

-> #2 (&rq->__lock){-.-.}-{2:2}:
       _raw_spin_lock_nested+0xb4/0x110 kernel/locking/spinlock.c:368
       raw_spin_rq_lock_nested+0x2c/0x44 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+0x7c/0x23c kernel/sched/fair.c:11494
       sched_cgroup_fork+0x334/0x3d8 kernel/sched/core.c:4462
       copy_process+0x24d4/0x3750 kernel/fork.c:2312
       kernel_clone+0x1d8/0xa58 kernel/fork.c:2601
       kernel_thread+0x148/0x1bc kernel/fork.c:2653
       rest_init+0x2c/0x38c init/main.c:701
       arch_call_rest_init+0x14/0x20 init/main.c:889
       start_kernel+0x444/0x604 init/main.c:1144
       __primary_switched+0xa8/0xb0 arch/arm64/kernel/head.S:468

-> #1 (&p->pi_lock){-.-.}-{2:2}:
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0xc4/0x14c kernel/locking/spinlock.c:162
       try_to_wake_up+0xb0/0xc2c kernel/sched/core.c:4026
       wake_up_process+0x18/0x24 kernel/sched/core.c:4211
       __up+0x11c/0x148 kernel/locking/semaphore.c:265
       up+0x90/0xb0 kernel/locking/semaphore.c:190
       __up_console_sem+0x8c/0x100 kernel/printk/printk.c:256
       console_unlock+0x1160/0x1394 kernel/printk/printk.c:2750
       vprintk_emit+0x13c/0x218 kernel/printk/printk.c:2268
       vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2279
       vprintk+0x218/0x2f0 kernel/printk/printk_safe.c:50
       _printk+0xdc/0x128 kernel/printk/printk.c:2289
       addrconf_notify+0x9e8/0xc58 net/ipv6/addrconf.c:3632
       notifier_call_chain kernel/notifier.c:83 [inline]
       raw_notifier_call_chain+0xd4/0x164 kernel/notifier.c:391
       call_netdevice_notifiers_info net/core/dev.c:1998 [inline]
       netdev_state_change+0x180/0x22c net/core/dev.c:1389
       linkwatch_do_dev+0x2b0/0x3c8 net/core/link_watch.c:167
       __linkwatch_run_queue+0x424/0x730 net/core/link_watch.c:213
       linkwatch_event+0x58/0x68 net/core/link_watch.c:252
       process_one_work+0x790/0x11b8 kernel/workqueue.c:2307
       worker_thread+0x910/0x1034 kernel/workqueue.c:2454
       kthread+0x37c/0x45c kernel/kthread.c:319
       ret_from_fork+0x10/0x20 arch/arm64/kernel/entry.S:870

-> #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 kernel/locking/lockdep.c:3787 [inline]
       __lock_acquire+0x32cc/0x7620 kernel/locking/lockdep.c:5011
       lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5622
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0xc4/0x14c kernel/locking/spinlock.c:162
       down_trylock+0x28/0xd8 kernel/locking/semaphore.c:138
       __down_trylock_console_sem+0x80/0x144 kernel/printk/printk.c:239
       console_trylock+0xb8/0x1f8 kernel/printk/printk.c:2565
       console_trylock_spinning+0x1c/0x280 kernel/printk/printk.c:1867
       vprintk_emit+0x120/0x218 kernel/printk/printk.c:2267
       vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2279
       vprintk+0x218/0x2f0 kernel/printk/printk_safe.c:50
       _printk+0xdc/0x128 kernel/printk/printk.c:2289
       fail_dump lib/fault-inject.c:45 [inline]
       should_fail+0x3e0/0x5cc lib/fault-inject.c:146
       __should_failslab+0xbc/0x110 mm/failslab.c:33
       should_failslab+0x10/0x28 mm/slab_common.c:1337
       slab_pre_alloc_hook+0x64/0xe8 mm/slab.h:494
       slab_alloc_node mm/slub.c:3134 [inline]
       slab_alloc mm/slub.c:3228 [inline]
       kmem_cache_alloc+0x98/0x45c mm/slub.c:3233
       kmem_cache_zalloc include/linux/slab.h:711 [inline]
       fill_pool lib/debugobjects.c:171 [inline]
       debug_objects_fill_pool+0x434/0x814 lib/debugobjects.c:600
       debug_object_activate+0x114/0x790 lib/debugobjects.c:696
       debug_timer_activate kernel/time/timer.c:729 [inline]
       __mod_timer+0x830/0xd30 kernel/time/timer.c:1050
       add_timer+0x6c/0x88 kernel/time/timer.c:1144
       __queue_delayed_work kernel/workqueue.c:1687 [inline]
       queue_delayed_work_on+0x1f4/0x330 kernel/workqueue.c:1712
       queue_delayed_work include/linux/workqueue.h:517 [inline]
       batadv_tt_init+0x234/0x26c net/batman-adv/translation-table.c:4179
       batadv_mesh_init+0x378/0x67c net/batman-adv/main.c:199
       batadv_softif_init_late+0x734/0xb94 net/batman-adv/soft-interface.c:807
       register_netdevice+0x440/0x1224 net/core/dev.c:10259
       batadv_softif_newlink+0x90/0xa0 net/batman-adv/soft-interface.c:1071
       __rtnl_newlink net/core/rtnetlink.c:3462 [inline]
       rtnl_newlink+0x1048/0x1ab8 net/core/rtnetlink.c:3510
       rtnetlink_rcv_msg+0xa74/0xdac net/core/rtnetlink.c:5587
       netlink_rcv_skb+0x20c/0x3b8 net/netlink/af_netlink.c:2504
       rtnetlink_rcv+0x28/0x38 net/core/rtnetlink.c:5605
       netlink_unicast_kernel net/netlink/af_netlink.c:1330 [inline]
       netlink_unicast+0x664/0x938 net/netlink/af_netlink.c:1356
       netlink_sendmsg+0x844/0xb38 net/netlink/af_netlink.c:1923
       sock_sendmsg_nosec net/socket.c:704 [inline]
       sock_sendmsg net/socket.c:724 [inline]
       ____sys_sendmsg+0x584/0x870 net/socket.c:2412
       ___sys_sendmsg+0x214/0x294 net/socket.c:2466
       __sys_sendmsg net/socket.c:2495 [inline]
       __do_sys_sendmsg net/socket.c:2504 [inline]
       __se_sys_sendmsg net/socket.c:2502 [inline]
       __arm64_sys_sendmsg+0x1ac/0x25c net/socket.c:2502
       __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
       invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
       el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
       do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
       el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:596
       el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:614
       el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

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 ***

2 locks held by syz-executor.0/4086:
 #0: ffff8000169c5988 (rtnl_mutex){+.+.}-{3:3}, at: rtnl_lock net/core/rtnetlink.c:72 [inline]
 #0: ffff8000169c5988 (rtnl_mutex){+.+.}-{3:3}, at: rtnetlink_rcv_msg+0xa2c/0xdac net/core/rtnetlink.c:5584
 #1: ffff0001b47fc498 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x108/0x214 kernel/time/timer.c:946

stack backtrace:
CPU: 0 PID: 4086 Comm: syz-executor.0 Not tainted 5.15.113-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/28/2023
Call trace:
 dump_backtrace+0x0/0x530 arch/arm64/kernel/stacktrace.c:152
 show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:216
 __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
 print_circular_bug+0x150/0x1b8 kernel/locking/lockdep.c:2011
 check_noncircular+0x2cc/0x378 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 kernel/locking/lockdep.c:3787 [inline]
 __lock_acquire+0x32cc/0x7620 kernel/locking/lockdep.c:5011
 lock_acquire+0x240/0x77c kernel/locking/lockdep.c:5622
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0xc4/0x14c kernel/locking/spinlock.c:162
 down_trylock+0x28/0xd8 kernel/locking/semaphore.c:138
 __down_trylock_console_sem+0x80/0x144 kernel/printk/printk.c:239
 console_trylock+0xb8/0x1f8 kernel/printk/printk.c:2565
 console_trylock_spinning+0x1c/0x280 kernel/printk/printk.c:1867
 vprintk_emit+0x120/0x218 kernel/printk/printk.c:2267
 vprintk_default+0xa0/0xe4 kernel/printk/printk.c:2279
 vprintk+0x218/0x2f0 kernel/printk/printk_safe.c:50
 _printk+0xdc/0x128 kernel/printk/printk.c:2289
 fail_dump lib/fault-inject.c:45 [inline]
 should_fail+0x3e0/0x5cc lib/fault-inject.c:146
 __should_failslab+0xbc/0x110 mm/failslab.c:33
 should_failslab+0x10/0x28 mm/slab_common.c:1337
 slab_pre_alloc_hook+0x64/0xe8 mm/slab.h:494
 slab_alloc_node mm/slub.c:3134 [inline]
 slab_alloc mm/slub.c:3228 [inline]
 kmem_cache_alloc+0x98/0x45c mm/slub.c:3233
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 fill_pool lib/debugobjects.c:171 [inline]
 debug_objects_fill_pool+0x434/0x814 lib/debugobjects.c:600
 debug_object_activate+0x114/0x790 lib/debugobjects.c:696
 debug_timer_activate kernel/time/timer.c:729 [inline]
 __mod_timer+0x830/0xd30 kernel/time/timer.c:1050
 add_timer+0x6c/0x88 kernel/time/timer.c:1144
 __queue_delayed_work kernel/workqueue.c:1687 [inline]
 queue_delayed_work_on+0x1f4/0x330 kernel/workqueue.c:1712
 queue_delayed_work include/linux/workqueue.h:517 [inline]
 batadv_tt_init+0x234/0x26c net/batman-adv/translation-table.c:4179
 batadv_mesh_init+0x378/0x67c net/batman-adv/main.c:199
 batadv_softif_init_late+0x734/0xb94 net/batman-adv/soft-interface.c:807
 register_netdevice+0x440/0x1224 net/core/dev.c:10259
 batadv_softif_newlink+0x90/0xa0 net/batman-adv/soft-interface.c:1071
 __rtnl_newlink net/core/rtnetlink.c:3462 [inline]
 rtnl_newlink+0x1048/0x1ab8 net/core/rtnetlink.c:3510
 rtnetlink_rcv_msg+0xa74/0xdac net/core/rtnetlink.c:5587
 netlink_rcv_skb+0x20c/0x3b8 net/netlink/af_netlink.c:2504
 rtnetlink_rcv+0x28/0x38 net/core/rtnetlink.c:5605
 netlink_unicast_kernel net/netlink/af_netlink.c:1330 [inline]
 netlink_unicast+0x664/0x938 net/netlink/af_netlink.c:1356
 netlink_sendmsg+0x844/0xb38 net/netlink/af_netlink.c:1923
 sock_sendmsg_nosec net/socket.c:704 [inline]
 sock_sendmsg net/socket.c:724 [inline]
 ____sys_sendmsg+0x584/0x870 net/socket.c:2412
 ___sys_sendmsg+0x214/0x294 net/socket.c:2466
 __sys_sendmsg net/socket.c:2495 [inline]
 __do_sys_sendmsg net/socket.c:2504 [inline]
 __se_sys_sendmsg net/socket.c:2502 [inline]
 __arm64_sys_sendmsg+0x1ac/0x25c net/socket.c:2502
 __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
 invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
 el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
 do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
 el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:596
 el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:614
 el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584
CPU: 0 PID: 4086 Comm: syz-executor.0 Not tainted 5.15.113-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/28/2023
Call trace:
 dump_backtrace+0x0/0x530 arch/arm64/kernel/stacktrace.c:152
 show_stack+0x2c/0x3c arch/arm64/kernel/stacktrace.c:216
 __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
 fail_dump lib/fault-inject.c:52 [inline]
 should_fail+0x400/0x5cc lib/fault-inject.c:146
 __should_failslab+0xbc/0x110 mm/failslab.c:33
 should_failslab+0x10/0x28 mm/slab_common.c:1337
 slab_pre_alloc_hook+0x64/0xe8 mm/slab.h:494
 slab_alloc_node mm/slub.c:3134 [inline]
 slab_alloc mm/slub.c:3228 [inline]
 kmem_cache_alloc+0x98/0x45c mm/slub.c:3233
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 fill_pool lib/debugobjects.c:171 [inline]
 debug_objects_fill_pool+0x434/0x814 lib/debugobjects.c:600
 debug_object_activate+0x114/0x790 lib/debugobjects.c:696
 debug_timer_activate kernel/time/timer.c:729 [inline]
 __mod_timer+0x830/0xd30 kernel/time/timer.c:1050
 add_timer+0x6c/0x88 kernel/time/timer.c:1144
 __queue_delayed_work kernel/workqueue.c:1687 [inline]
 queue_delayed_work_on+0x1f4/0x330 kernel/workqueue.c:1712
 queue_delayed_work include/linux/workqueue.h:517 [inline]
 batadv_tt_init+0x234/0x26c net/batman-adv/translation-table.c:4179
 batadv_mesh_init+0x378/0x67c net/batman-adv/main.c:199
 batadv_softif_init_late+0x734/0xb94 net/batman-adv/soft-interface.c:807
 register_netdevice+0x440/0x1224 net/core/dev.c:10259
 batadv_softif_newlink+0x90/0xa0 net/batman-adv/soft-interface.c:1071
 __rtnl_newlink net/core/rtnetlink.c:3462 [inline]
 rtnl_newlink+0x1048/0x1ab8 net/core/rtnetlink.c:3510
 rtnetlink_rcv_msg+0xa74/0xdac net/core/rtnetlink.c:5587
 netlink_rcv_skb+0x20c/0x3b8 net/netlink/af_netlink.c:2504
 rtnetlink_rcv+0x28/0x38 net/core/rtnetlink.c:5605
 netlink_unicast_kernel net/netlink/af_netlink.c:1330 [inline]
 netlink_unicast+0x664/0x938 net/netlink/af_netlink.c:1356
 netlink_sendmsg+0x844/0xb38 net/netlink/af_netlink.c:1923
 sock_sendmsg_nosec net/socket.c:704 [inline]
 sock_sendmsg net/socket.c:724 [inline]
 ____sys_sendmsg+0x584/0x870 net/socket.c:2412
 ___sys_sendmsg+0x214/0x294 net/socket.c:2466
 __sys_sendmsg net/socket.c:2495 [inline]
 __do_sys_sendmsg net/socket.c:2504 [inline]
 __se_sys_sendmsg net/socket.c:2502 [inline]
 __arm64_sys_sendmsg+0x1ac/0x25c net/socket.c:2502
 __invoke_syscall arch/arm64/kernel/syscall.c:38 [inline]
 invoke_syscall+0x98/0x2b8 arch/arm64/kernel/syscall.c:52
 el0_svc_common+0x138/0x258 arch/arm64/kernel/syscall.c:142
 do_el0_svc+0x58/0x14c arch/arm64/kernel/syscall.c:181
 el0_svc+0x7c/0x1f0 arch/arm64/kernel/entry-common.c:596
 el0t_64_sync_handler+0x84/0xe4 arch/arm64/kernel/entry-common.c:614
 el0t_64_sync+0x1a0/0x1a4 arch/arm64/kernel/entry.S:584

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2023/05/25 23:12 linux-5.15.y 1fe619a7d252 0513b3e6 .config console log report syz [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in lock_timer_base
2023/06/04 05:43 linux-5.15.y 0ab06468cbd1 a4ae4f42 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in lock_timer_base
2023/05/25 21:57 linux-5.15.y 1fe619a7d252 0513b3e6 .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan-arm64 possible deadlock in lock_timer_base
* Struck through repros no longer work on HEAD.