syzbot


possible deadlock in try_to_wake_up

Status: fixed on 2024/04/29 07:11
Reported-by: syzbot+f91aecb8835e72e8c465@syzkaller.appspotmail.com
Fix commit: a44770fed865 bpf, sockmap: Prevent lock inversion deadlock in map delete elem
First crash: 114d, last: 114d
Fix bisection: fixed by (bisect log) :
commit a44770fed86515eedb5a7c00b787f847ebb134a5
Author: Jakub Sitnicki <jakub@cloudflare.com>
Date: Tue Apr 2 10:46:21 2024 +0000

  bpf, sockmap: Prevent lock inversion deadlock in map delete elem

  
Bug presence (1)
Date Name Commit Repro Result
2024/04/25 upstream (ToT) e88c4cfcb7b8 C Didn't crash
Similar bugs (7)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-6.1 possible deadlock in try_to_wake_up (2) origin:upstream C 15 1d03h 71d 0/3 upstream: reported C repro on 2024/05/09 05:15
linux-5.15 possible deadlock in try_to_wake_up origin:upstream C 11 12h16m 105d 0/3 upstream: reported C repro on 2024/04/05 17:03
upstream possible deadlock in try_to_wake_up (2) mm 1 670d 666d 0/27 auto-obsoleted due to no activity on 2023/01/16 12:10
upstream possible deadlock in try_to_wake_up (4) bpf net C error 19 60d 123d 26/27 fixed on 2024/05/22 23:36
upstream possible deadlock in try_to_wake_up (5) mm C 24 5h25m 50d 1/27 upstream: reported C repro on 2024/05/30 18:36
upstream possible deadlock in try_to_wake_up (3) net 103 276d 285d 0/27 auto-obsoleted due to no activity on 2023/11/27 02:05
upstream possible deadlock in try_to_wake_up mm 39 2013d 2045d 0/27 auto-closed as invalid on 2019/07/13 09:55

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

but task is already holding lock:
ffff88802990c598 (&p->pi_lock){-.-.}-{2:2}, at: try_to_wake_up+0xad/0x12e0 kernel/sched/core.c:4112

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #1 (&p->pi_lock){-.-.}-{2:2}:
       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
       try_to_wake_up+0xad/0x12e0 kernel/sched/core.c:4112
       up+0x6e/0x90 kernel/locking/semaphore.c:191
       __up_console_sem+0x11a/0x1e0 kernel/printk/printk.c:260
       __console_unlock kernel/printk/printk.c:2691 [inline]
       console_unlock+0x591/0x7c0 kernel/printk/printk.c:2902
       vprintk_emit+0x523/0x740 kernel/printk/printk.c:2297
       dev_vprintk_emit+0x2aa/0x323 drivers/base/core.c:4902
       dev_printk_emit+0xd9/0x118 drivers/base/core.c:4913
       _dev_warn+0x11e/0x165 drivers/base/core.c:4969
       firmware_fallback_sysfs+0x674/0x940 drivers/base/firmware_loader/fallback.c:229
       _request_firmware+0xc13/0x1200 drivers/base/firmware_loader/main.c:856
       request_firmware_work_func+0x126/0x270 drivers/base/firmware_loader/main.c:1105
       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

