Message-ID: <20221201003648.6d8f69e0@yea>
Date:   Thu, 1 Dec 2022 00:36:48 +0100
From:   "Erhard F." <erhard_f@...lbox.org>
To:     netdev@...r.kernel.org
Subject: "WARNING: inconsistent lock state, inconsistent {IN-HARDIRQ-W} ->
 {HARDIRQ-ON-W} usage." with netconsole on (kernel 6.1.0-rc7)

I've noticed several locking problems when netconsole is used on various machines on different arches. Another one on my G4 would be https://bugzilla.kernel.org/show_bug.cgi?id=216723

So the issue probably is not network driver or architecture specific or only partly is. So I'll post the latest incarnation here hoping this is the right place for this report.

Output is from my Pentium 4 box; i get this every boot, kernel 6.1.0-rc7. Full dmesg and kernel .config attached.

[...]
netpoll: netconsole: local port 6666
netpoll: netconsole: local IPv4 address 192.168.178.10
netpoll: netconsole: interface 'eth0'
netpoll: netconsole: remote port 6666
netpoll: netconsole: remote IPv4 address 192.168.178.3
netpoll: netconsole: remote ethernet address 70:85:c2:30:ec:01
netpoll: netconsole: device eth0 not up yet, forcing it
8139too 0000:00:0f.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC5E1
netpoll: netconsole: carrier detect appears untrustworthy, waiting 4 seconds

================================
WARNING: inconsistent lock state
6.1.0-rc7-P4 #4 Not tainted
--------------------------------
inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage.
swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
c13c4804 (&syncp->seq#2){?.-.}-{0:0}, at: __napi_poll.constprop.0+0x26/0x1ad
{IN-HARDIRQ-W} state was registered at:
  lock_acquire+0xa8/0x276
  rtl8139_interrupt+0x1f7/0x46a
  __handle_irq_event_percpu+0x7d/0x276
  handle_irq_event+0x29/0x60
  handle_fasteoi_irq+0x68/0x192
  __handle_irq+0x92/0xad
  __common_interrupt+0x3e/0xc9
  common_interrupt+0x22/0x39
  asm_common_interrupt+0x102/0x180
  default_idle+0xb/0xc
  default_idle_call+0x65/0x1d4
  do_idle+0x1d4/0x1d9
  cpu_startup_entry+0x17/0x1a
  rest_init+0xd1/0x141
  arch_call_rest_init+0x8/0x9
  start_kernel+0x4fa/0x50e
  i386_start_kernel+0x43/0x47
  startup_32_smp+0x161/0x164
irq event stamp: 14984
hardirqs last  enabled at (14984): [<c68a205d>] net_rx_action+0x76/0x2eb
hardirqs last disabled at (14983): [<c68a2288>] net_rx_action+0x2a1/0x2eb
softirqs last  enabled at (14968): [<c62175d3>] call_on_stack+0x40/0x4c
softirqs last disabled at (14981): [<c62175d3>] call_on_stack+0x40/0x4c

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

       CPU0
       ----
  lock(&syncp->seq#2);
  <Interrupt>
    lock(&syncp->seq#2);

 *** DEADLOCK ***

1 lock held by swapper/0/0:
 #0: c13c48a4 (&tp->rx_lock){+.-.}-{2:2}, at: rtl8139_poll+0x31/0x505

stack backtrace:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.1.0-rc7-P4 #4
Hardware name:  /FS51, BIOS 6.00 PG 12/02/2003
Call Trace:
 <SOFTIRQ>
 dump_stack_lvl+0x68/0x9e
 dump_stack+0xd/0x12
 print_usage_bug.part.0+0x16c/0x17d
 mark_lock.cold+0x57/0x5c
 __lock_acquire+0x36e/0x23ce
 lock_acquire+0xa8/0x276
 ? __napi_poll.constprop.0+0x26/0x1ad
 ? __napi_alloc_skb+0x10f/0x1d0
 rtl8139_poll+0x1ed/0x505
 ? __napi_poll.constprop.0+0x26/0x1ad
 __napi_poll.constprop.0+0x26/0x1ad
 ? lockdep_hardirqs_on_prepare+0xac/0x193
 ? net_rx_action+0x76/0x2eb
 net_rx_action+0x235/0x2eb
 __do_softirq+0xb2/0x440
 ? __softirqentry_text_start+0x8/0x8
 call_on_stack+0x40/0x4c
 </SOFTIRQ>
 ? __irq_exit_rcu+0x90/0xb7
 ? irq_exit_rcu+0x8/0x11
 ? common_interrupt+0x27/0x39
 ? asm_common_interrupt+0x102/0x180
 ? mwait_idle+0x67/0x67
 ? default_idle+0xb/0xc
 ? __mutex_lock+0x85a/0xbc3
 ? default_idle+0xb/0xc
 ? arch_cpu_idle+0xd/0x11
 ? default_idle_call+0x65/0x1d4
 ? do_idle+0x1d4/0x1d9
 ? cpu_startup_entry+0x17/0x1a
 ? rest_init+0xd1/0x141
 ? arch_call_rest_init+0x8/0x9
 ? start_kernel+0x4fa/0x50e
 ? i386_start_kernel+0x43/0x47
 ? startup_32_smp+0x161/0x164
printk: console [netcon0] enabled
netconsole: network logging started
[...]


Some data about the machine:

 # inxi -bZ
System:
  Kernel: 6.1.0-rc7-P4 arch: i686 bits: 32 Console: pty pts/0
    Distro: Gentoo Base System release 2.9
Machine:
  Type: Desktop Mobo: Shuttle model: FS51 serial: N/A BIOS: Phoenix
    v: 6.00 PG date: 12/02/2003
CPU:
  Info: single core Intel Pentium 4 [MT] speed (MHz): avg: 3063
Graphics:
  Device-1: AMD RV350 [Radeon 9550/9600/X1050 Series] driver: radeon
    v: kernel
  Display: x11 server: X.Org v: 21.1.1 driver: X: loaded: radeon
    unloaded: fbdev,modesetting gpu: radeon resolution: 1400x900~60Hz
  OpenGL: renderer: llvmpipe (LLVM 14.0.6 128 bits) v: 4.5 Mesa 22.1.7
Network:
  Device-1: Ralink RT2500 Wireless 802.11bg driver: rt2500pci
  Device-2: Realtek RTL-8100/8101L/8139 PCI Fast Ethernet Adapter
    driver: 8139too


Regards,
Erhard F.

View attachment "dmesg_61-rc7_p4_gcc.txt" of type "text/plain" (45164 bytes)

View attachment "config_61-rc7_p4-gcc.txt" of type "text/plain" (113669 bytes)

Powered by blists - more mailing lists