possible deadlock in down_trylock (2)

Status: auto-obsoleted due to no activity on 2022/11/17 02:00
Subsystems: perf
[Documentation on labels]
Reported-by: syzbot+6e438330a01285fbb87a@syzkaller.appspotmail.com
First crash: 2838d, last: 1567d
Cause bisection: failed (error log, bisect log)
  
Fix bisection: failed (error log, bisect log)
  
▶ ▼ Discussions (1)
Title Replies (including bot) Last reply
possible deadlock in down_trylock (2) 0 (2) 2018/11/11 18:30
▶ ▼ Similar bugs (1)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in down_trylock (3) prio:low bpf trace 4 syz, C error 2 146d 369d 0/29 upstream: reported C repro on 2025/08/04 16:50
▶ ▼ Last patch testing requests (7)
Created Duration User Patch Repo Result
2022/11/17 01:30 19m retest repro linux-next OK log
2022/10/08 00:30 18m retest repro upstream OK log
2022/09/07 10:27 16m retest repro bpf-next OK log
2022/09/07 07:27 15m retest repro bpf-next OK log
2022/09/07 04:27 19m retest repro bpf-next OK log
2022/09/07 01:27 18m retest repro bpf-next OK log
2022/09/05 08:27 17m retest repro bpf OK log

Sample crash report:
======================================================
WARNING: possible circular locking dependency detected
5.0.0+ #15 Not tainted
------------------------------------------------------
syz-executor773/7680 is trying to acquire lock:
00000000c05ca8f5 ((console_sem).lock){-.-.}, at: down_trylock+0x13/0x70 kernel/locking/semaphore.c:136

but task is already holding lock:
00000000ff5f4b54 (&base->lock){-.-.}, at: lock_timer_base+0x56/0x1b0 kernel/time/timer.c:937

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #3 (&base->lock){-.-.}:
       lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4202
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
       lock_timer_base+0x56/0x1b0 kernel/time/timer.c:937
       __mod_timer kernel/time/timer.c:1009 [inline]
       mod_timer kernel/time/timer.c:1101 [inline]
       add_timer+0x108/0xbe0 kernel/time/timer.c:1137
       __queue_delayed_work+0x1af/0x270 kernel/workqueue.c:1649
       queue_delayed_work_on+0x19a/0x200 kernel/workqueue.c:1674
       queue_delayed_work include/linux/workqueue.h:509 [inline]
       schedule_delayed_work include/linux/workqueue.h:610 [inline]
       psi_task_change+0x409/0x610 kernel/sched/psi.c:546
       psi_enqueue kernel/sched/stats.h:82 [inline]
       enqueue_task kernel/sched/core.c:770 [inline]
       activate_task+0x1f8/0x470 kernel/sched/core.c:794
       wake_up_new_task+0x50d/0xbd0 kernel/sched/core.c:2469
       _do_fork+0x34f/0xfd0 kernel/fork.c:2251
       kernel_thread+0x34/0x40 kernel/fork.c:2285
       rest_init+0x28/0x37b init/main.c:408
       arch_call_rest_init+0xe/0x1b
       start_kernel+0x803/0x83c init/main.c:739
       x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:470
       x86_64_start_kernel+0x77/0x7b arch/x86/kernel/head64.c:451
       secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243

-> #2 (&rq->lock){-.-.}:
       lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4202
       __raw_spin_lock include/linux/spinlock_api_smp.h:142 [inline]
       _raw_spin_lock+0x2f/0x40 kernel/locking/spinlock.c:144
       rq_lock kernel/sched/sched.h:1168 [inline]
       task_fork_fair+0x6a/0x520 kernel/sched/fair.c:10136
       sched_fork+0x3b2/0x900 kernel/sched/core.c:2405
       copy_process.part.0+0x188c/0x7980 kernel/fork.c:1886
       copy_process kernel/fork.c:1709 [inline]
       _do_fork+0x257/0xfd0 kernel/fork.c:2226
       kernel_thread+0x34/0x40 kernel/fork.c:2285
       rest_init+0x28/0x37b init/main.c:408
       arch_call_rest_init+0xe/0x1b
       start_kernel+0x803/0x83c init/main.c:739
       x86_64_start_reservations+0x29/0x2b arch/x86/kernel/head64.c:470
       x86_64_start_kernel+0x77/0x7b arch/x86/kernel/head64.c:451
       secondary_startup_64+0xa4/0xb0 arch/x86/kernel/head_64.S:243