-> #0 ((console_sem).lock){-...}-{2:2}:
       check_prev_add kernel/locking/lockdep.c:3090 [inline]
       check_prevs_add kernel/locking/lockdep.c:3209 [inline]
       validate_chain+0x1661/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_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:139
       __down_trylock_console_sem+0x105/0x250 kernel/printk/printk.c:243
       console_trylock kernel/printk/printk.c:2644 [inline]
       console_trylock_spinning kernel/printk/printk.c:1896 [inline]
       vprintk_emit+0x1ee/0x740 kernel/printk/printk.c:2296
       _printk+0xd1/0x111 kernel/printk/printk.c:2322
       __report_bug lib/bug.c:195 [inline]
       report_bug+0x342/0x500 lib/bug.c:219
       handle_bug+0x3d/0x70 arch/x86/kernel/traps.c:324
       exc_invalid_op+0x16/0x40 arch/x86/kernel/traps.c:345
       asm_exc_invalid_op+0x16/0x20 arch/x86/include/asm/idtentry.h:568
       __local_bh_disable_ip+0x1ec/0x210 kernel/softirq.c:345
       __raw_spin_lock_bh include/linux/spinlock_api_smp.h:125 [inline]
       _raw_spin_lock_bh+0x18/0x40 kernel/locking/spinlock.c:178
       sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932
       bpf_prog_2e01b746faa822d9+0x42/0x46
       bpf_dispatcher_nop_func include/linux/bpf.h:989 [inline]
       __bpf_prog_run include/linux/filter.h:603 [inline]
       bpf_prog_run include/linux/filter.h:610 [inline]
       __bpf_trace_run kernel/trace/bpf_trace.c:2273 [inline]
       bpf_trace_run2+0x1fd/0x410 kernel/trace/bpf_trace.c:2312
       trace_sched_migrate_task include/trace/events/sched.h:274 [inline]
       set_task_cpu+0x503/0x5a0 kernel/sched/core.c:3154
       try_to_wake_up+0x544/0x12e0 kernel/sched/core.c:4222
       hrtimer_wakeup+0x5e/0x70 kernel/time/hrtimer.c:1940
       __run_hrtimer kernel/time/hrtimer.c:1686 [inline]
       __hrtimer_run_queues+0x5e5/0xe50 kernel/time/hrtimer.c:1750
       hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1812
       local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1095 [inline]
       __sysvec_apic_timer_interrupt+0x156/0x580 arch/x86/kernel/apic/apic.c:1112
       sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1106
       asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:653
       native_safe_halt arch/x86/include/asm/irqflags.h:51 [inline]
       arch_safe_halt arch/x86/include/asm/irqflags.h:89 [inline]
       acpi_safe_halt drivers/acpi/processor_idle.c:112 [inline]
       acpi_idle_do_entry+0x10f/0x340 drivers/acpi/processor_idle.c:572
       acpi_idle_enter+0x352/0x4f0 drivers/acpi/processor_idle.c:709
       cpuidle_enter_state+0x516/0xf80 drivers/cpuidle/cpuidle.c:239
       cpuidle_enter+0x59/0x90 drivers/cpuidle/cpuidle.c:356
       call_cpuidle kernel/sched/idle.c:155 [inline]
       cpuidle_idle_call kernel/sched/idle.c:236 [inline]
       do_idle+0x3ce/0x680 kernel/sched/idle.c:303
       cpu_startup_entry+0x3d/0x60 kernel/sched/idle.c:401
       rest_init+0x2da/0x300 init/main.c:732
       start_kernel+0x0/0x53f init/main.c:892
       start_kernel+0x496/0x53f init/main.c:1139
       secondary_startup_64_no_verify+0xcf/0xdb

other info that might help us debug this:

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(&p->pi_lock);
                               lock((console_sem).lock);
                               lock(&p->pi_lock);
  lock((console_sem).lock);

 *** DEADLOCK ***

2 locks held by swapper/0/0:
 #0: ffff88802990c598 (&p->pi_lock){-.-.}-{2:2}, at: try_to_wake_up+0xad/0x12e0 kernel/sched/core.c:4112
 #1: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:350 [inline]
 #1: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:791 [inline]
 #1: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: __bpf_trace_run kernel/trace/bpf_trace.c:2272 [inline]
 #1: ffffffff8d12a940 (rcu_read_lock){....}-{1:2}, at: bpf_trace_run2+0x110/0x410 kernel/trace/bpf_trace.c:2312

