syzbot


inconsistent lock state in sock_hash_delete_elem

Status: upstream: reported C repro on 2024/03/31 19:40
Subsystems: kernel
[Documentation on labels]
Reported-by: syzbot+1dab15008502531a13d2@syzkaller.appspotmail.com
First crash: 20d, last: 2d02h
Discussions (1)
Title Replies (including bot) Last reply
[syzbot] [kernel?] inconsistent lock state in sock_hash_delete_elem 1 (5) 2024/04/13 11:10
Last patch testing requests (3)
Created Duration User Patch Repo Result
2024/04/01 08:36 25m lizhi.xu@windriver.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git fe46a7dd189e OK log
2024/04/01 07:47 23m lizhi.xu@windriver.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git fe46a7dd189e error OK
2024/04/01 06:46 17m lizhi.xu@windriver.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git fe46a7dd189e report log

Sample crash report:
================================
WARNING: inconsistent lock state
6.8.0-syzkaller-08951-gfe46a7dd189e #0 Not tainted
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
syz-executor164/5064 [HC0[0]:SC0[0]:HE0:SE1] takes:
ffff8880b943e698 (&rq->__lock){?.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:559
{IN-HARDIRQ-W} state was registered at:
  lock_acquire kernel/locking/lockdep.c:5754 [inline]
  lock_acquire+0x1b1/0x540 kernel/locking/lockdep.c:5719
  _raw_spin_lock_nested+0x31/0x40 kernel/locking/spinlock.c:378
  raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:559
  raw_spin_rq_lock kernel/sched/sched.h:1385 [inline]
  rq_lock kernel/sched/sched.h:1699 [inline]
  scheduler_tick+0xa2/0x650 kernel/sched/core.c:5679
  update_process_times+0x199/0x220 kernel/time/timer.c:2481
  tick_periodic+0x7e/0x230 kernel/time/tick-common.c:100
  tick_handle_periodic+0x45/0x120 kernel/time/tick-common.c:112
  timer_interrupt+0x4e/0x80 arch/x86/kernel/time.c:57
  __handle_irq_event_percpu+0x22c/0x750 kernel/irq/handle.c:158
  handle_irq_event_percpu kernel/irq/handle.c:193 [inline]
  handle_irq_event+0xab/0x1e0 kernel/irq/handle.c:210
  handle_edge_irq+0x263/0xd10 kernel/irq/chip.c:831
  generic_handle_irq_desc include/linux/irqdesc.h:161 [inline]
  handle_irq arch/x86/kernel/irq.c:238 [inline]
  __common_interrupt+0xe1/0x250 arch/x86/kernel/irq.c:257
  common_interrupt+0xab/0xd0 arch/x86/kernel/irq.c:247
  asm_common_interrupt+0x26/0x40 arch/x86/include/asm/idtentry.h:693
  console_flush_all+0xa19/0xd70 kernel/printk/printk.c:2979
  console_unlock+0xae/0x290 kernel/printk/printk.c:3042
  vprintk_emit kernel/printk/printk.c:2342 [inline]
  vprintk_emit+0x11a/0x5a0 kernel/printk/printk.c:2297
  vprintk+0x7f/0xa0 kernel/printk/printk_safe.c:45
  _printk+0xc8/0x100 kernel/printk/printk.c:2367
  cpu_detect_tlb arch/x86/kernel/cpu/common.c:860 [inline]
  identify_boot_cpu arch/x86/kernel/cpu/common.c:1934 [inline]
  arch_cpu_finalize_init+0x7b/0x170 arch/x86/kernel/cpu/common.c:2310
  start_kernel+0x32b/0x490 init/main.c:1043
  x86_64_start_reservations+0x18/0x30 arch/x86/kernel/head64.c:509
  x86_64_start_kernel+0xb2/0xc0 arch/x86/kernel/head64.c:490
  common_startup_64+0x13e/0x148
irq event stamp: 4834
hardirqs last  enabled at (4831): [<ffffffff8ad60263>] __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:159 [inline]
hardirqs last  enabled at (4831): [<ffffffff8ad60263>] _raw_spin_unlock_irq+0x23/0x50 kernel/locking/spinlock.c:202
hardirqs last disabled at (4832): [<ffffffff8ad48b14>] __schedule+0x2644/0x5c70 kernel/sched/core.c:6634
softirqs last  enabled at (4834): [<ffffffff88cb2754>] spin_unlock_bh include/linux/spinlock.h:396 [inline]
softirqs last  enabled at (4834): [<ffffffff88cb2754>] sock_hash_delete_elem+0x1f4/0x260 net/core/sock_map.c:947
softirqs last disabled at (4833): [<ffffffff88cb262b>] spin_lock_bh include/linux/spinlock.h:356 [inline]
softirqs last disabled at (4833): [<ffffffff88cb262b>] sock_hash_delete_elem+0xcb/0x260 net/core/sock_map.c:939

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

       CPU0
       ----
  lock(&rq->__lock
);
  <Interrupt>
    lock(&rq->__lock
);

 *** DEADLOCK ***

2 locks held by syz-executor164/5064:
 #0: ffff8880b943e698
 (&rq->__lock
){?.-.}-{2:2}
, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:559
 #1: ffffffff8d7b08e0
 (rcu_read_lock
){....}-{1:2}
, at: rcu_lock_acquire include/linux/rcupdate.h:298 [inline]
, at: rcu_read_lock include/linux/rcupdate.h:750 [inline]
, at: __bpf_trace_run kernel/trace/bpf_trace.c:2380 [inline]
, at: bpf_trace_run4+0x107/0x460 kernel/trace/bpf_trace.c:2422

stack backtrace:
CPU: 0 PID: 5064 Comm: syz-executor164 Not tainted 6.8.0-syzkaller-08951-gfe46a7dd189e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x116/0x1f0 lib/dump_stack.c:114
 print_usage_bug kernel/locking/lockdep.c:3971 [inline]
 valid_state kernel/locking/lockdep.c:4013 [inline]
 mark_lock_irq kernel/locking/lockdep.c:4216 [inline]
 mark_lock+0x923/0xc60 kernel/locking/lockdep.c:4678
 mark_held_locks+0x9f/0xe0 kernel/locking/lockdep.c:4274
 __trace_hardirqs_on_caller kernel/locking/lockdep.c:4292 [inline]
 lockdep_hardirqs_on_prepare+0x137/0x420 kernel/locking/lockdep.c:4359
 trace_hardirqs_on+0x36/0x40 kernel/trace/trace_preemptirq.c:61
 __local_bh_enable_ip+0xa4/0x120 kernel/softirq.c:387
 spin_unlock_bh include/linux/spinlock.h:396 [inline]
 sock_hash_delete_elem+0x1f4/0x260 net/core/sock_map.c:947
 ___bpf_prog_run+0x3e51/0xae80 kernel/bpf/core.c:1997
 __bpf_prog_run32+0xc1/0x100 kernel/bpf/core.c:2236
 bpf_dispatcher_nop_func include/linux/bpf.h:1234 [inline]
 __bpf_prog_run include/linux/filter.h:657 [inline]
 bpf_prog_run include/linux/filter.h:664 [inline]
 __bpf_trace_run kernel/trace/bpf_trace.c:2381 [inline]
 bpf_trace_run4+0x176/0x460 kernel/trace/bpf_trace.c:2422
 __bpf_trace_sched_switch+0x13e/0x190 include/trace/events/sched.h:222
 trace_sched_switch include/trace/events/sched.h:222 [inline]
 __schedule+0x2266/0x5c70 kernel/sched/core.c:6733
 __schedule_loop kernel/sched/core.c:6813 [inline]
 schedule+0xe7/0x350 kernel/sched/core.c:6828
 ptrace_stop.part.0+0x440/0x940 kernel/signal.c:2358
 ptrace_stop kernel/signal.c:2260 [inline]
 ptrace_do_notify+0x222/0x2d0 kernel/signal.c:2395
 ptrace_notify+0xc5/0x130 kernel/signal.c:2407
 ptrace_report_syscall include/linux/ptrace.h:415 [inline]
 ptrace_report_syscall_entry include/linux/ptrace.h:452 [inline]
 syscall_trace_enter+0xb5/0x210 kernel/entry/common.c:45
 syscall_enter_from_user_mode_work include/linux/entry-common.h:168 [inline]
 syscall_enter_from_user_mode include/linux/entry-common.h:198 [inline]
 do_syscall_64+0x1f6/0x260 arch/x86/entry/common.c:79
 entry_SYSCALL_64_after_hwframe+0x6d/0x75
RIP: 0033:0x7f122969f6b3
Code: 00 00 00 00 0f 1f 00 83 ff 03 74 7b 83 ff 02 b8 fa ff ff ff 49 89 ca 0f 44 f8 80 3d ce e9 03 00 00 74 14 b8 e6 00 00 00 0f 05 <f7> d8 c3 66 2e 0f 1f 84 00 00 00 00 00 48 83 ec 28 48 89 54 24 10
RSP: 002b:00007ffd4d89e018 EFLAGS: 00000202
 ORIG_RAX: 00000000000000e6
RAX: ffffffffffffffda RBX: 00000000000013c9 RCX: 00007f122969f6b3
RDX: 00007ffd4d89e030 RSI: 0000000000000000 RDI: 0000000000000000
RBP: 0000000000012939 R08: 000000000000004c R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000202 R12: 00007ffd4d89e06c
R13: 431bde82d7b634db R14: 0000000000000001 R15: 0000000000000001
 </TASK>

Crashes (23):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/03/27 19:59 upstream fe46a7dd189e 454571b6 .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/04/14 18:40 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/13 07:07 upstream fe46a7dd189e c8349e48 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/12 18:46 upstream fe46a7dd189e 27de0a5c .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/04/11 08:18 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/04/11 05:15 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/10 22:37 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/04/10 15:38 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/10 08:25 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/10 06:17 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/09 22:05 upstream fe46a7dd189e 56086b24 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/09 00:17 upstream fe46a7dd189e 53df08b6 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/07 11:59 upstream fe46a7dd189e ca620dd8 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/04/07 11:58 upstream fe46a7dd189e ca620dd8 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/07 11:58 upstream fe46a7dd189e ca620dd8 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/06 00:23 upstream fe46a7dd189e 18ea8213 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/05 10:39 upstream fe46a7dd189e 0ee3535e .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/04 10:35 upstream fe46a7dd189e 51c4dcff .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/03 23:07 upstream fe46a7dd189e fed899ed .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/04/03 02:40 upstream fe46a7dd189e 7925100d .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/03/29 07:14 upstream fe46a7dd189e 120789fd .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-badwrites-root inconsistent lock state in sock_hash_delete_elem
2024/03/29 07:05 upstream fe46a7dd189e 120789fd .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
2024/03/27 19:33 upstream fe46a7dd189e 454571b6 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root inconsistent lock state in sock_hash_delete_elem
* Struck through repros no longer work on HEAD.