-> #1 (&p->pi_lock){-.-.}:
       lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4202
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
       try_to_wake_up+0x8f/0x1000 kernel/sched/core.c:2008
       wake_up_process+0x10/0x20 kernel/sched/core.c:2172
       __up.isra.0+0x136/0x1a0 kernel/locking/semaphore.c:262
       up+0x9c/0xe0 kernel/locking/semaphore.c:187
       __up_console_sem+0xb7/0x1c0 kernel/printk/printk.c:236
       console_unlock+0x681/0xeb0 kernel/printk/printk.c:2476
       vprintk_emit+0x280/0x6d0 kernel/printk/printk.c:1981
       vprintk_default+0x28/0x30 kernel/printk/printk.c:2008
       vprintk_func+0x7e/0x189 kernel/printk/printk_safe.c:398
       printk+0xba/0xed kernel/printk/printk.c:2041
       check_stack_usage kernel/exit.c:764 [inline]
       do_exit.cold+0x5d/0x254 kernel/exit.c:926
       do_group_exit+0x135/0x370 kernel/exit.c:980
       __do_sys_exit_group kernel/exit.c:991 [inline]
       __se_sys_exit_group kernel/exit.c:989 [inline]
       __x64_sys_exit_group+0x44/0x50 kernel/exit.c:989
       do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

-> #0 ((console_sem).lock){-.-.}:
       check_prevs_add kernel/locking/lockdep.c:2324 [inline]
       validate_chain kernel/locking/lockdep.c:2705 [inline]
       __lock_acquire+0x239c/0x3fb0 kernel/locking/lockdep.c:3692
       lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4202
       __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
       _raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
       down_trylock+0x13/0x70 kernel/locking/semaphore.c:136
       __down_trylock_console_sem+0xa8/0x210 kernel/printk/printk.c:219
       console_trylock+0x15/0xa0 kernel/printk/printk.c:2292
       console_trylock_spinning kernel/printk/printk.c:1705 [inline]
       vprintk_emit+0x267/0x6d0 kernel/printk/printk.c:1980
       vprintk_default+0x28/0x30 kernel/printk/printk.c:2008
       vprintk_func+0x7e/0x189 kernel/printk/printk_safe.c:398
       printk+0xba/0xed kernel/printk/printk.c:2041
       fail_dump lib/fault-inject.c:44 [inline]
       should_fail+0x708/0x852 lib/fault-inject.c:149
       __should_failslab+0x121/0x190 mm/failslab.c:32
       should_failslab+0x9/0x14 mm/slab_common.c:1610
       slab_pre_alloc_hook mm/slab.h:419 [inline]
       slab_alloc mm/slab.c:3378 [inline]
       kmem_cache_alloc+0x47/0x6f0 mm/slab.c:3554
       kmem_cache_zalloc include/linux/slab.h:730 [inline]
       fill_pool lib/debugobjects.c:134 [inline]
       __debug_object_init+0x755/0xc30 lib/debugobjects.c:379
       debug_object_init lib/debugobjects.c:431 [inline]
       debug_object_activate+0x2b8/0x4f0 lib/debugobjects.c:512
       debug_timer_activate kernel/time/timer.c:708 [inline]
       debug_activate kernel/time/timer.c:763 [inline]
       __mod_timer kernel/time/timer.c:1040 [inline]
       mod_timer kernel/time/timer.c:1101 [inline]
       add_timer+0x3ad/0xbe0 kernel/time/timer.c:1137
       __queue_delayed_work+0x1af/0x270 kernel/workqueue.c:1649
       queue_delayed_work_on+0x19a/0x200 kernel/workqueue.c:1674
       queue_delayed_work include/linux/workqueue.h:509 [inline]
       schedule_delayed_work include/linux/workqueue.h:610 [inline]
       unaccount_event kernel/events/core.c:4317 [inline]
       _free_event+0xe6f/0x13b0 kernel/events/core.c:4425
       put_event+0x47/0x60 kernel/events/core.c:4538
       perf_event_release_kernel+0x693/0xc60 kernel/events/core.c:4644
       perf_release+0x37/0x50 kernel/events/core.c:4654
       __fput+0x2e5/0x8d0 fs/file_table.c:278
       ____fput+0x16/0x20 fs/file_table.c:309
       task_work_run+0x14a/0x1c0 kernel/task_work.c:113
       tracehook_notify_resume include/linux/tracehook.h:188 [inline]
       exit_to_usermode_loop+0x273/0x2c0 arch/x86/entry/common.c:166
       prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
       syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
       do_syscall_64+0x52d/0x610 arch/x86/entry/common.c:293
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

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