stack backtrace:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.1.83-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
 check_noncircular+0x2fa/0x3b0 kernel/locking/lockdep.c:2170
 check_prev_add kernel/locking/lockdep.c:3090 [inline]
 check_prevs_add kernel/locking/lockdep.c:3209 [inline]
 validate_chain+0x1661/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_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:139
 __down_trylock_console_sem+0x105/0x250 kernel/printk/printk.c:243
 console_trylock kernel/printk/printk.c:2644 [inline]
 console_trylock_spinning kernel/printk/printk.c:1896 [inline]
 vprintk_emit+0x1ee/0x740 kernel/printk/printk.c:2296
 _printk+0xd1/0x111 kernel/printk/printk.c:2322
 __report_bug lib/bug.c:195 [inline]
 report_bug+0x342/0x500 lib/bug.c:219
 handle_bug+0x3d/0x70 arch/x86/kernel/traps.c:324
 exc_invalid_op+0x16/0x40 arch/x86/kernel/traps.c:345
 asm_exc_invalid_op+0x16/0x20 arch/x86/include/asm/idtentry.h:568
RIP: 0010:__local_bh_disable_ip+0x1ec/0x210 kernel/softirq.c:321
Code: 00 00 43 c6 44 2c 0b 00 65 48 8b 04 25 28 00 00 00 48 3b 84 24 80 00 00 00 75 2d 48 8d 65 d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 <0f> 0b e9 a0 fe ff ff e8 f8 de 35 09 41 f7 c6 00 02 00 00 0f 85 52
RSP: 0018:ffffc90000007980 EFLAGS: 00010006
RAX: 0000000080010004 RBX: ffffffff8897e69c RCX: ffffffff8cebd800
RDX: dffffc0000000000 RSI: 0000000000000201 RDI: ffffffff8897e69c
RBP: ffffc90000007a48 R08: 0000000000000005 R09: ffffffff8898283e
R10: 000000000000000c R11: ffffffff8cebd800 R12: dffffc0000000000
R13: 1ffff92000000f34 R14: ffffc900000079e0 R15: 0000000000000201
 __raw_spin_lock_bh include/linux/spinlock_api_smp.h:125 [inline]
 _raw_spin_lock_bh+0x18/0x40 kernel/locking/spinlock.c:178
 sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932
 bpf_prog_2e01b746faa822d9+0x42/0x46
 bpf_dispatcher_nop_func include/linux/bpf.h:989 [inline]
 __bpf_prog_run include/linux/filter.h:603 [inline]
 bpf_prog_run include/linux/filter.h:610 [inline]
 __bpf_trace_run kernel/trace/bpf_trace.c:2273 [inline]
 bpf_trace_run2+0x1fd/0x410 kernel/trace/bpf_trace.c:2312
 trace_sched_migrate_task include/trace/events/sched.h:274 [inline]
 set_task_cpu+0x503/0x5a0 kernel/sched/core.c:3154
 try_to_wake_up+0x544/0x12e0 kernel/sched/core.c:4222
 hrtimer_wakeup+0x5e/0x70 kernel/time/hrtimer.c:1940
 __run_hrtimer kernel/time/hrtimer.c:1686 [inline]
 __hrtimer_run_queues+0x5e5/0xe50 kernel/time/hrtimer.c:1750
 hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1812
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1095 [inline]
 __sysvec_apic_timer_interrupt+0x156/0x580 arch/x86/kernel/apic/apic.c:1112
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1106
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:653
RIP: 0010:native_save_fl arch/x86/include/asm/irqflags.h:22 [inline]
RIP: 0010:arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
RIP: 0010:arch_irqs_disabled arch/x86/include/asm/irqflags.h:130 [inline]
RIP: 0010:acpi_safe_halt drivers/acpi/processor_idle.c:113 [inline]
RIP: 0010:acpi_idle_do_entry+0x10f/0x340 drivers/acpi/processor_idle.c:572
Code: 67 f6 f6 48 83 e3 08 0f 85 0b 01 00 00 4c 8d 74 24 20 e8 f4 23 fd f6 0f 1f 44 00 00 e8 9a 63 f6 f6 0f 00 2d a3 23 b3 00 fb f4 <4c> 89 f3 48 c1 eb 03 42 80 3c 3b 00 74 08 4c 89 f7 e8 6b d9 4d f7
RSP: 0018:ffffffff8ce07b20 EFLAGS: 000002d3
RAX: ffffffff8a942156 RBX: 0000000000000000 RCX: ffffffff8cebd800
RDX: 0000000000000000 RSI: ffffffff8aebee40 RDI: ffffffff8b3d2b40
RBP: ffffffff8ce07bb0 R08: ffffffff8a942138 R09: fffffbfff19d7b01
R10: 0000000000000000 R11: dffffc0000000001 R12: 1ffffffff19c0f64
R13: ffff888015784804 R14: ffffffff8ce07b40 R15: dffffc0000000000
 acpi_idle_enter+0x352/0x4f0 drivers/acpi/processor_idle.c:709
 cpuidle_enter_state+0x516/0xf80 drivers/cpuidle/cpuidle.c:239
 cpuidle_enter+0x59/0x90 drivers/cpuidle/cpuidle.c:356
 call_cpuidle kernel/sched/idle.c:155 [inline]
 cpuidle_idle_call kernel/sched/idle.c:236 [inline]
 do_idle+0x3ce/0x680 kernel/sched/idle.c:303
 cpu_startup_entry+0x3d/0x60 kernel/sched/idle.c:401
 rest_init+0x2da/0x300 init/main.c:732
 arch_call_rest_init+0xa/0xa init/main.c:892
 start_kernel+0x496/0x53f init/main.c:1139
 secondary_startup_64_no_verify+0xcf/0xdb
 </TASK>
