Created attachment 295071 [details] dmesg (kernel 5.11-rc6, Shuttle XPC FS51, Pentium 4) Happens every time at booting since I got netconsole enabled. [...] netpoll: netconsole: local port 6666 netpoll: netconsole: local IPv4 address 192.168.2.7 netpoll: netconsole: interface 'eth0' netpoll: netconsole: remote port 6666 netpoll: netconsole: remote IPv4 address 192.168.2.3 netpoll: netconsole: remote ethernet address xx:xx:xx:xx:xx:xx 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 5.11.0-rc6-Pentium4 #4 Not tainted -------------------------------- inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: c1081800 (&syncp->seq#2){?.-.}-{0:0}, at: rtl8139_poll+0x24b/0x34a {IN-HARDIRQ-W} state was registered at: lock_acquire+0x236/0x2b4 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f rtl8139_interrupt+0x346/0x3cb __handle_irq_event_percpu+0xe5/0x20c handle_irq_event_percpu+0x17/0x3d handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x67/0xd7 __handle_irq+0x7d/0x9c common_interrupt+0x7b/0xe5 asm_common_interrupt+0x106/0x180 _raw_spin_unlock_irqrestore+0x28/0x33 __mod_timer+0x1cd/0x1d8 mod_timer+0xa/0xc mld_ifc_start_timer+0x24/0x37 mld_ifc_timer_expire+0x1b0/0x1c0 call_timer_fn+0xfe/0x201 __run_timers+0x134/0x159 run_timer_softirq+0x14/0x27 __do_softirq+0x15f/0x307 call_on_stack+0x40/0x46 do_softirq_own_stack+0x1c/0x1e __irq_exit_rcu+0x4f/0x85 irq_exit_rcu+0x8/0x11 sysvec_apic_timer_interrupt+0x3e/0x4b handle_exception_return+0x0/0xaf default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xb7/0x1c3 cpu_startup_entry+0x19/0x1b rest_init+0x11d/0x120 arch_call_rest_init+0x8/0xb start_kernel+0x412/0x420 i386_start_kernel+0x43/0x45 startup_32_smp+0x164/0x168 irq event stamp: 8782 hardirqs last enabled at (8782): [<dd8929e2>] net_rx_action+0x75/0x250 hardirqs last disabled at (8781): [<dd8929bf>] net_rx_action+0x52/0x250 softirqs last enabled at (8772): [<dd99221f>] __do_softirq+0x2d7/0x307 softirqs last disabled at (8779): [<dd40fc2e>] call_on_stack+0x40/0x46 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: c10818a0 (&tp->rx_lock){+.-.}-{2:2}, at: rtl8139_poll+0x31/0x34a stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.11.0-rc6-Pentium4 #4 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <SOFTIRQ> dump_stack+0x6b/0x89 print_usage_bug+0x17d/0x188 mark_lock.part.0+0xf8/0x272 ? check_chain_key+0xea/0x142 __lock_acquire+0x459/0x147f ? rcu_read_lock_sched_held+0x23/0x4a ? trace_kmalloc+0x8c/0xb9 ? __kmalloc_track_caller+0x113/0x126 lock_acquire+0x236/0x2b4 ? rtl8139_poll+0x24b/0x34a ? ksize+0xd/0x12 ? __alloc_skb+0x84/0x133 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f ? rtl8139_poll+0x24b/0x34a rtl8139_poll+0x24b/0x34a net_rx_action+0xd2/0x250 __do_softirq+0x15f/0x307 ? __entry_text_end+0x5/0x5 call_on_stack+0x40/0x46 </SOFTIRQ> ? __irq_exit_rcu+0x4f/0x85 ? irq_exit_rcu+0x8/0x11 ? common_interrupt+0xd3/0xe5 ? asm_common_interrupt+0x106/0x180 ? ldsem_down_write+0x1f/0x1f ? default_idle+0xa/0xc ? schedule_timeout+0x41/0x97 ? default_idle+0xa/0xc ? arch_cpu_idle+0xd/0xf ? default_idle_call+0x48/0x74 ? do_idle+0xb7/0x1c3 ? cpu_startup_entry+0x19/0x1b ? rest_init+0x11d/0x120 ? arch_call_rest_init+0x8/0xb ? start_kernel+0x412/0x420 ? i386_start_kernel+0x43/0x45 ? startup_32_smp+0x164/0x168 random: fast init done printk: console [netcon0] enabled netconsole: network logging started [...] # lspci 00:00.0 Host bridge: Silicon Integrated Systems [SiS] 651 Host (rev 02) 00:01.0 PCI bridge: Silicon Integrated Systems [SiS] AGP Port (virtual PCI-to-PCI bridge) 00:02.0 ISA bridge: Silicon Integrated Systems [SiS] SiS962 [MuTIOL Media IO] LPC Controller (rev 14) 00:02.1 SMBus: Silicon Integrated Systems [SiS] SiS961/2/3 SMBus controller 00:02.5 IDE interface: Silicon Integrated Systems [SiS] 5513 IDE Controller 00:02.7 Multimedia audio controller: Silicon Integrated Systems [SiS] SiS7012 AC'97 Sound Controller (rev a0) 00:03.0 USB controller: Silicon Integrated Systems [SiS] USB 1.1 Controller (rev 0f) 00:03.1 USB controller: Silicon Integrated Systems [SiS] USB 1.1 Controller (rev 0f) 00:03.2 USB controller: Silicon Integrated Systems [SiS] USB 1.1 Controller (rev 0f) 00:03.3 USB controller: Silicon Integrated Systems [SiS] USB 2.0 Controller 00:0a.0 Network controller: Ralink corp. RT2500 Wireless 802.11bg (rev 01) 00:0f.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL-8100/8101L/8139 PCI Fast Ethernet Adapter (rev 10) 00:10.0 FireWire (IEEE 1394): VIA Technologies, Inc. VT6306/7/8 [Fire II(M)] IEEE 1394 OHCI Controller (rev 46) 01:00.0 VGA compatible controller: Advanced Micro Devices, Inc. [AMD/ATI] RV350 [Radeon 9550/9600/X1050 Series] 01:00.1 Display controller: Advanced Micro Devices, Inc. [AMD/ATI] RV350 [Radeon 9550/9600/X1050 Series] (Secondary) # LC_ALL=C lscpu Architecture: i686 CPU op-mode(s): 32-bit Byte Order: Little Endian Address sizes: 36 bits physical, 32 bits virtual CPU(s): 1 On-line CPU(s) list: 0 Thread(s) per core: 1 Core(s) per socket: 1 Socket(s): 1 Vendor ID: GenuineIntel CPU family: 15 Model: 2 Model name: Intel(R) Pentium(R) 4 CPU 3.06GHz Stepping: 7 CPU MHz: 3062.724 BogoMIPS: 6127.67 Vulnerability Itlb multihit: Processor vulnerable Vulnerability L1tf: Vulnerable Vulnerability Mds: Vulnerable: Clear CPU buffers attempted, no microcode; SMT disabled Vulnerability Meltdown: Vulnerable Vulnerability Spec store bypass: Vulnerable Vulnerability Spectre v1: Mitigation; usercopy/swapgs barriers and __user pointer sanitization Vulnerability Spectre v2: Mitigation; Full generic retpoline, STIBP disabled, RSB filling Vulnerability Srbds: Not affected Vulnerability Tsx async abort: Not affected Flags: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe pebs bts cpuid cid xtpr
Created attachment 295073 [details] kernel .config (kernel 5.11-rc6, Shuttle XPC FS51, Pentium 4)
Created attachment 295579 [details] dmesg (kernel 5.12-rc1, Shuttle XPC FS51, Pentium 4) Same for 5.12-rc1. ================================ WARNING: inconsistent lock state 5.12.0-rc1-Pentium4 #2 Not tainted -------------------------------- inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: c113c804 (&syncp->seq#2){?.-.}-{0:0}, at: rtl8139_poll+0x251/0x350 {IN-HARDIRQ-W} state was registered at: lock_acquire+0x239/0x2c5 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f rtl8139_interrupt+0x346/0x3cb __handle_irq_event_percpu+0xe5/0x20c handle_irq_event_percpu+0x17/0x3d handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x67/0xd7 __handle_irq+0x7d/0x9c __common_interrupt+0x68/0xc3 common_interrupt+0x22/0x35 asm_common_interrupt+0x106/0x180 _raw_spin_unlock_irqrestore+0x41/0x45 __mod_timer+0x1cd/0x1d8 mod_timer+0xa/0xc mld_ifc_start_timer+0x24/0x37 mld_ifc_timer_expire+0x1b0/0x1c0 call_timer_fn+0xfe/0x201 __run_timers+0x134/0x159 run_timer_softirq+0x14/0x27 __do_softirq+0x15f/0x307 call_on_stack+0x40/0x46 do_softirq_own_stack+0x1c/0x1e __irq_exit_rcu+0x4f/0x85 irq_exit_rcu+0x8/0x11 sysvec_apic_timer_interrupt+0x20/0x2e handle_exception_return+0x0/0xaf default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xb7/0x1c3 cpu_startup_entry+0x19/0x1b rest_init+0x11d/0x120 arch_call_rest_init+0x8/0xb start_kernel+0x417/0x425 i386_start_kernel+0x43/0x45 startup_32_smp+0x164/0x168 irq event stamp: 26328 hardirqs last enabled at (26328): [<c4362e64>] __slab_alloc.constprop.0+0x3e/0x59 hardirqs last disabled at (26327): [<c4362e47>] __slab_alloc.constprop.0+0x21/0x59 softirqs last enabled at (26314): [<c4789f1f>] __do_softirq+0x2d7/0x307 softirqs last disabled at (26321): [<c420fecb>] call_on_stack+0x40/0x46 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: c113c8a4 (&tp->rx_lock){+.-.}-{2:2}, at: rtl8139_poll+0x31/0x350 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.12.0-rc1-Pentium4 #2 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <SOFTIRQ> dump_stack+0x78/0xa5 print_usage_bug+0x17d/0x188 mark_lock.part.0+0xfd/0x27a ? hlock_class+0x18/0x58 ? mark_lock.part.0+0x33/0x27a ? ___slab_alloc.constprop.0+0x2b7/0x2d1 __lock_acquire+0x458/0x1488 ? rcu_read_lock_sched_held+0x23/0x4a ? trace_kmalloc+0x8c/0xb9 ? __kmalloc_track_caller+0x130/0x143 lock_acquire+0x239/0x2c5 ? rtl8139_poll+0x251/0x350 ? __alloc_skb+0xb7/0x102 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f ? rtl8139_poll+0x251/0x350 rtl8139_poll+0x251/0x350 __napi_poll+0x24/0xf1 net_rx_action+0xbb/0x177 __do_softirq+0x15f/0x307 ? __entry_text_end+0x5/0x5 call_on_stack+0x40/0x46 </SOFTIRQ> ? __irq_exit_rcu+0x4f/0x85 ? irq_exit_rcu+0x8/0x11 ? common_interrupt+0x27/0x35 ? asm_common_interrupt+0x106/0x180 ? ldsem_down_write+0x1f/0x1f ? newidle_balance+0x1d0/0x3ab ? default_idle+0xa/0xc ? __pci_setup_bridge+0x4e/0x64 ? default_idle+0xa/0xc ? arch_cpu_idle+0xd/0xf ? default_idle_call+0x48/0x74 ? do_idle+0xb7/0x1c3 ? cpu_startup_entry+0x19/0x1b ? rest_init+0x11d/0x120 ? arch_call_rest_init+0x8/0xb ? start_kernel+0x417/0x425 ? i386_start_kernel+0x43/0x45 ? startup_32_smp+0x164/0x168
Thank you for the report! Are you able to apply patches and build the kernel to test? I think this would be the fix: diff --git a/drivers/net/ethernet/realtek/8139too.c b/drivers/net/ethernet/realtek/8139too.c index 1e5a453dea14..e5c333eacc11 100644 --- a/drivers/net/ethernet/realtek/8139too.c +++ b/drivers/net/ethernet/realtek/8139too.c @@ -2222,9 +2222,12 @@ static void rtl8139_poll_controller(struct net_device *dev) { struct rtl8139_private *tp = netdev_priv(dev); const int irq = tp->pci_dev->irq; + unsigned long flags; disable_irq_nosync(irq); + local_irq_save(flags); rtl8139_interrupt(irq, dev); + local_irq_restore(flags); enable_irq(irq); } #endif
With the patch applied I still get almost the same backtrace: [...] ================================ WARNING: inconsistent lock state 5.12.0-rc1-Pentium4+ #3 Not tainted -------------------------------- inconsistent {IN-HARDIRQ-W} -> {HARDIRQ-ON-W} usage. swapper/0/0 [HC0[0]:SC1[1]:HE1:SE0] takes: c113c804 (&syncp->seq#2){?.-.}-{0:0}, at: rtl8139_poll+0x251/0x350 {IN-HARDIRQ-W} state was registered at: lock_acquire+0x239/0x2c5 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f rtl8139_interrupt+0x346/0x3cb __handle_irq_event_percpu+0xe5/0x20c handle_irq_event_percpu+0x17/0x3d handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x67/0xd7 __handle_irq+0x7d/0x9c __common_interrupt+0x68/0xc3 common_interrupt+0x22/0x35 asm_common_interrupt+0x106/0x180 _raw_spin_unlock_irqrestore+0x41/0x45 __mod_timer+0x1cd/0x1d8 mod_timer+0xa/0xc mld_ifc_start_timer+0x24/0x37 mld_ifc_timer_expire+0x1b0/0x1c0 call_timer_fn+0xfe/0x201 __run_timers+0x134/0x159 run_timer_softirq+0x14/0x27 __do_softirq+0x15f/0x307 call_on_stack+0x40/0x46 do_softirq_own_stack+0x1c/0x1e __irq_exit_rcu+0x4f/0x85 irq_exit_rcu+0x8/0x11 sysvec_apic_timer_interrupt+0x20/0x2e handle_exception_return+0x0/0xaf default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xb7/0x1c3 cpu_startup_entry+0x19/0x1b rest_init+0x11d/0x120 arch_call_rest_init+0x8/0xb start_kernel+0x417/0x425 i386_start_kernel+0x43/0x45 startup_32_smp+0x164/0x168 irq event stamp: 23566 hardirqs last enabled at (23566): [<dad62e64>] __slab_alloc.constprop.0+0x3e/0x59 hardirqs last disabled at (23565): [<dad62e47>] __slab_alloc.constprop.0+0x21/0x59 softirqs last enabled at (23552): [<db189f1f>] __do_softirq+0x2d7/0x307 softirqs last disabled at (23559): [<dac0fecb>] call_on_stack+0x40/0x46 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: c113c8a4 (&tp->rx_lock){+.-.}-{2:2}, at: rtl8139_poll+0x31/0x350 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.12.0-rc1-Pentium4+ #3 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <SOFTIRQ> dump_stack+0x78/0xa5 print_usage_bug+0x17d/0x188 mark_lock.part.0+0xfd/0x27a ? hlock_class+0x18/0x58 ? mark_lock.part.0+0x33/0x27a ? ___slab_alloc.constprop.0+0x2b7/0x2d1 __lock_acquire+0x458/0x1488 ? rcu_read_lock_sched_held+0x23/0x4a ? trace_kmalloc+0x8c/0xb9 ? __kmalloc_track_caller+0x130/0x143 lock_acquire+0x239/0x2c5 ? rtl8139_poll+0x251/0x350 ? __alloc_skb+0xb7/0x102 do_write_seqcount_begin_nested.constprop.0+0x1a/0x1f ? rtl8139_poll+0x251/0x350 rtl8139_poll+0x251/0x350 __napi_poll+0x24/0xf1 net_rx_action+0xbb/0x177 __do_softirq+0x15f/0x307 ? __entry_text_end+0x5/0x5 call_on_stack+0x40/0x46 </SOFTIRQ> ? __irq_exit_rcu+0x4f/0x85 ? irq_exit_rcu+0x8/0x11 ? common_interrupt+0x27/0x35 ? asm_common_interrupt+0x106/0x180 ? ldsem_down_write+0x1f/0x1f ? pci_subsys_init+0x41/0x5c ? default_idle+0xa/0xc ? __pci_setup_bridge+0x25/0x64 ? default_idle+0xa/0xc ? arch_cpu_idle+0xd/0xf ? default_idle_call+0x48/0x74 ? do_idle+0xb7/0x1c3 ? cpu_startup_entry+0x19/0x1b ? rest_init+0x11d/0x120 ? arch_call_rest_init+0x8/0xb ? start_kernel+0x417/0x425 ? i386_start_kernel+0x43/0x45 ? startup_32_smp+0x164/0x168
Strange, I don't see the same syncp being taken both in RX and TX paths. Would you be able to translate the offsets into lines of code? For common builds you'd need to do something like: ./scripts/decode_stacktrace.sh vmlinux ./ ./ And then paste in the stack trace. The script will respond with line numbers. In particular I wonder what's at: rtl8139_poll+0x251/0x350 and: rtl8139_interrupt+0x346/0x3cb
Pasted the stuff after "{IN-HARDIRQ-W} state was registered at:" from v5.12-rc1 + patch and got: lock_acquire (/usr/src/linux-stable/kernel/locking/lockdep.c:437) startup_32_smp+0x164/0x168lock_acquire (/usr/src/linux-stable/kernel/locking/lockdep.c:437) do_write_seqcount_begin_nested.constprop.0 (/usr/src/linux-stable/./include/linux/seqlock.h:520) rtl8139_interrupt (/usr/src/linux-stable/drivers/net/ethernet/realtek/8139too.c:1806) __handle_irq_event_percpu (/usr/src/linux-stable/kernel/irq/handle.c:156) handle_irq_event_percpu (/usr/src/linux-stable/kernel/irq/handle.c:196) handle_irq_event (/usr/src/linux-stable/kernel/irq/handle.c:213) handle_fasteoi_irq (/usr/src/linux-stable/kernel/irq/chip.c:662) __handle_irq (/usr/src/linux-stable/arch/x86/kernel/irq_32.c:100) __common_interrupt (/usr/src/linux-stable/arch/x86/kernel/irq.c:234) common_interrupt (/usr/src/linux-stable/arch/x86/kernel/irq.c:240) asm_common_interrupt (/usr/src/linux-stable/./arch/x86/include/asm/idtentry.h:623) _raw_spin_unlock_irqrestore (/usr/src/linux-stable/kernel/locking/spinlock.c:192) __mod_timer (/usr/src/linux-stable/kernel/time/timer.c:1066) mod_timer (/usr/src/linux-stable/kernel/time/timer.c:1107) mld_ifc_start_timer (/usr/src/linux-stable/net/ipv6/mcast.c:1050) mld_ifc_timer_expire (/usr/src/linux-stable/net/ipv6/mcast.c:2481) call_timer_fn (/usr/src/linux-stable/./arch/x86/include/asm/jump_label.h:25) __run_timers (/usr/src/linux-stable/kernel/time/timer.c:1477) run_timer_softirq (/usr/src/linux-stable/kernel/time/timer.c:1760) __do_softirq (/usr/src/linux-stable/./arch/x86/include/asm/jump_label.h:25) call_on_stack (/usr/src/linux-stable/arch/x86/kernel/irq_32.c:60) do_softirq_own_stack (/usr/src/linux-stable/arch/x86/kernel/irq_32.c:150) __irq_exit_rcu (/usr/src/linux-stable/kernel/softirq.c:228) irq_exit_rcu (/usr/src/linux-stable/kernel/softirq.c:436) sysvec_apic_timer_interrupt (/usr/src/linux-stable/arch/x86/kernel/apic/apic.c:1100) handle_exception_return (/usr/src/linux-stable/arch/x86/entry/entry_32.S:1179) default_idle (/usr/src/linux-stable/arch/x86/kernel/process.c:689) arch_cpu_idle (/usr/src/linux-stable/arch/x86/kernel/process.c:681) default_idle_call (/usr/src/linux-stable/./arch/x86/include/asm/irqflags.h:40) do_idle (/usr/src/linux-stable/kernel/sched/idle.c:195) cpu_startup_entry (/usr/src/linux-stable/kernel/sched/idle.c:396 (discriminator 1)) rest_init (/usr/src/linux-stable/init/main.c:722) arch_call_rest_init+0x8/0xb start_kernel (/usr/src/linux-stable/init/main.c:1066) i386_start_kernel (/usr/src/linux-stable/arch/x86/kernel/head32.c:57) Pasted the stuff after "Call Trace: <SOFTIRQ>" from v5.12-rc1 + patch and got: dump_stack (/usr/src/linux-stable/lib/dump_stack.c:122) print_usage_bug (/usr/src/linux-stable/kernel/locking/lockdep.c:3806) mark_lock.part.0 (/usr/src/linux-stable/kernel/locking/lockdep.c:3818) ? hlock_class (/usr/src/linux-stable/kernel/locking/lockdep.c:198) ? mark_lock.part.0 (/usr/src/linux-stable/kernel/locking/lockdep.c:4456) ? ___slab_alloc.constprop.0 (/usr/src/linux-stable/mm/slub.c:2767) __lock_acquire (/usr/src/linux-stable/kernel/locking/lockdep.c:4387) ? rcu_read_lock_sched_held (/usr/src/linux-stable/./include/linux/lockdep.h:278) ? trace_kmalloc (/usr/src/linux-stable/./include/trace/events/kmem.h:46) ? __kmalloc_track_caller (/usr/src/linux-stable/mm/slub.c:4566) lock_acquire (/usr/src/linux-stable/kernel/locking/lockdep.c:437) ? rtl8139_poll (/usr/src/linux-stable/drivers/net/ethernet/realtek/8139too.c:2051) ? __alloc_skb (/usr/src/linux-stable/net/core/skbuff.c:441) do_write_seqcount_begin_nested.constprop.0 (/usr/src/linux-stable/./include/linux/seqlock.h:520) ? rtl8139_poll (/usr/src/linux-stable/drivers/net/ethernet/realtek/8139too.c:2051) rtl8139_poll (/usr/src/linux-stable/drivers/net/ethernet/realtek/8139too.c:2051) __napi_poll (/usr/src/linux-stable/net/core/dev.c:6892) net_rx_action (/usr/src/linux-stable/net/core/dev.c:6959) __do_softirq (/usr/src/linux-stable/./arch/x86/include/asm/jump_label.h:25) ? __entry_text_end (/usr/src/linux-stable/kernel/softirq.c:303) call_on_stack (/usr/src/linux-stable/arch/x86/kernel/irq_32.c:60) </SOFTIRQ> ? __irq_exit_rcu (/usr/src/linux-stable/kernel/softirq.c:228) ? irq_exit_rcu (/usr/src/linux-stable/kernel/softirq.c:436) ? common_interrupt (/usr/src/linux-stable/arch/x86/kernel/irq.c:240) ? asm_common_interrupt (/usr/src/linux-stable/./arch/x86/include/asm/idtentry.h:623) ? ldsem_down_write (/usr/src/linux-stable/arch/x86/kernel/process.c:687) ? pci_subsys_init (/usr/src/linux-stable/arch/x86/pci/legacy.c:23) ? default_idle (/usr/src/linux-stable/arch/x86/kernel/process.c:689) ? __pci_setup_bridge (/usr/src/linux-stable/drivers/pci/setup-bus.c:672) ? default_idle (/usr/src/linux-stable/arch/x86/kernel/process.c:689) ? arch_cpu_idle (/usr/src/linux-stable/arch/x86/kernel/process.c:681) ? default_idle_call (/usr/src/linux-stable/./arch/x86/include/asm/irqflags.h:40) ? do_idle (/usr/src/linux-stable/kernel/sched/idle.c:195) ? cpu_startup_entry (/usr/src/linux-stable/kernel/sched/idle.c:396 (discriminator 1)) ? rest_init (/usr/src/linux-stable/init/main.c:722) ? arch_call_rest_init+0x8/0xb ? start_kernel (/usr/src/linux-stable/init/main.c:1066) ? i386_start_kernel (/usr/src/linux-stable/arch/x86/kernel/head32.c:57)
Probably bug #208097 is relevant too? Same machine, also IRQ related problems.
Makes no sense, these are separate locks, let me ask Ahmed on the mailing list.
Created attachment 296653 [details] dmesg (kernel 5.12.1, Shuttle XPC FS51, Pentium 4) Looks like 5.12.x is still affected. Though the trace looks a bit different compared to 5.11-rc6 and 5.12-rc1: [...] printk: console [netcon0] enabled ================================ WARNING: inconsistent lock state 5.12.1-gentoo-Pentium4 #2 Not tainted -------------------------------- inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: c108c8a4 (&tp->rx_lock){?.-.}-{2:2}, at: rtl8139_poll+0x31/0x350 {HARDIRQ-ON-W} state was registered at: lock_acquire+0x239/0x2c5 _raw_spin_lock+0x22/0x31 rtl8139_poll+0x31/0x350 __napi_poll+0x24/0xf1 net_rx_action+0xbb/0x177 __do_softirq+0x15f/0x307 call_on_stack+0x40/0x46 do_softirq_own_stack+0x1c/0x1e __irq_exit_rcu+0x4f/0x85 irq_exit_rcu+0x8/0x11 common_interrupt+0x27/0x35 asm_common_interrupt+0x106/0x180 default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xb7/0x1c3 cpu_startup_entry+0x19/0x1b rest_init+0x11d/0x120 arch_call_rest_init+0x8/0xb start_kernel+0x417/0x425 i386_start_kernel+0x43/0x45 startup_32_smp+0x164/0x168 irq event stamp: 23068 hardirqs last enabled at (23067): [<ced8c8c8>] default_idle_call+0x39/0x74 hardirqs last disabled at (23068): [<ced86781>] common_interrupt+0xf/0x35 softirqs last enabled at (22798): [<ced8e59f>] __do_softirq+0x2d7/0x307 softirqs last disabled at (22785): [<ce80fee0>] call_on_stack+0x40/0x46 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&tp->rx_lock); <Interrupt> lock(&tp->rx_lock); *** DEADLOCK *** 3 locks held by swapper/0/0: #0: cf038eb4 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x192/0x1cc #1: cf006dc4 (console_owner){-...}-{0:0}, at: console_unlock+0x260/0x475 #2: cf09b6f0 (target_list_lock){-...}-{2:2}, at: write_msg+0x37/0xa5 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.12.1-gentoo-Pentium4 #2 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <IRQ> dump_stack+0x78/0xa5 print_usage_bug+0x17d/0x188 mark_lock.part.0+0xfd/0x27a ? mark_lock.part.0+0x33/0x27a ? check_chain_key+0xea/0x142 __lock_acquire+0x3fb/0x1488 ? __lock_acquire+0x9f6/0x1488 ? __lock_acquire+0x9f6/0x1488 lock_acquire+0x239/0x2c5 ? rtl8139_poll+0x31/0x350 ? check_chain_key+0xea/0x142 _raw_spin_lock+0x22/0x31 ? rtl8139_poll+0x31/0x350 rtl8139_poll+0x31/0x350 ? enable_irq+0x45/0x53 netpoll_poll_dev+0xd7/0x1c1 netpoll_send_skb+0x12d/0x256 netpoll_send_udp+0x384/0x38c write_msg+0x87/0xa5 ? netconsole_netdev_event+0x13f/0x13f console_unlock+0x38a/0x475 vprintk_emit+0x1b6/0x1cc vprintk_default+0x10/0x12 vprintk_func+0x96/0xa1 printk+0xe/0x10 crng_fast_load+0xdf/0xea add_interrupt_randomness+0xec/0x14a handle_irq_event_percpu+0x24/0x3d handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x67/0xd7 ? handle_level_irq+0x83/0x83 __handle_irq+0x7d/0x9c </IRQ> __common_interrupt+0x68/0xc3 common_interrupt+0x22/0x35 asm_common_interrupt+0x106/0x180 EIP: default_idle+0xa/0xc Code: 51 89 c3 89 55 f8 e8 60 de ff ff 8b 4d f8 31 d2 89 d8 e8 e2 a1 e7 ff 5b 5b 5d c3 cc cc cc cc cc 55 89 e5 e8 cc 7e a8 ff fb f4 <5d> c3 55 89 e5 64 a1 d4 97 14 cf f0 80 48 02 20 8b 10 80 e2 08 75 EAX: ced8c720 EBX: 00000000 ECX: 00000000 EDX: ffffffff ESI: ceff2800 EDI: 00000000 EBP: cefebf2c ESP: cefebf2c DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00200202 ? __sched_text_end+0x5/0x5 ? print_irq_lock_scenario.isra.0+0x7a/0x10c ? default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xb7/0x1c3 cpu_startup_entry+0x19/0x1b rest_init+0x11d/0x120 arch_call_rest_init+0x8/0xb start_kernel+0x417/0x425 i386_start_kernel+0x43/0x45 startup_32_smp+0x164/0x168 netconsole: network logging started [...]
Created attachment 296655 [details] kernel .config (kernel 5.12.1, Shuttle XPC FS51, Pentium 4)
Created attachment 297931 [details] dmesg (kernel 5.14-rc2, Shuttle XPC FS51, Pentium 4) Looks like it's still in... kernel v5.14-rc2: [...] printk: console [netcon0] enabled ================================ WARNING: inconsistent lock state 5.14.0-rc2-Pentium4 #5 Not tainted -------------------------------- inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: c10ac8a4 (&tp->rx_lock){?.-.}-{2:2}, at: rtl8139_poll+0x31/0x350 {HARDIRQ-ON-W} state was registered at: lock_acquire+0x1f2/0x22a _raw_spin_lock+0x22/0x31 rtl8139_poll+0x31/0x350 __napi_poll+0x24/0xf1 net_rx_action+0x118/0x28a __do_softirq+0x155/0x2f3 call_on_stack+0x40/0x46 do_softirq_own_stack+0x1c/0x1e __irq_exit_rcu+0x59/0x8f irq_exit_rcu+0x8/0x11 common_interrupt+0x27/0x35 asm_common_interrupt+0xff/0x180 default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xbe/0x1ca cpu_startup_entry+0x19/0x1b rest_init+0x121/0x124 arch_call_rest_init+0x11/0x45 start_kernel+0x6b3/0x6d1 i386_start_kernel+0x5d/0x73 startup_32_smp+0x161/0x164 irq event stamp: 14738 hardirqs last enabled at (14737): [<de353855>] default_idle_call+0x39/0x74 hardirqs last disabled at (14738): [<de34c6ea>] common_interrupt+0xf/0x35 softirqs last enabled at (13838): [<de3554e3>] __do_softirq+0x2c3/0x2f3 softirqs last disabled at (13827): [<dde10de7>] call_on_stack+0x40/0x46 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&tp->rx_lock); <Interrupt> lock(&tp->rx_lock); *** DEADLOCK *** 3 locks held by swapper/0/0: #0: de5f17d4 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x192/0x1cc #1: de5bf6a4 (console_owner){-...}-{0:0}, at: console_unlock+0x251/0x441 #2: de644850 (target_list_lock){-...}-{2:2}, at: write_msg+0x37/0xa5 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.14.0-rc2-Pentium4 #5 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <IRQ> dump_stack_lvl+0x53/0x76 dump_stack+0xd/0x10 print_usage_bug+0x17d/0x188 mark_lock.part.0+0xfd/0x27a ? mark_lock.part.0+0x33/0x27a ? check_chain_key+0xea/0x142 __lock_acquire+0x404/0x14a6 ? __lock_acquire+0xa03/0x14a6 ? __lock_acquire+0xa03/0x14a6 ? rtl8139_poll+0x31/0x350 lock_acquire+0x1f2/0x22a ? rtl8139_poll+0x31/0x350 ? check_chain_key+0xea/0x142 _raw_spin_lock+0x22/0x31 ? rtl8139_poll+0x31/0x350 rtl8139_poll+0x31/0x350 ? enable_irq+0x45/0x53 netpoll_poll_dev+0xd7/0x1c1 netpoll_send_skb+0x12d/0x256 netpoll_send_udp+0x384/0x38c write_msg+0x87/0xa5 ? netconsole_netdev_event+0x13f/0x13f console_unlock+0x37b/0x441 vprintk_emit+0x1b6/0x1cc vprintk_default+0x10/0x12 vprintk+0xbf/0xcb printk+0xf/0x11 crng_fast_load+0xdf/0xea add_interrupt_randomness+0x157/0x20a handle_irq_event_percpu+0x24/0x3a handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x67/0xd7 ? handle_level_irq+0x83/0x83 __handle_irq+0x7d/0x9c </IRQ> __common_interrupt+0x68/0xc3 common_interrupt+0x22/0x35 asm_common_interrupt+0xff/0x180 EIP: default_idle+0xa/0xc Code: e5 53 51 89 c3 89 55 f8 e8 31 d2 ff ff 8b 4d f8 31 d2 89 d8 e8 b5 b9 e6 ff 5b 5b 5d c3 cc cc cc 55 89 e5 e8 60 1f ac ff fb f4 <5d> c3 55 89 e5 64 a1 d8 c7 70 de f0 80 48 02 20 8b 10 80 e2 08 75 EAX: de3536b0 EBX: 00000000 ECX: 00000000 EDX: ffffffff ESI: de5aa800 EDI: 00000000 EBP: de5a3f1c ESP: de5a3f1c DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00200202 ? __sched_text_end+0x3/0x3 ? __schedule+0x390/0xb0e ? default_idle+0xa/0xc arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x74 do_idle+0xbe/0x1ca cpu_startup_entry+0x19/0x1b rest_init+0x121/0x124 arch_call_rest_init+0x11/0x45 start_kernel+0x6b3/0x6d1 i386_start_kernel+0x5d/0x73 startup_32_smp+0x161/0x164 netconsole: network logging started
Created attachment 297933 [details] kernel .config (kernel 5.14-rc2, Shuttle XPC FS51, Pentium 4)
Created attachment 299247 [details] dmesg (kernel 5.15-rc6, Shuttle XPC FS51, Pentium 4) [...] printk: console [netcon0] enabled ================================ WARNING: inconsistent lock state 5.15.0-rc6-Pentium4 #2 Not tainted -------------------------------- inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: c12298a4 (&tp->rx_lock){?.-.}-{2:2}, at: rtl8139_poll+0x31/0x34e {HARDIRQ-ON-W} state was registered at: lock_acquire+0x1f2/0x230 _raw_spin_lock+0x22/0x37 rtl8139_poll+0x31/0x34e __napi_poll.constprop.0+0x24/0xf5 net_rx_action+0x118/0x28c __do_softirq+0x155/0x2f9 call_on_stack+0x40/0x4c do_softirq_own_stack+0x1c/0x22 __irq_exit_rcu+0x57/0x8f irq_exit_rcu+0x8/0x11 common_interrupt+0x27/0x39 asm_common_interrupt+0xff/0x180 default_idle+0xa/0xc arch_cpu_idle+0xd/0x11 default_idle_call+0x48/0x78 do_idle+0xbe/0x1d0 cpu_startup_entry+0x19/0x1b rest_init+0x121/0x12a arch_call_rest_init+0x11/0x4b start_kernel+0x6a2/0x6c6 i386_start_kernel+0x5d/0x75 startup_32_smp+0x161/0x164 irq event stamp: 35934 hardirqs last enabled at (35933): [<d59e1054>] default_idle_call+0x39/0x78 hardirqs last disabled at (35934): [<d59d9bad>] common_interrupt+0xf/0x39 softirqs last enabled at (35832): [<d59e2d63>] __do_softirq+0x2c3/0x2f9 softirqs last disabled at (35821): [<d5411715>] call_on_stack+0x40/0x4c other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&tp->rx_lock); <Interrupt> lock(&tp->rx_lock); *** DEADLOCK *** 3 locks held by swapper/0/0: #0: d5ca38dc (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x15e/0x19c #1: d5c71784 (console_owner){-...}-{0:0}, at: console_unlock+0x1c5/0x400 #2: d5d07530 (target_list_lock){-...}-{2:2}, at: write_msg+0x37/0xa7 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.15.0-rc6-Pentium4 #2 Hardware name: /FS51, BIOS 6.00 PG 12/02/2003 Call Trace: <IRQ> dump_stack_lvl+0x53/0x7c dump_stack+0xd/0x12 print_usage_bug+0x17d/0x18e mark_lock.part.0+0xfb/0x27c ? mark_lock.part.0+0x33/0x27c ? check_chain_key+0xea/0x148 __lock_acquire+0x400/0x1472 ? __lock_acquire+0x9ee/0x1472 ? __lock_acquire+0x9ee/0x1472 ? rtl8139_poll+0x31/0x34e lock_acquire+0x1f2/0x230 ? rtl8139_poll+0x31/0x34e ? check_chain_key+0xea/0x148 _raw_spin_lock+0x22/0x37 ? rtl8139_poll+0x31/0x34e rtl8139_poll+0x31/0x34e ? enable_irq+0x45/0x59 netpoll_poll_dev+0xd7/0x1c7 netpoll_send_skb+0x12d/0x25a netpoll_send_udp+0x386/0x394 write_msg+0x83/0xa7 ? netconsole_netdev_event+0x14d/0x14d console_unlock+0x333/0x400 vprintk_emit+0x182/0x19c vprintk_default+0x10/0x14 vprintk+0x46/0x4c _printk+0xf/0x11 crng_fast_load+0xdf/0xee add_interrupt_randomness+0x159/0x221 handle_irq_event_percpu+0x24/0x3e handle_irq_event+0x29/0x42 handle_fasteoi_irq+0x69/0xdf ? handle_level_irq+0x89/0x89 __handle_irq+0x7d/0xa2 </IRQ> __common_interrupt+0x68/0xc9 common_interrupt+0x22/0x39 asm_common_interrupt+0xff/0x180 EIP: default_idle+0xa/0xc Code: 89 c3 89 55 f8 e8 fb cf ff ff 8b 4d f8 31 d2 89 d8 e8 b7 d3 e5 ff 5b 5b 5d 31 d2 89 d1 c3 cc cc 55 89 e5 e8 14 53 a3 ff fb f4 <5d> c3 55 89 e5 64 a1 f8 77 dd d5 f0 80 48 02 20 8b 10 80 e2 08 75 EAX: d59e0ea0 EBX: 00000000 ECX: 00000000 EDX: 00000000 ESI: d5c5c800 EDI: 00000000 EBP: d5c55f1c ESP: d5c55f1c DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00200246 ? __sched_text_end+0x2/0x2 ? task_blocks_on_rt_mutex.constprop.0.isra.0+0x254/0x283 ? default_idle+0xa/0xc arch_cpu_idle+0xd/0x11 default_idle_call+0x48/0x78 do_idle+0xbe/0x1d0 cpu_startup_entry+0x19/0x1b rest_init+0x121/0x12a arch_call_rest_init+0x11/0x4b start_kernel+0x6a2/0x6c6 i386_start_kernel+0x5d/0x75 startup_32_smp+0x161/0x164 netconsole: network logging started
Created attachment 299249 [details] kernel .config (kernel 5.15-rc6, Shuttle XPC FS51, Pentium 4)
Created attachment 300418 [details] dmesg (kernel 5.17-rc3, Shuttle XPC FS51, Pentium 4) Still in 5.17-rc3. [...] printk: console [netcon0] enabled ================================ WARNING: inconsistent lock state 5.17.0-rc3-P4 #2 Not tainted -------------------------------- inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: c12d98a4 (&tp->rx_lock){?.-.}-{2:2}, at: rtl8139_poll+0x2b/0x404 {HARDIRQ-ON-W} state was registered at: lock_acquire+0xa7/0x165 _raw_spin_lock+0x23/0x31 rtl8139_poll+0x2b/0x404 __napi_poll+0x26/0x13d net_rx_action+0xf0/0x213 __do_softirq+0x136/0x27f do_softirq_own_stack+0x50/0x56 irq_exit_rcu+0x96/0xa9 common_interrupt+0x29/0x3c asm_common_interrupt+0xff/0x180 default_idle+0xe/0x10 arch_cpu_idle+0xd/0xf default_idle_call+0x48/0x7c do_idle+0xc7/0x1f2 cpu_startup_entry+0x17/0x19 rest_init+0x1af/0x1b2 arch_call_rest_init+0x8/0xa start_kernel+0x2c6/0x33e i386_start_kernel+0x94/0x97 startup_32_smp+0x161/0x164 irq event stamp: 23324 hardirqs last enabled at (23323): [<d8555e47>] default_idle_call+0x39/0x7c hardirqs last disabled at (23324): [<d854dbed>] common_interrupt+0x10/0x3c softirqs last enabled at (23194): [<d8557d00>] __do_softirq+0x250/0x27f softirqs last disabled at (23189): [<d7e170f1>] do_softirq_own_stack+0x50/0x56 other info that might help us debug this: Possible unsafe locking scenario: CPU0 ---- lock(&tp->rx_lock); <Interrupt> lock(&tp->rx_lock); *** DEADLOCK *** [...]
Created attachment 300419 [details] kernel .config (kernel 5.17-rc3, Shuttle XPC FS51, Pentium 4)
Have not seen this on 5.18.x, 5.19.x nor on 6.0-rc. I think it's safe to close here.