Created attachment 288063 [details] BUG: sleeping function called from invalid context at net/core/dev.c:9919 Hi, I have a Fedora 31 x86_64 machine with a wireless pci-express card with chipset 08:00.0 Network controller: Intel Corporation Wireless 8265 / 8275 (rev 50) as a wireless access point with hostapd-2.9-2.fc31.x86_64 and in the logs appear the following: BUG: sleeping function called from invalid context at net/core/dev.c:9919 Mar 23 23:47:06 kernel: in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 372, name: kworker/0:2 Mar 23 23:47:06 kernel: INFO: lockdep is turned off. Mar 23 23:47:06 kernel: CPU: 0 PID: 372 Comm: kworker/0:2 Not tainted 5.6.0-0.rc7.git0.2.iwlwififix3.fc31.x86_64 #1 Mar 23 23:47:06 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Mar 23 23:47:06 kernel: Workqueue: events iwl_mvm_add_new_dqa_stream_wk [iwlmvm] Mar 23 23:47:06 kernel: Call Trace: Mar 23 23:47:06 kernel: dump_stack+0x8f/0xd0 Mar 23 23:47:06 kernel: ___might_sleep.cold+0xb3/0xc3 Mar 23 23:47:06 kernel: synchronize_net+0x18/0x30 Mar 23 23:47:06 kernel: iwl_mvm_inactivity_check+0x8ac/0xf10 [iwlmvm] Mar 23 23:47:06 kernel: iwl_mvm_add_new_dqa_stream_wk+0x176/0x920 [iwlmvm] Mar 23 23:47:06 kernel: process_one_work+0x25d/0x570 Mar 23 23:47:06 kernel: worker_thread+0x50/0x3b0 Mar 23 23:47:06 kernel: kthread+0x106/0x140 Mar 23 23:47:06 kernel: ? process_one_work+0x570/0x570 Mar 23 23:47:06 kernel: ? kthread_park+0x90/0x90 Mar 23 23:47:06 kernel: ret_from_fork+0x3a/0x50 Mar 23 23:47:06 kernel: BUG: scheduling while atomic: kworker/0:2/372/0x00000002 Mar 23 23:47:06 kernel: INFO: lockdep is turned off. Mar 23 23:47:06 kernel: Modules linked in: ebtable_filter ebtables ip6table_filter ip6_tables ccm 8021q garp mrp bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat intel_rapl_msr mei_hdcp iTCO_wdt iTCO_vendor_support intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass iwlmvm mac80211 libarc4 snd_hda_codec_hdmi crct10dif_pclmul crc32_pclmul snd_hda_codec_realtek snd_hda_codec_generic iwlwifi ledtrig_audio joydev ghash_clmulni_intel snd_hda_intel snd_intel_dspcfg intel_cstate cfg80211 intel_uncore snd_hda_codec intel_rapl_perf snd_hda_core snd_hwdep rfkill snd_seq wmi_bmof i2c_i801 snd_seq_device mei_me snd_pcm snd_timer snd mei soundcore lpc_ich ip_tables raid1 i915 i2c_algo_bit cec Mar 23 23:47:06 kernel: drm_kms_helper crc32c_intel drm r8169 e1000e ums_realtek uas usb_storage wmi video Mar 23 23:47:06 kernel: CPU: 0 PID: 372 Comm: kworker/0:2 Tainted: G W 5.6.0-0.rc7.git0.2.iwlwififix3.fc31.x86_64 #1 Mar 23 23:47:06 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Mar 23 23:47:06 kernel: Workqueue: events iwl_mvm_add_new_dqa_stream_wk [iwlmvm] Mar 23 23:47:06 kernel: Call Trace: Mar 23 23:47:06 kernel: dump_stack+0x8f/0xd0 Mar 23 23:47:06 kernel: __schedule_bug.cold+0x64/0x71 Mar 23 23:47:06 kernel: __schedule+0x822/0x990 Mar 23 23:47:06 kernel: ? wait_for_completion+0xe9/0x150 Mar 23 23:47:06 kernel: schedule+0x5f/0xd0 Mar 23 23:47:06 kernel: schedule_timeout+0x265/0x3a0 Mar 23 23:47:06 kernel: ? wait_for_completion+0x38/0x150 Mar 23 23:47:06 kernel: ? wait_for_completion+0xe9/0x150 Mar 23 23:47:06 kernel: wait_for_completion+0x108/0x150 Mar 23 23:47:06 kernel: ? wake_up_q+0xa0/0xa0 Mar 23 23:47:06 kernel: __wait_rcu_gp+0x157/0x170 Mar 23 23:47:06 kernel: synchronize_rcu.part.0+0x38/0x40 Mar 23 23:47:06 kernel: ? invoke_rcu_core+0xb0/0xb0 Mar 23 23:47:06 kernel: ? __bpf_trace_rcu_utilization+0x10/0x10 Mar 23 23:47:06 kernel: ? _cond_resched+0x15/0x30 Mar 23 23:47:06 kernel: iwl_mvm_inactivity_check+0x8ac/0xf10 [iwlmvm] Mar 23 23:47:06 kernel: iwl_mvm_add_new_dqa_stream_wk+0x176/0x920 [iwlmvm] Mar 23 23:47:06 kernel: process_one_work+0x25d/0x570 Mar 23 23:47:06 kernel: worker_thread+0x50/0x3b0 Mar 23 23:47:06 kernel: kthread+0x106/0x140 Mar 23 23:47:06 kernel: ? process_one_work+0x570/0x570 Mar 23 23:47:06 kernel: ? kthread_park+0x90/0x90 Mar 23 23:47:06 kernel: ret_from_fork+0x3a/0x50 Mar 23 23:47:06 kernel: ------------[ cut here ]------------ after several hours the machine freeze, and reboots via a watchdog thanks, Gabriel
Created attachment 288065 [details] BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 Hi, using the emailed patch the first bug in the logs is: hostapd[1750]: wlp8s0: STA 78:00:9e:ff:6d:3e IEEE 802.11: did not acknowledge authentication response Mar 25 19:12:41 kernel: BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 Mar 25 19:12:41 kernel: in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 2026, name: kworker/3:0 Mar 25 19:12:41 kernel: INFO: lockdep is turned off. Mar 25 19:12:41 kernel: CPU: 3 PID: 2026 Comm: kworker/3:0 Not tainted 5.6.0-0.rc7.git0.2.iwlwififix4.fc31.x86_64 #1 Mar 25 19:12:41 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Mar 25 19:12:41 kernel: Workqueue: events iwl_mvm_add_new_dqa_stream_wk [iwlmvm] Mar 25 19:12:41 kernel: Call Trace: Mar 25 19:12:41 kernel: dump_stack+0x8f/0xd0 Mar 25 19:12:41 kernel: ___might_sleep.cold+0xb3/0xc3 Mar 25 19:12:41 kernel: iwl_trans_pcie_send_hcmd+0xdf/0x420 [iwlwifi] Mar 25 19:12:41 kernel: iwl_trans_send_cmd+0x79/0x150 [iwlwifi] Mar 25 19:12:41 kernel: ? __iwl_dbg+0x107/0x160 [iwlwifi] Mar 25 19:12:41 kernel: iwl_mvm_send_cmd+0x28/0x70 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_send_cmd_pdu+0x43/0x50 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_disable_txq.constprop.0+0x169/0x210 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_inactivity_check+0x8c6/0xf00 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_add_new_dqa_stream_wk+0x176/0x920 [iwlmvm] Mar 25 19:12:41 kernel: process_one_work+0x25d/0x570 Mar 25 19:12:41 kernel: worker_thread+0x50/0x3b0 Mar 25 19:12:41 kernel: kthread+0x106/0x140 Mar 25 19:12:41 kernel: ? process_one_work+0x570/0x570 Mar 25 19:12:41 kernel: ? kthread_park+0x90/0x90 Mar 25 19:12:41 kernel: ret_from_fork+0x3a/0x50 Mar 25 19:12:41 kernel: BUG: scheduling while atomic: kworker/3:0/2026/0x00000002 Mar 25 19:12:41 kernel: INFO: lockdep is turned off. Mar 25 19:12:41 kernel: Modules linked in: ebtable_filter ebtables ip6table_filter ip6_tables ccm 8021q garp mrp bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel iwlmvm mac80211 kvm libarc4 irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel iTCO_wdt iTCO_vendor_support mei_hdcp snd_hda_codec_realtek snd_hda_codec_generic ledtrig_audio joydev iwlwifi snd_hda_codec_hdmi intel_cstate snd_hda_intel snd_intel_dspcfg intel_uncore snd_hda_codec wmi_bmof snd_hda_core intel_rapl_perf cfg80211 i2c_i801 snd_hwdep rfkill snd_seq snd_seq_device snd_pcm mei_me snd_timer lpc_ich mei snd soundcore ip_tables raid1 i915 i2c_algo_bit cec Mar 25 19:12:41 kernel: drm_kms_helper crc32c_intel r8169 drm ums_realtek uas e1000e usb_storage wmi video Mar 25 19:12:41 kernel: CPU: 3 PID: 2026 Comm: kworker/3:0 Tainted: G W 5.6.0-0.rc7.git0.2.iwlwififix4.fc31.x86_64 #1 Mar 25 19:12:41 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Mar 25 19:12:41 kernel: Workqueue: events iwl_mvm_add_new_dqa_stream_wk [iwlmvm] Mar 25 19:12:41 kernel: Call Trace: Mar 25 19:12:41 kernel: dump_stack+0x8f/0xd0 Mar 25 19:12:41 kernel: __schedule_bug.cold+0x64/0x71 Mar 25 19:12:41 kernel: __schedule+0x822/0x990 Mar 25 19:12:41 kernel: schedule+0x5f/0xd0 Mar 25 19:12:41 kernel: schedule_timeout+0x1a8/0x3a0 Mar 25 19:12:41 kernel: ? __next_timer_interrupt+0xd0/0xd0 Mar 25 19:12:41 kernel: iwl_trans_pcie_send_hcmd+0x258/0x420 [iwlwifi] Mar 25 19:12:41 kernel: ? finish_wait+0x90/0x90 Mar 25 19:12:41 kernel: iwl_trans_send_cmd+0x79/0x150 [iwlwifi] Mar 25 19:12:41 kernel: iwl_mvm_send_cmd_status+0x47/0xf0 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_send_cmd_pdu_status+0x45/0x50 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_invalidate_sta_queue+0x17b/0x2b0 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_inactivity_check+0xce2/0xf00 [iwlmvm] Mar 25 19:12:41 kernel: iwl_mvm_add_new_dqa_stream_wk+0x176/0x920 [iwlmvm] Mar 25 19:12:41 kernel: process_one_work+0x25d/0x570 Mar 25 19:12:41 kernel: worker_thread+0x50/0x3b0 Mar 25 19:12:41 kernel: kthread+0x106/0x140 Mar 25 19:12:41 kernel: ? process_one_work+0x570/0x570 Mar 25 19:12:41 kernel: ? kthread_park+0x90/0x90 Mar 25 19:12:41 kernel: ret_from_fork+0x3a/0x50 Mar 25 19:12:41 kernel: ------------[ cut here ]------------
Created attachment 288083 [details] partial patch commit cfbc6c4c5b91 [iwlwifi: mvm: support mac80211 TXQs model] extended the RCU read critical section in iwl_mvm_inactivity_check() to encompass iwl_mvm_free_inactive_queue() to protect sta/queue_owner. However, this puts the call to synchronize_net() in an RCU read critical section: iwl_mvm_inactivity_check() -> iwl_mvm_free_inactive_queue() -> iwl_mvm_remove_sta_queue_marking() -> synchronize_net() The attached patch removes the synchronize_net() as we can't call this from a RCU read critical section. I just need to finish my analysis on the original assertion that the TX path might be busy while we are destroying it.
Created attachment 288181 [details] Patch, exit RCU read critical section earlier
Created attachment 288197 [details] complete logs with WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1144 iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] (In reply to Mark Asselstine from comment #3) > Created attachment 288181 [details] > Patch, exit RCU read critical section earlier Hi, using kernel 5.6.2-300.iwlwififix5.fc31.x86_64 with the following patches: 0001-iwlwifi-Don-t-use-non-existent-queues.patch 0001-iwlwifi-set-free_queue-to-the-loop-variable-not-a-me.patch 0001-iwlwifi-we-can-synchronize_net-while-in-a-RCU-read-c.patch (2020-04-03 14:27:03) in the logs appears: Apr 03 15:12:23 kernel: ------------[ cut here ]------------ Apr 03 15:12:23 kernel: Invalid TXQ id Apr 03 15:12:23 kernel: WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1144 iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] Apr 03 15:12:23 kernel: Modules linked in: ccm 8021q garp mrp ebtable_filter ebtables ip6table_filter ip6_tables bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat iwlmvm mac80211 libarc4 intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel intel_cstate intel_uncore mei_hdcp snd_hda_codec_generic iwlwifi iTCO_wdt intel_rapl_perf snd_hda_codec_hdmi iTCO_vendor_support wmi_bmof ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_hda_codec cfg80211 snd_hda_core snd_hwdep snd_seq snd_seq_device joydev rfkill snd_pcm mei_me i2c_i801 snd_timer snd soundcore mei lpc_ich ip_tables raid1 i915 i2c_algo_bit cec Apr 03 15:12:23 kernel: drm_kms_helper crc32c_intel drm ums_realtek uas e1000e usb_storage r8169 wmi video Apr 03 15:12:23 kernel: CPU: 2 PID: 887 Comm: irq/42-iwlwifi Not tainted 5.6.2-300.iwlwififix5.fc31.x86_64 #1 Apr 03 15:12:23 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Apr 03 15:12:23 kernel: RIP: 0010:iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] Apr 03 15:12:23 kernel: Code: 7d 08 e9 74 fd ff ff 44 0f b7 74 24 18 44 8b 6c 24 20 e9 dd fb ff ff 48 c7 c7 76 3c b2 c0 c6 05 94 13 05 00 01 e8 f0 3e 5f f5 <0f> 0b e9 74 fe ff ff c7 44 24 08 08 00 00 00 e9 57 fd ff ff 0f 0b Apr 03 15:12:23 kernel: RSP: 0018:ffffadb9c0148bc0 EFLAGS: 00010282 Apr 03 15:12:23 kernel: RAX: 000000000000000e RBX: ffff901e5a454cd0 RCX: 0000000000000002 Apr 03 15:12:23 kernel: RDX: 0000000000007788 RSI: ffff901e84678d78 RDI: 0000000000000246 Apr 03 15:12:23 kernel: RBP: ffff901e76cdb3e8 R08: 00000062feef9e44 R09: 0000000000000000 Apr 03 15:12:23 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: ffff901e60f2eb00 Apr 03 15:12:23 kernel: R13: ffffadb9c0148c40 R14: 0000000000004288 R15: 0000000000000000 Apr 03 15:12:23 kernel: FS: 0000000000000000(0000) GS:ffff901e8ec00000(0000) knlGS:0000000000000000 Apr 03 15:12:23 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 03 15:12:23 kernel: CR2: 00007f15e1ae3000 CR3: 00000001e3612005 CR4: 00000000001606e0 Apr 03 15:12:23 kernel: Call Trace: Apr 03 15:12:23 kernel: <IRQ> Apr 03 15:12:23 kernel: iwl_mvm_tx_skb_sta+0x1a3/0x480 [iwlmvm] Apr 03 15:12:23 kernel: ? find_held_lock+0x32/0x90 Apr 03 15:12:23 kernel: ? mark_held_locks+0x2d/0x80 Apr 03 15:12:23 kernel: iwl_mvm_tx_skb+0x17/0x40 [iwlmvm] Apr 03 15:12:23 kernel: ieee80211_tx_frags+0x16d/0x230 [mac80211] Apr 03 15:12:23 kernel: __ieee80211_tx+0x79/0x1c0 [mac80211] Apr 03 15:12:23 kernel: ieee80211_tx+0x11f/0x150 [mac80211] Apr 03 15:12:23 kernel: ieee80211_tx_pending+0x118/0x380 [mac80211] Apr 03 15:12:23 kernel: ? mark_held_locks+0x2d/0x80 Apr 03 15:12:23 kernel: tasklet_action_common.isra.0+0x7e/0x190 Apr 03 15:12:23 kernel: __do_softirq+0xe1/0x45d Apr 03 15:12:23 kernel: do_softirq_own_stack+0x2a/0x40 Apr 03 15:12:23 kernel: </IRQ> Apr 03 15:12:23 kernel: ? iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: do_softirq.part.0+0x60/0x70 Apr 03 15:12:23 kernel: __local_bh_enable_ip+0xd0/0xe0 Apr 03 15:12:23 kernel: iwl_pcie_irq_handler+0x7b0/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: ? irq_thread+0x88/0x190 Apr 03 15:12:23 kernel: ? irq_forced_thread_fn+0x80/0x80 Apr 03 15:12:23 kernel: irq_thread_fn+0x20/0x60 Apr 03 15:12:23 kernel: irq_thread+0xe9/0x190 Apr 03 15:12:23 kernel: ? lockdep_hardirqs_on+0xf0/0x180 Apr 03 15:12:23 kernel: ? wake_threads_waitq+0x30/0x30 Apr 03 15:12:23 kernel: kthread+0x106/0x140 Apr 03 15:12:23 kernel: ? irq_thread_check_affinity+0xb0/0xb0 Apr 03 15:12:23 kernel: ? kthread_park+0x90/0x90 Apr 03 15:12:23 kernel: ret_from_fork+0x3a/0x50 Apr 03 15:12:23 kernel: irq event stamp: 666353 Apr 03 15:12:23 kernel: hardirqs last enabled at (666352): [<ffffffffb616fae5>] vprintk_emit+0x155/0x350 Apr 03 15:12:23 kernel: hardirqs last disabled at (666353): [<ffffffffb60038b2>] trace_hardirqs_off_thunk+0x1a/0x1c Apr 03 15:12:23 kernel: softirqs last enabled at (666334): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: softirqs last disabled at (666335): [<ffffffffb6c0107a>] do_softirq_own_stack+0x2a/0x40 Apr 03 15:12:23 kernel: ---[ end trace 588779a720b2e611 ]--- and at 19:18:12 appears another WARNING: Apr 03 19:18:12 kernel: ------------[ cut here ]------------ Apr 03 19:18:12 kernel: WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1728 iwl_mvm_rx_tx_cmd+0xb52/0xc80 [iwlmvm] Apr 03 19:18:12 kernel: Modules linked in: ccm 8021q garp mrp ebtable_filter ebtables ip6table_filter ip6_tables bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat iwlmvm mac80211 libarc4 intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel intel_cstate intel_uncore mei_hdcp snd_hda_codec_generic iwlwifi iTCO_wdt intel_rapl_perf snd_hda_codec_hdmi iTCO_vendor_support wmi_bmof ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_hda_codec cfg80211 snd_hda_core snd_hwdep snd_seq snd_seq_device joydev rfkill snd_pcm mei_me i2c_i801 snd_timer snd soundcore mei lpc_ich ip_tables raid1 i915 i2c_algo_bit cec Apr 03 19:18:12 kernel: drm_kms_helper crc32c_intel drm ums_realtek uas e1000e usb_storage r8169 wmi video Apr 03 19:18:12 kernel: CPU: 2 PID: 887 Comm: irq/42-iwlwifi Tainted: G W 5.6.2-300.iwlwififix5.fc31.x86_64 #1 Apr 03 19:18:12 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Apr 03 19:18:12 kernel: RIP: 0010:iwl_mvm_rx_tx_cmd+0xb52/0xc80 [iwlmvm] Apr 03 19:18:12 kernel: Code: 0f 85 4f f7 ff ff 48 c7 c2 f8 8d b2 c0 be ba 04 00 00 48 c7 c7 c8 90 b2 c0 c6 05 35 f9 04 00 01 e8 5f 95 66 f5 e9 2b f7 ff ff <0f> 0b e9 74 f8 ff ff 0f 0b e9 3d f8 ff ff 48 63 44 24 14 44 8b 4c Apr 03 19:18:12 kernel: RSP: 0018:ffffadb9c0537c78 EFLAGS: 00010202 Apr 03 19:18:12 kernel: RAX: 0000000000000005 RBX: ffffffffc0b1c2c0 RCX: 0000000000000001 Apr 03 19:18:12 kernel: RDX: 0000000000000004 RSI: ffffadb9c0537e00 RDI: ffff901e76cdb3e8 Apr 03 19:18:12 kernel: RBP: ffff901e76cdb3e8 R08: ffffadb9c0537e00 R09: 0000000000000000 Apr 03 19:18:12 kernel: R10: 00000003e9d18000 R11: 0000000000000000 R12: ffffadb9c0537e00 Apr 03 19:18:12 kernel: R13: ffff901e76cdc438 R14: ffff901e76cdb3e8 R15: ffff901e69d18000 Apr 03 19:18:12 kernel: FS: 0000000000000000(0000) GS:ffff901e8ec00000(0000) knlGS:0000000000000000 Apr 03 19:18:12 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 03 19:18:12 kernel: CR2: 00007f15e1ae3000 CR3: 00000001e3612002 CR4: 00000000001606e0 Apr 03 19:18:12 kernel: Call Trace: Apr 03 19:18:12 kernel: ? rcu_read_lock_sched_held+0x32/0x70 Apr 03 19:18:12 kernel: ? __iwl_dbg+0x12d/0x160 [iwlwifi] Apr 03 19:18:12 kernel: iwl_mvm_rx_common+0xcd/0x2b0 [iwlmvm] Apr 03 19:18:12 kernel: iwl_pcie_rx_handle+0x408/0xbf0 [iwlwifi] Apr 03 19:18:12 kernel: iwl_pcie_irq_handler+0x79f/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: ? irq_thread+0x88/0x190 Apr 03 19:18:12 kernel: ? irq_forced_thread_fn+0x80/0x80 Apr 03 19:18:12 kernel: irq_thread_fn+0x20/0x60 Apr 03 19:18:12 kernel: irq_thread+0xe9/0x190 Apr 03 19:18:12 kernel: ? lockdep_hardirqs_on+0xf0/0x180 Apr 03 19:18:12 kernel: ? wake_threads_waitq+0x30/0x30 Apr 03 19:18:12 kernel: kthread+0x106/0x140 Apr 03 19:18:12 kernel: ? irq_thread_check_affinity+0xb0/0xb0 Apr 03 19:18:12 kernel: ? kthread_park+0x90/0x90 Apr 03 19:18:12 kernel: ret_from_fork+0x3a/0x50 Apr 03 19:18:12 kernel: irq event stamp: 66553165 Apr 03 19:18:12 kernel: hardirqs last enabled at (66553164): [<ffffffffb6b605b6>] _raw_spin_unlock_irqrestore+0x46/0x60 Apr 03 19:18:12 kernel: hardirqs last disabled at (66553165): [<ffffffffb60038b2>] trace_hardirqs_off_thunk+0x1a/0x1c Apr 03 19:18:12 kernel: softirqs last enabled at (66553156): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: softirqs last disabled at (66553162): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: ---[ end trace 588779a720b2e612 ]--- ... ... the complete log is in the attachment. thanks, Gabriel
Created attachment 288199 [details] kernel: BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 complete logs with WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1144 iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] (In reply to Mark Asselstine from comment #3) > Created attachment 288181 [details] > Patch, exit RCU read critical section earlier Hi, using kernel 5.6.2-300.iwlwififix5.fc31.x86_64 with the following patches: 0001-iwlwifi-Don-t-use-non-existent-queues.patch 0001-iwlwifi-set-free_queue-to-the-loop-variable-not-a-me.patch 0001-iwlwifi-we-can-synchronize_net-while-in-a-RCU-read-c.patch (2020-04-03 14:27:03) in the logs appears: Apr 03 15:12:23 kernel: ------------[ cut here ]------------ Apr 03 15:12:23 kernel: Invalid TXQ id Apr 03 15:12:23 kernel: WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1144 iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] Apr 03 15:12:23 kernel: Modules linked in: ccm 8021q garp mrp ebtable_filter ebtables ip6table_filter ip6_tables bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat iwlmvm mac80211 libarc4 intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel intel_cstate intel_uncore mei_hdcp snd_hda_codec_generic iwlwifi iTCO_wdt intel_rapl_perf snd_hda_codec_hdmi iTCO_vendor_support wmi_bmof ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_hda_codec cfg80211 snd_hda_core snd_hwdep snd_seq snd_seq_device joydev rfkill snd_pcm mei_me i2c_i801 snd_timer snd soundcore mei lpc_ich ip_tables raid1 i915 i2c_algo_bit cec Apr 03 15:12:23 kernel: drm_kms_helper crc32c_intel drm ums_realtek uas e1000e usb_storage r8169 wmi video Apr 03 15:12:23 kernel: CPU: 2 PID: 887 Comm: irq/42-iwlwifi Not tainted 5.6.2-300.iwlwififix5.fc31.x86_64 #1 Apr 03 15:12:23 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Apr 03 15:12:23 kernel: RIP: 0010:iwl_mvm_tx_mpdu+0x580/0x5a0 [iwlmvm] Apr 03 15:12:23 kernel: Code: 7d 08 e9 74 fd ff ff 44 0f b7 74 24 18 44 8b 6c 24 20 e9 dd fb ff ff 48 c7 c7 76 3c b2 c0 c6 05 94 13 05 00 01 e8 f0 3e 5f f5 <0f> 0b e9 74 fe ff ff c7 44 24 08 08 00 00 00 e9 57 fd ff ff 0f 0b Apr 03 15:12:23 kernel: RSP: 0018:ffffadb9c0148bc0 EFLAGS: 00010282 Apr 03 15:12:23 kernel: RAX: 000000000000000e RBX: ffff901e5a454cd0 RCX: 0000000000000002 Apr 03 15:12:23 kernel: RDX: 0000000000007788 RSI: ffff901e84678d78 RDI: 0000000000000246 Apr 03 15:12:23 kernel: RBP: ffff901e76cdb3e8 R08: 00000062feef9e44 R09: 0000000000000000 Apr 03 15:12:23 kernel: R10: 0000000000000000 R11: 0000000000000000 R12: ffff901e60f2eb00 Apr 03 15:12:23 kernel: R13: ffffadb9c0148c40 R14: 0000000000004288 R15: 0000000000000000 Apr 03 15:12:23 kernel: FS: 0000000000000000(0000) GS:ffff901e8ec00000(0000) knlGS:0000000000000000 Apr 03 15:12:23 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 03 15:12:23 kernel: CR2: 00007f15e1ae3000 CR3: 00000001e3612005 CR4: 00000000001606e0 Apr 03 15:12:23 kernel: Call Trace: Apr 03 15:12:23 kernel: <IRQ> Apr 03 15:12:23 kernel: iwl_mvm_tx_skb_sta+0x1a3/0x480 [iwlmvm] Apr 03 15:12:23 kernel: ? find_held_lock+0x32/0x90 Apr 03 15:12:23 kernel: ? mark_held_locks+0x2d/0x80 Apr 03 15:12:23 kernel: iwl_mvm_tx_skb+0x17/0x40 [iwlmvm] Apr 03 15:12:23 kernel: ieee80211_tx_frags+0x16d/0x230 [mac80211] Apr 03 15:12:23 kernel: __ieee80211_tx+0x79/0x1c0 [mac80211] Apr 03 15:12:23 kernel: ieee80211_tx+0x11f/0x150 [mac80211] Apr 03 15:12:23 kernel: ieee80211_tx_pending+0x118/0x380 [mac80211] Apr 03 15:12:23 kernel: ? mark_held_locks+0x2d/0x80 Apr 03 15:12:23 kernel: tasklet_action_common.isra.0+0x7e/0x190 Apr 03 15:12:23 kernel: __do_softirq+0xe1/0x45d Apr 03 15:12:23 kernel: do_softirq_own_stack+0x2a/0x40 Apr 03 15:12:23 kernel: </IRQ> Apr 03 15:12:23 kernel: ? iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: do_softirq.part.0+0x60/0x70 Apr 03 15:12:23 kernel: __local_bh_enable_ip+0xd0/0xe0 Apr 03 15:12:23 kernel: iwl_pcie_irq_handler+0x7b0/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: ? irq_thread+0x88/0x190 Apr 03 15:12:23 kernel: ? irq_forced_thread_fn+0x80/0x80 Apr 03 15:12:23 kernel: irq_thread_fn+0x20/0x60 Apr 03 15:12:23 kernel: irq_thread+0xe9/0x190 Apr 03 15:12:23 kernel: ? lockdep_hardirqs_on+0xf0/0x180 Apr 03 15:12:23 kernel: ? wake_threads_waitq+0x30/0x30 Apr 03 15:12:23 kernel: kthread+0x106/0x140 Apr 03 15:12:23 kernel: ? irq_thread_check_affinity+0xb0/0xb0 Apr 03 15:12:23 kernel: ? kthread_park+0x90/0x90 Apr 03 15:12:23 kernel: ret_from_fork+0x3a/0x50 Apr 03 15:12:23 kernel: irq event stamp: 666353 Apr 03 15:12:23 kernel: hardirqs last enabled at (666352): [<ffffffffb616fae5>] vprintk_emit+0x155/0x350 Apr 03 15:12:23 kernel: hardirqs last disabled at (666353): [<ffffffffb60038b2>] trace_hardirqs_off_thunk+0x1a/0x1c Apr 03 15:12:23 kernel: softirqs last enabled at (666334): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 15:12:23 kernel: softirqs last disabled at (666335): [<ffffffffb6c0107a>] do_softirq_own_stack+0x2a/0x40 Apr 03 15:12:23 kernel: ---[ end trace 588779a720b2e611 ]--- and at 19:18:12 appears another WARNING: Apr 03 19:18:12 kernel: ------------[ cut here ]------------ Apr 03 19:18:12 kernel: WARNING: CPU: 2 PID: 887 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1728 iwl_mvm_rx_tx_cmd+0xb52/0xc80 [iwlmvm] Apr 03 19:18:12 kernel: Modules linked in: ccm 8021q garp mrp ebtable_filter ebtables ip6table_filter ip6_tables bridge stp llc xt_pkttype xt_state xt_conntrack iptable_filter xt_nat iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c nf_log_ipv4 nf_log_common xt_dscp xt_multiport xt_LOG xt_set xt_length xt_mark iptable_mangle ip_set_hash_net ip_set_bitmap_port ip_set_hash_ip ip_set_hash_netport ip_set nfnetlink sunrpc vfat fat iwlmvm mac80211 libarc4 intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp snd_hda_codec_realtek kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel intel_cstate intel_uncore mei_hdcp snd_hda_codec_generic iwlwifi iTCO_wdt intel_rapl_perf snd_hda_codec_hdmi iTCO_vendor_support wmi_bmof ledtrig_audio snd_hda_intel snd_intel_dspcfg snd_hda_codec cfg80211 snd_hda_core snd_hwdep snd_seq snd_seq_device joydev rfkill snd_pcm mei_me i2c_i801 snd_timer snd soundcore mei lpc_ich ip_tables raid1 i915 i2c_algo_bit cec Apr 03 19:18:12 kernel: drm_kms_helper crc32c_intel drm ums_realtek uas e1000e usb_storage r8169 wmi video Apr 03 19:18:12 kernel: CPU: 2 PID: 887 Comm: irq/42-iwlwifi Tainted: G W 5.6.2-300.iwlwififix5.fc31.x86_64 #1 Apr 03 19:18:12 kernel: Hardware name: LENOVO 10A8S08P00/SHARKBAY, BIOS FBKTDBAUS 12/24/2019 Apr 03 19:18:12 kernel: RIP: 0010:iwl_mvm_rx_tx_cmd+0xb52/0xc80 [iwlmvm] Apr 03 19:18:12 kernel: Code: 0f 85 4f f7 ff ff 48 c7 c2 f8 8d b2 c0 be ba 04 00 00 48 c7 c7 c8 90 b2 c0 c6 05 35 f9 04 00 01 e8 5f 95 66 f5 e9 2b f7 ff ff <0f> 0b e9 74 f8 ff ff 0f 0b e9 3d f8 ff ff 48 63 44 24 14 44 8b 4c Apr 03 19:18:12 kernel: RSP: 0018:ffffadb9c0537c78 EFLAGS: 00010202 Apr 03 19:18:12 kernel: RAX: 0000000000000005 RBX: ffffffffc0b1c2c0 RCX: 0000000000000001 Apr 03 19:18:12 kernel: RDX: 0000000000000004 RSI: ffffadb9c0537e00 RDI: ffff901e76cdb3e8 Apr 03 19:18:12 kernel: RBP: ffff901e76cdb3e8 R08: ffffadb9c0537e00 R09: 0000000000000000 Apr 03 19:18:12 kernel: R10: 00000003e9d18000 R11: 0000000000000000 R12: ffffadb9c0537e00 Apr 03 19:18:12 kernel: R13: ffff901e76cdc438 R14: ffff901e76cdb3e8 R15: ffff901e69d18000 Apr 03 19:18:12 kernel: FS: 0000000000000000(0000) GS:ffff901e8ec00000(0000) knlGS:0000000000000000 Apr 03 19:18:12 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Apr 03 19:18:12 kernel: CR2: 00007f15e1ae3000 CR3: 00000001e3612002 CR4: 00000000001606e0 Apr 03 19:18:12 kernel: Call Trace: Apr 03 19:18:12 kernel: ? rcu_read_lock_sched_held+0x32/0x70 Apr 03 19:18:12 kernel: ? __iwl_dbg+0x12d/0x160 [iwlwifi] Apr 03 19:18:12 kernel: iwl_mvm_rx_common+0xcd/0x2b0 [iwlmvm] Apr 03 19:18:12 kernel: iwl_pcie_rx_handle+0x408/0xbf0 [iwlwifi] Apr 03 19:18:12 kernel: iwl_pcie_irq_handler+0x79f/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: ? irq_thread+0x88/0x190 Apr 03 19:18:12 kernel: ? irq_forced_thread_fn+0x80/0x80 Apr 03 19:18:12 kernel: irq_thread_fn+0x20/0x60 Apr 03 19:18:12 kernel: irq_thread+0xe9/0x190 Apr 03 19:18:12 kernel: ? lockdep_hardirqs_on+0xf0/0x180 Apr 03 19:18:12 kernel: ? wake_threads_waitq+0x30/0x30 Apr 03 19:18:12 kernel: kthread+0x106/0x140 Apr 03 19:18:12 kernel: ? irq_thread_check_affinity+0xb0/0xb0 Apr 03 19:18:12 kernel: ? kthread_park+0x90/0x90 Apr 03 19:18:12 kernel: ret_from_fork+0x3a/0x50 Apr 03 19:18:12 kernel: irq event stamp: 66553165 Apr 03 19:18:12 kernel: hardirqs last enabled at (66553164): [<ffffffffb6b605b6>] _raw_spin_unlock_irqrestore+0x46/0x60 Apr 03 19:18:12 kernel: hardirqs last disabled at (66553165): [<ffffffffb60038b2>] trace_hardirqs_off_thunk+0x1a/0x1c Apr 03 19:18:12 kernel: softirqs last enabled at (66553156): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: softirqs last disabled at (66553162): [<ffffffffc094906d>] iwl_pcie_irq_handler+0x77d/0xe20 [iwlwifi] Apr 03 19:18:12 kernel: ---[ end trace 588779a720b2e612 ]--- ... Apr 03 19:28:42 kernel: WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected Apr 03 20:46:36 kernel: WARNING: CPU: 0 PID: 3126 at drivers/net/wireless/intel/iwlwifi/mvm/utils.c:635 iwl_mvm_reconfig_scd+0x153/0x160 [iwlmvm] Apr 03 20:49:46 kernel: BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 Apr 03 20:49:46 kernel: WARNING: CPU: 2 PID: 3191 at drivers/net/wireless/intel/iwlwifi/mvm/sta.c:861 iwl_mvm_enable_txq+0x221/0x2b0 [iwlmvm] Apr 03 20:49:47 kernel: WARNING: CPU: 2 PID: 3142 at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1770 iwl_pcie_enqueue_hcmd+0xa46/0xc00 [iwlwifi] ... the complete log is in the attachment. obsoleted the previous attachment because this log contains the previous attachment and also appears: Apr 03 20:49:46 kernel: BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 thanks, Gabriel
Created attachment 288779 [details] iwl_mvm_free_inactive_queue returns 0 or a error not a queue number Hi, iwl_mvm_free_inactive_queue returns 0 or a error not a queue number. I don't know if when iwl_mvm_disable_txq returns nonzero the queue is usable so better to set free_queue to -ENOSPC maybe is better to modify the for loop in iwl_mvm_inactivity_check to get all free queues and not only the first one so iwl_mvm_free_inactive_queue have more opportunity to get a usable queue but iwl_mvm_free_inactive_queue cannot be under rcu_read_lock(); so the bug is resolved for me with: https://bugzilla.kernel.org/attachment.cgi?id=287903 https://bugzilla.kernel.org/attachment.cgi?id=287955 and this patch I hope the patches get to all stable kernel series soon I'm currently in 5.6.7 and it don't have the first two patches and them solved a kernel NULL pointer dereference. Mark, thanks for all your help in solving the bugs, Gabriel
I have locally applied the two patches from #206765 mentioned in comment 6 plus attachment 288779 [details], and I'm still regularly getting [51383.047342] WARNING: CPU: 7 PID: 1065 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1500 iwl_mvm_rx_tx_cmd+0x42e/0x750 [iwlmvm] [51383.047343] Modules linked in: bridge stp llc xfrm_user rfcomm algif_skcipher bnep xt_mac xt_connmark xt_owner xt_mark xt_MASQUERADE iptable_nat nvidia_drm(PO) binfmt_misc vboxnetflt(O) vboxnetadp(O) vboxdrv(O) uinput nf_nat_sip nf_nat_irc nf_nat_ftp nvidia_modeset(PO) xt_state xt_nat nf_conntrack_sip nf_conntrack_pptp nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp nf_conncount snd_hda_codec_hdmi xt_conntrack nct6775 hwmon_vid ppp_async crc_ccitt xt_l2tp l2tp_ppp pppox btusb ppp_generic btrtl slhc btbcm btintel l2tp_ip6 l2tp_ip bluetooth l2tp_eth l2tp_netlink mei_hdcp l2tp_debugfs l2tp_core kvm_intel ecdh_generic joydev ip6_udp_tunnel iwlmvm snd_hda_codec_realtek ecc udp_tunnel kvm snd_hda_codec_generic irqbypass fuse nvidia(PO) crc32_pclmul snd_hda_intel iwlwifi snd_intel_dspcfg i2c_i801 snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me mei efivarfs [51383.047398] CPU: 7 PID: 1065 Comm: irq/144-iwlwifi Tainted: P W O 5.5.19-gentoo-dorellan #1 [51383.047399] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z270M-ITX/ac, BIOS P2.20 05/17/2017 [51383.047411] RIP: 0010:iwl_mvm_rx_tx_cmd+0x42e/0x750 [iwlmvm] [51383.047415] Code: 82 ff ff 4c 8b 54 24 08 41 88 85 f2 17 00 00 e9 05 fe ff ff 66 81 fb 8e 00 40 0f 94 c5 eb 9c 66 81 fb 85 00 40 0f 94 c5 eb 91 <0f> 0b 41 81 4e 28 00 01 00 00 eb 83 4d 89 ee e8 1e bf 3e d0 0f b6 [51383.047416] RSP: 0018:ffff979d004afcd0 EFLAGS: 00010246 [51383.047419] RAX: ffff9239a1657101 RBX: 0000000000000088 RCX: 0000000000d463e7 [51383.047421] RDX: 0000000000d463df RSI: 0000000000d463df RDI: 000000000002fad0 [51383.047422] RBP: ffff923d81e81e68 R08: 00000000000000fc R09: 0000000000000000 [51383.047424] R10: ffff923ae167ef30 R11: 0000000000000000 R12: ffff92398fa3502a [51383.047426] R13: ffff923d81e81e68 R14: ffff923ae167ef00 R15: ffff92398fe8b000 [51383.047428] FS: 0000000000000000(0000) GS:ffff923d8edc0000(0000) knlGS:0000000000000000 [51383.047430] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [51383.047432] CR2: 000033587dafe000 CR3: 00000001bf60a003 CR4: 00000000003606e0 [51383.047434] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [51383.047436] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [51383.047437] Call Trace: [51383.047449] iwl_mvm_rx_common+0xd9/0x290 [iwlmvm] [51383.047458] iwl_pcie_rx_handle+0x322/0x850 [iwlwifi] [51383.047467] iwl_pcie_irq_handler+0x1a9/0x760 [iwlwifi] [51383.047471] ? irq_forced_thread_fn+0x70/0x70 [51383.047474] irq_thread_fn+0x1b/0x60 [51383.047478] irq_thread+0xd7/0x160 [51383.047482] ? wake_threads_waitq+0x30/0x30 [51383.047486] kthread+0xf6/0x130 [51383.047489] ? irq_thread_check_affinity+0x80/0x80 [51383.047492] ? kthread_park+0x80/0x80 [51383.047498] ret_from_fork+0x35/0x40 [51383.047501] ---[ end trace e80778eb46da3062 ]---
Created attachment 289159 [details] dont call iwl_mvm_free_inactive_queue, iwl_mvm_unshare_queue, and iwl_mvm_change_queue_tid under rcu_read_lock() (In reply to triffid.hunter from comment #7) > I have locally applied the two patches from #206765 mentioned in comment 6 > plus attachment 288779 [details], and I'm still regularly getting > > [51383.047342] WARNING: CPU: 7 PID: 1065 at > drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1500 > iwl_mvm_rx_tx_cmd+0x42e/0x750 [iwlmvm] The last time the above WARNING triggered in my machine was under kernel 5.6.8 in 5.6.[11-12-13] don't happen, but I'm running a different patch (attached in this comment) from comment 6 because my machine triggered: BUG: sleeping function called from invalid context at drivers/net/wireless/intel/iwlwifi/pcie/tx.c:1924 in functions iwl_mvm_unshare_queue and iwl_mvm_change_queue_tid so I don't know if the patch attached here fixed the WARNING from comment 7 or was fixed in a kernel newer than 5.6.8 with this patch the only WARNING triggered in my machine are: May 15 21:16:38 kernel: Invalid TXQ id May 15 21:16:38 kernel: WARNING: CPU: 2 PID: 920 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1144 iwl_mvm_tx_mpdu+0x53f/0x560 [iwlmvm] and May 15 22:47:59 kernel: WARNING: CPU: 2 PID: 920 at drivers/net/wireless/intel/iwlwifi/mvm/sta.c:3732 iwl_mvm_sta_modify_sleep_tx_count+0x259/0x300 [iwlmvm] Gabriel
We made a bunch of fixes in this area which were included in v5.7-rc3, v5.4.36 and v5.6.8. Can you retest with one of these versions?
(In reply to Luca Coelho from comment #9) > We made a bunch of fixes in this area which were included in v5.7-rc3, > v5.4.36 and v5.6.8. Can you retest with one of these versions? Hi, I tested v5.6.8 and newer currently v5.7 and this bug isn't fixed. this bug is fixed with: https://bugzilla.kernel.org/attachment.cgi?id=289159 because iwl_mvm_free_inactive_queue returns an error not a queue number so when it returns an error we need set queue_number to -ENOSPC not the error returned or maybe instead of returning -ENOSPC returns the queue_number And dont call iwl_mvm_free_inactive_queue, iwl_mvm_unshare_queue, and iwl_mvm_change_queue_tid under rcu_read_lock() to prevent this bug I'm running this patch for several days under v5.6.8+, currently v5.7, and this bug isn't triggered anymore thanks, Gabriel
Okay, thanks for the report. Where did you send the attached email to? We have this patch that should solve the same problem: https://patchwork.kernel.org/patch/11472099/ But I didn't apply it because there were some concerns. I'll send it for the rc series and for fixes soon.
I'm having zero kernel messages from 5.7.1 after 17 hours of testing, whereas I could reliably get tons of aforementioned warnings in earlier releases. I'll keep an eye on it, and report back if I come across anything such as the bug mentioned in comment 10 which doesn't seem to have triggered here yet.
(In reply to Luca Coelho from comment #11) > Okay, thanks for the report. Where did you send the attached email to? > I didn't, only attached here, because I was testing the patch so I wasn't sure to be any side effects from moving rcu_read_unlock(); above iwl_mvm_unshare_queue and iwl_mvm_change_queue_tid. but in my testing several weeks the bug isn't triggered anymore, and no side effects happened and the patch has the journal of the bug instances when iwl_mvm_unshare_queue, and iwl_mvm_change_queue_tid were executed under rcu_read_unlock(); > We have this patch that should solve the same problem: > https://patchwork.kernel.org/patch/11472099/ I tried a similar version several weeks but in my testing the bug still happened when iwl_mvm_unshare_queue and/or iwl_mvm_change_queue_tid executed under rcu_read_unlock I reviewed https://bugzilla.kernel.org/attachment.cgi?id=289159 again and seems to be unnecessary set queue_number = -ENOSPC so I'm currently testing a patch with return ret; instead > > But I didn't apply it because there were some concerns. I'll send it for > the rc series and for fixes soon. Well in my computer the bug still happen with it, but may be particular to my computer workload. Gabriel
After a little more testing with 5.7.1 it turns out it's just taking longer to trigger. [380624.367421] WARNING: CPU: 7 PID: 1019 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1495 iwl_mvm_rx_tx_cmd+0x434/0x760 [iwlmvm] [380624.367422] Modules linked in: wireguard curve25519_x86_64 libchacha20poly1305 chacha_x86_64 libchacha poly1305_x86_64 libblake2s blake2s_x86_64 libblake2s_generic libcurve25519_generic bridge stp llc xfrm_user rfcomm algif_skcipher bnep xt_mac xt_connmark xt_owner xt_mark xt_MASQUERADE iptable_nat nvidia_drm(PO) binfmt_misc vboxnetflt(O) vboxnetadp(O) vboxdrv(O) uinput nvidia_modeset(PO) nf_nat_sip nf_nat_irc nf_nat_ftp xt_state xt_nat nf_conntrack_sip nf_conntrack_pptp nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp nf_conncount xt_conntrack nct6775 hwmon_vid ppp_async crc_ccitt xt_l2tp btusb l2tp_ppp btrtl pppox btbcm ppp_generic btintel slhc bluetooth l2tp_ip6 l2tp_ip l2tp_eth l2tp_netlink ecdh_generic ecc l2tp_debugfs joydev kvm_intel l2tp_core snd_hda_codec_realtek ip6_udp_tunnel udp_tunnel mei_hdcp snd_hda_codec_generic snd_hda_codec_hdmi fuse kvm iwlmvm snd_hda_intel irqbypass snd_intel_dspcfg nvidia(PO) crc32_pclmul snd_hda_codec snd_hwdep iwlwifi i2c_i801 snd_hda_core snd_pcm [380624.367463] mei_me mei efivarfs [380624.367468] CPU: 7 PID: 1019 Comm: irq/144-iwlwifi Tainted: P W O 5.7.1-gentoo-dorellan #1 [380624.367469] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z270M-ITX/ac, BIOS P2.20 05/17/2017 [380624.367478] RIP: 0010:iwl_mvm_rx_tx_cmd+0x434/0x760 [iwlmvm] [380624.367489] Code: 82 ff ff 4c 8b 54 24 08 41 88 85 ea 17 00 00 e9 ff fd ff ff 66 81 fb 8e 00 40 0f 94 c5 eb 9c 66 81 fb 85 00 40 0f 94 c5 eb 91 <0f> 0b 41 81 4e 28 00 01 00 00 eb 83 4d 89 ee e8 d8 03 b0 c1 0f b6 [380624.367495] RSP: 0018:ffffa90500433cd0 EFLAGS: 00010246 [380624.367502] RAX: ffffa1cba7097101 RBX: 0000000000000088 RCX: 00000000048aa3ff [380624.367504] RDX: 00000000048aa3f7 RSI: 00000000048aa3f7 RDI: 000000000002fcc0 [380624.367505] RBP: ffffa1d281cf9e88 R08: 00000000000000fd R09: 0000000000000000 [380624.367507] R10: ffffa1ceb136b630 R11: 0000000000000000 R12: ffffa1d1ee30a02e [380624.367508] R13: ffffa1d281cf9e88 R14: ffffa1ceb136b600 R15: ffffa1cb4faeb000 [380624.367510] FS: 0000000000000000(0000) GS:ffffa1d28edc0000(0000) knlGS:0000000000000000 [380624.367512] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [380624.367513] CR2: 00001af755f8b000 CR3: 00000003c080a001 CR4: 00000000003606e0 [380624.367515] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [380624.367516] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [380624.367517] Call Trace: [380624.367526] iwl_mvm_rx_common+0xd9/0x290 [iwlmvm] [380624.367534] iwl_pcie_rx_handle+0x320/0x820 [iwlwifi] [380624.367547] iwl_pcie_irq_handler+0x1a9/0x760 [iwlwifi] [380624.367558] ? irq_forced_thread_fn+0x70/0x70 [380624.367567] irq_thread_fn+0x1b/0x60 [380624.367576] irq_thread+0xd7/0x160 [380624.367584] ? wake_threads_waitq+0x30/0x30 [380624.367592] kthread+0x10e/0x150 [380624.367598] ? irq_thread_check_affinity+0x80/0x80 [380624.367601] ? kthread_park+0x80/0x80 [380624.367604] ret_from_fork+0x35/0x40 [380624.367607] ---[ end trace f114c08ca41e94d5 ]--- Uptime 6 days, 63 instances of this warning in the kernel buffer, and it's overflowed (dmesg | head shows half a warning message) so there may have been more.
From 5.7.6: [49246.106047] ------------[ cut here ]------------ [49246.106074] WARNING: CPU: 6 PID: 944 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1495 iwl_mvm_rx_tx_cmd+0x434/0x760 [iwlmvm] [49246.106076] Modules linked in: wireguard curve25519_x86_64 libchacha20poly1305 chacha_x86_64 libchacha poly1305_x86_64 libblake2s blake2s_x86_64 libblake2s_generic libcurve25519_generic bridge stp llc xfrm_user rfcomm algif_skcipher bnep xt_mac xt_connmark xt_owner xt_mark xt_MASQUERADE iptable_nat nvidia_drm(PO) binfmt_misc uinput nvidia_modeset(PO) nf_nat_sip nf_nat_irc nf_nat_ftp xt_state xt_nat nf_conntrack_sip nf_conntrack_pptp nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp nf_conncount xt_conntrack nct6775 hwmon_vid btusb btrtl btbcm btintel ppp_async crc_ccitt bluetooth joydev xt_l2tp ecdh_generic ecc l2tp_ppp pppox ppp_generic slhc l2tp_ip6 l2tp_ip l2tp_eth l2tp_netlink l2tp_debugfs l2tp_core ip6_udp_tunnel udp_tunnel mei_hdcp snd_hda_codec_realtek kvm_intel snd_hda_codec_generic snd_hda_codec_hdmi iwlmvm fuse kvm snd_hda_intel irqbypass nvidia(PO) i2c_i801 crc32_pclmul snd_intel_dspcfg iwlwifi snd_hda_codec snd_hwdep snd_hda_core snd_pcm mei_me mei efivarfs [49246.106158] CPU: 6 PID: 944 Comm: irq/144-iwlwifi Tainted: P O 5.7.6-gentoo-dorellan #1 [49246.106161] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z270M-ITX/ac, BIOS P2.20 05/17/2017 [49246.106179] RIP: 0010:iwl_mvm_rx_tx_cmd+0x434/0x760 [iwlmvm] [49246.106185] Code: 82 ff ff 4c 8b 54 24 08 41 88 85 ea 17 00 00 e9 ff fd ff ff 66 81 fb 8e 00 40 0f 94 c5 eb 9c 66 81 fb 85 00 40 0f 94 c5 eb 91 <0f> 0b 41 81 4e 28 00 01 00 00 eb 83 4d 89 ee e8 98 04 41 f8 0f b6 [49246.106189] RSP: 0018:ffff9d0a006d7cd0 EFLAGS: 00010246 [49246.106193] RAX: 0000000000000000 RBX: 0000000000000088 RCX: 000000008020001f [49246.106196] RDX: 0000000080200020 RSI: 0000000000000001 RDI: 0000000000000000 [49246.106199] RBP: ffff9991810d1e88 R08: 0000000000000001 R09: 0000000000000001 [49246.106202] R10: ffff999183cb9e30 R11: 0000000000000000 R12: ffff998fdc2fb826 [49246.106204] R13: ffff9991810d1e88 R14: ffff999183cb9e00 R15: ffff998ee2bdd000 [49246.106209] FS: 0000000000000000(0000) GS:ffff99918ed80000(0000) knlGS:0000000000000000 [49246.106212] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [49246.106215] CR2: 00005651d0c0ef50 CR3: 000000035480a003 CR4: 00000000003606e0 [49246.106218] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [49246.106221] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [49246.106223] Call Trace: [49246.106244] iwl_mvm_rx_common+0xd9/0x290 [iwlmvm] [49246.106257] iwl_pcie_rx_handle+0x320/0x820 [iwlwifi] [49246.106267] iwl_pcie_irq_handler+0x1a9/0x760 [iwlwifi] [49246.106275] ? irq_forced_thread_fn+0x70/0x70 [49246.106278] irq_thread_fn+0x1b/0x60 [49246.106283] irq_thread+0xd7/0x160 [49246.106287] ? wake_threads_waitq+0x30/0x30 [49246.106293] kthread+0x10e/0x150 [49246.106297] ? irq_thread_check_affinity+0x80/0x80 [49246.106301] ? kthread_park+0x80/0x80 [49246.106306] ret_from_fork+0x35/0x40 [49246.106311] ---[ end trace e97e4e008c682eab ]---
From 5.8.18: [159490.455557] WARNING: CPU: 6 PID: 961 at drivers/net/wireless/intel/iwlwifi/mvm/tx.c:1492 iwl_mvm_rx_tx_cmd+0x43b/0x760 [iwlmvm] [159490.455557] Modules linked in: wireguard libchacha20poly1305 chacha_x86_64 libchacha poly1305_x86_64 libblake2s blake2s_x86_64 libblake2s_generic curve25519_x86_64 libcurve25519_generic bridge stp llc xfrm_user rfcomm algif_skcipher bnep zram zsmalloc xt_connmark xt_owner xt_mac xt_mark xt_MASQUERADE iptable_nat binfmt_misc nvidia_drm(PO) uinput nf_nat_sip nf_nat_irc nf_nat_ftp xt_state xt_nat nf_conntrack_sip nf_conntrack_pptp nvidia_modeset(PO) nf_conntrack_irc nf_conntrack_h323 nf_conntrack_ftp nf_conncount xt_conntrack nct6775 hwmon_vid ppp_async crc_ccitt xt_l2tp l2tp_ppp pppox ppp_generic slhc l2tp_ip6 l2tp_ip joydev l2tp_eth l2tp_netlink l2tp_debugfs btusb btrtl btbcm btintel l2tp_core snd_hda_codec_realtek ip6_udp_tunnel udp_tunnel snd_hda_codec_hdmi snd_hda_codec_generic ee1004 bluetooth mei_hdcp fuse ecdh_generic ecc snd_hda_intel nvidia(PO) snd_intel_dspcfg iwlmvm kvm_intel snd_hda_codec kvm snd_hwdep i2c_i801 irqbypass snd_hda_core i2c_smbus iwlwifi crc32_pclmul snd_pcm mei_me [159490.455571] mei efivarfs [159490.455572] CPU: 6 PID: 961 Comm: irq/144-iwlwifi Tainted: P W O 5.8.18-gentoo-dorellan #1 [159490.455573] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z270M-ITX/ac, BIOS P2.20 05/17/2017 [159490.455576] RIP: 0010:iwl_mvm_rx_tx_cmd+0x43b/0x760 [iwlmvm] [159490.455576] Code: 81 ff ff 4c 8b 54 24 08 41 88 85 e2 17 00 00 e9 01 fe ff ff 66 81 fb 8e 00 40 0f 94 c5 eb 9c 66 81 fb 85 00 40 0f 94 c5 eb 91 <0f> 0b 41 81 4e 28 00 01 00 00 eb 83 4d 89 ee e8 a1 e9 ce cb 48 63 [159490.455577] RSP: 0018:ffffb8e7003d7cd0 EFLAGS: 00010246 [159490.455578] RAX: ffff9573db82ed01 RBX: 0000000000000088 RCX: 000000000045ed16 [159490.455578] RDX: 000000000045ed0e RSI: 000000000045ed0e RDI: 000000000002f040 [159490.455579] RBP: ffff9576bb311e68 R08: 00000000000000ff R09: 0000000000000000 [159490.455579] R10: ffff9574f150cb30 R11: 0000000000000000 R12: ffff957258f975c0 [159490.455580] R13: ffff9576bb311e68 R14: ffff9574f150cb00 R15: ffff9572ef729000 [159490.455580] FS: 0000000000000000(0000) GS:ffff9576ced80000(0000) knlGS:0000000000000000 [159490.455581] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [159490.455581] CR2: 00007fb27f255000 CR3: 000000020d80a006 CR4: 00000000003606e0 [159490.455582] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [159490.455582] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [159490.455583] Call Trace: [159490.455586] iwl_mvm_rx_common+0xd9/0x290 [iwlmvm] [159490.455588] iwl_pcie_rx_handle+0x34b/0x8b0 [iwlwifi] [159490.455590] iwl_pcie_irq_handler+0x1a9/0x760 [iwlwifi] [159490.455591] ? irq_forced_thread_fn+0x70/0x70 [159490.455592] irq_thread_fn+0x1b/0x60 [159490.455593] irq_thread+0xd7/0x160 [159490.455594] ? wake_threads_waitq+0x30/0x30 [159490.455595] ? irq_thread_check_affinity+0x80/0x80 [159490.455596] kthread+0x111/0x150 [159490.455597] ? kthread_park+0x80/0x80 [159490.455598] ret_from_fork+0x22/0x30 [159490.455599] ---[ end trace c0b50996c06f211f ]--- And it seems like it's making my connection to my router drop and reconnect..