WARNING: CPU: 0 PID: 0 at kernel/softirq.c:321 __local_bh_disable_ip+0x1ec/0x210 kernel/softirq.c:345
Modules linked in:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.1.83-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
RIP: 0010:__local_bh_disable_ip+0x1ec/0x210 kernel/softirq.c:321
Code: 00 00 43 c6 44 2c 0b 00 65 48 8b 04 25 28 00 00 00 48 3b 84 24 80 00 00 00 75 2d 48 8d 65 d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 <0f> 0b e9 a0 fe ff ff e8 f8 de 35 09 41 f7 c6 00 02 00 00 0f 85 52
RSP: 0018:ffffc90000007980 EFLAGS: 00010006
RAX: 0000000080010004 RBX: ffffffff8897e69c RCX: ffffffff8cebd800
RDX: dffffc0000000000 RSI: 0000000000000201 RDI: ffffffff8897e69c
RBP: ffffc90000007a48 R08: 0000000000000005 R09: ffffffff8898283e
R10: 000000000000000c R11: ffffffff8cebd800 R12: dffffc0000000000
R13: 1ffff92000000f34 R14: ffffc900000079e0 R15: 0000000000000201
FS:  0000000000000000(0000) GS:ffff8880b9800000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000555555630ca8 CR3: 0000000020de0000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 __raw_spin_lock_bh include/linux/spinlock_api_smp.h:125 [inline]
 _raw_spin_lock_bh+0x18/0x40 kernel/locking/spinlock.c:178
 sock_hash_delete_elem+0xac/0x2f0 net/core/sock_map.c:932
 bpf_prog_2e01b746faa822d9+0x42/0x46
 bpf_dispatcher_nop_func include/linux/bpf.h:989 [inline]
 __bpf_prog_run include/linux/filter.h:603 [inline]
 bpf_prog_run include/linux/filter.h:610 [inline]
 __bpf_trace_run kernel/trace/bpf_trace.c:2273 [inline]
 bpf_trace_run2+0x1fd/0x410 kernel/trace/bpf_trace.c:2312
 trace_sched_migrate_task include/trace/events/sched.h:274 [inline]
 set_task_cpu+0x503/0x5a0 kernel/sched/core.c:3154
 try_to_wake_up+0x544/0x12e0 kernel/sched/core.c:4222
 hrtimer_wakeup+0x5e/0x70 kernel/time/hrtimer.c:1940
 __run_hrtimer kernel/time/hrtimer.c:1686 [inline]
 __hrtimer_run_queues+0x5e5/0xe50 kernel/time/hrtimer.c:1750
 hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1812
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1095 [inline]
 __sysvec_apic_timer_interrupt+0x156/0x580 arch/x86/kernel/apic/apic.c:1112
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1106
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/0x20 arch/x86/include/asm/idtentry.h:653
RIP: 0010:native_save_fl arch/x86/include/asm/irqflags.h:22 [inline]
RIP: 0010:arch_local_save_flags arch/x86/include/asm/irqflags.h:70 [inline]
RIP: 0010:arch_irqs_disabled arch/x86/include/asm/irqflags.h:130 [inline]
RIP: 0010:acpi_safe_halt drivers/acpi/processor_idle.c:113 [inline]
RIP: 0010:acpi_idle_do_entry+0x10f/0x340 drivers/acpi/processor_idle.c:572
Code: 67 f6 f6 48 83 e3 08 0f 85 0b 01 00 00 4c 8d 74 24 20 e8 f4 23 fd f6 0f 1f 44 00 00 e8 9a 63 f6 f6 0f 00 2d a3 23 b3 00 fb f4 <4c> 89 f3 48 c1 eb 03 42 80 3c 3b 00 74 08 4c 89 f7 e8 6b d9 4d f7
RSP: 0018:ffffffff8ce07b20 EFLAGS: 000002d3
RAX: ffffffff8a942156 RBX: 0000000000000000 RCX: ffffffff8cebd800
RDX: 0000000000000000 RSI: ffffffff8aebee40 RDI: ffffffff8b3d2b40
RBP: ffffffff8ce07bb0 R08: ffffffff8a942138 R09: fffffbfff19d7b01
R10: 0000000000000000 R11: dffffc0000000001 R12: 1ffffffff19c0f64
R13: ffff888015784804 R14: ffffffff8ce07b40 R15: dffffc0000000000
 acpi_idle_enter+0x352/0x4f0 drivers/acpi/processor_idle.c:709
 cpuidle_enter_state+0x516/0xf80 drivers/cpuidle/cpuidle.c:239
 cpuidle_enter+0x59/0x90 drivers/cpuidle/cpuidle.c:356
 call_cpuidle kernel/sched/idle.c:155 [inline]
 cpuidle_idle_call kernel/sched/idle.c:236 [inline]
 do_idle+0x3ce/0x680 kernel/sched/idle.c:303
 cpu_startup_entry+0x3d/0x60 kernel/sched/idle.c:401
 rest_init+0x2da/0x300 init/main.c:732
 arch_call_rest_init+0xa/0xa init/main.c:892
 start_kernel+0x496/0x53f init/main.c:1139
 secondary_startup_64_no_verify+0xcf/0xdb
 </TASK>
