Message-ID: <000000000000bed0ca06157b3c5f@google.com>
Date: Sat, 06 Apr 2024 22:48:24 -0700
From: syzbot <syzbot+b55883d68766eadcee77@...kaller.appspotmail.com>
To: anna-maria@...utronix.de, frederic@...nel.org, 
	linux-kernel@...r.kernel.org, mingo@...nel.org, 
	syzkaller-bugs@...glegroups.com, tglx@...utronix.de
Subject: [syzbot] [kernel?] inconsistent lock state in __do_softirq

Hello,

syzbot found the following issue on:

HEAD commit:    fe46a7dd189e Merge tag 'sound-6.9-rc1' of git://git.kernel..
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=170c9f0d180000
kernel config:  https://syzkaller.appspot.com/x/.config?x=1a07d5da4eb21586
dashboard link: https://syzkaller.appspot.com/bug?extid=b55883d68766eadcee77
compiler:       gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/b42ab0fd4947/disk-fe46a7dd.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/b8a6e7231930/vmlinux-fe46a7dd.xz
kernel image: https://storage.googleapis.com/syzbot-assets/4fbf3e4ce6f8/bzImage-fe46a7dd.xz

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

================================
WARNING: inconsistent lock state
6.8.0-syzkaller-08951-gfe46a7dd189e #0 Not tainted
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
kworker/1:1/44 [HC0[0]:SC1[1]:HE0:SE0] takes:
ffff8880b953e6d8 (&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_level_irq+0x25d/0x6f0 kernel/irq/chip.c:648
  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
  __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:151 [inline]
  _raw_spin_unlock_irqrestore+0x31/0x80 kernel/locking/spinlock.c:194
  __setup_irq+0x1069/0x1e80 kernel/irq/manage.c:1818
  request_threaded_irq+0x2b4/0x3e0 kernel/irq/manage.c:2202
  request_irq include/linux/interrupt.h:168 [inline]
  setup_default_timer_irq arch/x86/kernel/time.c:70 [inline]
  hpet_time_init+0x5b/0x90 arch/x86/kernel/time.c:82
  x86_late_time_init+0x51/0xc0 arch/x86/kernel/time.c:94
  start_kernel+0x317/0x490 init/main.c:1039
  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: 976815
hardirqs last  enabled at (976811): [<ffffffff8ad33eab>] irqentry_exit+0x3b/0x90 kernel/entry/common.c:351
hardirqs last disabled at (976812): [<ffffffff8ad577f4>] __schedule+0x2644/0x5c70 kernel/sched/core.c:6634
softirqs last  enabled at (976814): [<ffffffff88cc194d>] spin_unlock_bh include/linux/spinlock.h:396 [inline]
softirqs last  enabled at (976814): [<ffffffff88cc194d>] __sock_map_delete net/core/sock_map.c:424 [inline]
softirqs last  enabled at (976814): [<ffffffff88cc194d>] sock_map_delete_elem+0xfd/0x150 net/core/sock_map.c:446
softirqs last disabled at (976815): [<ffffffff8152e202>] do_softirq kernel/softirq.c:455 [inline]
softirqs last disabled at (976815): [<ffffffff8152e202>] do_softirq+0xb2/0xf0 kernel/softirq.c:442

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

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

 *** DEADLOCK ***

5 locks held by kworker/1:1/44:
 #0: ffff888015074948
 ((wq_completion)events
){+.+.}-{0:0}
, at: process_one_work+0x1296/0x1a60 kernel/workqueue.c:3229
 #1: ffffc90000b47d80
 ((work_completion)(&(&krcp->krw_arr[i].rcu_work)->work)
){+.+.}-{0:0}
, at: process_one_work+0x906/0x1a60 kernel/workqueue.c:3230
 #2: ffffffff8d7b48c0
 (rcu_callback
){....}-{0:0}
, at: rcu_lock_acquire include/linux/rcupdate.h:298 [inline]
, at: kvfree_rcu_bulk+0x143/0x550 kernel/rcu/tree.c:3027
 #3: ffff8880b953e6d8
 (&rq->__lock
){?.-.}-{2:2}
, at: raw_spin_rq_lock_nested+0x29/0x130 kernel/sched/core.c:559
 #4: ffffffff8d7b49e0
 (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: 1 PID: 44 Comm: kworker/1:1 Not tainted 6.8.0-syzkaller-08951-gfe46a7dd189e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 03/27/2024
Workqueue: events kfree_rcu_work

Call Trace:
 <IRQ>
 __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
 __do_softirq+0x1d6/0x8de kernel/softirq.c:538
 do_softirq kernel/softirq.c:455 [inline]
 do_softirq+0xb2/0xf0 kernel/softirq.c:442
 </IRQ>
 <TASK>
 __local_bh_enable_ip+0x100/0x120 kernel/softirq.c:382
 spin_unlock_bh include/linux/spinlock.h:396 [inline]
 __sock_map_delete net/core/sock_map.c:424 [inline]
 sock_map_delete_elem+0xfd/0x150 net/core/sock_map.c:446
 bpf_prog_2c29ac5cdc6b1842+0x42/0x4a
 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+0x179/0x460 kernel/trace/bpf_trace.c:2422


---
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 syzkaller@...glegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

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

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

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

Powered by blists - more mailing lists