1 lock held by syz-executor773/7680:
 #0: 00000000ff5f4b54 (&base->lock){-.-.}, at: lock_timer_base+0x56/0x1b0 kernel/time/timer.c:937

stack backtrace:
CPU: 0 PID: 7680 Comm: syz-executor773 Not tainted 5.0.0+ #15
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x172/0x1f0 lib/dump_stack.c:113
 print_circular_bug.isra.0.cold+0x1cc/0x28f kernel/locking/lockdep.c:1562
 check_prev_add.constprop.0+0xf11/0x23c0 kernel/locking/lockdep.c:2211
 check_prevs_add kernel/locking/lockdep.c:2324 [inline]
 validate_chain kernel/locking/lockdep.c:2705 [inline]
 __lock_acquire+0x239c/0x3fb0 kernel/locking/lockdep.c:3692
 lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:4202
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
 down_trylock+0x13/0x70 kernel/locking/semaphore.c:136
 __down_trylock_console_sem+0xa8/0x210 kernel/printk/printk.c:219
 console_trylock+0x15/0xa0 kernel/printk/printk.c:2292
 console_trylock_spinning kernel/printk/printk.c:1705 [inline]
 vprintk_emit+0x267/0x6d0 kernel/printk/printk.c:1980
 vprintk_default+0x28/0x30 kernel/printk/printk.c:2008
 vprintk_func+0x7e/0x189 kernel/printk/printk_safe.c:398
 printk+0xba/0xed kernel/printk/printk.c:2041
 fail_dump lib/fault-inject.c:44 [inline]
 should_fail+0x708/0x852 lib/fault-inject.c:149
 __should_failslab+0x121/0x190 mm/failslab.c:32
 should_failslab+0x9/0x14 mm/slab_common.c:1610
 slab_pre_alloc_hook mm/slab.h:419 [inline]
 slab_alloc mm/slab.c:3378 [inline]
 kmem_cache_alloc+0x47/0x6f0 mm/slab.c:3554
 kmem_cache_zalloc include/linux/slab.h:730 [inline]
 fill_pool lib/debugobjects.c:134 [inline]
 __debug_object_init+0x755/0xc30 lib/debugobjects.c:379
 debug_object_init lib/debugobjects.c:431 [inline]
 debug_object_activate+0x2b8/0x4f0 lib/debugobjects.c:512
 debug_timer_activate kernel/time/timer.c:708 [inline]
 debug_activate kernel/time/timer.c:763 [inline]
 __mod_timer kernel/time/timer.c:1040 [inline]
 mod_timer kernel/time/timer.c:1101 [inline]
 add_timer+0x3ad/0xbe0 kernel/time/timer.c:1137
 __queue_delayed_work+0x1af/0x270 kernel/workqueue.c:1649
 queue_delayed_work_on+0x19a/0x200 kernel/workqueue.c:1674
 queue_delayed_work include/linux/workqueue.h:509 [inline]
 schedule_delayed_work include/linux/workqueue.h:610 [inline]
 unaccount_event kernel/events/core.c:4317 [inline]
 _free_event+0xe6f/0x13b0 kernel/events/core.c:4425
 put_event+0x47/0x60 kernel/events/core.c:4538
 perf_event_release_kernel+0x693/0xc60 kernel/events/core.c:4644
 perf_release+0x37/0x50 kernel/events/core.c:4654
 __fput+0x2e5/0x8d0 fs/file_table.c:278
 ____fput+0x16/0x20 fs/file_table.c:309
 task_work_run+0x14a/0x1c0 kernel/task_work.c:113
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_usermode_loop+0x273/0x2c0 arch/x86/entry/common.c:166
 prepare_exit_to_usermode arch/x86/entry/common.c:197 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:268 [inline]
 do_syscall_64+0x52d/0x610 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x44df59
Code: 4d c9 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 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 0f 83 1b c9 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f724395fcb8 EFLAGS: 00000246 ORIG_RAX: 0000000000000021
RAX: 0000000000000006 RBX: 00007f724395fcc0 RCX: 000000000044df59
RDX: 0000000000000001 RSI: 0000000000000006 RDI: 0000000000000005
RBP: 0000000000000003 R08: 0000000000000001 R09: 0000000000000031
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000006e6a0c
R13: 00007ffc2a98791f R14: 00007f72439609c0 R15: 0000000000000000

Crashes (17):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/03/10 15:50 upstream 6cdc577a18a6 12365b99 .config console log report syz C ci-upstream-kasan-gce-root
2019/06/13 06:06 bpf-next aee450cbe482 3f4e812b .config console log report syz C ci-upstream-bpf-next-kasan-gce
2018/11/11 18:29 bpf-next 407be8d03e20 7b5f8621 .config console log report syz C ci-upstream-bpf-next-kasan-gce
2018/10/31 18:42 bpf 27b31e68bc9f 89781090 .config console log report syz ci-upstream-bpf-kasan-gce
2019/05/07 08:25 bpf-next d24ed99b3b27 d28f4ce5 .config console log report syz ci-upstream-bpf-next-kasan-gce
2019/03/14 08:12 bpf-next d9862cfbe209 d09a902e .config console log report syz ci-upstream-bpf-next-kasan-gce
2019/06/18 05:28 linux-next a125097c8410 442206d7 .config console log report syz ci-upstream-linux-next-kasan-gce-root
2022/02/03 02:21 upstream 27bb0b18c208 4ebb2798 .config console log report info ci-upstream-kasan-gce possible deadlock in down_trylock
2022/01/06 05:48 upstream 49ef78e59b07 6acc789a .config console log report info ci-upstream-kasan-gce possible deadlock in down_trylock
2021/12/21 10:06 upstream 86085fe79e3c 62bd192b .config console log report info ci-upstream-kasan-gce possible deadlock in down_trylock
2021/12/16 01:14 upstream 2b14864acbaa 572bcb40 .config console log report info ci-upstream-kasan-gce possible deadlock in down_trylock
2021/12/03 11:54 upstream 5f58da2befa5 c7c20675 .config console log report info ci-upstream-kasan-gce-smack-root possible deadlock in down_trylock
2021/11/05 20:31 upstream fe91c4725aee 4c1be0be .config console log report info ci-upstream-kasan-gce-smack-root possible deadlock in down_trylock
2021/10/14 16:44 upstream 26d657410983 5462d470 .config console log report info ci-upstream-kasan-gce possible deadlock in down_trylock
2022/01/19 15:28 upstream 1d1df41c5a33 0620189b .config console log report info ci-qemu-upstream-386 possible deadlock in down_trylock
2021/09/10 05:54 bpf-next 0b46b7550560 e2776ee4 .config console log report info ci-upstream-bpf-next-kasan-gce possible deadlock in down_trylock
2022/04/25 09:12 linux-next f1244c81da13 c889aef9 .config console log report info ci-upstream-linux-next-kasan-gce-root possible deadlock in down_trylock
* Struck through repros no longer work on HEAD.