----------------
Code disassembly (best guess):
   0:	67 f6 f6             	addr32 div %dh
   3:	48 83 e3 08          	and    $0x8,%rbx
   7:	0f 85 0b 01 00 00    	jne    0x118
   d:	4c 8d 74 24 20       	lea    0x20(%rsp),%r14
  12:	e8 f4 23 fd f6       	call   0xf6fd240b
  17:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1)
  1c:	e8 9a 63 f6 f6       	call   0xf6f663bb
  21:	0f 00 2d a3 23 b3 00 	verw   0xb323a3(%rip)        # 0xb323cb
  28:	fb                   	sti
  29:	f4                   	hlt
* 2a:	4c 89 f3             	mov    %r14,%rbx <-- trapping instruction
  2d:	48 c1 eb 03          	shr    $0x3,%rbx
  31:	42 80 3c 3b 00       	cmpb   $0x0,(%rbx,%r15,1)
  36:	74 08                	je     0x40
  38:	4c 89 f7             	mov    %r14,%rdi
  3b:	e8 6b d9 4d f7       	call   0xf74dd9ab

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/03/27 17:51 linux-6.1.y e5cd595e23c1 454571b6 .config console log report syz C [disk image] [vmlinux] [kernel image] ci2-linux-6-1-kasan-perf possible deadlock in try_to_wake_up
* Struck through repros no longer work on HEAD.