[linus:master] [usb] a7f3813e58: WARNING:inconsistent_lock_state

From: kernel test robot
Date: Fri Jun 14 2024 - 02:10:53 EST




Hello,

kernel test robot noticed "WARNING:inconsistent_lock_state" on:

commit: a7f3813e589fd8e2834720829a47b5eb914a9afe ("usb: gadget: dummy_hcd: Switch to hrtimer transfer scheduler")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[test failed on linus/master d20f6b3d747c36889b7ce75ee369182af3decb6b]
[test failed on linux-next/master 6906a84c482f098d31486df8dc98cead21cce2d0]

in testcase: boot

compiler: gcc-13
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)


+---------------------------------------------------+------------+------------+
| | 920e7522e3 | a7f3813e58 |
+---------------------------------------------------+------------+------------+
| WARNING:inconsistent_lock_state | 0 | 9 |
+---------------------------------------------------+------------+------------+


If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202406141323.413a90d2-lkp@xxxxxxxxx


[ 9.059145][ C1] WARNING: inconsistent lock state
[ 9.059806][ C1] 6.9.0-rc2-00079-ga7f3813e589f #1 Tainted: G W
[ 9.060791][ C1] --------------------------------
[ 9.061452][ C1] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
[ 9.062377][ C1] swapper/1/0 [HC1[1]:SC0[0]:HE0:SE1] takes:
[ 9.063151][ C1] e7491784 (&syncp->seq#2){?...}-{0:0}, at: __usb_hcd_giveback_urb (drivers/usb/core/hcd.c:1651)
[ 9.064334][ C1] {HARDIRQ-ON-W} state was registered at:
[ 9.065080][ C1] __lock_acquire (kernel/locking/lockdep.c:5091 (discriminator 1))
[ 9.065718][ C1] lock_acquire (kernel/locking/lockdep.c:467 (discriminator 4) kernel/locking/lockdep.c:5756 (discriminator 4) kernel/locking/lockdep.c:5719 (discriminator 4))
[ 9.066493][ C1] dsa_user_xmit (include/linux/seqlock.h:423 include/linux/seqlock.h:470 include/linux/seqlock.h:495 include/linux/u64_stats_sync.h:146 include/linux/u64_stats_sync.h:182 include/linux/netdevice.h:2763 net/dsa/user.c:928)
[ 9.067097][ C1] dev_hard_start_xmit (include/linux/netdevice.h:4903 include/linux/netdevice.h:4917 net/core/dev.c:3531 net/core/dev.c:3547)
[ 9.067783][ C1] __dev_queue_xmit (include/linux/netdevice.h:3287 (discriminator 25) net/core/dev.c:4336 (discriminator 25))
[ 9.068380][ C1] neigh_resolve_output (net/core/neighbour.c:1573)
[ 9.068989][ C1] ip6_finish_output2 (include/net/neighbour.h:542 (discriminator 2) net/ipv6/ip6_output.c:137 (discriminator 2))
[ 9.069558][ C1] ip6_finish_output+0x88/0x334
[ 9.070027][ C1] ip6_output (net/ipv6/ip6_output.c:247)
[ 9.070340][ C1] mld_sendpack (net/ipv6/mcast.c:1822)
[ 9.070679][ C1] mld_send_cr (net/ipv6/mcast.c:2120)
[ 9.071008][ C1] mld_ifc_work (net/ipv6/mcast.c:2652)
[ 9.071340][ C1] process_one_work (arch/x86/include/asm/atomic.h:23 include/linux/atomic/atomic-arch-fallback.h:457 include/linux/jump_label.h:260 include/linux/jump_label.h:270 include/trace/events/workqueue.h:108 kernel/workqueue.c:3259)
[ 9.071709][ C1] worker_thread (kernel/workqueue.c:3329 (discriminator 2) kernel/workqueue.c:3416 (discriminator 2))
[ 9.072097][ C1] kthread (kernel/kthread.c:388)
[ 9.072390][ C1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 9.072726][ C1] ret_from_fork_asm (arch/x86/entry/entry_32.S:737)
[ 9.073080][ C1] restore_all_switch_stack (arch/x86/entry/entry_32.S:944)
[ 9.073490][ C1] irq event stamp: 9450
[ 9.073816][ C1] hardirqs last enabled at (9449): cpuidle_idle_call (kernel/sched/idle.c:192)
[ 9.074473][ C1] hardirqs last disabled at (9450): sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043)
[ 9.075191][ C1] softirqs last enabled at (9444): __do_softirq (kernel/softirq.c:401 (discriminator 2) kernel/softirq.c:583 (discriminator 2))
[ 9.075819][ C1] softirqs last disabled at (9439): do_softirq_own_stack (arch/x86/kernel/irq_32.c:57 arch/x86/kernel/irq_32.c:147)
[ 9.076487][ C1]
[ 9.076487][ C1] other info that might help us debug this:
[ 9.077082][ C1] Possible unsafe locking scenario:
[ 9.077082][ C1]
[ 9.077627][ C1] CPU0
[ 9.077881][ C1] ----
[ 9.078119][ C1] lock(&syncp->seq#2);
[ 9.078439][ C1] <Interrupt>
[ 9.078691][ C1] lock(&syncp->seq#2);
[ 9.079016][ C1]
[ 9.079016][ C1] *** DEADLOCK ***
[ 9.079016][ C1]
[ 9.079612][ C1] no locks held by swapper/1/0.
[ 9.079964][ C1]
[ 9.079964][ C1] stack backtrace:
[ 9.080391][ C1] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W 6.9.0-rc2-00079-ga7f3813e589f #1 f0ecba0cf7deeaf8786bb8219ff9a6fa3c51532b
[ 9.081435][ C1] Call Trace:
[ 9.081686][ C1] dump_stack_lvl (lib/dump_stack.c:117)
[ 9.082053][ C1] dump_stack (lib/dump_stack.c:124)
[ 9.082359][ C1] print_usage_bug+0x208/0x2e0
[ 9.082769][ C1] mark_lock_irq (kernel/locking/lockdep.c:3971 (discriminator 1) kernel/locking/lockdep.c:4013 (discriminator 1) kernel/locking/lockdep.c:4216 (discriminator 1))
[ 9.083119][ C1] mark_lock (kernel/locking/lockdep.c:4678)
[ 9.083437][ C1] mark_usage (kernel/locking/lockdep.c:4564 (discriminator 1))
[ 9.083765][ C1] __lock_acquire (kernel/locking/lockdep.c:5091 (discriminator 1))
[ 9.084121][ C1] lock_acquire (kernel/locking/lockdep.c:467 (discriminator 4) kernel/locking/lockdep.c:5756 (discriminator 4) kernel/locking/lockdep.c:5719 (discriminator 4))
[ 9.084452][ C1] ? __usb_hcd_giveback_urb (drivers/usb/core/hcd.c:1651)
[ 9.084879][ C1] ? sched_clock_noinstr (arch/x86/kernel/tsc.c:267)
[ 9.085237][ C1] ? local_clock_noinstr (kernel/sched/clock.c:301 (discriminator 1))
[ 9.085624][ C1] ? lock_acquire (kernel/locking/lockdep.c:467 (discriminator 4) kernel/locking/lockdep.c:5756 (discriminator 4) kernel/locking/lockdep.c:5719 (discriminator 4))
[ 9.085975][ C1] tx_complete (include/linux/skbuff.h:2228 (discriminator 2) include/linux/skbuff.h:2336 (discriminator 2) include/linux/skbuff.h:2369 (discriminator 2) drivers/net/usb/lan78xx.c:3334 (discriminator 2) drivers/net/usb/lan78xx.c:3385 (discriminator 2))
[ 9.086304][ C1] ? __usb_hcd_giveback_urb (drivers/usb/core/hcd.c:1651)
[ 9.086700][ C1] __usb_hcd_giveback_urb (drivers/usb/core/hcd.c:1651)
[ 9.087089][ C1] usb_hcd_giveback_urb (drivers/usb/core/hcd.c:1752)
[ 9.087462][ C1] dummy_timer (include/linux/spinlock.h:351 drivers/usb/gadget/udc/dummy_hcd.c:1986)
[ 9.087807][ C1] __hrtimer_run_queues (kernel/time/hrtimer.c:1692 kernel/time/hrtimer.c:1756)
[ 9.088197][ C1] ? transfer (drivers/usb/gadget/udc/dummy_hcd.c:1781)
[ 9.088511][ C1] hrtimer_run_queues (kernel/time/hrtimer.c:1932)
[ 9.088869][ C1] update_process_times (kernel/time/timer.c:2467 (discriminator 1) kernel/time/timer.c:2485 (discriminator 1))
[ 9.089230][ C1] tick_nohz_lowres_handler (kernel/time/tick-sched.c:274 kernel/time/tick-sched.c:294 kernel/time/tick-sched.c:1480)
[ 9.089638][ C1] ? sysvec_call_function_single (arch/x86/kernel/apic/apic.c:1043)
[ 9.090076][ C1] __sysvec_apic_timer_interrupt (arch/x86/include/asm/atomic.h:23 include/linux/atomic/atomic-arch-fallback.h:457 include/linux/jump_label.h:260 include/linux/jump_label.h:270 arch/x86/include/asm/trace/irq_vectors.h:41 arch/x86/kernel/apic/apic.c:1050)
[ 9.090509][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043 (discriminator 3) arch/x86/kernel/apic/apic.c:1043 (discriminator 3))
[ 9.090949][ C1] handle_exception (arch/x86/entry/entry_32.S:1047)
[ 9.091305][ C1] EIP: default_idle (arch/x86/include/asm/irqflags.h:37 arch/x86/include/asm/irqflags.h:72 arch/x86/kernel/process.c:743)
[ 9.091654][ C1] Code: ff 89 da b8 fc a2 30 c3 e8 6f 7c 4f ff e9 e8 fa ff ff cc cc cc cc cc cc a1 a0 ea 65 c3 85 c0 7e 07 0f 00 2d f6 ed 17 c2 fb f4 <fa> c3 55 89 e5 53 64 8b 1d 00 32 64 c3 f0 80 4b 02 20 8b 03 a8 08
All code
========
0: ff 89 da b8 fc a2 decl -0x5d034726(%rcx)
6: 30 c3 xor %al,%bl
8: e8 6f 7c 4f ff call 0xffffffffff4f7c7c
d: e9 e8 fa ff ff jmp 0xfffffffffffffafa
12: cc int3
13: cc int3
14: cc int3
15: cc int3
16: cc int3
17: cc int3
18: a1 a0 ea 65 c3 85 c0 movabs 0x77ec085c365eaa0,%eax
1f: 7e 07
21: 0f 00 2d f6 ed 17 c2 verw -0x3de8120a(%rip) # 0xffffffffc217ee1e
28: fb sti
29: f4 hlt
2a:* fa cli <-- trapping instruction
2b: c3 ret
2c: 55 push %rbp
2d: 89 e5 mov %esp,%ebp
2f: 53 push %rbx
30: 64 8b 1d 00 32 64 c3 mov %fs:-0x3c9bce00(%rip),%ebx # 0xffffffffc3643237
37: f0 80 4b 02 20 lock orb $0x20,0x2(%rbx)
3c: 8b 03 mov (%rbx),%eax
3e: a8 08 test $0x8,%al

Code starting with the faulting instruction
===========================================
0: fa cli
1: c3 ret
2: 55 push %rbp
3: 89 e5 mov %esp,%ebp
5: 53 push %rbx
6: 64 8b 1d 00 32 64 c3 mov %fs:-0x3c9bce00(%rip),%ebx # 0xffffffffc364320d
d: f0 80 4b 02 20 lock orb $0x20,0x2(%rbx)
12: 8b 03 mov (%rbx),%eax
14: a8 08 test $0x8,%al


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240614/202406141323.413a90d2-lkp@xxxxxxxxx



--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki