* netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
@ 2025-08-13 4:14 Mike Galbraith
2025-08-14 10:16 ` Breno Leitao
0 siblings, 1 reply; 27+ messages in thread
From: Mike Galbraith @ 2025-08-13 4:14 UTC (permalink / raw)
To: LKML; +Cc: Breno Leitao
Greetings,
Netconsole works peachy for my r8169 equipped desktop box, but HP lappy
with Intel wireless grumbles w/wo lockdep enabled (see mutterings below
lock order complaint).
bart:/root # hwinfo --netcard
11: PCI 200.0: 0282 WLAN controller
[Created at pci.387]
Unique ID: y9sn.0LuFraIuP2D
Parent ID: qTvu.sUcXY2K9Kn9
SysFS ID: /devices/pci0000:00/0000:00:1c.1/0000:02:00.0
SysFS BusID: 0000:02:00.0
Hardware Class: network
Device Name: "Intel Stone Peak 2 7265 Combo /NON-vPro NGFF Combo Wireless-AC 7265"
Model: "Intel Dual Band Wireless-AC 7265"
Vendor: pci 0x8086 "Intel Corporation"
Device: pci 0x095a "Wireless 7265"
SubVendor: pci 0x8086 "Intel Corporation"
SubDevice: pci 0x5010 "Dual Band Wireless-AC 7265"
[ 106.798290] netconsole: network logging started
[ 106.806110] netconsole: network logging has already stopped
[ 107.969494] printk: legacy console [netcon0] enabled
[ 107.969759] netconsole: netconsole: local port 6665
[ 107.969831] netconsole: netconsole: local IPv4 address 192.168.178.4
[ 107.969871] netconsole: netconsole: interface name 'wlan0'
[ 107.969904] netconsole: netconsole: local ethernet address '00:00:00:00:00:00'
[ 107.969945] netconsole: netconsole: remote port 6666
[ 107.969977] netconsole: netconsole: remote IPv4 address 192.168.178.3
[ 107.970014] netconsole: netconsole: remote ethernet address d4:3d:7e:fc:4f:09
[ 107.983276] netconsole: network logging started
[ 107.983687] =====================================================
[ 107.983689] WARNING: HARDIRQ-safe -> HARDIRQ-unsafe lock order detected
[ 107.983692] 6.17.0.g8742b2d8-master #195 Tainted: G I
[ 107.983695] -----------------------------------------------------
[ 107.983696] netconsole.sh/4031 [HC0[0]:SC0[2]:HE0:SE0] is trying to acquire:
[ 107.983700] ffff8a0101b80f58 (&fq->lock){+.-.}-{3:3}, at: ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.983855]
and this task is already holding:
[ 107.983856] ffffffffc1ab9ad8 (target_list_lock){....}-{3:3}, at: write_msg+0x4c/0x120 [netconsole]
[ 107.983869] which would create a new lock dependency:
[ 107.983870] (target_list_lock){....}-{3:3} -> (&fq->lock){+.-.}-{3:3}
[ 107.983876]
but this new dependency connects a HARDIRQ-irq-safe lock:
[ 107.983878] (console_owner){-...}-{0:0}
[ 107.983880]
... which became HARDIRQ-irq-safe at:
[ 107.983882] __lock_acquire+0x3d6/0xbc0
[ 107.983889] lock_acquire.part.0+0xa1/0x210
[ 107.983893] console_lock_spinning_enable+0x5e/0x60
[ 107.983899] console_emit_next_record+0xde/0x250
[ 107.983904] console_flush_all+0x24d/0x370
[ 107.983909] console_unlock+0x66/0x130
[ 107.983914] vprintk_emit+0x142/0x360
[ 107.983918] dev_vprintk_emit+0x4e/0x70
[ 107.983923] dev_printk_emit+0x51/0x70
[ 107.983927] _dev_warn+0x6f/0x85
[ 107.983931] atkbd_receive_byte.cold+0x96/0xe5
[ 107.983935] ps2_interrupt+0x9e/0x1a0
[ 107.983941] serio_interrupt+0x44/0x90
[ 107.983945] i8042_handle_data+0x108/0x260
[ 107.983949] i8042_interrupt+0x11/0x30
[ 107.983953] __handle_irq_event_percpu+0x81/0x280
[ 107.983957] handle_irq_event+0x38/0x80
[ 107.983960] handle_edge_irq+0xd9/0x1c0
[ 107.983965] __common_interrupt+0x70/0x180
[ 107.983971] common_interrupt+0xb7/0xe0
[ 107.983976] asm_common_interrupt+0x26/0x40
[ 107.983979] ___slab_alloc+0x291/0xe60
[ 107.983983] __slab_alloc.isra.0+0x52/0x90
[ 107.983985] kmem_cache_alloc_noprof+0xc9/0x470
[ 107.983988] vm_area_dup+0x25/0x170
[ 107.983992] dup_mmap+0x29c/0x860
[ 107.983995] dup_mm.constprop.0+0x65/0x130
[ 107.983998] copy_process+0x105f/0x1a90
[ 107.984000] kernel_clone+0x98/0x410
[ 107.984003] __do_sys_clone+0x65/0x90
[ 107.984005] do_syscall_64+0x94/0xa10
[ 107.984010] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.984013]
to a HARDIRQ-irq-unsafe lock:
[ 107.984014] (&fq->lock){+.-.}-{3:3}
[ 107.984017]
... which became HARDIRQ-irq-unsafe at:
[ 107.984018] ...
[ 107.984019] __lock_acquire+0x3d6/0xbc0
[ 107.984023] lock_acquire.part.0+0xa1/0x210
[ 107.984027] _raw_spin_lock_bh+0x38/0x50
[ 107.984030] ieee80211_get_txq_stats+0x30/0x190 [mac80211]
[ 107.984161] nl80211_send_iface+0x369/0x820 [cfg80211]
[ 107.984295] nl80211_notify_iface+0x4c/0xb0 [cfg80211]
[ 107.984403] cfg80211_register_netdevice+0x6f/0xe0 [cfg80211]
[ 107.984514] ieee80211_if_add+0x3ba/0x670 [mac80211]
[ 107.984640] ieee80211_register_hw+0xca6/0xcd0 [mac80211]
[ 107.984757] iwl_mvm_mac_setup_register+0xbe6/0xde0 [iwlmvm]
[ 107.984789] iwl_mvm_start_post_nvm+0x5f/0xd0 [iwlmvm]
[ 107.984819] iwl_op_mode_mvm_start+0xbc5/0xca0 [iwlmvm]
[ 107.984846] _iwl_op_mode_start.isra.0+0x3f/0xb0 [iwlwifi]
[ 107.984880] iwl_opmode_register+0x6f/0xe0 [iwlwifi]
[ 107.984909] cmac_clone_tfm+0x18/0x30 [cmac]
[ 107.984914] do_one_initcall+0x57/0x370
[ 107.984920] do_init_module+0x60/0x220
[ 107.984924] init_module_from_file+0x85/0xc0
[ 107.984927] idempotent_init_module+0x104/0x300
[ 107.984930] __x64_sys_finit_module+0x6d/0xd0
[ 107.984933] do_syscall_64+0x94/0xa10
[ 107.984938] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.984941]
other info that might help us debug this:
[ 107.984942] Chain exists of:
console_owner --> target_list_lock --> &fq->lock
[ 107.984947] Possible interrupt unsafe locking scenario:
[ 107.984948] CPU0 CPU1
[ 107.984949] ---- ----
[ 107.984950] lock(&fq->lock);
[ 107.984952] local_irq_disable();
[ 107.984952] lock(console_owner);
[ 107.984954] lock(target_list_lock);
[ 107.984956] <Interrupt>
[ 107.984957] lock(console_owner);
[ 107.984959]
*** DEADLOCK ***
[ 107.984959] 12 locks held by netconsole.sh/4031:
[ 107.984962] #0: ffff8a010e32e428 (sb_writers#14){.+.+}-{0:0}, at: ksys_write+0x69/0xe0
[ 107.984972] #1: ffff8a0105152d88 (&buffer->mutex){+.+.}-{4:4}, at: configfs_write_iter+0x2e/0x120 [configfs]
[ 107.984983] #2: ffff8a01142ae5b8 (&p->frag_sem){.+.+}-{4:4}, at: configfs_write_iter+0x9b/0x120 [configfs]
[ 107.984991] #3: ffffffffc1ab9688 (dynamic_netconsole_mutex){+.+.}-{4:4}, at: enabled_store+0x42/0x300 [netconsole]
[ 107.985001] #4: ffffffff9076e800 (console_lock){+.+.}-{0:0}, at: _printk+0x5b/0x80
[ 107.985009] #5: ffffffff9076e850 (console_srcu){....}-{0:0}, at: console_flush_all+0x3b/0x370
[ 107.985018] #6: ffffffff9068e440 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x42/0x60
[ 107.985026] #7: ffffffff9068e3c0 (printk_legacy_map-wait-type-override){....}-{4:4}, at: console_emit_next_record+0x1de/0x250
[ 107.985034] #8: ffffffffc1ab9ad8 (target_list_lock){....}-{3:3}, at: write_msg+0x4c/0x120 [netconsole]
[ 107.985042] #9: ffffffff907713c0 (rcu_read_lock){....}-{1:3}, at: __netpoll_send_skb+0x4a/0x3b0
[ 107.985049] #10: ffff8a0107196918 (_xmit_ETHER#2){+.-.}-{3:3}, at: __netpoll_send_skb+0x2e0/0x3b0
[ 107.985056] #11: ffffffff907713c0 (rcu_read_lock){....}-{1:3}, at: __ieee80211_subif_start_xmit+0xb2/0x3d0 [mac80211]
[ 107.985189]
the dependencies between HARDIRQ-irq-safe lock and the holding lock:
[ 107.985191] -> (console_owner){-...}-{0:0} {
[ 107.985195] IN-HARDIRQ-W at:
[ 107.985196] __lock_acquire+0x3d6/0xbc0
[ 107.985201] lock_acquire.part.0+0xa1/0x210
[ 107.985205] console_lock_spinning_enable+0x5e/0x60
[ 107.985210] console_emit_next_record+0xde/0x250
[ 107.985215] console_flush_all+0x24d/0x370
[ 107.985220] console_unlock+0x66/0x130
[ 107.985224] vprintk_emit+0x142/0x360
[ 107.985229] dev_vprintk_emit+0x4e/0x70
[ 107.985234] dev_printk_emit+0x51/0x70
[ 107.985237] _dev_warn+0x6f/0x85
[ 107.985241] atkbd_receive_byte.cold+0x96/0xe5
[ 107.985245] ps2_interrupt+0x9e/0x1a0
[ 107.985250] serio_interrupt+0x44/0x90
[ 107.985254] i8042_handle_data+0x108/0x260
[ 107.985258] i8042_interrupt+0x11/0x30
[ 107.985262] __handle_irq_event_percpu+0x81/0x280
[ 107.985266] handle_irq_event+0x38/0x80
[ 107.985269] handle_edge_irq+0xd9/0x1c0
[ 107.985274] __common_interrupt+0x70/0x180
[ 107.985279] common_interrupt+0xb7/0xe0
[ 107.985285] asm_common_interrupt+0x26/0x40
[ 107.985287] ___slab_alloc+0x291/0xe60
[ 107.985290] __slab_alloc.isra.0+0x52/0x90
[ 107.985292] kmem_cache_alloc_noprof+0xc9/0x470
[ 107.985295] vm_area_dup+0x25/0x170
[ 107.985299] dup_mmap+0x29c/0x860
[ 107.985303] dup_mm.constprop.0+0x65/0x130
[ 107.985305] copy_process+0x105f/0x1a90
[ 107.985308] kernel_clone+0x98/0x410
[ 107.985310] __do_sys_clone+0x65/0x90
[ 107.985313] do_syscall_64+0x94/0xa10
[ 107.985317] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.985321] INITIAL USE at:
[ 107.985322] __lock_acquire+0x3d6/0xbc0
[ 107.985326] lock_acquire.part.0+0xa1/0x210
[ 107.985329] console_lock_spinning_enable+0x5e/0x60
[ 107.985334] console_emit_next_record+0x1cc/0x250
[ 107.985339] console_flush_all+0x24d/0x370
[ 107.985344] console_unlock+0x66/0x130
[ 107.985348] vprintk_emit+0x142/0x360
[ 107.985353] _printk+0x5b/0x80
[ 107.985358] register_console.cold+0x46/0xaa
[ 107.985363] con_init+0x237/0x240
[ 107.985367] console_init+0x11c/0x1a0
[ 107.985371] start_kernel+0x33f/0x470
[ 107.985376] x86_64_start_reservations+0x24/0x30
[ 107.985379] x86_64_start_kernel+0xce/0xd0
[ 107.985382] common_startup_64+0x13e/0x141
[ 107.985385] }
[ 107.985386] ... key at: [<ffffffff9068e440>] console_owner_dep_map+0x0/0x40
[ 107.985391] -> (target_list_lock){....}-{3:3} {
[ 107.985394] INITIAL USE at:
[ 107.985396] __lock_acquire+0x3d6/0xbc0
[ 107.985400] lock_acquire.part.0+0xa1/0x210
[ 107.985403] _raw_spin_lock_irqsave+0x3f/0x60
[ 107.985406] make_netconsole_target+0xd8/0x1b0 [netconsole]
[ 107.985412] configfs_mkdir+0x1c8/0x510 [configfs]
[ 107.985419] vfs_mkdir+0x19d/0x270
[ 107.985423] do_mkdirat+0x13c/0x180
[ 107.985426] __x64_sys_mkdir+0x46/0x60
[ 107.985430] do_syscall_64+0x94/0xa10
[ 107.985434] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.985437] }
[ 107.985438] ... key at: [<ffffffffc1ab9ad8>] target_list_lock+0x18/0xffffffffffe48540 [netconsole]
[ 107.985445] ... acquired at:
[ 107.985446] __lock_acquire+0x550/0xbc0
[ 107.985450] lock_acquire.part.0+0xa1/0x210
[ 107.985453] _raw_spin_lock_irqsave+0x3f/0x60
[ 107.985455] write_msg+0x4c/0x120 [netconsole]
[ 107.985460] console_emit_next_record+0x203/0x250
[ 107.985465] console_flush_all+0x24d/0x370
[ 107.985470] console_unlock+0x66/0x130
[ 107.985474] vprintk_emit+0x142/0x360
[ 107.985479] _printk+0x5b/0x80
[ 107.985483] register_console.cold+0x46/0xaa
[ 107.985488] enabled_store+0x23c/0x300 [netconsole]
[ 107.985493] configfs_write_iter+0xbd/0x120 [configfs]
[ 107.985498] vfs_write+0x213/0x520
[ 107.985504] ksys_write+0x69/0xe0
[ 107.985506] do_syscall_64+0x94/0xa10
[ 107.985510] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.985513]
the dependencies between the lock to be acquired
[ 107.985514] and HARDIRQ-irq-unsafe lock:
[ 107.985531] -> (&fq->lock){+.-.}-{3:3} {
[ 107.985535] HARDIRQ-ON-W at:
[ 107.985537] __lock_acquire+0x3d6/0xbc0
[ 107.985540] lock_acquire.part.0+0xa1/0x210
[ 107.985544] _raw_spin_lock_bh+0x38/0x50
[ 107.985546] ieee80211_get_txq_stats+0x30/0x190 [mac80211]
[ 107.985671] nl80211_send_iface+0x369/0x820 [cfg80211]
[ 107.985785] nl80211_notify_iface+0x4c/0xb0 [cfg80211]
[ 107.985888] cfg80211_register_netdevice+0x6f/0xe0 [cfg80211]
[ 107.985998] ieee80211_if_add+0x3ba/0x670 [mac80211]
[ 107.986122] ieee80211_register_hw+0xca6/0xcd0 [mac80211]
[ 107.986237] iwl_mvm_mac_setup_register+0xbe6/0xde0 [iwlmvm]
[ 107.986267] iwl_mvm_start_post_nvm+0x5f/0xd0 [iwlmvm]
[ 107.986296] iwl_op_mode_mvm_start+0xbc5/0xca0 [iwlmvm]
[ 107.986322] _iwl_op_mode_start.isra.0+0x3f/0xb0 [iwlwifi]
[ 107.986353] iwl_opmode_register+0x6f/0xe0 [iwlwifi]
[ 107.986382] cmac_clone_tfm+0x18/0x30 [cmac]
[ 107.986385] do_one_initcall+0x57/0x370
[ 107.986390] do_init_module+0x60/0x220
[ 107.986393] init_module_from_file+0x85/0xc0
[ 107.986396] idempotent_init_module+0x104/0x300
[ 107.986400] __x64_sys_finit_module+0x6d/0xd0
[ 107.986403] do_syscall_64+0x94/0xa10
[ 107.986407] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.986410] IN-SOFTIRQ-W at:
[ 107.986412] __lock_acquire+0x3d6/0xbc0
[ 107.986416] lock_acquire.part.0+0xa1/0x210
[ 107.986419] _raw_spin_lock_bh+0x38/0x50
[ 107.986422] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.986548] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
[ 107.986666] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
[ 107.986774] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
[ 107.986881] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
[ 107.986983] dev_hard_start_xmit+0xa9/0x290
[ 107.986989] __dev_queue_xmit+0x1bc/0xc20
[ 107.986995] ip_finish_output2+0x1f7/0x800
[ 107.986999] ip_output+0xb3/0x3c0
[ 107.987002] igmp_ifc_timer_expire+0x21/0xf0
[ 107.987005] call_timer_fn+0xa5/0x250
[ 107.987009] __run_timers+0x1f2/0x2c0
[ 107.987011] run_timer_base+0x46/0x60
[ 107.987014] run_timer_softirq+0x1a/0x30
[ 107.987017] handle_softirqs+0xdb/0x3f0
[ 107.987020] __irq_exit_rcu+0xc1/0x130
[ 107.987022] irq_exit_rcu+0xe/0x30
[ 107.987025] sysvec_apic_timer_interrupt+0xa1/0xd0
[ 107.987028] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 107.987031] lock_is_held_type+0xee/0x120
[ 107.987034] mem_cgroup_from_task+0x6c/0xb0
[ 107.987039] handle_mm_fault+0x272/0x440
[ 107.987045] do_user_addr_fault+0x207/0x680
[ 107.987048] exc_page_fault+0x85/0x210
[ 107.987051] asm_exc_page_fault+0x26/0x30
[ 107.987054] INITIAL USE at:
[ 107.987055] __lock_acquire+0x3d6/0xbc0
[ 107.987059] lock_acquire.part.0+0xa1/0x210
[ 107.987063] _raw_spin_lock_bh+0x38/0x50
[ 107.987065] ieee80211_get_txq_stats+0x30/0x190 [mac80211]
[ 107.987191] nl80211_send_iface+0x369/0x820 [cfg80211]
[ 107.987306] nl80211_notify_iface+0x4c/0xb0 [cfg80211]
[ 107.987411] cfg80211_register_netdevice+0x6f/0xe0 [cfg80211]
[ 107.987520] ieee80211_if_add+0x3ba/0x670 [mac80211]
[ 107.987644] ieee80211_register_hw+0xca6/0xcd0 [mac80211]
[ 107.987759] iwl_mvm_mac_setup_register+0xbe6/0xde0 [iwlmvm]
[ 107.987788] iwl_mvm_start_post_nvm+0x5f/0xd0 [iwlmvm]
[ 107.987817] iwl_op_mode_mvm_start+0xbc5/0xca0 [iwlmvm]
[ 107.987843] _iwl_op_mode_start.isra.0+0x3f/0xb0 [iwlwifi]
[ 107.987874] iwl_opmode_register+0x6f/0xe0 [iwlwifi]
[ 107.987903] cmac_clone_tfm+0x18/0x30 [cmac]
[ 107.987906] do_one_initcall+0x57/0x370
[ 107.987911] do_init_module+0x60/0x220
[ 107.987914] init_module_from_file+0x85/0xc0
[ 107.987917] idempotent_init_module+0x104/0x300
[ 107.987920] __x64_sys_finit_module+0x6d/0xd0
[ 107.987923] do_syscall_64+0x94/0xa10
[ 107.987928] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.987931] }
[ 107.987932] ... key at: [<ffffffffc1742030>] __key.11+0x0/0x10 [mac80211]
[ 107.988053] ... acquired at:
[ 107.988054] check_prev_add+0xfb/0xca0
[ 107.988058] validate_chain+0x48c/0x530
[ 107.988061] __lock_acquire+0x550/0xbc0
[ 107.988064] lock_acquire.part.0+0xa1/0x210
[ 107.988068] _raw_spin_lock_bh+0x38/0x50
[ 107.988070] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.988198] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
[ 107.988314] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
[ 107.988424] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
[ 107.988530] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
[ 107.988634] netpoll_start_xmit+0x8b/0xd0
[ 107.988638] __netpoll_send_skb+0x329/0x3b0
[ 107.988641] write_msg+0x104/0x120 [netconsole]
[ 107.988647] console_emit_next_record+0x203/0x250
[ 107.988652] console_flush_all+0x24d/0x370
[ 107.988657] console_unlock+0x66/0x130
[ 107.988662] vprintk_emit+0x142/0x360
[ 107.988666] _printk+0x5b/0x80
[ 107.988671] enabled_store.cold+0x7e/0x83 [netconsole]
[ 107.988677] configfs_write_iter+0xbd/0x120 [configfs]
[ 107.988683] vfs_write+0x213/0x520
[ 107.988689] ksys_write+0x69/0xe0
[ 107.988691] do_syscall_64+0x94/0xa10
[ 107.988695] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.988699]
stack backtrace:
[ 107.988703] CPU: 0 UID: 0 PID: 4031 Comm: netconsole.sh Kdump: loaded Tainted: G I 6.17.0.g8742b2d8-master #195 PREEMPT(lazy) b303cf59d81e6fee2841762da0be977f2e8b800d
[ 107.988711] Tainted: [I]=FIRMWARE_WORKAROUND
[ 107.988712] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 107.988714] Call Trace:
[ 107.988716] <TASK>
[ 107.988720] dump_stack_lvl+0x5b/0x80
[ 107.988727] print_bad_irq_dependency+0x2ba/0x2c0
[ 107.988735] check_irq_usage+0x36c/0x430
[ 107.988745] ? check_noncircular+0x81/0x150
[ 107.988753] ? check_prev_add+0xfb/0xca0
[ 107.988757] check_prev_add+0xfb/0xca0
[ 107.988763] validate_chain+0x48c/0x530
[ 107.988769] __lock_acquire+0x550/0xbc0
[ 107.988776] lock_acquire.part.0+0xa1/0x210
[ 107.988781] ? ieee80211_queue_skb+0xfd/0x350 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.988896] ? rcu_is_watching+0x11/0x40
[ 107.988903] ? lock_acquire+0xee/0x130
[ 107.988909] _raw_spin_lock_bh+0x38/0x50
[ 107.988912] ? ieee80211_queue_skb+0xfd/0x350 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989021] ieee80211_queue_skb+0xfd/0x350 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989128] __ieee80211_xmit_fast+0x202/0x360 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989239] ? __skb_get_hash_net+0x54/0x1f0
[ 107.989245] ? __skb_get_hash_net+0x54/0x1f0
[ 107.989254] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989362] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989465] ? __lock_acquire+0x550/0xbc0
[ 107.989474] ieee80211_subif_start_xmit+0x46/0x230 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.989576] ? lock_acquire.part.0+0xb1/0x210
[ 107.989584] netpoll_start_xmit+0x8b/0xd0
[ 107.989589] __netpoll_send_skb+0x329/0x3b0
[ 107.989595] write_msg+0x104/0x120 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.989603] ? console_emit_next_record+0x1de/0x250
[ 107.989610] console_emit_next_record+0x203/0x250
[ 107.989615] ? console_emit_next_record+0x1de/0x250
[ 107.989624] console_flush_all+0x24d/0x370
[ 107.989629] ? console_flush_all+0x3b/0x370
[ 107.989637] console_unlock+0x66/0x130
[ 107.989644] vprintk_emit+0x142/0x360
[ 107.989652] _printk+0x5b/0x80
[ 107.989661] enabled_store.cold+0x7e/0x83 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.989671] configfs_write_iter+0xbd/0x120 [configfs fddadc1058896f4b55fcdc7e57d7a9a452005598]
[ 107.989680] vfs_write+0x213/0x520
[ 107.989691] ksys_write+0x69/0xe0
[ 107.989695] do_syscall_64+0x94/0xa10
[ 107.989701] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.989704] ? lockdep_hardirqs_on+0x78/0x100
[ 107.989708] ? do_syscall_64+0x139/0xa10
[ 107.989713] ? exc_page_fault+0x85/0x210
[ 107.989716] ? __lock_release.isra.0+0x5d/0x180
[ 107.989721] ? exc_page_fault+0x85/0x210
[ 107.989724] ? exc_page_fault+0x85/0x210
[ 107.989726] ? lock_release+0x86/0x150
[ 107.989731] ? exc_page_fault+0x116/0x210
[ 107.989737] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.989740] RIP: 0033:0x7ff02f721000
[ 107.989745] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 107.989748] RSP: 002b:00007ffd43e35dc8 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 107.989754] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ff02f721000
[ 107.989757] RDX: 0000000000000002 RSI: 00005646d313ed00 RDI: 0000000000000001
[ 107.989759] RBP: 00005646d313ed00 R08: 0000000000000000 R09: 0000000000000000
[ 107.989761] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000002
[ 107.989763] R13: 00007ff02f8005c0 R14: 00007ff02f7fdf60 R15: 00005646d31438e0
[ 107.989772] </TASK>
[ 107.989850] ------------[ cut here ]------------
[ 107.989852] WARNING: CPU: 0 PID: 4031 at net/mac80211/tx.c:3814 ieee80211_tx_dequeue+0x71c/0x7e0 [mac80211]
[ 107.989974] Modules linked in: netconsole ccm nf_nat_tftp nf_conntrack_tftp nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct af_packet nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables ip_set nfnetlink cmac algif_hash algif_skcipher af_alg iwlmvm binfmt_misc mac80211 snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_codec_generic libarc4 intel_rapl_msr uvcvideo intel_rapl_common snd_hda_intel btusb snd_intel_dspcfg x86_pkg_temp_thermal btrtl intel_powerclamp uvc snd_hda_codec iwlwifi btbcm snd_hwdep videobuf2_vmalloc coretemp iTCO_wdt btintel nls_iso8859_1 mei_pxp snd_hda_core videobuf2_memops intel_pmc_bxt videobuf2_v4l2 nls_cp437 kvm_intel mei_hdcp iTCO_vendor_support snd_pcm videobuf2_common mfd_core bluetooth cfg80211 videodev snd_timer kvm mc irqbypass mei_me snd i2c_i801 pcspkr rfkill soundcore i2c_smbus mei thermal battery tiny_power_button ac button acpi_pad joydev sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc
[ 107.990064] dm_mod fuse configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit drm_buddy drm_client_lib drm_display_helper polyval_clmulni ghash_clmulni_intel drm_kms_helper cec rc_core video ttm xhci_pci xhci_hcd ahci drm libahci usbcore libata wmi serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel
[ 107.990109] CPU: 0 UID: 0 PID: 4031 Comm: netconsole.sh Kdump: loaded Tainted: G I 6.17.0.g8742b2d8-master #195 PREEMPT(lazy) b303cf59d81e6fee2841762da0be977f2e8b800d
[ 107.990115] Tainted: [I]=FIRMWARE_WORKAROUND
[ 107.990116] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 107.990118] RIP: 0010:ieee80211_tx_dequeue+0x71c/0x7e0 [mac80211]
[ 107.990241] Code: 84 00 fc ff ff 48 8b 44 24 20 48 8b bc 24 a0 00 00 00 31 d2 48 8d 70 0a e8 51 6d ff ff 84 c0 0f 85 87 fa ff ff e9 db fb ff ff <0f> 0b e9 32 f9 ff ff e8 58 2b 97 cd 85 c0 0f 85 9c fb ff ff e8 eb
[ 107.990244] RSP: 0018:ffffd21786b8b6d0 EFLAGS: 00010246
[ 107.990247] RAX: 0000000000000002 RBX: ffff8a010ba768e0 RCX: 0000000000000002
[ 107.990249] RDX: ffffffffc159fee9 RSI: ffff8a0129034168 RDI: ffff8a0101b80e60
[ 107.990251] RBP: ffff8a0129034168 R08: 0000000000000000 R09: 0000000000000000
[ 107.990253] R10: ffffffffc159fee9 R11: 0000000000000003 R12: 0000000000000002
[ 107.990254] R13: ffff8a0129034000 R14: ffff8a0101b80e60 R15: ffff8a0101b830a8
[ 107.990257] FS: 00007ff02f99e740(0000) GS:ffff8a02ddc30000(0000) knlGS:0000000000000000
[ 107.990260] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 107.990262] CR2: 00007fd965d88560 CR3: 00000001155ef001 CR4: 00000000003726f0
[ 107.990265] Call Trace:
[ 107.990267] <TASK>
[ 107.990271] ? rcu_is_watching+0x11/0x40
[ 107.990279] ? rcu_is_watching+0x11/0x40
[ 107.990284] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 107.990289] ? rcu_is_watching+0x11/0x40
[ 107.990295] ? lock_acquire+0xee/0x130
[ 107.990299] ? iwl_mvm_mac_itxq_xmit+0x59/0x1f0 [iwlmvm 0ca4634732a6b637e7b0ee22fbce9d6f1340b022]
[ 107.990332] iwl_mvm_mac_itxq_xmit+0xb3/0x1f0 [iwlmvm 0ca4634732a6b637e7b0ee22fbce9d6f1340b022]
[ 107.990362] ieee80211_queue_skb+0x21b/0x350 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.990480] __ieee80211_xmit_fast+0x202/0x360 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.990596] ? __skb_get_hash_net+0x54/0x1f0
[ 107.990602] ? __skb_get_hash_net+0x54/0x1f0
[ 107.990611] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.990723] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.990829] ? __lock_acquire+0x550/0xbc0
[ 107.990837] ieee80211_subif_start_xmit+0x46/0x230 [mac80211 6e705e26db77cf4ab5101c61ecbd7b898fac9e56]
[ 107.990942] ? lock_acquire.part.0+0xb1/0x210
[ 107.990950] netpoll_start_xmit+0x8b/0xd0
[ 107.990955] __netpoll_send_skb+0x329/0x3b0
[ 107.990961] write_msg+0x104/0x120 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.990970] ? console_emit_next_record+0x1de/0x250
[ 107.990976] console_emit_next_record+0x203/0x250
[ 107.990981] ? console_emit_next_record+0x1de/0x250
[ 107.990990] console_flush_all+0x24d/0x370
[ 107.990995] ? console_flush_all+0x3b/0x370
[ 107.991003] console_unlock+0x66/0x130
[ 107.991011] vprintk_emit+0x142/0x360
[ 107.991019] _printk+0x5b/0x80
[ 107.991028] enabled_store.cold+0x7e/0x83 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.991037] configfs_write_iter+0xbd/0x120 [configfs fddadc1058896f4b55fcdc7e57d7a9a452005598]
[ 107.991046] vfs_write+0x213/0x520
[ 107.991058] ksys_write+0x69/0xe0
[ 107.991062] do_syscall_64+0x94/0xa10
[ 107.991067] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.991070] ? lockdep_hardirqs_on+0x78/0x100
[ 107.991074] ? do_syscall_64+0x139/0xa10
[ 107.991080] ? exc_page_fault+0x85/0x210
[ 107.991082] ? __lock_release.isra.0+0x5d/0x180
[ 107.991088] ? exc_page_fault+0x85/0x210
[ 107.991090] ? exc_page_fault+0x85/0x210
[ 107.991093] ? lock_release+0x86/0x150
[ 107.991098] ? exc_page_fault+0x116/0x210
[ 107.991104] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.991107] RIP: 0033:0x7ff02f721000
[ 107.991110] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 107.991125] RSP: 002b:00007ffd43e35dc8 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 107.991131] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ff02f721000
[ 107.991134] RDX: 0000000000000002 RSI: 00005646d313ed00 RDI: 0000000000000001
[ 107.991137] RBP: 00005646d313ed00 R08: 0000000000000000 R09: 0000000000000000
[ 107.991139] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000002
[ 107.991142] R13: 00007ff02f8005c0 R14: 00007ff02f7fdf60 R15: 00005646d31438e0
[ 107.991158] </TASK>
[ 107.991160] irq event stamp: 11319
[ 107.991161] hardirqs last enabled at (11317): [<ffffffff8ee014ea>] asm_sysvec_call_function+0x1a/0x20
[ 107.991167] hardirqs last disabled at (11318): [<ffffffff8f1a57e2>] console_emit_next_record+0x1c2/0x250
[ 107.991173] softirqs last enabled at (11068): [<ffffffff8f09a97c>] restore_fpregs_from_user+0x8c/0x180
[ 107.991177] softirqs last disabled at (11319): [<ffffffffc184aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.991296] ---[ end trace 0000000000000000 ]---
[ 107.991343] ------------[ cut here ]------------
[ 107.991345] netpoll_send_skb_on_dev(): wlan0 enabled interrupts in poll (ieee80211_subif_start_xmit+0x0/0x230 [mac80211])
[ 107.991475] WARNING: CPU: 0 PID: 4031 at net/core/netpoll.c:359 __netpoll_send_skb+0x382/0x3b0
[ 107.991481] Modules linked in: netconsole ccm nf_nat_tftp nf_conntrack_tftp nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct af_packet nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables ip_set nfnetlink cmac algif_hash algif_skcipher af_alg iwlmvm binfmt_misc mac80211 snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_codec_generic libarc4 intel_rapl_msr uvcvideo intel_rapl_common snd_hda_intel btusb snd_intel_dspcfg x86_pkg_temp_thermal btrtl intel_powerclamp uvc snd_hda_codec iwlwifi btbcm snd_hwdep videobuf2_vmalloc coretemp iTCO_wdt btintel nls_iso8859_1 mei_pxp snd_hda_core videobuf2_memops intel_pmc_bxt videobuf2_v4l2 nls_cp437 kvm_intel mei_hdcp iTCO_vendor_support snd_pcm videobuf2_common mfd_core bluetooth cfg80211 videodev snd_timer kvm mc irqbypass mei_me snd i2c_i801 pcspkr rfkill soundcore i2c_smbus mei thermal battery tiny_power_button ac button acpi_pad joydev sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc
[ 107.991550] dm_mod fuse configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit drm_buddy drm_client_lib drm_display_helper polyval_clmulni ghash_clmulni_intel drm_kms_helper cec rc_core video ttm xhci_pci xhci_hcd ahci drm libahci usbcore libata wmi serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel
[ 107.991588] CPU: 0 UID: 0 PID: 4031 Comm: netconsole.sh Kdump: loaded Tainted: G W I 6.17.0.g8742b2d8-master #195 PREEMPT(lazy) b303cf59d81e6fee2841762da0be977f2e8b800d
[ 107.991594] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 107.991596] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 107.991597] RIP: 0010:__netpoll_send_skb+0x382/0x3b0
[ 107.991601] Code: 0f 85 65 ff ff ff 49 8b 44 24 08 49 8d b4 24 20 01 00 00 48 c7 c7 d8 cd 30 90 c6 05 3d 4b d7 00 01 48 8b 50 20 e8 be fd 5d ff <0f> 0b e9 3a ff ff ff 9c 58 f6 c4 02 0f 84 a5 fd ff ff 80 3d 1b 4b
[ 107.991604] RSP: 0018:ffffd21786b8ba98 EFLAGS: 00010282
[ 107.991607] RAX: 0000000000000000 RBX: ffff8a0258b64000 RCX: 0000000000000000
[ 107.991609] RDX: 0000000000000004 RSI: 0000000000000001 RDI: 00000000ffffffff
[ 107.991610] RBP: ffff8a012a7bb148 R08: 0000000000000000 R09: ffffd21786b8b860
[ 107.991612] R10: ffffffff9073e628 R11: 0000000000000003 R12: ffff8a010ba74000
[ 107.991614] R13: ffff8a010ee4ae00 R14: ffff8a0107196800 R15: 0000000000000000
[ 107.991616] FS: 00007ff02f99e740(0000) GS:ffff8a02ddc30000(0000) knlGS:0000000000000000
[ 107.991618] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 107.991621] CR2: 00007fd965d88560 CR3: 00000001155ef001 CR4: 00000000003726f0
[ 107.991623] Call Trace:
[ 107.991624] <TASK>
[ 107.991629] write_msg+0x104/0x120 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.991638] ? console_emit_next_record+0x1de/0x250
[ 107.991646] console_emit_next_record+0x203/0x250
[ 107.991651] ? console_emit_next_record+0x1de/0x250
[ 107.991660] console_flush_all+0x24d/0x370
[ 107.991665] ? console_flush_all+0x3b/0x370
[ 107.991672] console_unlock+0x66/0x130
[ 107.991680] vprintk_emit+0x142/0x360
[ 107.991688] _printk+0x5b/0x80
[ 107.991697] enabled_store.cold+0x7e/0x83 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 107.991707] configfs_write_iter+0xbd/0x120 [configfs fddadc1058896f4b55fcdc7e57d7a9a452005598]
[ 107.991715] vfs_write+0x213/0x520
[ 107.991726] ksys_write+0x69/0xe0
[ 107.991731] do_syscall_64+0x94/0xa10
[ 107.991736] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.991739] ? lockdep_hardirqs_on+0x78/0x100
[ 107.991743] ? do_syscall_64+0x139/0xa10
[ 107.991749] ? exc_page_fault+0x85/0x210
[ 107.991751] ? __lock_release.isra.0+0x5d/0x180
[ 107.991756] ? exc_page_fault+0x85/0x210
[ 107.991759] ? exc_page_fault+0x85/0x210
[ 107.991762] ? lock_release+0x86/0x150
[ 107.991767] ? exc_page_fault+0x116/0x210
[ 107.991773] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 107.991776] RIP: 0033:0x7ff02f721000
[ 107.991778] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 107.991781] RSP: 002b:00007ffd43e35dc8 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 107.991784] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ff02f721000
[ 107.991786] RDX: 0000000000000002 RSI: 00005646d313ed00 RDI: 0000000000000001
[ 107.991788] RBP: 00005646d313ed00 R08: 0000000000000000 R09: 0000000000000000
[ 107.991790] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000002
[ 107.991792] R13: 00007ff02f8005c0 R14: 00007ff02f7fdf60 R15: 00005646d31438e0
[ 107.991801] </TASK>
[ 107.991802] irq event stamp: 11319
[ 107.991803] hardirqs last enabled at (11317): [<ffffffff8ee014ea>] asm_sysvec_call_function+0x1a/0x20
[ 107.991808] hardirqs last disabled at (11318): [<ffffffff8f1a57e2>] console_emit_next_record+0x1c2/0x250
[ 107.991813] softirqs last enabled at (11068): [<ffffffff8f09a97c>] restore_fpregs_from_user+0x8c/0x180
[ 107.991817] softirqs last disabled at (11319): [<ffffffffc184aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.991940] ---[ end trace 0000000000000000 ]---
[ 108.006632] ------------[ cut here ]------------
[ 108.006635] WARNING: CPU: 0 PID: 4031 at net/core/netpoll.c:505 netpoll_send_udp+0x3b3/0x3c0
[ 108.006642] Modules linked in: netconsole ccm nf_nat_tftp nf_conntrack_tftp nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct af_packet nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables ip_set nfnetlink cmac algif_hash algif_skcipher af_alg iwlmvm binfmt_misc mac80211 snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_codec_generic libarc4 intel_rapl_msr uvcvideo intel_rapl_common snd_hda_intel btusb snd_intel_dspcfg x86_pkg_temp_thermal btrtl intel_powerclamp uvc snd_hda_codec iwlwifi btbcm snd_hwdep videobuf2_vmalloc coretemp iTCO_wdt btintel nls_iso8859_1 mei_pxp snd_hda_core videobuf2_memops intel_pmc_bxt videobuf2_v4l2 nls_cp437 kvm_intel mei_hdcp iTCO_vendor_support snd_pcm videobuf2_common mfd_core bluetooth cfg80211 videodev snd_timer kvm mc irqbypass mei_me snd i2c_i801 pcspkr rfkill soundcore i2c_smbus mei thermal battery tiny_power_button ac button acpi_pad joydev sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc
[ 108.006697] dm_mod fuse configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit drm_buddy drm_client_lib drm_display_helper polyval_clmulni ghash_clmulni_intel drm_kms_helper cec rc_core video ttm xhci_pci xhci_hcd ahci drm libahci usbcore libata wmi serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel
[ 108.006729] CPU: 0 UID: 0 PID: 4031 Comm: netconsole.sh Kdump: loaded Tainted: G W I 6.17.0.g8742b2d8-master #195 PREEMPT(lazy) b303cf59d81e6fee2841762da0be977f2e8b800d
[ 108.006735] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 108.006736] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 108.006737] RIP: 0010:netpoll_send_udp+0x3b3/0x3c0
[ 108.006740] Code: 0c 13 71 10 48 8d 49 04 ff ca 75 f5 83 d6 00 89 f2 c1 ee 10 66 01 d6 83 d6 00 f7 d6 66 89 70 0a b8 08 00 00 00 e9 a4 fe ff ff <0f> 0b e9 75 fc ff ff 66 0f 1f 44 00 00 f3 0f 1e fa 0f 1f 44 00 00
[ 108.006743] RSP: 0018:ffffd21786b8ba88 EFLAGS: 00010202
[ 108.006745] RAX: 0000000000000296 RBX: ffff8a012a7bb148 RCX: 0000000000000000
[ 108.006747] RDX: 0000000000000028 RSI: ffffffff91aa2428 RDI: ffff8a012a7bb148
[ 108.006748] RBP: ffffd21786b8bac8 R08: 0000000000000000 R09: 0000000000000000
[ 108.006750] R10: ffffffffc159fee9 R11: 0000000000000000 R12: 0000000000000410
[ 108.006751] R13: 0000000000000028 R14: ffff8a012a7bb148 R15: ffffffff91aa2428
[ 108.006752] FS: 00007ff02f99e740(0000) GS:ffff8a02ddc30000(0000) knlGS:0000000000000000
[ 108.006754] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 108.006756] CR2: 00007fd965d88560 CR3: 00000001155ef001 CR4: 00000000003726f0
[ 108.006757] Call Trace:
[ 108.006760] <TASK>
[ 108.006763] ? __netpoll_send_skb+0xc9/0x3b0
[ 108.006769] write_msg+0x104/0x120 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 108.006777] ? console_emit_next_record+0x1de/0x250
[ 108.006782] console_emit_next_record+0x203/0x250
[ 108.006786] ? console_emit_next_record+0x1de/0x250
[ 108.006791] console_flush_all+0x24d/0x370
[ 108.006795] ? console_flush_all+0x3b/0x370
[ 108.006799] console_unlock+0x66/0x130
[ 108.006804] vprintk_emit+0x142/0x360
[ 108.006809] _printk+0x5b/0x80
[ 108.006816] enabled_store.cold+0x7e/0x83 [netconsole 641ec3b0b2ff98f93fe3092a7f84ed3654235c84]
[ 108.006823] configfs_write_iter+0xbd/0x120 [configfs fddadc1058896f4b55fcdc7e57d7a9a452005598]
[ 108.006829] vfs_write+0x213/0x520
[ 108.006836] ksys_write+0x69/0xe0
[ 108.006839] do_syscall_64+0x94/0xa10
[ 108.006843] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 108.006845] ? lockdep_hardirqs_on+0x78/0x100
[ 108.006848] ? do_syscall_64+0x139/0xa10
[ 108.006852] ? exc_page_fault+0x85/0x210
[ 108.006853] ? __lock_release.isra.0+0x5d/0x180
[ 108.006857] ? exc_page_fault+0x85/0x210
[ 108.006859] ? exc_page_fault+0x85/0x210
[ 108.006861] ? lock_release+0x86/0x150
[ 108.006864] ? exc_page_fault+0x116/0x210
[ 108.006868] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 108.006870] RIP: 0033:0x7ff02f721000
[ 108.006873] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 108.006875] RSP: 002b:00007ffd43e35dc8 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 108.006877] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007ff02f721000
[ 108.006879] RDX: 0000000000000002 RSI: 00005646d313ed00 RDI: 0000000000000001
[ 108.006880] RBP: 00005646d313ed00 R08: 0000000000000000 R09: 0000000000000000
[ 108.006881] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000002
[ 108.006882] R13: 00007ff02f8005c0 R14: 00007ff02f7fdf60 R15: 00005646d31438e0
[ 108.006888] </TASK>
[ 108.006889] irq event stamp: 11319
[ 108.006890] hardirqs last enabled at (11317): [<ffffffff8ee014ea>] asm_sysvec_call_function+0x1a/0x20
[ 108.006893] hardirqs last disabled at (11318): [<ffffffff8f1a57e2>] console_emit_next_record+0x1c2/0x250
[ 108.006896] softirqs last enabled at (11068): [<ffffffff8f09a97c>] restore_fpregs_from_user+0x8c/0x180
[ 108.006899] softirqs last disabled at (11319): [<ffffffffc184aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 108.006991] ---[ end trace 0000000000000000 ]---
[ 130.992035] netfs: FS-Cache loaded
[ 131.108351] Key type dns_resolver registered
[ 131.408618] NFS: Registering the id_resolver key type
[ 131.408693] Key type id_resolver registered
[ 131.408728] Key type id_legacy registered
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-13 4:14 netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning Mike Galbraith
@ 2025-08-14 10:16 ` Breno Leitao
2025-08-14 15:45 ` Pavel Begunkov
2025-08-15 0:23 ` Jakub Kicinski
0 siblings, 2 replies; 27+ messages in thread
From: Breno Leitao @ 2025-08-14 10:16 UTC (permalink / raw)
To: Mike Galbraith, paulmck, asml.silence, kuba; +Cc: LKML, netdev, boqun.feng
Hello Mike,
On Wed, Aug 13, 2025 at 06:14:36AM +0200, Mike Galbraith wrote:
> [ 107.984942] Chain exists of:
> console_owner --> target_list_lock --> &fq->lock
>
> [ 107.984947] Possible interrupt unsafe locking scenario:
>
> [ 107.984948] CPU0 CPU1
> [ 107.984949] ---- ----
> [ 107.984950] lock(&fq->lock);
> [ 107.984952] local_irq_disable();
> [ 107.984952] lock(console_owner);
> [ 107.984954] lock(target_list_lock);
Thanks for the report. I _think_ I understand the problem, it should be
easier to see it while thinking about a single CPU:
1) lock(&fq->lock); // This is not hard irq safe log
2) IRQ // IRQ hits the while the lock is held
2.1) printk() // WARNs and printk can in fact happen during IRQs
2.2) netconsole subsystem /// target_list_lock is not important and can be ignored
2.2) netpoll // net poll will call the network subsystem to send the packet
2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
3) Dead lock!
Given fq->lock is not IRQ safe, then this is a possible deadlock.
In fact, I would say that FQ is not the only lock that might get into
this deadlock.
Possible solutions that come to my mind:
1) make those lock (fq->lock and TX locks) IRQ safe
* cons: This has network performance penalties, and very intrusive.
2) Making printk from IRQs deferred. Calling `printk_deferred_enter` at
IRQs handlers ?!
* Cons: This will add latency to printk() inside IRQs.
3) Create a deferred mechanism inside netconsole, that would buffer and
defer the TX of the packet to outside of the IRQs.
a) Basically on netconsole, check if it is being invoke inside an
IRQ, then buffer the message and it it at Softirq/task context.
* Cons: this would use extra memory for printks() inside IRQs and also
latency (netconsole only).
Let me add some other developers who might have other opinions and help
to decide what is the best approach.
--breno
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-14 10:16 ` Breno Leitao
@ 2025-08-14 15:45 ` Pavel Begunkov
2025-08-15 0:23 ` Jakub Kicinski
1 sibling, 0 replies; 27+ messages in thread
From: Pavel Begunkov @ 2025-08-14 15:45 UTC (permalink / raw)
To: Breno Leitao, Mike Galbraith, paulmck, kuba; +Cc: LKML, netdev, boqun.feng
On 8/14/25 11:16, Breno Leitao wrote:
> Hello Mike,
>
> On Wed, Aug 13, 2025 at 06:14:36AM +0200, Mike Galbraith wrote:
>> [ 107.984942] Chain exists of:
>> console_owner --> target_list_lock --> &fq->lock
>>
>> [ 107.984947] Possible interrupt unsafe locking scenario:
>>
>> [ 107.984948] CPU0 CPU1
>> [ 107.984949] ---- ----
>> [ 107.984950] lock(&fq->lock);
>> [ 107.984952] local_irq_disable();
>> [ 107.984952] lock(console_owner);
>> [ 107.984954] lock(target_list_lock);
>
> Thanks for the report. I _think_ I understand the problem, it should be
> easier to see it while thinking about a single CPU:
>
> 1) lock(&fq->lock); // This is not hard irq safe log
> 2) IRQ // IRQ hits the while the lock is held
> 2.1) printk() // WARNs and printk can in fact happen during IRQs
> 2.2) netconsole subsystem /// target_list_lock is not important and can be ignored
> 2.2) netpoll // net poll will call the network subsystem to send the packet
> 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
> 3) Dead lock!
>
> Given fq->lock is not IRQ safe, then this is a possible deadlock.
>
> In fact, I would say that FQ is not the only lock that might get into
> this deadlock.
>
> Possible solutions that come to my mind:
>
> 1) make those lock (fq->lock and TX locks) IRQ safe
And I'm pretty sure the list is not exhaustive.
> * cons: This has network performance penalties, and very intrusive.
> 2) Making printk from IRQs deferred. Calling `printk_deferred_enter` at
> IRQs handlers ?!
It'd only help if the deferred printk doesn't need the
console_lock / doesn't disable irqs.
> * Cons: This will add latency to printk() inside IRQs.
> 3) Create a deferred mechanism inside netconsole, that would buffer and
> defer the TX of the packet to outside of the IRQs.
> a) Basically on netconsole, check if it is being invoke inside an
> IRQ, then buffer the message and it it at Softirq/task context.
> * Cons: this would use extra memory for printks() inside IRQs and also
> latency (netconsole only).
That should work, we basically need to pull xmit out of the
console_lock protected section, and deferring is not a bad option
> Let me add some other developers who might have other opinions and help
> to decide what is the best approach.
--
Pavel Begunkov
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-14 10:16 ` Breno Leitao
2025-08-14 15:45 ` Pavel Begunkov
@ 2025-08-15 0:23 ` Jakub Kicinski
2025-08-15 10:44 ` Pavel Begunkov
2025-08-15 12:45 ` Mike Galbraith
1 sibling, 2 replies; 27+ messages in thread
From: Jakub Kicinski @ 2025-08-15 0:23 UTC (permalink / raw)
To: Breno Leitao
Cc: Mike Galbraith, paulmck, asml.silence, LKML, netdev, boqun.feng
On Thu, 14 Aug 2025 03:16:11 -0700 Breno Leitao wrote:
> 2.2) netpoll // net poll will call the network subsystem to send the packet
> 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
Where does netpoll take fq->lock ?
We started hitting this a lot in the CI as well, lockdep must have
gotten more sensitive in 6.17. Last I checked lockdep didn't understand
that we manually test for nesting with netif_local_xmit_active().
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 0:23 ` Jakub Kicinski
@ 2025-08-15 10:44 ` Pavel Begunkov
2025-08-15 16:42 ` Jakub Kicinski
2025-08-15 12:45 ` Mike Galbraith
1 sibling, 1 reply; 27+ messages in thread
From: Pavel Begunkov @ 2025-08-15 10:44 UTC (permalink / raw)
To: Jakub Kicinski, Breno Leitao
Cc: Mike Galbraith, paulmck, LKML, netdev, boqun.feng
On 8/15/25 01:23, Jakub Kicinski wrote:
> On Thu, 14 Aug 2025 03:16:11 -0700 Breno Leitao wrote:
>> 2.2) netpoll // net poll will call the network subsystem to send the packet
>> 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
The report for reference:
https://lore.kernel.org/all/fb38cfe5153fd67f540e6e8aff814c60b7129480.camel@gmx.de/>
> Where does netpoll take fq->lock ?
the dependencies between the lock to be acquired
[ 107.985514] and HARDIRQ-irq-unsafe lock:
[ 107.985531] -> (&fq->lock){+.-.}-{3:3} {
...
[ 107.988053] ... acquired at:
[ 107.988054] check_prev_add+0xfb/0xca0
[ 107.988058] validate_chain+0x48c/0x530
[ 107.988061] __lock_acquire+0x550/0xbc0
[ 107.988064] lock_acquire.part.0+0xa1/0x210
[ 107.988068] _raw_spin_lock_bh+0x38/0x50
[ 107.988070] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 107.988198] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
[ 107.988314] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
[ 107.988424] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
[ 107.988530] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
[ 107.988634] netpoll_start_xmit+0x8b/0xd0
[ 107.988638] __netpoll_send_skb+0x329/0x3b0
[ 107.988641] write_msg+0x104/0x120 [netconsole]
[ 107.988647] console_emit_next_record+0x203/0x250
[ 107.988652] console_flush_all+0x24d/0x370
[ 107.988657] console_unlock+0x66/0x130
[ 107.988662] vprintk_emit+0x142/0x360
[ 107.988666] _printk+0x5b/0x80
[ 107.988671] enabled_store.cold+0x7e/0x83 [netconsole]
[ 107.988677] configfs_write_iter+0xbd/0x120 [configfs]
[ 107.988683] vfs_write+0x213/0x520
[ 107.988689] ksys_write+0x69/0xe0
[ 107.988691] do_syscall_64+0x94/0xa10
[ 107.988695] entry_SYSCALL_64_after_hwframe+0x4b/0x53
>
> We started hitting this a lot in the CI as well, lockdep must have
> gotten more sensitive in 6.17. Last I checked lockdep didn't understand
FWIW, I remember there were similar reports last year but with
xmit lock.
> that we manually test for nesting with netif_local_xmit_active().
Looks like Breno tried to simplify it, the original syz report
gave the following scenario:
[ 107.984942] Chain exists of:
console_owner --> target_list_lock --> &fq->lock
[ 107.984947] Possible interrupt unsafe locking scenario:
[ 107.984948] CPU0 CPU1
[ 107.984949] ---- ----
[ 107.984950] lock(&fq->lock);
[ 107.984952] local_irq_disable();
[ 107.984952] lock(console_owner);
[ 107.984954] lock(target_list_lock);
[ 107.984956] <Interrupt>
[ 107.984957] lock(console_owner);
Seems like with the fq->lock trace I pasted above we can get sth like:
CPU0 CPU1
---- ----
lock(&fq->lock);
local_irq_disable();
lock(console_owner);
lock(target_list_lock);
lock(&fq->lock);
<Interrupt>
lock(console_owner);
Nesting checks won't help with this one.
--
Pavel Begunkov
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 0:23 ` Jakub Kicinski
2025-08-15 10:44 ` Pavel Begunkov
@ 2025-08-15 12:45 ` Mike Galbraith
1 sibling, 0 replies; 27+ messages in thread
From: Mike Galbraith @ 2025-08-15 12:45 UTC (permalink / raw)
To: Jakub Kicinski, Breno Leitao
Cc: paulmck, asml.silence, LKML, netdev, boqun.feng
On Thu, 2025-08-14 at 17:23 -0700, Jakub Kicinski wrote:
>
> We started hitting this a lot in the CI as well, lockdep must have
> gotten more sensitive in 6.17.
FWIW, the issues wireless lappy reported aren't merge window arrivals.
6.12.41+lockdep behaved as master, wired ran clean, wireless grumbled.
-Mike
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 10:44 ` Pavel Begunkov
@ 2025-08-15 16:42 ` Jakub Kicinski
2025-08-15 17:29 ` Breno Leitao
` (2 more replies)
0 siblings, 3 replies; 27+ messages in thread
From: Jakub Kicinski @ 2025-08-15 16:42 UTC (permalink / raw)
To: Pavel Begunkov, Johannes Berg
Cc: Breno Leitao, Mike Galbraith, paulmck, LKML, netdev, boqun.feng
On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> On 8/15/25 01:23, Jakub Kicinski wrote:
> > On Thu, 14 Aug 2025 03:16:11 -0700 Breno Leitao wrote:
> >> 2.2) netpoll // net poll will call the network subsystem to send the packet
> >> 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
>
> The report for reference:
>
> https://lore.kernel.org/all/fb38cfe5153fd67f540e6e8aff814c60b7129480.camel@gmx.de/>
> > Where does netpoll take fq->lock ?
>
> the dependencies between the lock to be acquired
> [ 107.985514] and HARDIRQ-irq-unsafe lock:
> [ 107.985531] -> (&fq->lock){+.-.}-{3:3} {
> ...
> [ 107.988053] ... acquired at:
> [ 107.988054] check_prev_add+0xfb/0xca0
> [ 107.988058] validate_chain+0x48c/0x530
> [ 107.988061] __lock_acquire+0x550/0xbc0
> [ 107.988064] lock_acquire.part.0+0xa1/0x210
> [ 107.988068] _raw_spin_lock_bh+0x38/0x50
> [ 107.988070] ieee80211_queue_skb+0xfd/0x350 [mac80211]
> [ 107.988198] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
> [ 107.988314] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
> [ 107.988424] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
> [ 107.988530] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
Ah, that's WiFi's stack queuing. Dunno whether we expect netpoll to
work over WiFi. I suspect disabling netconsole over WiFi may be the
most sensible way out. Johannes, do you expect mac80211 Tx to be IRQ-safe?
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 16:42 ` Jakub Kicinski
@ 2025-08-15 17:29 ` Breno Leitao
2025-08-15 17:33 ` Jakub Kicinski
` (2 more replies)
2025-08-15 17:37 ` Calvin Owens
2025-08-26 14:10 ` Johannes Berg
2 siblings, 3 replies; 27+ messages in thread
From: Breno Leitao @ 2025-08-15 17:29 UTC (permalink / raw)
To: Jakub Kicinski
Cc: Pavel Begunkov, Johannes Berg, Mike Galbraith, paulmck, LKML,
netdev, boqun.feng
On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > On 8/15/25 01:23, Jakub Kicinski wrote:
>
> I suspect disabling netconsole over WiFi may be the most sensible way out.
I believe we might be facing a similar issue with virtio-net.
Specifically, any network adapter where TX is not safe to use in IRQ
context encounters this problem.
If we want to keep netconsole enabled on all TX paths, a possible
solution is to defer the transmission work when netconsole is called
inside an IRQ.
The idea is that netconsole first checks if it is running in an IRQ
context using in_irq(). If so, it queues the skb without transmitting it
immediately and schedules deferred work to handle the transmission
later.
A rough implementation could be:
static void send_udp(struct netconsole_target *nt, const char *msg, int len) {
/* get the SKB that is already populated, with all the headers
* and ready to be sent
*/
struct sk_buff = netpoll_get_skb(&nt->np, msg, len);
if (in_irq()) {
skb_queue_tail(&np->delayed_queue, skb);
schedule_delayed_work(flush_delayed_queue, 0);
return;
}
return __netpoll_send_skb(struct netpoll *np, struct sk_buff *skb)
}
This approach does not require additional memory or extra data copying,
since copying from the printk buffer to the skb must be performed
regardless.
The main drawback is a slight delay for messages sent from within an IRQ
context, though I believe such cases are infrequent.
We could potentially also perform the flush from softirq context, which
would help reduce this latency further.
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 17:29 ` Breno Leitao
@ 2025-08-15 17:33 ` Jakub Kicinski
2025-08-18 12:23 ` Breno Leitao
2025-08-15 19:10 ` Calvin Owens
2025-08-15 20:02 ` Pavel Begunkov
2 siblings, 1 reply; 27+ messages in thread
From: Jakub Kicinski @ 2025-08-15 17:33 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Johannes Berg, Mike Galbraith, paulmck, LKML,
netdev, boqun.feng
On Fri, 15 Aug 2025 10:29:00 -0700 Breno Leitao wrote:
> On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> > On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > > On 8/15/25 01:23, Jakub Kicinski wrote:
> >
> > I suspect disabling netconsole over WiFi may be the most sensible way out.
>
> I believe we might be facing a similar issue with virtio-net.
I could be misremembering but I thought virtio-net try_lock()s.
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 16:42 ` Jakub Kicinski
2025-08-15 17:29 ` Breno Leitao
@ 2025-08-15 17:37 ` Calvin Owens
2025-08-26 14:10 ` Johannes Berg
2 siblings, 0 replies; 27+ messages in thread
From: Calvin Owens @ 2025-08-15 17:37 UTC (permalink / raw)
To: Jakub Kicinski
Cc: Pavel Begunkov, Johannes Berg, Breno Leitao, Mike Galbraith,
paulmck, LKML, netdev, boqun.feng
On Friday 08/15 at 09:42 -0700, Jakub Kicinski wrote:
> On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > On 8/15/25 01:23, Jakub Kicinski wrote:
> > > On Thu, 14 Aug 2025 03:16:11 -0700 Breno Leitao wrote:
> > >> 2.2) netpoll // net poll will call the network subsystem to send the packet
> > >> 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
> >
> > The report for reference:
> >
> > https://lore.kernel.org/all/fb38cfe5153fd67f540e6e8aff814c60b7129480.camel@gmx.de/>
> > > Where does netpoll take fq->lock ?
> >
> > the dependencies between the lock to be acquired
> > [ 107.985514] and HARDIRQ-irq-unsafe lock:
> > [ 107.985531] -> (&fq->lock){+.-.}-{3:3} {
> > ...
> > [ 107.988053] ... acquired at:
> > [ 107.988054] check_prev_add+0xfb/0xca0
> > [ 107.988058] validate_chain+0x48c/0x530
> > [ 107.988061] __lock_acquire+0x550/0xbc0
> > [ 107.988064] lock_acquire.part.0+0xa1/0x210
> > [ 107.988068] _raw_spin_lock_bh+0x38/0x50
> > [ 107.988070] ieee80211_queue_skb+0xfd/0x350 [mac80211]
> > [ 107.988198] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
> > [ 107.988314] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
> > [ 107.988424] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
> > [ 107.988530] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
>
> Ah, that's WiFi's stack queuing. Dunno whether we expect netpoll to
> work over WiFi. I suspect disabling netconsole over WiFi may be the
> most sensible way out. Johannes, do you expect mac80211 Tx to be IRQ-safe?
It'd be a bit of a shame IMHO to summarily break netconsole over wifi:
it works well enough in practice that I've personally found it helpful
for quick debugging across large numbers of IoT devices (user context
OOPSes outside net/ usually seem to make it out, as do WARNs and other
non-fatal splats).
But if Johannes' answer is "no", maybe there's no way out :/
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 17:29 ` Breno Leitao
2025-08-15 17:33 ` Jakub Kicinski
@ 2025-08-15 19:10 ` Calvin Owens
2025-08-16 9:19 ` Mike Galbraith
2025-08-15 20:02 ` Pavel Begunkov
2 siblings, 1 reply; 27+ messages in thread
From: Calvin Owens @ 2025-08-15 19:10 UTC (permalink / raw)
To: Breno Leitao
Cc: Jakub Kicinski, Pavel Begunkov, Johannes Berg, Mike Galbraith,
paulmck, LKML, netdev, boqun.feng
On Friday 08/15 at 10:29 -0700, Breno Leitao wrote:
> On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> > On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > > On 8/15/25 01:23, Jakub Kicinski wrote:
> >
> > I suspect disabling netconsole over WiFi may be the most sensible way out.
>
> I believe we might be facing a similar issue with virtio-net.
> Specifically, any network adapter where TX is not safe to use in IRQ
> context encounters this problem.
>
> If we want to keep netconsole enabled on all TX paths, a possible
> solution is to defer the transmission work when netconsole is called
> inside an IRQ.
>
> The idea is that netconsole first checks if it is running in an IRQ
> context using in_irq(). If so, it queues the skb without transmitting it
> immediately and schedules deferred work to handle the transmission
> later.
>
> A rough implementation could be:
>
> static void send_udp(struct netconsole_target *nt, const char *msg, int len) {
>
> /* get the SKB that is already populated, with all the headers
> * and ready to be sent
> */
> struct sk_buff = netpoll_get_skb(&nt->np, msg, len);
>
> if (in_irq()) {
> skb_queue_tail(&np->delayed_queue, skb);
> schedule_delayed_work(flush_delayed_queue, 0);
> return;
> }
>
> return __netpoll_send_skb(struct netpoll *np, struct sk_buff *skb)
> }
>
> This approach does not require additional memory or extra data copying,
> since copying from the printk buffer to the skb must be performed
> regardless.
>
> The main drawback is a slight delay for messages sent from within an IRQ
> context, though I believe such cases are infrequent.
>
> We could potentially also perform the flush from softirq context, which
> would help reduce this latency further.
If we take an OOPS in any IRQ, I suspect that delayed_work will never
get a chance to run, and we'll now lose all such OOPSes over netconsole?
I don't think softirq would get a chance either in that case?
Clearly, if it was a net driver's IRQ, that's not likely to happen
anyway. But in my experience, OOPSes in IRQs other than the driver
underlying netconsole's netdev *do* get emitted pretty reliably.
If your condition instead becomes:
if (in_irq() && !oops_in_progress)
...I think we can have our cake and eat it too? In an OOPS we're
busting locks and such, all bets are off anyway. Although, I suppose
that might still drop messages emitted immediately before it...
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 17:29 ` Breno Leitao
2025-08-15 17:33 ` Jakub Kicinski
2025-08-15 19:10 ` Calvin Owens
@ 2025-08-15 20:02 ` Pavel Begunkov
2025-08-18 12:10 ` Breno Leitao
2 siblings, 1 reply; 27+ messages in thread
From: Pavel Begunkov @ 2025-08-15 20:02 UTC (permalink / raw)
To: Breno Leitao, Jakub Kicinski
Cc: Johannes Berg, Mike Galbraith, paulmck, LKML, netdev, boqun.feng
On 8/15/25 18:29, Breno Leitao wrote:
> On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
>> On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
>>> On 8/15/25 01:23, Jakub Kicinski wrote:
>>
>> I suspect disabling netconsole over WiFi may be the most sensible way out.
>
> I believe we might be facing a similar issue with virtio-net.
> Specifically, any network adapter where TX is not safe to use in IRQ
> context encounters this problem.
>
> If we want to keep netconsole enabled on all TX paths, a possible
> solution is to defer the transmission work when netconsole is called
> inside an IRQ.
>
> The idea is that netconsole first checks if it is running in an IRQ
> context using in_irq(). If so, it queues the skb without transmitting it
> immediately and schedules deferred work to handle the transmission
> later.
>
> A rough implementation could be:
>
> static void send_udp(struct netconsole_target *nt, const char *msg, int len) {
>
> /* get the SKB that is already populated, with all the headers
> * and ready to be sent
> */
> struct sk_buff = netpoll_get_skb(&nt->np, msg, len);
>
> if (in_irq()) {
It's not just irq handlers but any context that has irqs disabled, and
since it's nested under irq-safe console_owner it'd need to always be
deferred or somehow moved out of the console_owner critical section.
Maybe there is printk lock trickery I don't understand, however.
> skb_queue_tail(&np->delayed_queue, skb);
> schedule_delayed_work(flush_delayed_queue, 0);
> return;
> }
>
> return __netpoll_send_skb(struct netpoll *np, struct sk_buff *skb)
> }
>
> This approach does not require additional memory or extra data copying,
> since copying from the printk buffer to the skb must be performed
> regardless.
>
> The main drawback is a slight delay for messages sent from within an IRQ
> context, though I believe such cases are infrequent.
>
> We could potentially also perform the flush from softirq context, which
> would help reduce this latency further.
--
Pavel Begunkov
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 19:10 ` Calvin Owens
@ 2025-08-16 9:19 ` Mike Galbraith
0 siblings, 0 replies; 27+ messages in thread
From: Mike Galbraith @ 2025-08-16 9:19 UTC (permalink / raw)
To: Calvin Owens, Breno Leitao
Cc: Jakub Kicinski, Pavel Begunkov, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Fri, 2025-08-15 at 12:10 -0700, Calvin Owens wrote:
>
> If your condition instead becomes:
>
> if (in_irq() && !oops_in_progress)
>
> ...I think we can have our cake and eat it too? In an OOPS we're
> busting locks and such, all bets are off anyway. Although, I suppose
> that might still drop messages emitted immediately before it...
I tried that to skip the __netpoll_send_skb() xmit loop, but lockdep
didn't look any happier, so I rummaged for a wireless signpost to
redirect all wireless traffic instead.
With only the __netpoll_send_skb() fork-in-road, lappy moaned as below,
all of which use of local_bh_disable() in queue_process() silenced.
sharp stick:
---
net/core/netpoll.c | 9 +++++----
1 file changed, 5 insertions(+), 4 deletions(-)
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -90,7 +90,6 @@ static void queue_process(struct work_st
struct netpoll_info *npinfo =
container_of(work, struct netpoll_info, tx_work.work);
struct sk_buff *skb;
- unsigned long flags;
while ((skb = skb_dequeue(&npinfo->txq))) {
struct net_device *dev = skb->dev;
@@ -102,7 +101,7 @@ static void queue_process(struct work_st
continue;
}
- local_irq_save(flags);
+ local_bh_disable();
/* check if skb->queue_mapping is still valid */
q_index = skb_get_queue_mapping(skb);
if (unlikely(q_index >= dev->real_num_tx_queues)) {
@@ -115,13 +114,13 @@ static void queue_process(struct work_st
!dev_xmit_complete(netpoll_start_xmit(skb, dev, txq))) {
skb_queue_head(&npinfo->txq, skb);
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ local_bh_enable();
schedule_delayed_work(&npinfo->tx_work, HZ/10);
return;
}
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ local_bh_enable();
}
}
@@ -339,6 +338,8 @@ static netdev_tx_t __netpoll_send_skb(st
/* try until next clock tick */
for (tries = jiffies_to_usecs(1)/USEC_PER_POLL;
tries > 0; --tries) {
+ if (dev->ieee80211_ptr && !oops_in_progress)
+ break;
if (HARD_TX_TRYLOCK(dev, txq)) {
if (!netif_xmit_stopped(txq))
status = netpoll_start_xmit(skb, dev, txq);
wireless lappy gripes:
[ 61.191326][ T3992] netconsole: network logging started
[ 61.193561][ T504] ------------[ cut here ]------------
[ 61.193798][ T504] WARNING: CPU: 1 PID: 504 at kernel/softirq.c:387 __local_bh_enable_ip+0x8f/0xe0
[ 61.193852][ T504] Modules linked in: netconsole ccm nf_nat_tftp nf_conntrack_tftp nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject af_packet nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables ip_set nfnetlink cmac algif_hash algif_skcipher af_alg iwlmvm mac80211 snd_hda_codec_hdmi binfmt_misc snd_hda_codec_conexant snd_hda_codec_generic snd_hda_intel intel_rapl_msr intel_rapl_common snd_intel_dspcfg x86_pkg_temp_thermal intel_powerclamp libarc4 snd_hda_codec btusb snd_hwdep coretemp iTCO_wdt intel_pmc_bxt snd_hda_core iTCO_vendor_support mei_hdcp mei_pxp mfd_core btrtl nls_iso8859_1 kvm_intel btbcm btintel nls_cp437 kvm snd_pcm iwlwifi snd_timer irqbypass uvcvideo bluetooth cfg80211 uvc videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev mc i2c_i801 snd pcspkr mei_me i2c_smbus soundcore rfkill mei thermal battery tiny_power_button acpi_pad button ac joydev sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse
[ 61.194109][ T504] dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit drm_buddy drm_client_lib drm_display_helper polyval_clmulni ghash_clmulni_intel drm_kms_helper cec rc_core ttm video xhci_pci xhci_hcd drm ahci libahci usbcore wmi libata serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel
[ 61.194852][ T504] CPU: 1 UID: 0 PID: 504 Comm: kworker/1:3 Kdump: loaded Tainted: G I 6.17.0.gdfd4b508-master #199 PREEMPT(lazy) d58b2f71f2d7e509bfea5f74e10faccc1d76d31c
[ 61.194932][ T504] Tainted: [I]=FIRMWARE_WORKAROUND
[ 61.194961][ T504] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 61.195003][ T504] Workqueue: events queue_process
[ 61.195038][ T504] RIP: 0010:__local_bh_enable_ip+0x8f/0xe0
[ 61.195119][ T504] Code: 3e bf 01 00 00 00 e8 90 ba 03 00 e8 1b 71 19 00 fb 65 8b 05 e3 81 ee 01 85 c0 74 41 5b 5d c3 65 8b 05 91 bf ee 01 85 c0 75 a4 <0f> 0b eb a0 e8 48 70 19 00 eb a1 48 89 ef e8 ae 1c 09 00 eb aa 48
[ 61.195204][ T504] RSP: 0018:ffffcf9b80fb7b20 EFLAGS: 00010046
[ 61.195241][ T504] RAX: 0000000000000000 RBX: 0000000000000201 RCX: ffffcf9b80fb7ad4
[ 61.195282][ T504] RDX: 0000000000000001 RSI: 0000000000000201 RDI: ffffffffc1a4ae30
[ 61.195323][ T504] RBP: ffffffffc1a4ae30 R08: 0000000000000001 R09: 0000000000000002
[ 61.195364][ T504] R10: ffffcf9b80fb7988 R11: 0000000000000004 R12: ffff8b2c8440e168
[ 61.195403][ T504] R13: ffff8b2c8fe78f20 R14: ffff8b2c8440e000 R15: ffff8b2c8fe78f40
[ 61.195442][ T504] FS: 0000000000000000(0000) GS:ffff8b2e394b0000(0000) knlGS:0000000000000000
[ 61.195487][ T504] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 61.195523][ T504] CR2: 000055ac249a6b20 CR3: 000000015aed7002 CR4: 00000000003726f0
[ 61.195563][ T504] Call Trace:
[ 61.195585][ T504] <TASK>
[ 61.195610][ T504] ieee80211_queue_skb+0x140/0x350 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.195821][ T504] __ieee80211_xmit_fast+0x202/0x360 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.196014][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.196051][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.196098][ T504] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.196283][ T504] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.196469][ T504] ieee80211_subif_start_xmit+0x46/0x230 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.196698][ T504] ? lock_acquire.part.0+0xb1/0x210
[ 61.196740][ T504] ? netif_skb_features+0xb6/0x2b0
[ 61.196778][ T504] netpoll_start_xmit+0x8b/0xd0
[ 61.196813][ T504] queue_process+0xb5/0x200
[ 61.196850][ T504] process_one_work+0x21f/0x5b0
[ 61.196890][ T504] ? lock_is_held_type+0xca/0x120
[ 61.196937][ T504] worker_thread+0x1ce/0x3c0
[ 61.196975][ T504] ? bh_worker+0x250/0x250
[ 61.197007][ T504] kthread+0x146/0x230
[ 61.197040][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.197078][ T504] ret_from_fork+0x1a6/0x1f0
[ 61.197112][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.197150][ T504] ret_from_fork_asm+0x11/0x20
[ 61.197209][ T504] </TASK>
[ 61.197292][ T504] irq event stamp: 164585
[ 61.197322][ T504] hardirqs last enabled at (164583): [<ffffffffac57987c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 61.197377][ T504] hardirqs last disabled at (164584): [<ffffffffac31a93e>] queue_process+0x11e/0x200
[ 61.197428][ T504] softirqs last enabled at (164454): [<ffffffffab90251e>] handle_softirqs+0x31e/0x3f0
[ 61.197479][ T504] softirqs last disabled at (164585): [<ffffffffc1a4aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 61.197664][ T504] ---[ end trace 0000000000000000 ]---
[ 61.197707][ T504]
[ 61.197717][ T504] ================================
[ 61.197728][ T504] WARNING: inconsistent lock state
[ 61.197740][ T504] 6.17.0.gdfd4b508-master #199 Tainted: G W I
[ 61.197754][ T504] --------------------------------
[ 61.197765][ T504] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
[ 61.197778][ T504] kworker/1:3/504 [HC0[0]:SC0[0]:HE0:SE1] takes:
[ 61.197793][ T504] ffff8b2c84899d18 (_xmit_ETHER#2){+.?.}-{3:3}, at: queue_process+0x138/0x200
[ 61.197820][ T504] {IN-SOFTIRQ-W} state was registered at:
[ 61.197832][ T504] __lock_acquire+0x3d6/0xbc0
[ 61.197849][ T504] lock_acquire.part.0+0xa1/0x210
[ 61.197863][ T504] _raw_spin_lock+0x33/0x40
[ 61.197875][ T504] __dev_queue_xmit+0x7fb/0xc20
[ 61.197891][ T504] ip_finish_output2+0x1f7/0x800
[ 61.197905][ T504] ip_output+0xb3/0x3c0
[ 61.197918][ T504] igmp_ifc_timer_expire+0x21/0xf0
[ 61.197931][ T504] call_timer_fn+0xa5/0x250
[ 61.197944][ T504] __run_timers+0x1f2/0x2c0
[ 61.197957][ T504] run_timer_base+0x46/0x60
[ 61.197969][ T504] run_timer_softirq+0x1a/0x30
[ 61.197981][ T504] handle_softirqs+0xdb/0x3f0
[ 61.197994][ T504] __irq_exit_rcu+0xc1/0x130
[ 61.198006][ T504] irq_exit_rcu+0xe/0x30
[ 61.198018][ T504] sysvec_apic_timer_interrupt+0x55/0xd0
[ 61.198032][ T504] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 61.198046][ T504] irq event stamp: 164586
[ 61.198058][ T504] hardirqs last enabled at (164583): [<ffffffffac57987c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 61.198077][ T504] hardirqs last disabled at (164584): [<ffffffffac31a93e>] queue_process+0x11e/0x200
[ 61.198094][ T504] softirqs last enabled at (164586): [<ffffffffc1a4ae30>] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 61.198239][ T504] softirqs last disabled at (164585): [<ffffffffc1a4aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 61.198375][ T504]
[ 61.198375][ T504] other info that might help us debug this:
[ 61.198391][ T504] Possible unsafe locking scenario:
[ 61.198391][ T504]
[ 61.198406][ T504] CPU0
[ 61.198416][ T504] ----
[ 61.198425][ T504] lock(_xmit_ETHER#2);
[ 61.198440][ T504] <Interrupt>
[ 61.198449][ T504] lock(_xmit_ETHER#2);
[ 61.198463][ T504]
[ 61.198463][ T504] *** DEADLOCK ***
[ 61.198463][ T504]
[ 61.198482][ T504] 4 locks held by kworker/1:3/504:
[ 61.198494][ T504] #0: ffff8b2c8004d148 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x52a/0x5b0
[ 61.198521][ T504] #1: ffffcf9b80fb7e28 ((work_completion)(&(&npinfo->tx_work)->work)){+.+.}-{0:0}, at: process_one_work+0x1f0/0x5b0
[ 61.198546][ T504] #2: ffff8b2c84899d18 (_xmit_ETHER#2){+.?.}-{3:3}, at: queue_process+0x138/0x200
[ 61.198573][ T504] #3: ffffffffacf71400 (rcu_read_lock){....}-{1:3}, at: __ieee80211_subif_start_xmit+0xb2/0x3d0 [mac80211]
[ 61.198718][ T504]
[ 61.198718][ T504] stack backtrace:
[ 61.198735][ T504] CPU: 1 UID: 0 PID: 504 Comm: kworker/1:3 Kdump: loaded Tainted: G W I 6.17.0.gdfd4b508-master #199 PREEMPT(lazy) d58b2f71f2d7e509bfea5f74e10faccc1d76d31c
[ 61.198742][ T504] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 61.198743][ T504] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 61.198745][ T504] Workqueue: events queue_process
[ 61.198750][ T504] Call Trace:
[ 61.198751][ T504] <TASK>
[ 61.198755][ T504] dump_stack_lvl+0x5b/0x80
[ 61.198762][ T504] print_usage_bug.part.0+0x22c/0x2c0
[ 61.198769][ T504] mark_lock_irq+0x3a9/0x590
[ 61.198775][ T504] ? save_trace+0x65/0x1e0
[ 61.198783][ T504] mark_lock+0x1b7/0x3c0
[ 61.198788][ T504] mark_held_locks+0x40/0x70
[ 61.198793][ T504] ? ieee80211_queue_skb+0x140/0x350 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.198914][ T504] lockdep_hardirqs_on_prepare.part.0+0xaf/0x160
[ 61.198919][ T504] trace_hardirqs_on+0x44/0xc0
[ 61.198923][ T504] __local_bh_enable_ip+0x75/0xe0
[ 61.198927][ T504] ieee80211_queue_skb+0x140/0x350 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.199047][ T504] __ieee80211_xmit_fast+0x202/0x360 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.199184][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.199190][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.199199][ T504] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.199310][ T504] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.199422][ T504] ieee80211_subif_start_xmit+0x46/0x230 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.199527][ T504] ? lock_acquire.part.0+0xb1/0x210
[ 61.199534][ T504] ? netif_skb_features+0xb6/0x2b0
[ 61.199541][ T504] netpoll_start_xmit+0x8b/0xd0
[ 61.199547][ T504] queue_process+0xb5/0x200
[ 61.199552][ T504] process_one_work+0x21f/0x5b0
[ 61.199557][ T504] ? lock_is_held_type+0xca/0x120
[ 61.199565][ T504] worker_thread+0x1ce/0x3c0
[ 61.199570][ T504] ? bh_worker+0x250/0x250
[ 61.199574][ T504] kthread+0x146/0x230
[ 61.199578][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.199582][ T504] ret_from_fork+0x1a6/0x1f0
[ 61.199588][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.199592][ T504] ret_from_fork_asm+0x11/0x20
[ 61.199602][ T504] </TASK>
[ 61.200069][ T504] ------------[ cut here ]------------
[ 61.200093][ T504] WARNING: CPU: 1 PID: 504 at net/mac80211/tx.c:3814 ieee80211_tx_dequeue+0x71c/0x7e0 [mac80211]
[ 61.200309][ T504] Modules linked in: netconsole ccm nf_nat_tftp nf_conntrack_tftp nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject af_packet nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nf_tables ip_set nfnetlink cmac algif_hash algif_skcipher af_alg iwlmvm mac80211 snd_hda_codec_hdmi binfmt_misc snd_hda_codec_conexant snd_hda_codec_generic snd_hda_intel intel_rapl_msr intel_rapl_common snd_intel_dspcfg x86_pkg_temp_thermal intel_powerclamp libarc4 snd_hda_codec btusb snd_hwdep coretemp iTCO_wdt intel_pmc_bxt snd_hda_core iTCO_vendor_support mei_hdcp mei_pxp mfd_core btrtl nls_iso8859_1 kvm_intel btbcm btintel nls_cp437 kvm snd_pcm iwlwifi snd_timer irqbypass uvcvideo bluetooth cfg80211 uvc videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev mc i2c_i801 snd pcspkr mei_me i2c_smbus soundcore rfkill mei thermal battery tiny_power_button acpi_pad button ac joydev sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse
[ 61.200565][ T504] dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit drm_buddy drm_client_lib drm_display_helper polyval_clmulni ghash_clmulni_intel drm_kms_helper cec rc_core ttm video xhci_pci xhci_hcd drm ahci libahci usbcore wmi libata serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel
[ 61.200923][ T504] CPU: 1 UID: 0 PID: 504 Comm: kworker/1:3 Kdump: loaded Tainted: G W I 6.17.0.gdfd4b508-master #199 PREEMPT(lazy) d58b2f71f2d7e509bfea5f74e10faccc1d76d31c
[ 61.200969][ T504] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 61.200992][ T504] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 61.201018][ T504] Workqueue: events queue_process
[ 61.201050][ T504] RIP: 0010:ieee80211_tx_dequeue+0x71c/0x7e0 [mac80211]
[ 61.201269][ T504] Code: 84 00 fc ff ff 48 8b 44 24 20 48 8b bc 24 a0 00 00 00 31 d2 48 8d 70 0a e8 51 6d ff ff 84 c0 0f 85 87 fa ff ff e9 db fb ff ff <0f> 0b e9 32 f9 ff ff e8 98 35 f7 e9 85 c0 0f 85 9c fb ff ff e8 eb
[ 61.201316][ T504] RSP: 0018:ffffcf9b80fb7a00 EFLAGS: 00010246
[ 61.201343][ T504] RAX: 0000000000000002 RBX: ffff8b2c861a68e0 RCX: 0000000000000002
[ 61.201369][ T504] RDX: ffffffffc1798ee9 RSI: ffff8b2c8440e168 RDI: ffff8b2c8fe78e60
[ 61.201395][ T504] RBP: ffff8b2c8440e168 R08: 0000000000000000 R09: 0000000000000000
[ 61.201420][ T504] R10: ffffffffc1798ee9 R11: 0000000000000003 R12: 0000000000000002
[ 61.201445][ T504] R13: ffff8b2c8440e000 R14: ffff8b2c8fe78e60 R15: ffff8b2c8fe7b0a8
[ 61.201470][ T504] FS: 0000000000000000(0000) GS:ffff8b2e394b0000(0000) knlGS:0000000000000000
[ 61.201499][ T504] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 61.201524][ T504] CR2: 000055ac249a6b20 CR3: 000000026524f006 CR4: 00000000003726f0
[ 61.201551][ T504] Call Trace:
[ 61.201571][ T504] <TASK>
[ 61.201594][ T504] ? rcu_is_watching+0x11/0x40
[ 61.201624][ T504] ? rcu_is_watching+0x11/0x40
[ 61.201650][ T504] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 61.201683][ T504] ? rcu_is_watching+0x11/0x40
[ 61.201709][ T504] ? lock_acquire+0xee/0x130
[ 61.201734][ T504] ? iwl_mvm_mac_itxq_xmit+0x59/0x1f0 [iwlmvm c8adf931d43d5fa86daab53059e4bf48817253e5]
[ 61.201820][ T504] iwl_mvm_mac_itxq_xmit+0xb3/0x1f0 [iwlmvm c8adf931d43d5fa86daab53059e4bf48817253e5]
[ 61.201900][ T504] ieee80211_queue_skb+0x21b/0x350 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.202128][ T504] __ieee80211_xmit_fast+0x202/0x360 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.202330][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.202352][ T504] ? __skb_get_hash_net+0x54/0x1f0
[ 61.202375][ T504] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.202549][ T504] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.202719][ T504] ieee80211_subif_start_xmit+0x46/0x230 [mac80211 b718f73b247535542b221eff8a4a9e1817e251c7]
[ 61.202878][ T504] ? lock_acquire.part.0+0xb1/0x210
[ 61.202900][ T504] ? netif_skb_features+0xb6/0x2b0
[ 61.202920][ T504] netpoll_start_xmit+0x8b/0xd0
[ 61.202939][ T504] queue_process+0xb5/0x200
[ 61.202958][ T504] process_one_work+0x21f/0x5b0
[ 61.202983][ T504] ? lock_is_held_type+0xca/0x120
[ 61.203006][ T504] worker_thread+0x1ce/0x3c0
[ 61.203024][ T504] ? bh_worker+0x250/0x250
[ 61.203040][ T504] kthread+0x146/0x230
[ 61.203057][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.203075][ T504] ret_from_fork+0x1a6/0x1f0
[ 61.203093][ T504] ? kthreads_online_cpu+0x110/0x110
[ 61.203128][ T504] ret_from_fork_asm+0x11/0x20
[ 61.203154][ T504] </TASK>
[ 61.203166][ T504] irq event stamp: 164586
[ 61.203179][ T504] hardirqs last enabled at (164583): [<ffffffffac57987c>] _raw_spin_unlock_irqrestore+0x4c/0x60
[ 61.203203][ T504] hardirqs last disabled at (164584): [<ffffffffac31a93e>] queue_process+0x11e/0x200
[ 61.203224][ T504] softirqs last enabled at (164586): [<ffffffffc1a4ae30>] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 61.203393][ T504] softirqs last disabled at (164585): [<ffffffffc1a4aded>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 61.203552][ T504] ---[ end trace 0000000000000000 ]---
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 20:02 ` Pavel Begunkov
@ 2025-08-18 12:10 ` Breno Leitao
2025-08-19 17:27 ` Breno Leitao
0 siblings, 1 reply; 27+ messages in thread
From: Breno Leitao @ 2025-08-18 12:10 UTC (permalink / raw)
To: Pavel Begunkov
Cc: Jakub Kicinski, Johannes Berg, Mike Galbraith, paulmck, LKML,
netdev, boqun.feng
On Fri, Aug 15, 2025 at 09:02:27PM +0100, Pavel Begunkov wrote:
> On 8/15/25 18:29, Breno Leitao wrote:
> > On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> > > On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > > > On 8/15/25 01:23, Jakub Kicinski wrote:
> > >
> > > I suspect disabling netconsole over WiFi may be the most sensible way out.
> >
> > I believe we might be facing a similar issue with virtio-net.
> > Specifically, any network adapter where TX is not safe to use in IRQ
> > context encounters this problem.
> >
> > If we want to keep netconsole enabled on all TX paths, a possible
> > solution is to defer the transmission work when netconsole is called
> > inside an IRQ.
> >
> > The idea is that netconsole first checks if it is running in an IRQ
> > context using in_irq(). If so, it queues the skb without transmitting it
> > immediately and schedules deferred work to handle the transmission
> > later.
> >
> > A rough implementation could be:
> >
> > static void send_udp(struct netconsole_target *nt, const char *msg, int len) {
> >
> > /* get the SKB that is already populated, with all the headers
> > * and ready to be sent
> > */
> > struct sk_buff = netpoll_get_skb(&nt->np, msg, len);
> >
> > if (in_irq()) {
>
> It's not just irq handlers but any context that has irqs disabled, and
> since it's nested under irq-safe console_owner it'd need to always be
> deferred or somehow moved out of the console_owner critical section.
Agree. An IRQ-unsafe lock (fq lock) should not be reachable from an IRQ
disabled code path. So, one solution might be to always send TX packets
from a workqueue (unless it is on panic, as suggested by Calvin).
I've created a quick PoC to see how it looks like to always transmit
from a a work queue:
commit 02d0f38c3e435e4349de2fa3ce50fa8841aa0df9
Author: Breno Leitao <leitao@debian.org>
Date: Mon Aug 18 04:09:44 2025 -0700
netpoll: move packet transmission to workqueue for non-blocking output
This patch modifies the netpoll subsystem to perform packet transmission
asynchronously via a dedicated workqueue, always sending the packet from
a workqueue. This fix potential deadlock when the network locks are not
HARDIRQ safe.
Packets generated for transmission are queued on tx_queue and the workqueue
is scheduled to send them in process context, avoiding sending packets
directly from atomic context except during oops handling.
This affect only netconsole, given that no other netpoll user uses
netpoll_send_udp().
Signed-off-by: Breno Leitao <leitao@debian.org>
diff --git a/include/linux/netpoll.h b/include/linux/netpoll.h
index b5ea9882eda8b..bac9dec8bd3bc 100644
--- a/include/linux/netpoll.h
+++ b/include/linux/netpoll.h
@@ -35,8 +35,8 @@ struct netpoll {
bool ipv6;
u16 local_port, remote_port;
u8 remote_mac[ETH_ALEN];
- struct sk_buff_head skb_pool;
- struct work_struct refill_wq;
+ struct sk_buff_head skb_pool, tx_queue;
+ struct work_struct refill_wq, tx_wq;
};
#define np_info(np, fmt, ...) \
diff --git a/net/core/netpoll.c b/net/core/netpoll.c
index 5f65b62346d4e..92a4186cebb83 100644
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -496,6 +496,16 @@ static void push_eth(struct netpoll *np, struct sk_buff *skb)
eth->h_proto = htons(ETH_P_IP);
}
+static int netpoll_queue_skb(struct netpoll *np, struct sk_buff *skb)
+{
+ /* Queue at the tail and TX from the head */
+ skb_queue_tail(&np->tx_queue, skb);
+ schedule_work(&np->tx_wq);
+
+ /* TODO: this will need some refactor to update netconsole stats properly */
+ return NET_XMIT_SUCCESS;
+}
+
int netpoll_send_udp(struct netpoll *np, const char *msg, int len)
{
int total_len, ip_len, udp_len;
@@ -528,7 +538,10 @@ int netpoll_send_udp(struct netpoll *np, const char *msg, int len)
push_eth(np, skb);
skb->dev = np->dev;
- return (int)netpoll_send_skb(np, skb);
+ if (oops_in_progress)
+ return (int)netpoll_send_skb(np, skb);
+
+ return netpoll_queue_skb(np, skb);
}
EXPORT_SYMBOL(netpoll_send_udp);
@@ -540,6 +553,23 @@ static void skb_pool_flush(struct netpoll *np)
cancel_work_sync(&np->refill_wq);
skb_pool = &np->skb_pool;
skb_queue_purge_reason(skb_pool, SKB_CONSUMED);
+
+ /* tx_queue must be empty here, given we the pkts were flushed
+ * after users got disabled.
+ */
+ if (WARN_ON_ONCE(skb_queue_len(&np->tx_queue)))
+ skb_queue_purge(&np->tx_queue);
+}
+
+static void netpoll_flush_tx_poll(struct work_struct *work)
+{
+ struct sk_buff *skb;
+ struct netpoll *np;
+
+ np = container_of(work, struct netpoll, tx_wq);
+
+ while ((skb = skb_dequeue(&np->tx_queue)))
+ netpoll_send_skb(np, skb);
}
static void refill_skbs_work_handler(struct work_struct *work)
@@ -557,6 +587,7 @@ int __netpoll_setup(struct netpoll *np, struct net_device *ndev)
int err;
skb_queue_head_init(&np->skb_pool);
+ skb_queue_head_init(&np->tx_queue);
if (ndev->priv_flags & IFF_DISABLE_NETPOLL) {
np_err(np, "%s doesn't support polling, aborting\n",
@@ -596,6 +627,7 @@ int __netpoll_setup(struct netpoll *np, struct net_device *ndev)
/* fill up the skb queue */
refill_skbs(np);
INIT_WORK(&np->refill_wq, refill_skbs_work_handler);
+ INIT_WORK(&np->tx_wq, netpoll_flush_tx_poll);
/* last thing to do is link it to the net device structure */
rcu_assign_pointer(ndev->npinfo, npinfo);
@@ -815,6 +847,8 @@ static void __netpoll_cleanup(struct netpoll *np)
if (!npinfo)
return;
+ cancel_work_sync(&np->tx_wq);
+
if (refcount_dec_and_test(&npinfo->refcnt)) {
const struct net_device_ops *ops;
^ permalink raw reply related [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 17:33 ` Jakub Kicinski
@ 2025-08-18 12:23 ` Breno Leitao
0 siblings, 0 replies; 27+ messages in thread
From: Breno Leitao @ 2025-08-18 12:23 UTC (permalink / raw)
To: Jakub Kicinski
Cc: Pavel Begunkov, Johannes Berg, Mike Galbraith, paulmck, LKML,
netdev, boqun.feng
On Fri, Aug 15, 2025 at 10:33:08AM -0700, Jakub Kicinski wrote:
> On Fri, 15 Aug 2025 10:29:00 -0700 Breno Leitao wrote:
> > On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> > > On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > > > On 8/15/25 01:23, Jakub Kicinski wrote:
> > >
> > > I suspect disabling netconsole over WiFi may be the most sensible way out.
> >
> > I believe we might be facing a similar issue with virtio-net.
>
> I could be misremembering but I thought virtio-net try_lock()s.
virtio-net shows the same problem on net-next, as of bab3ce404553de56242
("Merge branch '100GbE' of
git://git.kernel.org/pub/scm/linux/kernel/git/tnguy/next-queue")
Chain exists of:
console_owner --> target_list_lock --> _xmit_ETHER#2
Looking at the stack I see it is using try lock:
_raw_spin_trylock (./include/linux/spinlock_api_smp.h:90 kernel/locking/spinlock.c:138)
virtnet_poll (./include/linux/spinlock.h:? ./include/linux/netdevice.h:4684 drivers/net/virtio_net.c:3056 drivers/net/virtio_net.c:3108)
Why would the try_lock() avoid such a problem?
I understand that, whenever the try_lock() succeed, it will reach
a HARDIRQ-unsafe lock (_xmit_ETHER) from a HARDIRQ-safe lock (console
lock), which is the path that should be avoided.
Full lockdep snippet when using virtio-net:
[ 16.284303] ========================================================
[ 16.284303] WARNING: possible irq lock inversion dependency detected
[ 16.284305] 6.17.0-rc1-00216-g059cb8675a8c #8 Tainted: G E
[ 16.284306] --------------------------------------------------------
[ 16.284306] swapper/16/0 just changed the state of lock:
[ 16.284307] ffffffff82d84290 (console_owner){-...}-{0:0}, at: console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284315] but this lock took another, HARDIRQ-unsafe lock in the past:
[ 16.284316] (_xmit_ETHER#2){+.-.}-{3:3}
[ 16.284317]
[ 16.284317]
[ 16.284317] and interrupts could create inverse lock ordering between them.
[ 16.284317]
[ 16.284318]
[ 16.284318] other info that might help us debug this:
[ 16.284318] Chain exists of:
[ 16.284318] console_owner --> target_list_lock --> _xmit_ETHER#2
[ 16.284318]
[ 16.284320] Possible interrupt unsafe locking scenario:
[ 16.284320]
[ 16.284321] CPU0 CPU1
[ 16.284321] ---- ----
[ 16.284321] lock(_xmit_ETHER#2);
[ 16.284322] local_irq_disable();
[ 16.284323] lock(console_owner);
[ 16.284323] lock(target_list_lock);
[ 16.284324] <Interrupt>
[ 16.284324] lock(console_owner);
[ 16.284325]
[ 16.284325] *** DEADLOCK ***
[ 16.284325]
[ 16.284325] 2 locks held by swapper/16/0:
[ 16.284326] #0: ffffffff82d842b8 (console_lock){+.+.}-{0:0}, at: irq_work_run_list (kernel/irq_work.c:222 kernel/irq_work.c:252)
[ 16.284330] #1: ffffffff82683d60 (console_srcu){....}-{0:0}, at: console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284333]
[ 16.284333] the shortest dependencies between 2nd lock and 1st lock:
[ 16.284336] -> (_xmit_ETHER#2){+.-.}-{3:3} ops: 558 {
[ 16.284340] HARDIRQ-ON-W at:
[ 16.284342] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284343] _raw_spin_trylock (./include/linux/spinlock_api_smp.h:90 kernel/locking/spinlock.c:138)
[ 16.284346] virtnet_poll (./include/linux/spinlock.h:? ./include/linux/netdevice.h:4684 drivers/net/virtio_net.c:3056 drivers/net/virtio_net.c:3108)
[ 16.284348] __napi_poll (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/napi.h:14 net/core/dev.c:7495)
[ 16.284350] net_rx_action (net/core/dev.c:7559 net/core/dev.c:7684)
[ 16.284351] handle_softirqs (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/irq.h:142 kernel/softirq.c:580)
[ 16.284353] do_softirq (kernel/softirq.c:480)
[ 16.284353] __local_bh_enable_ip (kernel/softirq.c:?)
[ 16.284354] virtnet_napi_enable (drivers/net/virtio_net.c:2874)
[ 16.284356] virtnet_open (drivers/net/virtio_net.c:? drivers/net/virtio_net.c:3211)
[ 16.284357] __dev_open (net/core/dev.c:1682)
[ 16.284358] netif_open (net/core/dev.c:1706)
[ 16.284359] dev_open (net/core/dev_api.c:?)
[ 16.284360] netpoll_setup (net/core/netpoll.c:744)
[ 16.284361] init_netconsole (drivers/net/netconsole.c:1876 drivers/net/netconsole.c:1927)
[ 16.284364] do_one_initcall (init/main.c:1269)
[ 16.284365] do_initcall_level (init/main.c:1330)
[ 16.284367] do_initcalls (init/main.c:1344)
[ 16.284369] kernel_init_freeable (init/main.c:1583)
[ 16.284452] kernel_init (init/main.c:1471)
[ 16.284455] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284456] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284458] IN-SOFTIRQ-W at:
[ 16.284458] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284459] _raw_spin_lock (./include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154)
[ 16.284460] virtnet_poll_tx (./include/linux/netdevice.h:4661 drivers/net/virtio_net.c:3255)
[ 16.284462] __napi_poll (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/napi.h:14 net/core/dev.c:7495)
[ 16.284463] net_rx_action (net/core/dev.c:7559 net/core/dev.c:7684)
[ 16.284463] handle_softirqs (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/irq.h:142 kernel/softirq.c:580)
[ 16.284464] do_softirq (kernel/softirq.c:480)
[ 16.284465] __local_bh_enable_ip (kernel/softirq.c:?)
[ 16.284466] virtnet_napi_tx_enable (drivers/net/virtio_net.c:2895)
[ 16.284467] virtnet_open (drivers/net/virtio_net.c:3205)
[ 16.284468] __dev_open (net/core/dev.c:1682)
[ 16.284469] netif_open (net/core/dev.c:1706)
[ 16.284470] dev_open (net/core/dev_api.c:?)
[ 16.284470] netpoll_setup (net/core/netpoll.c:744)
[ 16.284471] init_netconsole (drivers/net/netconsole.c:1876 drivers/net/netconsole.c:1927)
[ 16.284472] do_one_initcall (init/main.c:1269)
[ 16.284473] do_initcall_level (init/main.c:1330)
[ 16.284475] do_initcalls (init/main.c:1344)
[ 16.284476] kernel_init_freeable (init/main.c:1583)
[ 16.284478] kernel_init (init/main.c:1471)
[ 16.284479] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284480] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284481] INITIAL USE at:
[ 16.284482] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284482] _raw_spin_trylock (./include/linux/spinlock_api_smp.h:90 kernel/locking/spinlock.c:138)
[ 16.284484] virtnet_poll (./include/linux/spinlock.h:? ./include/linux/netdevice.h:4684 drivers/net/virtio_net.c:3056 drivers/net/virtio_net.c:3108)
[ 16.284485] __napi_poll (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/napi.h:14 net/core/dev.c:7495)
[ 16.284485] net_rx_action (net/core/dev.c:7559 net/core/dev.c:7684)
[ 16.284486] handle_softirqs (./arch/x86/include/asm/jump_label.h:36 ./include/trace/events/irq.h:142 kernel/softirq.c:580)
[ 16.284487] do_softirq (kernel/softirq.c:480)
[ 16.284488] __local_bh_enable_ip (kernel/softirq.c:?)
[ 16.284489] virtnet_napi_enable (drivers/net/virtio_net.c:2874)
[ 16.284490] virtnet_open (drivers/net/virtio_net.c:? drivers/net/virtio_net.c:3211)
[ 16.284490] __dev_open (net/core/dev.c:1682)
[ 16.284491] netif_open (net/core/dev.c:1706)
[ 16.284492] dev_open (net/core/dev_api.c:?)
[ 16.284492] netpoll_setup (net/core/netpoll.c:744)
[ 16.284493] init_netconsole (drivers/net/netconsole.c:1876 drivers/net/netconsole.c:1927)
[ 16.284494] do_one_initcall (init/main.c:1269)
[ 16.284495] do_initcall_level (init/main.c:1330)
[ 16.284496] do_initcalls (init/main.c:1344)
[ 16.284498] kernel_init_freeable (init/main.c:1583)
[ 16.284499] kernel_init (init/main.c:1471)
[ 16.284501] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284502] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284503] }
[ 16.284503] ... key at: netdev_xmit_lock_key+0x10/0x390
[ 16.284506] ... acquired at:
[ 16.284507] _raw_spin_lock (./include/linux/spinlock_api_smp.h:133 kernel/locking/spinlock.c:154)
[ 16.284508] virtnet_poll_tx (./include/linux/netdevice.h:4661 drivers/net/virtio_net.c:3255)
[ 16.284509] netpoll_poll_dev (net/core/netpoll.c:157 net/core/netpoll.c:170 net/core/netpoll.c:200)
[ 16.284510] netpoll_send_skb (./include/asm-generic/delay.h:62 net/core/netpoll.c:356 net/core/netpoll.c:410)
[ 16.284511] netpoll_send_udp (net/core/netpoll.c:532)
[ 16.284511] write_ext_msg (drivers/net/netconsole.c:1498 drivers/net/netconsole.c:1536 drivers/net/netconsole.c:1692 drivers/net/netconsole.c:1710)
[ 16.284513] console_flush_all (kernel/printk/printk.c:3055 kernel/printk/printk.c:3139 kernel/printk/printk.c:3226)
[ 16.284515] console_unlock (kernel/printk/printk.c:3285 kernel/printk/printk.c:3325)
[ 16.284516] vprintk_emit (kernel/printk/printk.c:?)
[ 16.284518] _printk (kernel/printk/printk.c:2478)
[ 16.284519] register_console (kernel/printk/printk.c:4127)
[ 16.284521] init_netconsole (drivers/net/netconsole.c:1960)
[ 16.284522] do_one_initcall (init/main.c:1269)
[ 16.284523] do_initcall_level (init/main.c:1330)
[ 16.284524] do_initcalls (init/main.c:1344)
[ 16.284526] kernel_init_freeable (init/main.c:1583)
[ 16.284527] kernel_init (init/main.c:1471)
[ 16.284529] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284530] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284530]
[ 16.284531] -> (target_list_lock){....}-{3:3} ops: 420 {
[ 16.284533] INITIAL USE at:
[ 16.284534] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284592] _raw_spin_lock_irqsave (./include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 16.284593] init_netconsole (./include/linux/list.h:169 drivers/net/netconsole.c:1944)
[ 16.284595] do_one_initcall (init/main.c:1269)
[ 16.284596] do_initcall_level (init/main.c:1330)
[ 16.284597] do_initcalls (init/main.c:1344)
[ 16.284599] kernel_init_freeable (init/main.c:1583)
[ 16.284600] kernel_init (init/main.c:1471)
[ 16.284602] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284603] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284604] }
[ 16.284604] ... key at: target_list_lock (??:?)
[ 16.284606] ... acquired at:
[ 16.284606] _raw_spin_lock_irqsave (./include/linux/spinlock_api_smp.h:110 kernel/locking/spinlock.c:162)
[ 16.284607] write_ext_msg (drivers/net/netconsole.c:?)
[ 16.284609] console_flush_all (kernel/printk/printk.c:3055 kernel/printk/printk.c:3139 kernel/printk/printk.c:3226)
[ 16.284610] console_unlock (kernel/printk/printk.c:3285 kernel/printk/printk.c:3325)
[ 16.284612] vprintk_emit (kernel/printk/printk.c:?)
[ 16.284613] _printk (kernel/printk/printk.c:2478)
[ 16.284614] register_console (kernel/printk/printk.c:4127)
[ 16.284616] init_netconsole (drivers/net/netconsole.c:1960)
[ 16.284617] do_one_initcall (init/main.c:1269)
[ 16.284618] do_initcall_level (init/main.c:1330)
[ 16.284619] do_initcalls (init/main.c:1344)
[ 16.284620] kernel_init_freeable (init/main.c:1583)
[ 16.284622] kernel_init (init/main.c:1471)
[ 16.284623] ret_from_fork (arch/x86/kernel/process.c:154)
[ 16.284624] ret_from_fork_asm (arch/x86/entry/entry_64.S:258)
[ 16.284625]
[ 16.284625] -> (console_owner){-...}-{0:0} ops: 2643 {
[ 16.284627] IN-HARDIRQ-W at:
[ 16.284628] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284629] console_flush_all (kernel/printk/printk.c:1924 kernel/printk/printk.c:3132 kernel/printk/printk.c:3226)
[ 16.284630] console_unlock (kernel/printk/printk.c:3285 kernel/printk/printk.c:3325)
[ 16.284631] wake_up_klogd_work_func (kernel/printk/printk.c:4529)
[ 16.284632] irq_work_run_list (kernel/irq_work.c:222 kernel/irq_work.c:252)
[ 16.284634] update_process_times (kernel/time/timer.c:2478)
[ 16.284636] tick_nohz_handler (kernel/time/tick-sched.c:187 kernel/time/tick-sched.c:306)
[ 16.284638] __hrtimer_run_queues (kernel/time/hrtimer.c:1761 kernel/time/hrtimer.c:1825)
[ 16.284639] hrtimer_interrupt (kernel/time/hrtimer.c:1890)
[ 16.284640] __sysvec_apic_timer_interrupt (./arch/x86/include/asm/jump_label.h:36 ./arch/x86/include/asm/trace/irq_vectors.h:40 arch/x86/kernel/apic/apic.c:1057)
[ 16.284642] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1050 arch/x86/kernel/apic/apic.c:1050)
[ 16.284643] asm_sysvec_apic_timer_interrupt (./arch/x86/include/asm/idtentry.h:702)
[ 16.284644] pv_native_safe_halt (arch/x86/kernel/paravirt.c:82)
[ 16.284645] default_idle (./arch/x86/include/asm/paravirt.h:107 arch/x86/kernel/process.c:757)
[ 16.284647] default_idle_call (./include/linux/cpuidle.h:143 kernel/sched/idle.c:123)
[ 16.284648] do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284649] cpu_startup_entry (kernel/sched/idle.c:427)
[ 16.284650] start_secondary (arch/x86/kernel/smpboot.c:315)
[ 16.284651] common_startup_64 (arch/x86/kernel/head_64.S:419)
[ 16.284653] INITIAL USE at:
[ 16.284654] }
[ 16.284654] ... key at: console_owner_dep_map (??:?)
[ 16.284842] ... acquired at:
[ 16.284843] mark_lock (kernel/locking/lockdep.c:4753)
[ 16.284844] __lock_acquire (kernel/locking/lockdep.c:? kernel/locking/lockdep.c:5191)
[ 16.284845] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284846] console_flush_all (kernel/printk/printk.c:1924 kernel/printk/printk.c:3132 kernel/printk/printk.c:3226)
[ 16.284847] console_unlock (kernel/printk/printk.c:3285 kernel/printk/printk.c:3325)
[ 16.284849] wake_up_klogd_work_func (kernel/printk/printk.c:4529)
[ 16.284849] irq_work_run_list (kernel/irq_work.c:222 kernel/irq_work.c:252)
[ 16.284850] update_process_times (kernel/time/timer.c:2478)
[ 16.284852] tick_nohz_handler (kernel/time/tick-sched.c:187 kernel/time/tick-sched.c:306)
[ 16.284854] __hrtimer_run_queues (kernel/time/hrtimer.c:1761 kernel/time/hrtimer.c:1825)
[ 16.284854] hrtimer_interrupt (kernel/time/hrtimer.c:1890)
[ 16.284855] __sysvec_apic_timer_interrupt (./arch/x86/include/asm/jump_label.h:36 ./arch/x86/include/asm/trace/irq_vectors.h:40 arch/x86/kernel/apic/apic.c:1057)
[ 16.284856] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1050 arch/x86/kernel/apic/apic.c:1050)
[ 16.284858] asm_sysvec_apic_timer_interrupt (./arch/x86/include/asm/idtentry.h:702)
[ 16.284858] pv_native_safe_halt (arch/x86/kernel/paravirt.c:82)
[ 16.284859] default_idle (./arch/x86/include/asm/paravirt.h:107 arch/x86/kernel/process.c:757)
[ 16.284861] default_idle_call (./include/linux/cpuidle.h:143 kernel/sched/idle.c:123)
[ 16.284862] do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284863] cpu_startup_entry (kernel/sched/idle.c:427)
[ 16.284863] start_secondary (arch/x86/kernel/smpboot.c:315)
[ 16.284864] common_startup_64 (arch/x86/kernel/head_64.S:419)
[ 16.284866]
[ 16.284866]
[ 16.284866] stack backtrace:
[ 16.284870] Tainted: [E]=UNSIGNED_MODULE
[ 16.284871] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
[ 16.284872] Call Trace:
[ 16.284873] <IRQ>
[ 16.284876] dump_stack_lvl (lib/dump_stack.c:123)
[ 16.284880] print_irq_inversion_bug (kernel/locking/lockdep.c:?)
[ 16.284882] mark_lock_irq (kernel/locking/lockdep.c:?)
[ 16.284883] ? stack_trace_save (kernel/stacktrace.c:123)
[ 16.284886] mark_lock (kernel/locking/lockdep.c:4753)
[ 16.284887] __lock_acquire (kernel/locking/lockdep.c:? kernel/locking/lockdep.c:5191)
[ 16.284890] ? printk_get_next_message (kernel/printk/printk.c:3024)
[ 16.284892] ? console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284894] lock_acquire (kernel/locking/lockdep.c:5868)
[ 16.284895] ? console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284897] ? console_flush_all (kernel/printk/printk.c:1924 kernel/printk/printk.c:3132 kernel/printk/printk.c:3226)
[ 16.284899] ? console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284900] console_flush_all (kernel/printk/printk.c:1924 kernel/printk/printk.c:3132 kernel/printk/printk.c:3226)
[ 16.284923] ? console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284925] ? console_flush_all (./include/linux/rcupdate.h:336 ./include/linux/srcu.h:319 kernel/printk/printk.c:288 kernel/printk/printk.c:3203)
[ 16.284928] console_unlock (kernel/printk/printk.c:3285 kernel/printk/printk.c:3325)
[ 16.284930] wake_up_klogd_work_func (kernel/printk/printk.c:4529)
[ 16.284931] irq_work_run_list (kernel/irq_work.c:222 kernel/irq_work.c:252)
[ 16.284933] update_process_times (kernel/time/timer.c:2478)
[ 16.284935] tick_nohz_handler (kernel/time/tick-sched.c:187 kernel/time/tick-sched.c:306)
[ 16.284936] ? tick_setup_sched_timer (kernel/time/tick-sched.c:285)
[ 16.284938] __hrtimer_run_queues (kernel/time/hrtimer.c:1761 kernel/time/hrtimer.c:1825)
[ 16.284940] hrtimer_interrupt (kernel/time/hrtimer.c:1890)
[ 16.284942] __sysvec_apic_timer_interrupt (./arch/x86/include/asm/jump_label.h:36 ./arch/x86/include/asm/trace/irq_vectors.h:40 arch/x86/kernel/apic/apic.c:1057)
[ 16.284943] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1050 arch/x86/kernel/apic/apic.c:1050)
[ 16.284945] </IRQ>
[ 16.284946] <TASK>
[ 16.284947] asm_sysvec_apic_timer_interrupt (./arch/x86/include/asm/idtentry.h:702)
[ 16.284948] RIP: 0010:pv_native_safe_halt (arch/x86/kernel/paravirt.c:82)
[ 16.284950] Code: bd 54 01 e8 2f 00 00 00 48 2b 05 a0 8b 57 00 c3 cc cc cc cc cc cc cc f3 0f 1e fa eb 07 0f 00 2d 0d f3 05 00 f3 0f 1e fa fb f4 <c3> cc cc cc cc cc cc cc cc cc cc cc cc 66 0f 1f 00 50 8b 37 83 e6
All code
========
0: bd 54 01 e8 2f mov $0x2fe80154,%ebp
5: 00 00 add %al,(%rax)
7: 00 48 2b add %cl,0x2b(%rax)
a: 05 a0 8b 57 00 add $0x578ba0,%eax
f: c3 ret
10: cc int3
11: cc int3
12: cc int3
13: cc int3
14: cc int3
15: cc int3
16: cc int3
17: f3 0f 1e fa endbr64
1b: eb 07 jmp 0x24
1d: 0f 00 2d 0d f3 05 00 verw 0x5f30d(%rip) # 0x5f331
24: f3 0f 1e fa endbr64
28: fb sti
29: f4 hlt
2a:* c3 ret <-- trapping instruction
2b: cc int3
2c: cc int3
2d: cc int3
2e: cc int3
2f: cc int3
30: cc int3
31: cc int3
32: cc int3
33: cc int3
34: cc int3
35: cc int3
36: cc int3
37: 66 0f 1f 00 nopw (%rax)
3b: 50 push %rax
3c: 8b 37 mov (%rdi),%esi
3e: 83 .byte 0x83
3f: e6 .byte 0xe6
Code starting with the faulting instruction
===========================================
0: c3 ret
1: cc int3
2: cc int3
3: cc int3
4: cc int3
5: cc int3
6: cc int3
7: cc int3
8: cc int3
9: cc int3
a: cc int3
b: cc int3
c: cc int3
d: 66 0f 1f 00 nopw (%rax)
11: 50 push %rax
12: 8b 37 mov (%rdi),%esi
14: 83 .byte 0x83
15: e6 .byte 0xe6
[ 16.284952] RSP: 0018:ffa000000012bed8 EFLAGS: 00000282
[ 16.284953] RAX: af64f61648e76300 RBX: ffffffff813cd1f0 RCX: 4000000000000000
[ 16.284954] RDX: 0000000000000001 RSI: ffffffff81fd2a36 RDI: ffffffff813cd1f0
[ 16.284955] RBP: ffa000000012bef8 R08: 0000000000060000 R09: 0000000000000001
[ 16.284956] R10: 0000000000000001 R11: 00000000fffeff01 R12: 0000000000000000
[ 16.284956] R13: 0000000000000000 R14: 0000000000000010 R15: 0000000000000000
[ 16.284958] ? do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284959] ? default_idle_call (./include/linux/cpuidle.h:132 kernel/sched/idle.c:121)
[ 16.284960] ? do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284962] ? do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284962] default_idle (./arch/x86/include/asm/paravirt.h:107 arch/x86/kernel/process.c:757)
[ 16.284964] default_idle_call (./include/linux/cpuidle.h:143 kernel/sched/idle.c:123)
[ 16.284965] do_idle (kernel/sched/idle.c:191 kernel/sched/idle.c:330)
[ 16.284967] cpu_startup_entry (kernel/sched/idle.c:427)
[ 16.284968] start_secondary (arch/x86/kernel/smpboot.c:315)
[ 16.284969] common_startup_64 (arch/x86/kernel/head_64.S:419)
[ 16.284972] </TASK>
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-18 12:10 ` Breno Leitao
@ 2025-08-19 17:27 ` Breno Leitao
2025-08-20 12:31 ` Mike Galbraith
0 siblings, 1 reply; 27+ messages in thread
From: Breno Leitao @ 2025-08-19 17:27 UTC (permalink / raw)
To: Pavel Begunkov
Cc: Jakub Kicinski, Johannes Berg, Mike Galbraith, paulmck, LKML,
netdev, boqun.feng
On Mon, Aug 18, 2025 at 05:10:24AM -0700, Breno Leitao wrote:
> On Fri, Aug 15, 2025 at 09:02:27PM +0100, Pavel Begunkov wrote:
> > On 8/15/25 18:29, Breno Leitao wrote:
> > > On Fri, Aug 15, 2025 at 09:42:17AM -0700, Jakub Kicinski wrote:
> > > > On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > > > > On 8/15/25 01:23, Jakub Kicinski wrote:
> > > >
> > > > I suspect disabling netconsole over WiFi may be the most sensible way out.
> > >
> > > I believe we might be facing a similar issue with virtio-net.
> > > Specifically, any network adapter where TX is not safe to use in IRQ
> > > context encounters this problem.
> > >
> > > If we want to keep netconsole enabled on all TX paths, a possible
> > > solution is to defer the transmission work when netconsole is called
> > > inside an IRQ.
> > >
> > > The idea is that netconsole first checks if it is running in an IRQ
> > > context using in_irq(). If so, it queues the skb without transmitting it
> > > immediately and schedules deferred work to handle the transmission
> > > later.
> > >
> > > A rough implementation could be:
> > >
> > > static void send_udp(struct netconsole_target *nt, const char *msg, int len) {
> > >
> > > /* get the SKB that is already populated, with all the headers
> > > * and ready to be sent
> > > */
> > > struct sk_buff = netpoll_get_skb(&nt->np, msg, len);
> > >
> > > if (in_irq()) {
> >
> > It's not just irq handlers but any context that has irqs disabled, and
> > since it's nested under irq-safe console_owner it'd need to always be
> > deferred or somehow moved out of the console_owner critical section.
>
> Agree. An IRQ-unsafe lock (fq lock) should not be reachable from an IRQ
> disabled code path. So, one solution might be to always send TX packets
> from a workqueue (unless it is on panic, as suggested by Calvin).
I’ve continued investigating possible solutions, and it looks like
moving netconsole over to the non‑blocking console (nbcon) framework
might be the right approach. Unlike the classic console path, nbcon
doesn’t rely on the global console lock, which was one of the main
concerns regarding the possible deadlock.
Migrating netconsole to nbcon was already on my TODO list, since nbcon
is the modern infrastructure, but this issue accelerated that
transition. I’ve put together a PoC, and so far I haven’t seen any
lockdep warnings — even when explicitly triggering printk() from
different contexts.
The new path is protected by NETCONSOLE_NBCON, which is disabled by
default. This allows us to experiment and test both approaches.
commit 9180c12086954d30b23ec2b4bbb7859aa1192aca
Author: Breno Leitao <leitao@debian.org>
Date: Tue Aug 19 04:14:58 2025 -0700
netconsole: Add support for nbcon
Add support for running netconsole using the new non‑blocking console
(nbcon) infrastructure.
The nbcon framework improves console handling by avoiding the global
console lock and enabling asynchronous, non‑blocking writes from
multiple contexts.
Key changes:
* Introduce CONFIG_NETCONSOLE_NBCON (EXPERIMENTAL, depends on
NETCONSOLE_EXTENDED_LOG && EXPERT) to enable nbcon mode.
* Split out do_write_msg() for chunked send logic, re‑used in both
sync and nbcon paths.
* Add .write_thread callbacks for normal and extended netconsole when
nbcon is enabled.
* Provide device_lock/unlock helpers wrapping target_list_lock for
safe nbcon integration.
* Keep existing synchronous .write paths as the default when nbcon
support is disabled, preserving backward compatibility.
With this option enabled, netconsole can operate as a fully
asynchronous, lockless nbcon backend, not depending on console lock
anymore.
This support is marked experimental for now until it receives wider
testing.
This patch doesn't implement optional .write_atomic callbacks,
I initially implemented it to deferred the skbs, but, later I found that
even printks() from inside IRQs are sent using the .write_thread()
callback. Reading the code, I got the impression that .write_atomic
callback is only called from an atomic context and there is a write in
opertion, which might get interrupted (?). More on this soon.
Signed-off-by: Breno Leitao <leitao@debian.org>
diff --git a/drivers/net/Kconfig b/drivers/net/Kconfig
index b29628d46be9b..ec9a430aa160e 100644
--- a/drivers/net/Kconfig
+++ b/drivers/net/Kconfig
@@ -382,6 +382,16 @@ config NETCONSOLE_PREPEND_RELEASE
message. See <file:Documentation/networking/netconsole.rst> for
details.
+config NETCONSOLE_NBCON
+ bool "Enable non blocking netconsole (EXPERIMENTAL)"
+ depends on NETCONSOLE
+ default n
+ help
+ Move netconsole to use non-blocking console (nbcons). Non-blocking
+ console (nbcon) is a new console infrastructure introduced to improve
+ console handling by avoiding the global console lock (Big Kernel
+ Lock) and enabling non-blocking, asynchronous writes to the console.
+
config NETPOLL
def_bool NETCONSOLE
diff --git a/drivers/net/netconsole.c b/drivers/net/netconsole.c
index e3722de08ea9f..5cd279e09fc8b 100644
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -1708,12 +1708,30 @@ static void write_ext_msg(struct console *con, const char *msg,
spin_unlock_irqrestore(&target_list_lock, flags);
}
-static void write_msg(struct console *con, const char *msg, unsigned int len)
+static void do_write_msg(struct netconsole_target *nt, const char *msg, unsigned int len)
{
+ const char *tmp;
int frag, left;
+
+ /*
+ * We nest this inside the for-each-target loop above
+ * so that we're able to get as much logging out to
+ * at least one target if we die inside here, instead
+ * of unnecessarily keeping all targets in lock-step.
+ */
+ tmp = msg;
+ for (left = len; left;) {
+ frag = min(left, MAX_PRINT_CHUNK);
+ send_udp(nt, tmp, frag);
+ tmp += frag;
+ left -= frag;
+ }
+}
+
+static void write_msg(struct console *con, const char *msg, unsigned int len)
+{
unsigned long flags;
struct netconsole_target *nt;
- const char *tmp;
if (oops_only && !oops_in_progress)
return;
@@ -1723,21 +1741,8 @@ static void write_msg(struct console *con, const char *msg, unsigned int len)
spin_lock_irqsave(&target_list_lock, flags);
list_for_each_entry(nt, &target_list, list) {
- if (!nt->extended && nt->enabled && netif_running(nt->np.dev)) {
- /*
- * We nest this inside the for-each-target loop above
- * so that we're able to get as much logging out to
- * at least one target if we die inside here, instead
- * of unnecessarily keeping all targets in lock-step.
- */
- tmp = msg;
- for (left = len; left;) {
- frag = min(left, MAX_PRINT_CHUNK);
- send_udp(nt, tmp, frag);
- tmp += frag;
- left -= frag;
- }
- }
+ if (!nt->extended && nt->enabled && netif_running(nt->np.dev))
+ do_write_msg(nt, msg, len);
}
spin_unlock_irqrestore(&target_list_lock, flags);
}
@@ -1917,16 +1922,69 @@ static void free_param_target(struct netconsole_target *nt)
kfree(nt);
}
+#ifdef CONFIG_NETCONSOLE_NBCON
+static void netcon_write_ext_thread(struct console *con, struct nbcon_write_context *wctxt)
+{
+ struct netconsole_target *nt;
+
+ list_for_each_entry(nt, &target_list, list)
+ if (nt->extended && nt->enabled && netif_running(nt->np.dev)) {
+ if (!nbcon_enter_unsafe(wctxt))
+ continue;
+ send_ext_msg_udp(nt, wctxt->outbuf, wctxt->len);
+ nbcon_exit_unsafe(wctxt);
+ }
+}
+
+static void netcon_write_thread(struct console *con, struct nbcon_write_context *wctxt)
+{
+ struct netconsole_target *nt;
+
+ list_for_each_entry(nt, &target_list, list)
+ if (!nt->extended && nt->enabled && netif_running(nt->np.dev)) {
+ if (!nbcon_enter_unsafe(wctxt))
+ continue;
+ do_write_msg(nt, wctxt->outbuf, wctxt->len);
+ nbcon_exit_unsafe(wctxt);
+ }
+}
+
+static void netconsole_device_lock(struct console *con, unsigned long *flags)
+{
+ /* protects all the targets at the same time */
+ spin_lock_irqsave(&target_list_lock, *flags);
+}
+
+static void netconsole_device_unlock(struct console *con, unsigned long flags)
+{
+ spin_unlock_irqrestore(&target_list_lock, flags);
+}
+#endif
+
static struct console netconsole_ext = {
.name = "netcon_ext",
+#ifdef CONFIG_NETCONSOLE_NBCON
+ .flags = CON_ENABLED | CON_EXTENDED | CON_NBCON,
+ .write_thread = netcon_write_ext_thread,
+ .device_lock = netconsole_device_lock,
+ .device_unlock = netconsole_device_unlock,
+#else
.flags = CON_ENABLED | CON_EXTENDED,
.write = write_ext_msg,
+#endif
};
static struct console netconsole = {
.name = "netcon",
+#ifdef CONFIG_NETCONSOLE_NBCON
+ .flags = CON_ENABLED | CON_NBCON,
+ .write_thread = netcon_write_thread,
+ .device_lock = netconsole_device_lock,
+ .device_unlock = netconsole_device_unlock,
+#else
.flags = CON_ENABLED,
.write = write_msg,
+#endif
};
static int __init init_netconsole(void)
^ permalink raw reply related [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-19 17:27 ` Breno Leitao
@ 2025-08-20 12:31 ` Mike Galbraith
2025-08-20 17:36 ` Breno Leitao
0 siblings, 1 reply; 27+ messages in thread
From: Mike Galbraith @ 2025-08-20 12:31 UTC (permalink / raw)
To: Breno Leitao, Pavel Begunkov
Cc: Jakub Kicinski, Johannes Berg, paulmck, LKML, netdev, boqun.feng
On Tue, 2025-08-19 at 10:27 -0700, Breno Leitao wrote:
>
> I’ve continued investigating possible solutions, and it looks like
> moving netconsole over to the non‑blocking console (nbcon) framework
> might be the right approach. Unlike the classic console path, nbcon
> doesn’t rely on the global console lock, which was one of the main
> concerns regarding the possible deadlock.
ATM at least, classic can remotely log a crash whereas nbcon can't per
test drive, so it would be nice for classic to stick around until nbcon
learns some atomic packet blasting.
> The new path is protected by NETCONSOLE_NBCON, which is disabled by
> default. This allows us to experiment and test both approaches.
As patch sits, interrupts being disabled is still a problem, gripes
below. Not disabling IRQs makes nbcon gripe free, but creates the
issue of netpoll_tx_running() lying to the rest of NETPOLL consumers.
RT and the wireless stack have in common that IRQs being disabled in
netpoll.c sucks rocks for them. I've been carrying a hack to allow RT
to use netconsole since 5.15, and adapted it to squelch nbcons inspired
gripes as well (had to whack irqsave/restore in your patch as well).
Once the dust settles, perhaps RT can simply select NETCONSOLE_NBCON to
solve its netconsole woes for free.
[ 99.875439] netconsole: network logging started
[ 99.876652] ------------[ cut here ]------------
[ 99.876922] WARNING: CPU: 3 PID: 4396 at kernel/softirq.c:387 __local_bh_enable_ip+0x8f/0xe0
[ 99.877007] Modules linked in: netconsole ccm af_packet bridge stp llc iscsi_ibft iscsi_boot_sysfs cmac algif_hash algif_skcipher af_alg iwlmvm intel_rapl_msr intel_rapl_common mac80211 snd_hda_codec_hdmi binfmt_misc x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_conexant snd_hda_codec_generic coretemp libarc4 kvm_intel uvcvideo snd_hda_intel snd_intel_dspcfg uvc snd_hda_codec videobuf2_vmalloc videobuf2_memops snd_hwdep mei_hdcp iwlwifi kvm iTCO_wdt btusb snd_hda_core videobuf2_v4l2 intel_pmc_bxt btrtl videobuf2_common btbcm snd_pcm iTCO_vendor_support mfd_core btintel nls_iso8859_1 videodev nls_cp437 snd_timer cfg80211 irqbypass mc snd bluetooth mei_me i2c_i801 pcspkr rfkill i2c_smbus soundcore mei thermal battery joydev button acpi_pad ac sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit ghash_clmulni_intel drm_buddy drm_client_lib drm_display_helper xhci_pci drm_kms_helper xhci_hcd ahci ttm libahci video drm wmi libata
[ 99.877440] usbcore usb_common serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel gf128mul
[ 99.878391] CPU: 3 UID: 0 PID: 4396 Comm: pr/netcon0 Kdump: loaded Tainted: G I 6.17.0.gb19a97d5-master #220 PREEMPT(lazy)
[ 99.878492] Tainted: [I]=FIRMWARE_WORKAROUND
[ 99.878529] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 99.878588] RIP: 0010:__local_bh_enable_ip+0x8f/0xe0
[ 99.878639] Code: 3e bf 01 00 00 00 e8 f0 68 03 00 e8 3b 75 14 00 fb 65 8b 05 ab 6f 9b 01 85 c0 74 41 5b 5d c3 65 8b 05 a1 a8 9b 01 85 c0 75 a4 <0f> 0b eb a0 e8 68 74 14 00 eb a1 48 89 ef e8 de c0 07 00 eb aa 48
[ 99.878774] RSP: 0018:ffff8881051abac8 EFLAGS: 00010046
[ 99.878823] RAX: 0000000000000000 RBX: 0000000000000201 RCX: ffff8881051aba84
[ 99.878881] RDX: 0000000000000001 RSI: 0000000000000201 RDI: ffffffffa137b870
[ 99.878937] RBP: ffffffffa137b870 R08: 0000000000000008 R09: ffffffff832b3620
[ 99.878993] R10: 0000000000000001 R11: 000000000000240f R12: ffff8881037c2168
[ 99.879049] R13: ffff888102bc0f00 R14: ffff8881037c2000 R15: ffff888102bc0f20
[ 99.879105] FS: 0000000000000000(0000) GS:ffff888261310000(0000) knlGS:0000000000000000
[ 99.879217] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 99.879307] CR2: 00007f6f8ca7c4c0 CR3: 0000000004e4e003 CR4: 00000000003726f0
[ 99.879418] Call Trace:
[ 99.879466] <TASK>
[ 99.879522] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.879752] __ieee80211_xmit_fast+0x217/0x3a0 [mac80211]
[ 99.879962] ? __skb_get_hash_net+0x47/0x1c0
[ 99.880009] ? __skb_get_hash_net+0x47/0x1c0
[ 99.880075] ieee80211_xmit_fast+0xee/0x1e0 [mac80211]
[ 99.880265] __ieee80211_subif_start_xmit+0x141/0x390 [mac80211]
[ 99.880464] ieee80211_subif_start_xmit+0x39/0x200 [mac80211]
[ 99.880629] ? lock_acquire.part.0+0x94/0x1e0
[ 99.880681] ? lock_acquire.part.0+0xa4/0x1e0
[ 99.880736] ? netif_skb_features+0xb6/0x2b0
[ 99.880784] netpoll_start_xmit+0x125/0x1a0
[ 99.880839] __netpoll_send_skb+0x329/0x3b0
[ 99.880897] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 99.881015] nbcon_emit_next_record+0x239/0x290
[ 99.881123] ? nbcon_kthread_func+0x24/0x210
[ 99.881190] nbcon_emit_one+0x83/0xd0
[ 99.881265] nbcon_kthread_func+0x150/0x210
[ 99.881371] ? nbcon_device_release+0x110/0x110
[ 99.881458] kthread+0x139/0x220
[ 99.881525] ? _raw_spin_unlock_irq+0x28/0x50
[ 99.881601] ? kthreads_online_cpu+0xf0/0xf0
[ 99.881695] ret_from_fork+0x213/0x270
[ 99.881765] ? kthreads_online_cpu+0xf0/0xf0
[ 99.881852] ret_from_fork_asm+0x11/0x20
[ 99.881994] </TASK>
[ 99.882038] irq event stamp: 63
[ 99.882094] hardirqs last enabled at (61): [<ffffffff8130a198>] finish_task_switch.isra.0+0xb8/0x290
[ 99.882220] hardirqs last disabled at (62): [<ffffffff81cfccf3>] _raw_spin_lock_irqsave+0x53/0x60
[ 99.882343] softirqs last enabled at (0): [<ffffffff812c4d0b>] copy_process+0x81b/0x1930
[ 99.882455] softirqs last disabled at (63): [<ffffffffa137b82d>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 99.882789] ---[ end trace 0000000000000000 ]---
[ 99.882929]
[ 99.882948] ================================
[ 99.882972] WARNING: inconsistent lock state
[ 99.882996] 6.17.0.gb19a97d5-master #220 Tainted: G W I
[ 99.883028] --------------------------------
[ 99.883051] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage.
[ 99.883081] pr/netcon0/4396 [HC0[0]:SC0[0]:HE0:SE1] takes:
[ 99.883117] ffff8881225d3118 (_xmit_ETHER#2){+.?.}-{3:3}, at: __netpoll_send_skb+0x2e0/0x3b0
[ 99.883207] {IN-SOFTIRQ-W} state was registered at:
[ 99.883233] __lock_acquire+0x3d6/0xbc0
[ 99.883266] lock_acquire.part.0+0x94/0x1e0
[ 99.883297] _raw_spin_lock+0x33/0x40
[ 99.883326] __dev_queue_xmit+0x7d2/0xbf0
[ 99.883358] ip_finish_output2+0x1f7/0x7f0
[ 99.883390] ip_output+0xa6/0x3a0
[ 99.883419] igmp_ifc_timer_expire+0x21/0xf0
[ 99.883449] call_timer_fn+0x98/0x230
[ 99.883480] __run_timers+0x1dc/0x2a0
[ 99.883511] run_timer_base+0x46/0x60
[ 99.883542] run_timer_softirq+0x1a/0x30
[ 99.883574] handle_softirqs+0xdb/0x3f0
[ 99.883608] __irq_exit_rcu+0xc1/0x130
[ 99.883641] irq_exit_rcu+0xe/0x30
[ 99.883666] sysvec_apic_timer_interrupt+0xa1/0xd0
[ 99.883701] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 99.883732] cpuidle_enter_state+0x10d/0x530
[ 99.883767] cpuidle_enter+0x2d/0x40
[ 99.883799] cpuidle_idle_call+0xfd/0x1a0
[ 99.883831] do_idle+0x83/0xc0
[ 99.883858] cpu_startup_entry+0x29/0x30
[ 99.883889] start_secondary+0xf3/0x110
[ 99.883917] common_startup_64+0x13e/0x148
[ 99.883950] irq event stamp: 64
[ 99.883971] hardirqs last enabled at (61): [<ffffffff8130a198>] finish_task_switch.isra.0+0xb8/0x290
[ 99.884013] hardirqs last disabled at (62): [<ffffffff81cfccf3>] _raw_spin_lock_irqsave+0x53/0x60
[ 99.884056] softirqs last enabled at (64): [<ffffffffa137b870>] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.884310] softirqs last disabled at (63): [<ffffffffa137b82d>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 99.884540]
[ 99.884540] other info that might help us debug this:
[ 99.884576] Possible unsafe locking scenario:
[ 99.884576]
[ 99.884611] CPU0
[ 99.884629] ----
[ 99.884647] lock(_xmit_ETHER#2);
[ 99.884679] <Interrupt>
[ 99.884698] lock(_xmit_ETHER#2);
[ 99.884728]
[ 99.884728] *** DEADLOCK ***
[ 99.884728]
[ 99.884768] 5 locks held by pr/netcon0/4396:
[ 99.884795] #0: ffffffff8255a030 (console_srcu){....}-{0:0}, at: console_srcu_read_lock+0x49/0x60
[ 99.884859] #1: ffffffffa16e3ab8 (target_list_lock){+.+.}-{3:3}, at: netconsole_device_lock+0x19/0x20 [netconsole]
[ 99.884925] #2: ffffffff8255cb80 (rcu_read_lock){....}-{1:3}, at: __netpoll_send_skb+0x4a/0x3b0
[ 99.884987] #3: ffff8881225d3118 (_xmit_ETHER#2){+.?.}-{3:3}, at: __netpoll_send_skb+0x2e0/0x3b0
[ 99.885052] #4: ffffffff8255cb80 (rcu_read_lock){....}-{1:3}, at: __ieee80211_subif_start_xmit+0xa5/0x390 [mac80211]
[ 99.885319]
[ 99.885319] stack backtrace:
[ 99.885354] CPU: 3 UID: 0 PID: 4396 Comm: pr/netcon0 Kdump: loaded Tainted: G W I 6.17.0.gb19a97d5-master #220 PREEMPT(lazy)
[ 99.885372] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 99.885375] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 99.885380] Call Trace:
[ 99.885385] <TASK>
[ 99.885394] dump_stack_lvl+0x5b/0x80
[ 99.885413] print_usage_bug.part.0+0x22c/0x2c0
[ 99.885431] mark_lock_irq+0x399/0x580
[ 99.885446] ? stack_trace_save+0x3e/0x50
[ 99.885458] ? save_trace+0xbe/0x170
[ 99.885476] mark_lock+0x1b7/0x3c0
[ 99.885491] mark_held_locks+0x40/0x70
[ 99.885504] ? ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.885708] lockdep_hardirqs_on_prepare.part.0+0xaf/0x160
[ 99.885730] trace_hardirqs_on+0x44/0xc0
[ 99.885743] __local_bh_enable_ip+0x75/0xe0
[ 99.885768] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.886068] __ieee80211_xmit_fast+0x217/0x3a0 [mac80211]
[ 99.886278] ? __skb_get_hash_net+0x47/0x1c0
[ 99.886292] ? __skb_get_hash_net+0x47/0x1c0
[ 99.886312] ieee80211_xmit_fast+0xee/0x1e0 [mac80211]
[ 99.886512] __ieee80211_subif_start_xmit+0x141/0x390 [mac80211]
[ 99.886713] ieee80211_subif_start_xmit+0x39/0x200 [mac80211]
[ 99.886899] ? lock_acquire.part.0+0x94/0x1e0
[ 99.886915] ? lock_acquire.part.0+0xa4/0x1e0
[ 99.886931] ? netif_skb_features+0xb6/0x2b0
[ 99.886945] netpoll_start_xmit+0x125/0x1a0
[ 99.886964] __netpoll_send_skb+0x329/0x3b0
[ 99.886984] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 99.887005] nbcon_emit_next_record+0x239/0x290
[ 99.887029] ? nbcon_kthread_func+0x24/0x210
[ 99.887040] nbcon_emit_one+0x83/0xd0
[ 99.887055] nbcon_kthread_func+0x150/0x210
[ 99.887077] ? nbcon_device_release+0x110/0x110
[ 99.887090] kthread+0x139/0x220
[ 99.887105] ? _raw_spin_unlock_irq+0x28/0x50
[ 99.887119] ? kthreads_online_cpu+0xf0/0xf0
[ 99.887145] ret_from_fork+0x213/0x270
[ 99.887162] ? kthreads_online_cpu+0xf0/0xf0
[ 99.887181] ret_from_fork_asm+0x11/0x20
[ 99.887214] </TASK>
[ 99.888658] ------------[ cut here ]------------
[ 99.888709] WARNING: CPU: 3 PID: 4396 at net/mac80211/tx.c:3814 ieee80211_tx_dequeue+0x6f6/0x7b0 [mac80211]
[ 99.889145] Modules linked in: netconsole ccm af_packet bridge stp llc iscsi_ibft iscsi_boot_sysfs cmac algif_hash algif_skcipher af_alg iwlmvm intel_rapl_msr intel_rapl_common mac80211 snd_hda_codec_hdmi binfmt_misc x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_conexant snd_hda_codec_generic coretemp libarc4 kvm_intel uvcvideo snd_hda_intel snd_intel_dspcfg uvc snd_hda_codec videobuf2_vmalloc videobuf2_memops snd_hwdep mei_hdcp iwlwifi kvm iTCO_wdt btusb snd_hda_core videobuf2_v4l2 intel_pmc_bxt btrtl videobuf2_common btbcm snd_pcm iTCO_vendor_support mfd_core btintel nls_iso8859_1 videodev nls_cp437 snd_timer cfg80211 irqbypass mc snd bluetooth mei_me i2c_i801 pcspkr rfkill i2c_smbus soundcore mei thermal battery joydev button acpi_pad ac sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit ghash_clmulni_intel drm_buddy drm_client_lib drm_display_helper xhci_pci drm_kms_helper xhci_hcd ahci ttm libahci video drm wmi libata
[ 99.889869] usbcore usb_common serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel gf128mul
[ 99.890607] CPU: 3 UID: 0 PID: 4396 Comm: pr/netcon0 Kdump: loaded Tainted: G W I 6.17.0.gb19a97d5-master #220 PREEMPT(lazy)
[ 99.890707] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 99.890750] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 99.890807] RIP: 0010:ieee80211_tx_dequeue+0x6f6/0x7b0 [mac80211]
[ 99.891278] Code: 84 16 fc ff ff 48 8b 44 24 20 48 8b bc 24 a0 00 00 00 31 d2 48 8d 70 0a e8 47 61 ff ff 84 c0 0f 85 9d fa ff ff e9 f1 fb ff ff <0f> 0b e9 48 f9 ff ff e8 4e b4 fe df 85 c0 0f 85 b2 fb ff ff e8 91
[ 99.891392] RSP: 0018:ffff8881051ab9b0 EFLAGS: 00010246
[ 99.891453] RAX: 0000000000000002 RBX: ffff88810ee7a8a0 RCX: 0000000000000002
[ 99.891513] RDX: ffffffffa1808a49 RSI: ffff8881037c2168 RDI: ffff888102bc0e40
[ 99.891574] RBP: ffff8881037c2168 R08: 0000000000000000 R09: 0000000000000000
[ 99.891633] R10: ffffffffa1808a49 R11: 0000000000000002 R12: 0000000000000002
[ 99.891688] R13: ffff8881037c2000 R14: ffff888102bc0e40 R15: ffff888102bc3088
[ 99.891747] FS: 0000000000000000(0000) GS:ffff888261310000(0000) knlGS:0000000000000000
[ 99.891815] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 99.891867] CR2: 00007f6f8ca7c4c0 CR3: 0000000004e4e003 CR4: 00000000003726f0
[ 99.891926] Call Trace:
[ 99.891963] <TASK>
[ 99.892006] ? rcu_is_watching+0x11/0x40
[ 99.892072] ? rcu_is_watching+0x11/0x40
[ 99.892129] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 99.892194] ? rcu_is_watching+0x11/0x40
[ 99.892248] ? lock_acquire+0xee/0x130
[ 99.892300] ? iwl_mvm_mac_itxq_xmit+0x59/0x1f0 [iwlmvm]
[ 99.892545] iwl_mvm_mac_itxq_xmit+0xb3/0x1f0 [iwlmvm]
[ 99.892747] ieee80211_queue_skb+0x21b/0x350 [mac80211]
[ 99.893200] __ieee80211_xmit_fast+0x217/0x3a0 [mac80211]
[ 99.893657] ? __skb_get_hash_net+0x47/0x1c0
[ 99.893719] ? __skb_get_hash_net+0x47/0x1c0
[ 99.893792] ieee80211_xmit_fast+0xee/0x1e0 [mac80211]
[ 99.894230] __ieee80211_subif_start_xmit+0x141/0x390 [mac80211]
[ 99.894650] ieee80211_subif_start_xmit+0x39/0x200 [mac80211]
[ 99.895057] ? lock_acquire.part.0+0x94/0x1e0
[ 99.895157] ? lock_acquire.part.0+0xa4/0x1e0
[ 99.895224] ? netif_skb_features+0xb6/0x2b0
[ 99.895284] netpoll_start_xmit+0x125/0x1a0
[ 99.895349] __netpoll_send_skb+0x329/0x3b0
[ 99.895416] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 99.895490] nbcon_emit_next_record+0x239/0x290
[ 99.895564] ? nbcon_kthread_func+0x24/0x210
[ 99.895617] nbcon_emit_one+0x83/0xd0
[ 99.895674] nbcon_kthread_func+0x150/0x210
[ 99.895742] ? nbcon_device_release+0x110/0x110
[ 99.895798] kthread+0x139/0x220
[ 99.895849] ? _raw_spin_unlock_irq+0x28/0x50
[ 99.895903] ? kthreads_online_cpu+0xf0/0xf0
[ 99.895965] ret_from_fork+0x213/0x270
[ 99.896019] ? kthreads_online_cpu+0xf0/0xf0
[ 99.896081] ret_from_fork_asm+0x11/0x20
[ 99.896179] </TASK>
[ 99.896212] irq event stamp: 64
[ 99.896248] hardirqs last enabled at (61): [<ffffffff8130a198>] finish_task_switch.isra.0+0xb8/0x290
[ 99.896326] hardirqs last disabled at (62): [<ffffffff81cfccf3>] _raw_spin_lock_irqsave+0x53/0x60
[ 99.896403] softirqs last enabled at (64): [<ffffffffa137b870>] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.896859] softirqs last disabled at (63): [<ffffffffa137b82d>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 99.897285] ---[ end trace 0000000000000000 ]---
[ 99.897458] ------------[ cut here ]------------
[ 99.897508] netpoll_send_skb_on_dev(): wlan0 enabled interrupts in poll (ieee80211_subif_start_xmit+0x0/0x200 [mac80211])
[ 99.898032] WARNING: CPU: 3 PID: 4396 at net/core/netpoll.c:359 __netpoll_send_skb+0x382/0x3b0
[ 99.898133] Modules linked in: netconsole ccm af_packet bridge stp llc iscsi_ibft iscsi_boot_sysfs cmac algif_hash algif_skcipher af_alg iwlmvm intel_rapl_msr intel_rapl_common mac80211 snd_hda_codec_hdmi binfmt_misc x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_conexant snd_hda_codec_generic coretemp libarc4 kvm_intel uvcvideo snd_hda_intel snd_intel_dspcfg uvc snd_hda_codec videobuf2_vmalloc videobuf2_memops snd_hwdep mei_hdcp iwlwifi kvm iTCO_wdt btusb snd_hda_core videobuf2_v4l2 intel_pmc_bxt btrtl videobuf2_common btbcm snd_pcm iTCO_vendor_support mfd_core btintel nls_iso8859_1 videodev nls_cp437 snd_timer cfg80211 irqbypass mc snd bluetooth mei_me i2c_i801 pcspkr rfkill i2c_smbus soundcore mei thermal battery joydev button acpi_pad ac sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit ghash_clmulni_intel drm_buddy drm_client_lib drm_display_helper xhci_pci drm_kms_helper xhci_hcd ahci ttm libahci video drm wmi libata
[ 99.898853] usbcore usb_common serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel gf128mul
[ 99.899647] CPU: 3 UID: 0 PID: 4396 Comm: pr/netcon0 Kdump: loaded Tainted: G W I 6.17.0.gb19a97d5-master #220 PREEMPT(lazy)
[ 99.899762] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 99.899809] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 99.899868] RIP: 0010:__netpoll_send_skb+0x382/0x3b0
[ 99.899933] Code: 0f 85 65 ff ff ff 49 8b 44 24 08 49 8d b4 24 20 01 00 00 48 c7 c7 40 43 14 82 c6 05 ef 24 b8 00 01 48 8b 50 20 e8 de c3 7f ff <0f> 0b e9 3a ff ff ff 9c 58 f6 c4 02 0f 84 a5 fd ff ff 80 3d cd 24
[ 99.900049] RSP: 0018:ffff8881051abd68 EFLAGS: 00010292
[ 99.900105] RAX: 000000000000006d RBX: ffff888115403200 RCX: 0000000000000000
[ 99.900163] RDX: 0000000000000003 RSI: ffffffff82169464 RDI: 00000000ffffffff
[ 99.900222] RBP: ffff88811586d148 R08: 00000000ffffdfff R09: ffffffff82529e08
[ 99.900278] R10: ffffffff82479e60 R11: 5f6c6c6f7074656e R12: ffff88810ee78000
[ 99.900335] R13: ffff88813b78da00 R14: ffff8881225d3000 R15: 0000000000000000
[ 99.900392] FS: 0000000000000000(0000) GS:ffff888261310000(0000) knlGS:0000000000000000
[ 99.900456] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 99.900507] CR2: 00007f6f8ca7c4c0 CR3: 0000000004e4e003 CR4: 00000000003726f0
[ 99.900567] Call Trace:
[ 99.900604] <TASK>
[ 99.900655] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 99.900736] nbcon_emit_next_record+0x239/0x290
[ 99.900814] ? nbcon_kthread_func+0x24/0x210
[ 99.900869] nbcon_emit_one+0x83/0xd0
[ 99.900927] nbcon_kthread_func+0x150/0x210
[ 99.900999] ? nbcon_device_release+0x110/0x110
[ 99.901058] kthread+0x139/0x220
[ 99.901110] ? _raw_spin_unlock_irq+0x28/0x50
[ 99.901166] ? kthreads_online_cpu+0xf0/0xf0
[ 99.901229] ret_from_fork+0x213/0x270
[ 99.901282] ? kthreads_online_cpu+0xf0/0xf0
[ 99.901343] ret_from_fork_asm+0x11/0x20
[ 99.901436] </TASK>
[ 99.901472] irq event stamp: 64
[ 99.901508] hardirqs last enabled at (61): [<ffffffff8130a198>] finish_task_switch.isra.0+0xb8/0x290
[ 99.901588] hardirqs last disabled at (62): [<ffffffff81cfccf3>] _raw_spin_lock_irqsave+0x53/0x60
[ 99.901664] softirqs last enabled at (64): [<ffffffffa137b870>] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 99.902125] softirqs last disabled at (63): [<ffffffffa137b82d>] ieee80211_queue_skb+0xfd/0x350 [mac80211]
[ 99.902552] ---[ end trace 0000000000000000 ]---
[ 99.903332] ------------[ cut here ]------------
[ 99.903382] WARNING: CPU: 3 PID: 4396 at net/core/netpoll.c:505 netpoll_send_udp+0x3b3/0x3c0
[ 99.903469] Modules linked in: netconsole ccm af_packet bridge stp llc iscsi_ibft iscsi_boot_sysfs cmac algif_hash algif_skcipher af_alg iwlmvm intel_rapl_msr intel_rapl_common mac80211 snd_hda_codec_hdmi binfmt_misc x86_pkg_temp_thermal intel_powerclamp snd_hda_codec_conexant snd_hda_codec_generic coretemp libarc4 kvm_intel uvcvideo snd_hda_intel snd_intel_dspcfg uvc snd_hda_codec videobuf2_vmalloc videobuf2_memops snd_hwdep mei_hdcp iwlwifi kvm iTCO_wdt btusb snd_hda_core videobuf2_v4l2 intel_pmc_bxt btrtl videobuf2_common btbcm snd_pcm iTCO_vendor_support mfd_core btintel nls_iso8859_1 videodev nls_cp437 snd_timer cfg80211 irqbypass mc snd bluetooth mei_me i2c_i801 pcspkr rfkill i2c_smbus soundcore mei thermal battery joydev button acpi_pad ac sch_fq_codel nfsd auth_rpcgss nfs_acl lockd grace sunrpc fuse dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 i2c_algo_bit ghash_clmulni_intel drm_buddy drm_client_lib drm_display_helper xhci_pci drm_kms_helper xhci_hcd ahci ttm libahci video drm wmi libata
[ 99.904176] usbcore usb_common serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel gf128mul
[ 99.904880] CPU: 3 UID: 0 PID: 4396 Comm: pr/netcon0 Kdump: loaded Tainted: G W I 6.17.0.gb19a97d5-master #220 PREEMPT(lazy)
[ 99.904980] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 99.905024] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 99.905081] RIP: 0010:netpoll_send_udp+0x3b3/0x3c0
[ 99.905143] Code: 0c 13 71 10 48 8d 49 04 ff ca 75 f5 83 d6 00 89 f2 c1 ee 10 66 01 d6 83 d6 00 f7 d6 66 89 70 0a b8 08 00 00 00 e9 a4 fe ff ff <0f> 0b e9 75 fc ff ff 66 0f 1f 44 00 00 f3 0f 1e fa 0f 1f 44 00 00
[ 99.905261] RSP: 0018:ffff8881051abd58 EFLAGS: 00010202
[ 99.905320] RAX: 0000000000000292 RBX: ffff88811586d148 RCX: 0000000000000000
[ 99.905380] RDX: 0000000000000023 RSI: ffff88820897d3e8 RDI: ffff88811586d148
[ 99.905440] RBP: ffff8881051abd98 R08: ffffffffa168e9b0 R09: ffff888105cc8ea0
[ 99.905500] R10: ffffffffa137ef4d R11: 0000000000000000 R12: 0000000000000023
[ 99.905560] R13: 0000000000000023 R14: ffff88811586d148 R15: ffff88820897d3e8
[ 99.905622] FS: 0000000000000000(0000) GS:ffff888261310000(0000) knlGS:0000000000000000
[ 99.905689] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 99.905743] CR2: 00007f6f8ca7c4c0 CR3: 0000000004e4e003 CR4: 00000000003726f0
[ 99.905807] Call Trace:
[ 99.905844] <TASK>
[ 99.905882] ? __netpoll_send_skb+0xc9/0x3b0
[ 99.905965] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 99.906012] nbcon_emit_next_record+0x239/0x290
[ 99.906057] ? nbcon_kthread_func+0x24/0x210
[ 99.906089] nbcon_emit_one+0x83/0xd0
[ 99.906123] nbcon_kthread_func+0x150/0x210
[ 99.906165] ? nbcon_device_release+0x110/0x110
[ 99.906198] kthread+0x139/0x220
[ 99.906228] ? _raw_spin_unlock_irq+0x28/0x50
[ 99.906259] ? kthreads_online_cpu+0xf0/0xf0
[ 99.906291] ret_from_fork+0x213/0x270
[ 99.906320] ? kthreads_online_cpu+0xf0/0xf0
[ 99.906355] ret_from_fork_asm+0x11/0x20
[ 99.906405] </TASK>
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-20 12:31 ` Mike Galbraith
@ 2025-08-20 17:36 ` Breno Leitao
2025-08-21 3:37 ` Mike Galbraith
0 siblings, 1 reply; 27+ messages in thread
From: Breno Leitao @ 2025-08-20 17:36 UTC (permalink / raw)
To: Mike Galbraith
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Wed, Aug 20, 2025 at 02:31:02PM +0200, Mike Galbraith wrote:
> On Tue, 2025-08-19 at 10:27 -0700, Breno Leitao wrote:
> >
> > I’ve continued investigating possible solutions, and it looks like
> > moving netconsole over to the non‑blocking console (nbcon) framework
> > might be the right approach. Unlike the classic console path, nbcon
> > doesn’t rely on the global console lock, which was one of the main
> > concerns regarding the possible deadlock.
>
> ATM at least, classic can remotely log a crash whereas nbcon can't per
> test drive, so it would be nice for classic to stick around until nbcon
> learns some atomic packet blasting.
Oh, does it mean that during crash nbcon invokes `write_atomic` call
back, and because this patch doesn't implement it, it will not send
those pkts? Am I reading it correct?
> > The new path is protected by NETCONSOLE_NBCON, which is disabled by
> > default. This allows us to experiment and test both approaches.
>
> As patch sits, interrupts being disabled is still a problem, gripes
> below.
You mean that the IRQs are disabled at the acquire of target_list_lock?
If so, an option is to turn that list an RCU list ?!
> Not disabling IRQs makes nbcon gripe free, but creates the
> issue of netpoll_tx_running() lying to the rest of NETPOLL consumers.
>
> RT and the wireless stack have in common that IRQs being disabled in
> netpoll.c sucks rocks for them. I've been carrying a hack to allow RT
> to use netconsole since 5.15, and adapted it to squelch nbcons inspired
> gripes as well (had to whack irqsave/restore in your patch as well).
> Once the dust settles, perhaps RT can simply select NETCONSOLE_NBCON to
> solve its netconsole woes for free.
What is this patch you have?
Thanks
--breno
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-20 17:36 ` Breno Leitao
@ 2025-08-21 3:37 ` Mike Galbraith
2025-08-21 3:51 ` Mike Galbraith
2025-08-21 10:06 ` Mike Galbraith
0 siblings, 2 replies; 27+ messages in thread
From: Mike Galbraith @ 2025-08-21 3:37 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Wed, 2025-08-20 at 10:36 -0700, Breno Leitao wrote:
> On Wed, Aug 20, 2025 at 02:31:02PM +0200, Mike Galbraith wrote:
> > On Tue, 2025-08-19 at 10:27 -0700, Breno Leitao wrote:
> > >
> > > I’ve continued investigating possible solutions, and it looks like
> > > moving netconsole over to the non‑blocking console (nbcon) framework
> > > might be the right approach. Unlike the classic console path, nbcon
> > > doesn’t rely on the global console lock, which was one of the main
> > > concerns regarding the possible deadlock.
> >
> > ATM at least, classic can remotely log a crash whereas nbcon can't per
> > test drive, so it would be nice for classic to stick around until nbcon
> > learns some atomic packet blasting.
>
> Oh, does it mean that during crash nbcon invokes `write_atomic` call
> back, and because this patch doesn't implement it, it will not send
> those pkts? Am I reading it correct?
No, I'm just saying that the kernel's last gasp doesn't make it out of
the box with CONFIG_NETCONSOLE_NBCON=y as your patch sits.
It doesn't with my wireless or RT lockdep et al appeasement hackery
either, but I don't care deeply, as long as I can capture kernel spew
inspired by LTP and whatnot, I'm happy.. kdump logs most death rattles.
> > > The new path is protected by NETCONSOLE_NBCON, which is disabled by
> > > default. This allows us to experiment and test both approaches.
> >
> > As patch sits, interrupts being disabled is still a problem, gripes
> > below.
>
> You mean that the IRQs are disabled at the acquire of target_list_lock?
> If so, an option is to turn that list an RCU list ?!
Yeah. I switched to local_bh_disable(), but was originally using
rcu_read_lock_bh() for RT.
> > Not disabling IRQs makes nbcon gripe free, but creates the
> > issue of netpoll_tx_running() lying to the rest of NETPOLL consumers.
> >
> > RT and the wireless stack have in common that IRQs being disabled in
> > netpoll.c sucks rocks for them. I've been carrying a hack to allow RT
> > to use netconsole since 5.15
(hm, grepping my modest forest I see it's actually 4.10.. hohum)
> What is this patch you have?
Make boxen stop bitching at NETCONSOLE_NBCON version below.
netpoll: Make it RT friendly
PREEMPT_RT cannot alloc/free memory when not preemptible, making
disabling of IRQs across transmission an issue for RT.
Use local_bh_disable() to provide local exclusion for RT (via
softirq_ctrl.lock) for normal and fallback transmission paths
instead of disabling IRQs. Since zap_completion_queue() callers
ensure pointer stability, replace get_cpu_var() therein with
this_cpu_ptr() to keep it preemptible across kfree().
Disable a couple warnings for RT, and we're done.
v0.kinda-works -> v1:
remove get_cpu_var() from zap_completion_queue().
fix/test netpoll_tx_running() to work for RT/!RT.
fix/test xmit fallback path for RT.
(blessed by nobody, plz keep all shrapnel etc etc:)
Signed-off-by: Mike Galbraith <efault@gmx.de>
---
drivers/net/netconsole.c | 4 ++--
include/linux/netpoll.h | 4 +++-
net/core/netpoll.c | 47 ++++++++++++++++++++++++++++++++++++--
---------
3 files changed, 41 insertions(+), 14 deletions(-)
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
static void netconsole_device_lock(struct console *con, unsigned long
*flags)
{
/* protects all the targets at the same time */
- spin_lock_irqsave(&target_list_lock, *flags);
+ spin_lock(&target_list_lock);
}
static void netconsole_device_unlock(struct console *con, unsigned
long flags)
{
- spin_unlock_irqrestore(&target_list_lock, flags);
+ spin_unlock(&target_list_lock);
}
#endif
--- a/include/linux/netpoll.h
+++ b/include/linux/netpoll.h
@@ -100,9 +100,11 @@ static inline void netpoll_poll_unlock(v
smp_store_release(&napi->poll_owner, -1);
}
+DECLARE_PER_CPU(int, _netpoll_tx_running);
+
static inline bool netpoll_tx_running(struct net_device *dev)
{
- return irqs_disabled();
+ return this_cpu_read(_netpoll_tx_running);
}
#else
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -58,6 +58,29 @@ static void zap_completion_queue(void);
static unsigned int carrier_timeout = 4;
module_param(carrier_timeout, uint, 0644);
+DEFINE_PER_CPU(int, _netpoll_tx_running);
+EXPORT_PER_CPU_SYMBOL(_netpoll_tx_running);
+
+#define
netpoll_tx_begin(flags) \
+ do { \
+ if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
+ IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
+ local_bh_disable(); \
+ else \
+ local_irq_save(flags); \
+ this_cpu_write(_netpoll_tx_running,
1); \
+ } while (0)
+
+#define netpoll_tx_end(flags) \
+ do { \
+ this_cpu_write(_netpoll_tx_running,
0); \
+ if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
+ IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
+ local_bh_enable(); \
+ else \
+ local_irq_restore(flags); \
+ } while (0)
+
static netdev_tx_t netpoll_start_xmit(struct sk_buff *skb,
struct net_device *dev,
struct netdev_queue *txq)
@@ -90,7 +113,7 @@ static void queue_process(struct work_st
struct netpoll_info *npinfo =
container_of(work, struct netpoll_info, tx_work.work);
struct sk_buff *skb;
- unsigned long flags;
+ unsigned long __maybe_unused flags;
while ((skb = skb_dequeue(&npinfo->txq))) {
struct net_device *dev = skb->dev;
@@ -102,7 +125,7 @@ static void queue_process(struct work_st
continue;
}
- local_irq_save(flags);
+ netpoll_tx_begin(flags);
/* check if skb->queue_mapping is still valid */
q_index = skb_get_queue_mapping(skb);
if (unlikely(q_index >= dev->real_num_tx_queues)) {
@@ -115,13 +138,13 @@ static void queue_process(struct work_st
!dev_xmit_complete(netpoll_start_xmit(skb, dev,
txq))) {
skb_queue_head(&npinfo->txq, skb);
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
schedule_delayed_work(&npinfo->tx_work,
HZ/10);
return;
}
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
}
}
@@ -246,7 +269,7 @@ static void refill_skbs(struct netpoll *
static void zap_completion_queue(void)
{
unsigned long flags;
- struct softnet_data *sd = &get_cpu_var(softnet_data);
+ struct softnet_data *sd = this_cpu_ptr(&softnet_data);
if (sd->completion_queue) {
struct sk_buff *clist;
@@ -267,8 +290,6 @@ static void zap_completion_queue(void)
}
}
}
-
- put_cpu_var(softnet_data);
}
static struct sk_buff *find_skb(struct netpoll *np, int len, int
reserve)
@@ -319,7 +340,9 @@ static netdev_tx_t __netpoll_send_skb(st
/* It is up to the caller to keep npinfo alive. */
struct netpoll_info *npinfo;
+#if (!defined(CONFIG_PREEMPT_RT) && !defined(CONFIG_NETCONSOLE_NBCON))
lockdep_assert_irqs_disabled();
+#endif
dev = np->dev;
rcu_read_lock();
@@ -356,9 +379,11 @@ static netdev_tx_t __netpoll_send_skb(st
udelay(USEC_PER_POLL);
}
+#if (!defined(CONFIG_PREEMPT_RT) && !defined(CONFIG_NETCONSOLE_NBCON))
WARN_ONCE(!irqs_disabled(),
"netpoll_send_skb_on_dev(): %s enabled
interrupts in poll (%pS)\n",
dev->name, dev->netdev_ops->ndo_start_xmit);
+#endif
}
@@ -399,16 +424,16 @@ static void netpoll_udp_checksum(struct
netdev_tx_t netpoll_send_skb(struct netpoll *np, struct sk_buff *skb)
{
- unsigned long flags;
+ unsigned long __maybe_unused flags;
netdev_tx_t ret;
if (unlikely(!np)) {
dev_kfree_skb_irq(skb);
ret = NET_XMIT_DROP;
} else {
- local_irq_save(flags);
+ netpoll_tx_begin(flags);
ret = __netpoll_send_skb(np, skb);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
}
return ret;
}
@@ -501,7 +526,7 @@ int netpoll_send_udp(struct netpoll *np,
int total_len, ip_len, udp_len;
struct sk_buff *skb;
- if (!IS_ENABLED(CONFIG_PREEMPT_RT))
+ if (!IS_ENABLED(CONFIG_PREEMPT_RT) &&
!IS_ENABLED(CONFIG_NETCONSOLE_NBCON))
WARN_ON_ONCE(!irqs_disabled());
udp_len = len + sizeof(struct udphdr);
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-21 3:37 ` Mike Galbraith
@ 2025-08-21 3:51 ` Mike Galbraith
2025-08-21 17:35 ` Breno Leitao
2025-08-21 10:06 ` Mike Galbraith
1 sibling, 1 reply; 27+ messages in thread
From: Mike Galbraith @ 2025-08-21 3:51 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Thu, 2025-08-21 at 05:37 +0200, Mike Galbraith wrote:
>
> > What is this patch you have?
>
> Make boxen stop bitching at NETCONSOLE_NBCON version below.
Grr, whitespace damaged. Doesn't really matter given it's not a
submission, but it annoys me when I meet it on lkml, so take2.
netpoll: Make it RT friendly
PREEMPT_RT cannot alloc/free memory when not preemptible, making
disabling of IRQs across transmission an issue for RT.
Use local_bh_disable() to provide local exclusion for RT (via
softirq_ctrl.lock) for normal and fallback transmission paths
instead of disabling IRQs. Since zap_completion_queue() callers
ensure pointer stability, replace get_cpu_var() therein with
this_cpu_ptr() to keep it preemptible across kfree().
Disable a couple warnings for RT, and we're done.
v0.kinda-works -> v1:
remove get_cpu_var() from zap_completion_queue().
fix/test netpoll_tx_running() to work for RT/!RT.
fix/test xmit fallback path for RT.
Signed-off-by: Mike Galbraith <efault@gmx.de>
---
drivers/net/netconsole.c | 4 ++--
include/linux/netpoll.h | 4 +++-
net/core/netpoll.c | 47 ++++++++++++++++++++++++++++++++++++-----------
3 files changed, 41 insertions(+), 14 deletions(-)
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
static void netconsole_device_lock(struct console *con, unsigned long *flags)
{
/* protects all the targets at the same time */
- spin_lock_irqsave(&target_list_lock, *flags);
+ spin_lock(&target_list_lock);
}
static void netconsole_device_unlock(struct console *con, unsigned long flags)
{
- spin_unlock_irqrestore(&target_list_lock, flags);
+ spin_unlock(&target_list_lock);
}
#endif
--- a/include/linux/netpoll.h
+++ b/include/linux/netpoll.h
@@ -100,9 +100,11 @@ static inline void netpoll_poll_unlock(v
smp_store_release(&napi->poll_owner, -1);
}
+DECLARE_PER_CPU(int, _netpoll_tx_running);
+
static inline bool netpoll_tx_running(struct net_device *dev)
{
- return irqs_disabled();
+ return this_cpu_read(_netpoll_tx_running);
}
#else
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -58,6 +58,29 @@ static void zap_completion_queue(void);
static unsigned int carrier_timeout = 4;
module_param(carrier_timeout, uint, 0644);
+DEFINE_PER_CPU(int, _netpoll_tx_running);
+EXPORT_PER_CPU_SYMBOL(_netpoll_tx_running);
+
+#define netpoll_tx_begin(flags) \
+ do { \
+ if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
+ IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
+ local_bh_disable(); \
+ else \
+ local_irq_save(flags); \
+ this_cpu_write(_netpoll_tx_running, 1); \
+ } while (0)
+
+#define netpoll_tx_end(flags) \
+ do { \
+ this_cpu_write(_netpoll_tx_running, 0); \
+ if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
+ IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
+ local_bh_enable(); \
+ else \
+ local_irq_restore(flags); \
+ } while (0)
+
static netdev_tx_t netpoll_start_xmit(struct sk_buff *skb,
struct net_device *dev,
struct netdev_queue *txq)
@@ -90,7 +113,7 @@ static void queue_process(struct work_st
struct netpoll_info *npinfo =
container_of(work, struct netpoll_info, tx_work.work);
struct sk_buff *skb;
- unsigned long flags;
+ unsigned long __maybe_unused flags;
while ((skb = skb_dequeue(&npinfo->txq))) {
struct net_device *dev = skb->dev;
@@ -102,7 +125,7 @@ static void queue_process(struct work_st
continue;
}
- local_irq_save(flags);
+ netpoll_tx_begin(flags);
/* check if skb->queue_mapping is still valid */
q_index = skb_get_queue_mapping(skb);
if (unlikely(q_index >= dev->real_num_tx_queues)) {
@@ -115,13 +138,13 @@ static void queue_process(struct work_st
!dev_xmit_complete(netpoll_start_xmit(skb, dev, txq))) {
skb_queue_head(&npinfo->txq, skb);
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
schedule_delayed_work(&npinfo->tx_work, HZ/10);
return;
}
HARD_TX_UNLOCK(dev, txq);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
}
}
@@ -246,7 +269,7 @@ static void refill_skbs(struct netpoll *
static void zap_completion_queue(void)
{
unsigned long flags;
- struct softnet_data *sd = &get_cpu_var(softnet_data);
+ struct softnet_data *sd = this_cpu_ptr(&softnet_data);
if (sd->completion_queue) {
struct sk_buff *clist;
@@ -267,8 +290,6 @@ static void zap_completion_queue(void)
}
}
}
-
- put_cpu_var(softnet_data);
}
static struct sk_buff *find_skb(struct netpoll *np, int len, int reserve)
@@ -319,7 +340,9 @@ static netdev_tx_t __netpoll_send_skb(st
/* It is up to the caller to keep npinfo alive. */
struct netpoll_info *npinfo;
+#if (!defined(CONFIG_PREEMPT_RT) && !defined(CONFIG_NETCONSOLE_NBCON))
lockdep_assert_irqs_disabled();
+#endif
dev = np->dev;
rcu_read_lock();
@@ -356,9 +379,11 @@ static netdev_tx_t __netpoll_send_skb(st
udelay(USEC_PER_POLL);
}
+#if (!defined(CONFIG_PREEMPT_RT) && !defined(CONFIG_NETCONSOLE_NBCON))
WARN_ONCE(!irqs_disabled(),
"netpoll_send_skb_on_dev(): %s enabled interrupts in poll (%pS)\n",
dev->name, dev->netdev_ops->ndo_start_xmit);
+#endif
}
@@ -399,16 +424,16 @@ static void netpoll_udp_checksum(struct
netdev_tx_t netpoll_send_skb(struct netpoll *np, struct sk_buff *skb)
{
- unsigned long flags;
+ unsigned long __maybe_unused flags;
netdev_tx_t ret;
if (unlikely(!np)) {
dev_kfree_skb_irq(skb);
ret = NET_XMIT_DROP;
} else {
- local_irq_save(flags);
+ netpoll_tx_begin(flags);
ret = __netpoll_send_skb(np, skb);
- local_irq_restore(flags);
+ netpoll_tx_end(flags);
}
return ret;
}
@@ -501,7 +526,7 @@ int netpoll_send_udp(struct netpoll *np,
int total_len, ip_len, udp_len;
struct sk_buff *skb;
- if (!IS_ENABLED(CONFIG_PREEMPT_RT))
+ if (!IS_ENABLED(CONFIG_PREEMPT_RT) && !IS_ENABLED(CONFIG_NETCONSOLE_NBCON))
WARN_ON_ONCE(!irqs_disabled());
udp_len = len + sizeof(struct udphdr);
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-21 3:37 ` Mike Galbraith
2025-08-21 3:51 ` Mike Galbraith
@ 2025-08-21 10:06 ` Mike Galbraith
2025-08-21 13:12 ` Mike Galbraith
1 sibling, 1 reply; 27+ messages in thread
From: Mike Galbraith @ 2025-08-21 10:06 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Thu, 2025-08-21 at 05:37 +0200, Mike Galbraith wrote:
> On Wed, 2025-08-20 at 10:36 -0700, Breno Leitao wrote:
> > On Wed, Aug 20, 2025 at 02:31:02PM +0200, Mike Galbraith wrote:
> > > On Tue, 2025-08-19 at 10:27 -0700, Breno Leitao wrote:
> > > >
> > > > I’ve continued investigating possible solutions, and it looks like
> > > > moving netconsole over to the non‑blocking console (nbcon) framework
> > > > might be the right approach. Unlike the classic console path, nbcon
> > > > doesn’t rely on the global console lock, which was one of the main
> > > > concerns regarding the possible deadlock.
> > >
> > > ATM at least, classic can remotely log a crash whereas nbcon can't per
> > > test drive, so it would be nice for classic to stick around until nbcon
> > > learns some atomic packet blasting.
> >
> > Oh, does it mean that during crash nbcon invokes `write_atomic` call
> > back, and because this patch doesn't implement it, it will not send
> > those pkts? Am I reading it correct?
>
> No, I'm just saying that the kernel's last gasp doesn't make it out of
> the box with CONFIG_NETCONSOLE_NBCON=y as your patch sits.
A quick test proved you correct as to the why.
--- a/drivers/net/netconsole.c
+++ b/drivers/net/netconsole.c
@@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
static void netconsole_device_lock(struct console *con, unsigned long *flags)
{
/* protects all the targets at the same time */
- spin_lock_irqsave(&target_list_lock, *flags);
+ spin_lock(&target_list_lock);
}
static void netconsole_device_unlock(struct console *con, unsigned long flags)
{
- spin_unlock_irqrestore(&target_list_lock, flags);
+ spin_unlock(&target_list_lock);
}
#endif
@@ -1966,6 +1966,7 @@ static struct console netconsole_ext = {
#ifdef CONFIG_NETCONSOLE_NBCON
.flags = CON_ENABLED | CON_EXTENDED | CON_NBCON,
.write_thread = netcon_write_ext_thread,
+ .write_atomic = netcon_write_ext_thread,
.device_lock = netconsole_device_lock,
.device_unlock = netconsole_device_unlock,
#else
@@ -1979,6 +1980,7 @@ static struct console netconsole = {
#ifdef CONFIG_NETCONSOLE_NBCON
.flags = CON_ENABLED | CON_NBCON,
.write_thread = netcon_write_thread,
+ .write_atomic = netcon_write_thread,
.device_lock = netconsole_device_lock,
.device_unlock = netconsole_device_unlock,
#else
...presto, wired desktop box now captures wireless lappy crash.
[ 48.378783] netconsole: network logging started
[ 77.329021] sysrq: Trigger a crash
[ 77.329392] Kernel panic - not syncing: sysrq triggered crash
[ 77.329556] ------------[ cut here ]------------
[ 77.329562] WARNING: CPU: 3 PID: 2452 at kernel/softirq.c:387 __local_bh_enable_ip+0x8f/0xe0
[ 77.329593] Modules linked in: netconsole ccm 8021q garp mrp af_packet bridge stp llc iscsi_ibft iscsi_boot_sysfs cmac algif_hash algif_skcipher af_alg iwlmvm snd_hda_codec_hdmi snd_hda_codec_conexant snd_hda_codec_generic mac80211 binfmt_misc libarc4 intel_rapl_msr uvcvideo intel_rapl_common snd_hda_intel uvc x86_pkg_temp_thermal snd_intel_dspcfg videobuf2_vmalloc snd_hda_codec intel_powerclamp videobuf2_memops videobuf2_v4l2 iwlwifi coretemp btusb iTCO_wdt snd_hwdep kvm_intel btrtl snd_hda_core videobuf2_common intel_pmc_bxt nls_iso8859_1 btbcm iTCO_vendor_support nls_cp437 mei_hdcp mfd_core btintel videodev snd_pcm cfg80211 kvm mc bluetooth snd_timer irqbypass i2c_i801 snd pcspkr mei_me rfkill soundcore i2c_smbus mei thermal battery acpi_pad ac button joydev nfsd sch_fq_codel auth_rpcgss nfs_acl lockd grace sunrpc fuse dm_mod configfs dmi_sysfs hid_multitouch hid_generic usbhid i915 ghash_clmulni_intel i2c_algo_bit drm_buddy drm_client_lib video drm_display_helper xhci_pci xhci_hcd drm_kms_helper ahci ttm libahci
[ 77.329898] usbcore libata drm wmi usb_common serio_raw sd_mod scsi_dh_emc scsi_dh_rdac scsi_dh_alua sg scsi_mod scsi_common vfat fat virtio_blk virtio_mmio virtio virtio_ring ext4 crc16 mbcache jbd2 loop msr efivarfs autofs4 aesni_intel gf128mul
[ 77.329993] CPU: 3 UID: 0 PID: 2452 Comm: bash Kdump: loaded Tainted: G I 6.17.0.g068a56e5-master #231 PREEMPT(lazy)
[ 77.330011] Tainted: [I]=FIRMWARE_WORKAROUND
[ 77.330016] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 77.330021] RIP: 0010:__local_bh_enable_ip+0x8f/0xe0
[ 77.330041] Code: 3e bf 01 00 00 00 e8 f0 68 03 00 e8 3b 75 14 00 fb 65 8b 05 ab af 9b 01 85 c0 74 41 5b 5d c3 65 8b 05 a1 e8 9b 01 85 c0 75 a4 <0f> 0b eb a0 e8 68 74 14 00 eb a1 48 89 ef e8 de c0 07 00 eb aa 48
[ 77.330050] RSP: 0018:ffff8881251bf898 EFLAGS: 00010046
[ 77.330061] RAX: 0000000000000000 RBX: 0000000000000201 RCX: ffff8881251bf854
[ 77.330069] RDX: 0000000000000001 RSI: 0000000000000201 RDI: ffffffffa136b870
[ 77.330075] RBP: ffffffffa136b870 R08: 0000000000000002 R09: ffffffff832b6820
[ 77.330081] R10: 0000000000000001 R11: 0000000000000000 R12: ffff888126da2168
[ 77.330088] R13: ffff8881221e8f00 R14: ffff888126da2000 R15: ffff8881221e8f20
[ 77.330095] FS: 00007f22ad9c3740(0000) GS:ffff88826130c000(0000) knlGS:0000000000000000
[ 77.330104] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 77.330111] CR2: 0000563c1913f2e0 CR3: 0000000111548006 CR4: 00000000003726f0
[ 77.330118] Call Trace:
[ 77.330124] <TASK>
[ 77.330139] ieee80211_queue_skb+0x140/0x350 [mac80211]
[ 77.330428] __ieee80211_xmit_fast+0x217/0x3a0 [mac80211]
[ 77.330698] ? __skb_get_hash_net+0x47/0x1c0
[ 77.330718] ? __skb_get_hash_net+0x47/0x1c0
[ 77.330768] ieee80211_xmit_fast+0xee/0x1e0 [mac80211]
[ 77.331012] __ieee80211_subif_start_xmit+0x141/0x390 [mac80211]
[ 77.331218] ? __lock_acquire+0x550/0xbc0
[ 77.331268] ieee80211_subif_start_xmit+0x39/0x200 [mac80211]
[ 77.331478] ? lock_acquire.part.0+0xa4/0x1e0
[ 77.331512] ? netif_skb_features+0xb6/0x2b0
[ 77.331535] netpoll_start_xmit+0x125/0x1a0
[ 77.331569] __netpoll_send_skb+0x309/0x310
[ 77.331594] ? netpoll_send_skb+0x24/0x80
[ 77.331618] netpoll_send_skb+0x42/0x80
[ 77.331644] netcon_write_thread+0xb3/0xe0 [netconsole]
[ 77.331684] nbcon_emit_next_record+0x25f/0x290
[ 77.331739] __nbcon_atomic_flush_pending_con+0x9a/0xf0
[ 77.331786] __nbcon_atomic_flush_pending+0xbc/0x130
[ 77.331822] vprintk_emit+0x258/0x540
[ 77.331866] _printk+0x4c/0x50
[ 77.331908] vpanic+0xb1/0x290
[ 77.331934] panic+0x4c/0x4c
[ 77.331956] ? rcu_read_unlock+0x17/0x60
[ 77.331993] sysrq_handle_crash+0x1a/0x20
[ 77.332011] __handle_sysrq.cold+0x8f/0xd4
[ 77.332037] write_sysrq_trigger+0x66/0x80
[ 77.332059] proc_reg_write+0x53/0x90
[ 77.332074] ? rcu_read_lock_any_held+0x6b/0xa0
[ 77.332090] vfs_write+0xcc/0x550
[ 77.332115] ? exc_page_fault+0x75/0x1e0
[ 77.332130] ? __lock_release.isra.0+0x54/0x140
[ 77.332150] ? exc_page_fault+0x75/0x1e0
[ 77.332167] ? exc_page_fault+0x75/0x1e0
[ 77.332199] ksys_write+0x5c/0xd0
[ 77.332228] do_syscall_64+0x76/0x3d0
[ 77.332260] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 77.332271] RIP: 0033:0x7f22ad721000
[ 77.332285] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 77.332294] RSP: 002b:00007ffd75be2678 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 77.332306] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f22ad721000
[ 77.332313] RDX: 0000000000000002 RSI: 0000563c1913f2e0 RDI: 0000000000000001
[ 77.332319] RBP: 0000563c1913f2e0 R08: 0000000000000000 R09: 0000000000000000
[ 77.332326] R10: 00007f22ad610ea0 R11: 0000000000000202 R12: 0000000000000002
[ 77.332331] R13: 00007f22ad8005c0 R14: 00007f22ad7fdf60 R15: 0000563c19336af0
[ 77.332405] </TASK>
[ 77.332410] irq event stamp: 44121
[ 77.332415] hardirqs last enabled at (44119): [<ffffffff81351872>] __up_console_sem+0x52/0x60
[ 77.332429] hardirqs last disabled at (44120): [<ffffffff8120632a>] vpanic+0x3a/0x290
[ 77.332442] softirqs last enabled at (43324): [<ffffffff812cf84e>] handle_softirqs+0x31e/0x3f0
[ 77.332459] softirqs last disabled at (44121): [<ffffffff81aca754>] netpoll_send_skb+0x24/0x80
[ 77.332475] ---[ end trace 0000000000000000 ]---
[ 77.336439] CPU: 3 UID: 0 PID: 2452 Comm: bash Kdump: loaded Tainted: G W I 6.17.0.g068a56e5-master #231 PREEMPT(lazy)
[ 77.336507] Tainted: [W]=WARN, [I]=FIRMWARE_WORKAROUND
[ 77.336552] Hardware name: HP HP Spectre x360 Convertible/804F, BIOS F.47 11/22/2017
[ 77.336597] Call Trace:
[ 77.336646] <TASK>
[ 77.336705] dump_stack_lvl+0x5b/0x80
[ 77.336848] vpanic+0xca/0x290
[ 77.336968] panic+0x4c/0x4c
[ 77.337045] ? rcu_read_unlock+0x17/0x60
[ 77.337127] sysrq_handle_crash+0x1a/0x20
[ 77.337186] __handle_sysrq.cold+0x8f/0xd4
[ 77.337253] write_sysrq_trigger+0x66/0x80
[ 77.337315] proc_reg_write+0x53/0x90
[ 77.337373] ? rcu_read_lock_any_held+0x6b/0xa0
[ 77.337430] vfs_write+0xcc/0x550
[ 77.337494] ? exc_page_fault+0x75/0x1e0
[ 77.337550] ? __lock_release.isra.0+0x54/0x140
[ 77.337612] ? exc_page_fault+0x75/0x1e0
[ 77.338937] ? exc_page_fault+0x75/0x1e0
[ 77.339125] ksys_write+0x5c/0xd0
[ 77.339227] do_syscall_64+0x76/0x3d0
[ 77.339302] entry_SYSCALL_64_after_hwframe+0x4b/0x53
[ 77.339355] RIP: 0033:0x7f22ad721000
[ 77.339410] Code: 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 80 3d 09 ca 0e 00 00 74 17 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 58 c3 0f 1f 80 00 00 00 00 48 83 ec 28 48 89
[ 77.339460] RSP: 002b:00007ffd75be2678 EFLAGS: 00000202 ORIG_RAX: 0000000000000001
[ 77.339517] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f22ad721000
[ 77.339565] RDX: 0000000000000002 RSI: 0000563c1913f2e0 RDI: 0000000000000001
[ 77.339611] RBP: 0000563c1913f2e0 R08: 0000000000000000 R09: 0000000000000000
[ 77.339655] R10: 00007f22ad610ea0 R11: 0000000000000202 R12: 0000000000000002
[ 77.339700] R13: 00007f22ad8005c0 R14: 00007f22ad7fdf60 R15: 0000563c19336af0
[ 77.339807] </TASK>
The wireless stack now hates vpanic() for disabling IRQs, but that's
way better than death rattle not being transmitted.
-Mike
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-21 10:06 ` Mike Galbraith
@ 2025-08-21 13:12 ` Mike Galbraith
0 siblings, 0 replies; 27+ messages in thread
From: Mike Galbraith @ 2025-08-21 13:12 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Thu, 2025-08-21 at 12:06 +0200, Mike Galbraith wrote:
>
> A quick test proved you correct as to the why.
After a bit more testing/twiddling, seems NETCONSOLE_NBCON could
improve things at least a bit for RT. I was able to cleanly log an irq
thread handling sysrq-c over a wired interface. That beats silence.
Wireless wants more than a wee twiddle w/wo RT or NETCONSOLE_NBCON.
The path of least resistance there is bounce to kworker. Oh well.
-Mike
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-21 3:51 ` Mike Galbraith
@ 2025-08-21 17:35 ` Breno Leitao
2025-08-22 3:54 ` Mike Galbraith
0 siblings, 1 reply; 27+ messages in thread
From: Breno Leitao @ 2025-08-21 17:35 UTC (permalink / raw)
To: Mike Galbraith
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Thu, Aug 21, 2025 at 05:51:59AM +0200, Mike Galbraith wrote:
> On Thu, 2025-08-21 at 05:37 +0200, Mike Galbraith wrote:
> >
> > > What is this patch you have?
> >
> > Make boxen stop bitching at NETCONSOLE_NBCON version below.
>
> Grr, whitespace damaged. Doesn't really matter given it's not a
> submission, but it annoys me when I meet it on lkml, so take2.
>
> netpoll: Make it RT friendly
>
> PREEMPT_RT cannot alloc/free memory when not preemptible, making
> disabling of IRQs across transmission an issue for RT.
>
> Use local_bh_disable() to provide local exclusion for RT (via
> softirq_ctrl.lock) for normal and fallback transmission paths
> instead of disabling IRQs. Since zap_completion_queue() callers
> ensure pointer stability, replace get_cpu_var() therein with
> this_cpu_ptr() to keep it preemptible across kfree().
>
> Disable a couple warnings for RT, and we're done.
>
> v0.kinda-works -> v1:
> remove get_cpu_var() from zap_completion_queue().
> fix/test netpoll_tx_running() to work for RT/!RT.
> fix/test xmit fallback path for RT.
>
> Signed-off-by: Mike Galbraith <efault@gmx.de>
> ---
> drivers/net/netconsole.c | 4 ++--
> include/linux/netpoll.h | 4 +++-
> net/core/netpoll.c | 47 ++++++++++++++++++++++++++++++++++++-----------
> 3 files changed, 41 insertions(+), 14 deletions(-)
>
> --- a/drivers/net/netconsole.c
> +++ b/drivers/net/netconsole.c
> @@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
> static void netconsole_device_lock(struct console *con, unsigned long *flags)
> {
> /* protects all the targets at the same time */
> - spin_lock_irqsave(&target_list_lock, *flags);
> + spin_lock(&target_list_lock);
I personally think this target_list_lock can be moved to an RCU lock.
If that is doable, then we probably make netconsole_device_lock()
to a simple `rcu_read_lock()`, which would solve this problem as well.
> static void netconsole_device_unlock(struct console *con, unsigned long flags)
> {
> - spin_unlock_irqrestore(&target_list_lock, flags);
> + spin_unlock(&target_list_lock);
> }
> #endif
>
> --- a/include/linux/netpoll.h
> +++ b/include/linux/netpoll.h
> @@ -100,9 +100,11 @@ static inline void netpoll_poll_unlock(v
> smp_store_release(&napi->poll_owner, -1);
> }
>
> +DECLARE_PER_CPU(int, _netpoll_tx_running);
> +
> static inline bool netpoll_tx_running(struct net_device *dev)
> {
> - return irqs_disabled();
> + return this_cpu_read(_netpoll_tx_running);
> }
>
> #else
> --- a/net/core/netpoll.c
> +++ b/net/core/netpoll.c
> @@ -58,6 +58,29 @@ static void zap_completion_queue(void);
> static unsigned int carrier_timeout = 4;
> module_param(carrier_timeout, uint, 0644);
>
> +DEFINE_PER_CPU(int, _netpoll_tx_running);
> +EXPORT_PER_CPU_SYMBOL(_netpoll_tx_running);
> +
> +#define netpoll_tx_begin(flags) \
> + do { \
> + if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
> + IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
> + local_bh_disable(); \
> + else \
> + local_irq_save(flags); \
> + this_cpu_write(_netpoll_tx_running, 1); \
> + } while (0)
Why can't we just use local_bh_disable() in both cases?
> +
> +#define netpoll_tx_end(flags) \
> + do { \
> + this_cpu_write(_netpoll_tx_running, 0); \
> + if (IS_ENABLED(CONFIG_PREEMPT_RT) || \
> + IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
> + local_bh_enable(); \
> + else \
> + local_irq_restore(flags); \
> + } while (0)
> +
> static netdev_tx_t netpoll_start_xmit(struct sk_buff *skb,
> struct net_device *dev,
> struct netdev_queue *txq)
> @@ -90,7 +113,7 @@ static void queue_process(struct work_st
> struct netpoll_info *npinfo =
> container_of(work, struct netpoll_info, tx_work.work);
> struct sk_buff *skb;
> - unsigned long flags;
> + unsigned long __maybe_unused flags;
>
> while ((skb = skb_dequeue(&npinfo->txq))) {
> struct net_device *dev = skb->dev;
> @@ -102,7 +125,7 @@ static void queue_process(struct work_st
> continue;
> }
>
> - local_irq_save(flags);
It is unclear to me why we have irqs disabled in here. Nothing below
seems to depend on irq being disabled?
> + netpoll_tx_begin(flags);
> /* check if skb->queue_mapping is still valid */
> q_index = skb_get_queue_mapping(skb);
> if (unlikely(q_index >= dev->real_num_tx_queues)) {
> @@ -115,13 +138,13 @@ static void queue_process(struct work_st
> !dev_xmit_complete(netpoll_start_xmit(skb, dev, txq))) {
> skb_queue_head(&npinfo->txq, skb);
> HARD_TX_UNLOCK(dev, txq);
It seems the queue is already protected in here, so, why do we need to
local_irq_save above?
> - local_irq_restore(flags);
> + netpoll_tx_end(flags);
>
> schedule_delayed_work(&npinfo->tx_work, HZ/10);
> return;
> }
> HARD_TX_UNLOCK(dev, txq);
> - local_irq_restore(flags);
> + netpoll_tx_end(flags);
> }
> }
>
> @@ -246,7 +269,7 @@ static void refill_skbs(struct netpoll *
> static void zap_completion_queue(void)
> {
> unsigned long flags;
> - struct softnet_data *sd = &get_cpu_var(softnet_data);
> + struct softnet_data *sd = this_cpu_ptr(&softnet_data);
How do I check if this is safe to do ?
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-21 17:35 ` Breno Leitao
@ 2025-08-22 3:54 ` Mike Galbraith
2025-08-26 12:43 ` Breno Leitao
0 siblings, 1 reply; 27+ messages in thread
From: Mike Galbraith @ 2025-08-22 3:54 UTC (permalink / raw)
To: Breno Leitao
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Thu, 2025-08-21 at 10:35 -0700, Breno Leitao wrote:
> > On Thu, Aug 21, 2025 at 05:51:59AM +0200, Mike Galbraith wrote:
> > > > --- a/drivers/net/netconsole.c
> > > > +++ b/drivers/net/netconsole.c
> > > > @@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
> > > > static void netconsole_device_lock(struct console *con, unsigned long *flags)
> > > > {
> > > > /* protects all the targets at the same time */
> > > > - spin_lock_irqsave(&target_list_lock, *flags);
> > > > + spin_lock(&target_list_lock);
> >
> > I personally think this target_list_lock can be moved to an RCU lock.
> >
> > If that is doable, then we probably make netconsole_device_lock()
> > to a simple `rcu_read_lock()`, which would solve this problem as well.
The bigger issue for the nbcon patch would seem to be the seemingly
required .write_atomic leading to landing here with disabled IRQs.
WRT my patch, seeing a hard RT crash on wired box cleanly logged with
your nbcon patch applied (plus my twiddle mentioned earlier) tells me
my patch has lost its original reason to exist. It's relevant to this
thread only in that those once thought to be RT specific IRQ disable
spots turned out to actually be RT agnostic wireless sore spots.
> > > > --- a/net/core/netpoll.c
> > > > +++ b/net/core/netpoll.c
> > > > @@ -58,6 +58,29 @@ static void zap_completion_queue(void);
> > > > static unsigned int carrier_timeout = 4;
> > > > module_param(carrier_timeout, uint, 0644);
> > > >
> > > > +DEFINE_PER_CPU(int, _netpoll_tx_running);
> > > > +EXPORT_PER_CPU_SYMBOL(_netpoll_tx_running);
> > > > +
> > > > +#define
> > > > netpoll_tx_begin(flags) \
> > > > + do
> > > > { \
> > > > + if (IS_ENABLED(CONFIG_PREEMPT_RT)
> > > > || \
> > > > +
> > > > IS_ENABLED(CONFIG_NETCONSOLE_NBCON)) \
> > > > + local_bh_disable();
> > > > \
> > > > + else
> > > > \
> > > > + local_irq_save(flags);
> > > > \
> > > > + this_cpu_write(_netpoll_tx_running,
> > > > 1); \
> > > > + } while (0)
> >
> > Why can't we just use local_bh_disable() in both cases?
Yeah, believe so.
> > >
> > > > @@ -246,7 +269,7 @@ static void refill_skbs(struct netpoll *
> > > > static void zap_completion_queue(void)
> > > > {
> > > > unsigned long flags;
> > > > - struct softnet_data *sd = &get_cpu_var(softnet_data);
> > > > + struct softnet_data *sd = this_cpu_ptr(&softnet_data);
> >
> > How do I check if this is safe to do ?
Too much water under the bridge, I don't recall my path to conclusion
reached, and it seems to no longer matter.
-Mike
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-22 3:54 ` Mike Galbraith
@ 2025-08-26 12:43 ` Breno Leitao
2025-08-26 13:56 ` Mike Galbraith
0 siblings, 1 reply; 27+ messages in thread
From: Breno Leitao @ 2025-08-26 12:43 UTC (permalink / raw)
To: Mike Galbraith, Simon Horman, kuba, calvin
Cc: Pavel Begunkov, Jakub Kicinski, Johannes Berg, paulmck, LKML,
netdev, boqun.feng
On Fri, Aug 22, 2025 at 05:54:28AM +0200, Mike Galbraith wrote:
> On Thu, 2025-08-21 at 10:35 -0700, Breno Leitao wrote:
> > > On Thu, Aug 21, 2025 at 05:51:59AM +0200, Mike Galbraith wrote:
>
> > > > > --- a/drivers/net/netconsole.c
> > > > > +++ b/drivers/net/netconsole.c
> > > > > @@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
> > > > > static void netconsole_device_lock(struct console *con, unsigned long *flags)
> > > > > {
> > > > > /* protects all the targets at the same time */
> > > > > - spin_lock_irqsave(&target_list_lock, *flags);
> > > > > + spin_lock(&target_list_lock);
> > >
> > > I personally think this target_list_lock can be moved to an RCU lock.
> > >
> > > If that is doable, then we probably make netconsole_device_lock()
> > > to a simple `rcu_read_lock()`, which would solve this problem as well.
>
> The bigger issue for the nbcon patch would seem to be the seemingly
> required .write_atomic leading to landing here with disabled IRQs.
In this case, instead of transmitting through netpoll directly in the
.write_atomic context, we could queue the messages for later delivery.
With the current implementation, this is not straightforward unless we
introduce an additional message copy at the start of .write_atomic.
This is where the interface between netpoll and netconsole becomes
problematic. Ideally, we would avoid carrying extra data into netconsole
and instead copy the message into an SKB and queue the SKB for
transmission.
The core issue is that netpoll and netconsole are tightly coupled, and
several pieces of functionality that live in netpoll really belong in
netconsole. A good example is the SKB pool: that’s a netconsole concept,
not a netpoll one. None of the other netpoll users send raw char *
messages. They all work directly with skbs, so, in order to achieve it,
we need to move the concept of skb pool into netconsole, and give
netconsole the management of the skb pool.
> WRT my patch, seeing a hard RT crash on wired box cleanly logged with
> your nbcon patch applied (plus my twiddle mentioned earlier) tells me
> my patch has lost its original reason to exist. It's relevant to this
> thread only in that those once thought to be RT specific IRQ disable
> spots turned out to actually be RT agnostic wireless sore spots.
Thanks. As a follow-up, I would suggest the following steps:
1) Decouple the SKB pool from netpoll and move it into netconsole
* This makes netconsole behave like any other netpoll user,
interacting with netpoll by sending SKBs.
* The SKB population logic would then reside in netconsole, where it
logically belongs.
* Enable NBCONS in netconsole, guarded by NETCONSOLE_NBCON
* In normal .write_atomic() mode, messages should be queued in
a workqueue.
* If oops_in_progress is set, we bypass the queue and
transmit the SKB immediately. (Maybe disabling lockdep?!).
Any concern with this plan?
--breno
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-26 12:43 ` Breno Leitao
@ 2025-08-26 13:56 ` Mike Galbraith
0 siblings, 0 replies; 27+ messages in thread
From: Mike Galbraith @ 2025-08-26 13:56 UTC (permalink / raw)
To: Breno Leitao, Simon Horman, kuba, calvin
Cc: Pavel Begunkov, Johannes Berg, paulmck, LKML, netdev, boqun.feng
On Tue, 2025-08-26 at 05:43 -0700, Breno Leitao wrote:
> On Fri, Aug 22, 2025 at 05:54:28AM +0200, Mike Galbraith wrote:
> > On Thu, 2025-08-21 at 10:35 -0700, Breno Leitao wrote:
> > > > On Thu, Aug 21, 2025 at 05:51:59AM +0200, Mike Galbraith wrote:
> >
> > > > > > --- a/drivers/net/netconsole.c
> > > > > > +++ b/drivers/net/netconsole.c
> > > > > > @@ -1952,12 +1952,12 @@ static void netcon_write_thread(struct c
> > > > > > static void netconsole_device_lock(struct console *con, unsigned long *flags)
> > > > > > {
> > > > > > /* protects all the targets at the same time */
> > > > > > - spin_lock_irqsave(&target_list_lock, *flags);
> > > > > > + spin_lock(&target_list_lock);
> > > >
> > > > I personally think this target_list_lock can be moved to an RCU lock.
> > > >
> > > > If that is doable, then we probably make netconsole_device_lock()
> > > > to a simple `rcu_read_lock()`, which would solve this problem as well.
> >
> > The bigger issue for the nbcon patch would seem to be the seemingly
> > required .write_atomic leading to landing here with disabled IRQs.
>
> In this case, instead of transmitting through netpoll directly in the
> .write_atomic context, we could queue the messages for later delivery.
>
> With the current implementation, this is not straightforward unless we
> introduce an additional message copy at the start of .write_atomic.
>
> This is where the interface between netpoll and netconsole becomes
> problematic. Ideally, we would avoid carrying extra data into netconsole
> and instead copy the message into an SKB and queue the SKB for
> transmission.
>
> The core issue is that netpoll and netconsole are tightly coupled, and
> several pieces of functionality that live in netpoll really belong in
> netconsole. A good example is the SKB pool: that’s a netconsole concept,
> not a netpoll one. None of the other netpoll users send raw char *
> messages. They all work directly with skbs, so, in order to achieve it,
> we need to move the concept of skb pool into netconsole, and give
> netconsole the management of the skb pool.
>
> > WRT my patch, seeing a hard RT crash on wired box cleanly logged with
> > your nbcon patch applied (plus my twiddle mentioned earlier) tells me
> > my patch has lost its original reason to exist. It's relevant to this
> > thread only in that those once thought to be RT specific IRQ disable
> > spots turned out to actually be RT agnostic wireless sore spots.
>
> Thanks. As a follow-up, I would suggest the following steps:
>
> 1) Decouple the SKB pool from netpoll and move it into netconsole
>
> * This makes netconsole behave like any other netpoll user,
> interacting with netpoll by sending SKBs.
> * The SKB population logic would then reside in netconsole, where it
> logically belongs.
>
> * Enable NBCONS in netconsole, guarded by NETCONSOLE_NBCON
> * In normal .write_atomic() mode, messages should be queued in
> a workqueue.
> * If oops_in_progress is set, we bypass the queue and
> transmit the SKB immediately. (Maybe disabling lockdep?!).
>
> Any concern with this plan?
Nope, sounds like progress to me.
From an RT perspective, the further netconsole gets from the netpoll's
definition of acceptable IRQ holdoff, the better. For a death rattle,
it doesn't matter, but for mundane kernel squeaks that's a fail.
-Mike
^ permalink raw reply [flat|nested] 27+ messages in thread
* Re: netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning
2025-08-15 16:42 ` Jakub Kicinski
2025-08-15 17:29 ` Breno Leitao
2025-08-15 17:37 ` Calvin Owens
@ 2025-08-26 14:10 ` Johannes Berg
2 siblings, 0 replies; 27+ messages in thread
From: Johannes Berg @ 2025-08-26 14:10 UTC (permalink / raw)
To: Jakub Kicinski, Pavel Begunkov
Cc: Breno Leitao, Mike Galbraith, paulmck, LKML, netdev, boqun.feng
On Fri, 2025-08-15 at 09:42 -0700, Jakub Kicinski wrote:
> On Fri, 15 Aug 2025 11:44:45 +0100 Pavel Begunkov wrote:
> > On 8/15/25 01:23, Jakub Kicinski wrote:
> > > On Thu, 14 Aug 2025 03:16:11 -0700 Breno Leitao wrote:
> > > > 2.2) netpoll // net poll will call the network subsystem to send the packet
> > > > 2.3) lock(&fq->lock); // Try to get the lock while the lock was already held
> >
> > The report for reference:
> >
> > https://lore.kernel.org/all/fb38cfe5153fd67f540e6e8aff814c60b7129480.camel@gmx.de/>
> > > Where does netpoll take fq->lock ?
> >
> > the dependencies between the lock to be acquired
> > [ 107.985514] and HARDIRQ-irq-unsafe lock:
> > [ 107.985531] -> (&fq->lock){+.-.}-{3:3} {
> > ...
> > [ 107.988053] ... acquired at:
> > [ 107.988054] check_prev_add+0xfb/0xca0
> > [ 107.988058] validate_chain+0x48c/0x530
> > [ 107.988061] __lock_acquire+0x550/0xbc0
> > [ 107.988064] lock_acquire.part.0+0xa1/0x210
> > [ 107.988068] _raw_spin_lock_bh+0x38/0x50
> > [ 107.988070] ieee80211_queue_skb+0xfd/0x350 [mac80211]
> > [ 107.988198] __ieee80211_xmit_fast+0x202/0x360 [mac80211]
> > [ 107.988314] ieee80211_xmit_fast+0xfb/0x1f0 [mac80211]
> > [ 107.988424] __ieee80211_subif_start_xmit+0x14e/0x3d0 [mac80211]
> > [ 107.988530] ieee80211_subif_start_xmit+0x46/0x230 [mac80211]
>
> Ah, that's WiFi's stack queuing. Dunno whether we expect netpoll to
> work over WiFi. I suspect disabling netconsole over WiFi may be the
> most sensible way out. Johannes, do you expect mac80211 Tx to be IRQ-safe?
I see there's a long thread beyond this, but I just got back from
vacation and haven't read all of it.
As for this question itself, I'd say no. In some cases it probably could
be made safe for mac80211 _itself_ (by adjust that lock and maybe
another one or two), but that wouldn't extend to the drivers, so it'd be
up to the individual drivers. In most cases mac80211 calls wake_tx_queue
(either driver or its own implementation) and that will pull frame(s),
but either way it's going to go all the way into the driver, with
unknown results.
I guess we could do that async since we queue there anyway, but in this
case (of wanting to get things out of a dying system) that'd probably be
counter-productive...
Maybe if it's an individual driver opt-in, but I don't really see it
working for most drivers.
johannes
^ permalink raw reply [flat|nested] 27+ messages in thread
end of thread, other threads:[~2025-08-26 14:10 UTC | newest]
Thread overview: 27+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2025-08-13 4:14 netconsole: HARDIRQ-safe -> HARDIRQ-unsafe lock order warning Mike Galbraith
2025-08-14 10:16 ` Breno Leitao
2025-08-14 15:45 ` Pavel Begunkov
2025-08-15 0:23 ` Jakub Kicinski
2025-08-15 10:44 ` Pavel Begunkov
2025-08-15 16:42 ` Jakub Kicinski
2025-08-15 17:29 ` Breno Leitao
2025-08-15 17:33 ` Jakub Kicinski
2025-08-18 12:23 ` Breno Leitao
2025-08-15 19:10 ` Calvin Owens
2025-08-16 9:19 ` Mike Galbraith
2025-08-15 20:02 ` Pavel Begunkov
2025-08-18 12:10 ` Breno Leitao
2025-08-19 17:27 ` Breno Leitao
2025-08-20 12:31 ` Mike Galbraith
2025-08-20 17:36 ` Breno Leitao
2025-08-21 3:37 ` Mike Galbraith
2025-08-21 3:51 ` Mike Galbraith
2025-08-21 17:35 ` Breno Leitao
2025-08-22 3:54 ` Mike Galbraith
2025-08-26 12:43 ` Breno Leitao
2025-08-26 13:56 ` Mike Galbraith
2025-08-21 10:06 ` Mike Galbraith
2025-08-21 13:12 ` Mike Galbraith
2025-08-15 17:37 ` Calvin Owens
2025-08-26 14:10 ` Johannes Berg
2025-08-15 12:45 ` Mike Galbraith
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).