On Mon, 13 Jan 2020 at 12:49, Tony Chuang <yhchuang@xxxxxxxxxxx> wrote: > > It seems like the firmware is not responsive, and is not reporting TX > status or consuming H2C commands. > The first trace dump "purge skb(s) not reported by firmware" will be > printed when driver timed-out for TX status report. It could happen > sometimes when driver turns power off too quickly after de-auth sent. > Or firmware just missed it. Originally I was thinking that the TX status > missing means that the firmware is not working, but seems it's not > true. So I think I might lower the print level (WARN() -> rtw_warn()). > > But from your kernel log I can see that the h2c commands failed to > be sent to firmware, which means there's another things that cause > firmware to stall. It will be better if you can turn the debug masks on, > and reproduce it, to help me so see what happened. > To turn the debug masks on: > $ echo 0xffffffff > /sys/module/rtw88/parameters/debug_mask Yet another catch. And it looks like it happened when I switched on/off WiFi in Network manager because the network not worked. https://pastebin.com/pYyswtwT [64440.892201] rtw_pci 0000:05:00.0: wrong bfee role [64440.892280] wlp5s0: associated [66459.825899] rtw_pci 0000:05:00.0: failed to send h2c command [68226.924564] rtw_pci 0000:05:00.0: firmware failed to restore hardware setting [69219.317785] rtw_pci 0000:05:00.0: firmware failed to restore hardware setting [69219.822479] ------------[ cut here ]------------ [69219.822595] purge skb(s) not reported by firmware [69219.822642] WARNING: CPU: 9 PID: 0 at drivers/net/wireless/realtek/rtw88/tx.c:155 rtw_tx_report_purge_timer+0x20/0x50 [rtw88] [69219.822648] Modules linked in: ccm uinput rfcomm xt_CHECKSUM xt_MASQUERADE xt_conntrack ipt_REJECT nf_nat_tftp nf_conntrack_tftp tun bridge stp llc nft_objref nf_conntrack_netbios_ns nf_conntrack_broadcast nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nf_tables_set nft_chain_nat nf_tables ebtable_nat ebtable_broute ip6table_nat ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_raw iptable_security ip_set nfnetlink ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter cmac bnep sunrpc vfat fat edac_mce_amd snd_hda_codec_realtek kvm_amd snd_hda_codec_generic snd_hda_codec_hdmi ledtrig_audio kvm snd_hda_intel rtwpci snd_intel_dspcfg irqbypass rtw88 snd_hda_codec mac80211 btusb snd_hda_core btrtl btbcm crct10dif_pclmul snd_hwdep btintel crc32_pclmul snd_seq snd_seq_device eeepc_wmi bluetooth cfg80211 snd_pcm ghash_clmulni_intel joydev [69219.822689] asus_wmi sparse_keymap snd_timer video wmi_bmof ecdh_generic snd sp5100_tco ecc k10temp pcspkr rfkill soundcore ccp i2c_piix4 libarc4 gpio_amdpt gpio_generic acpi_cpufreq binfmt_misc ip_tables xfs libcrc32c amdgpu amd_iommu_v2 gpu_sched ttm drm_kms_helper drm igb crc32c_intel dca i2c_algo_bit nvme nvme_core wmi pinctrl_amd fuse [69219.822716] CPU: 9 PID: 0 Comm: swapper/9 Not tainted 5.5.0-0.rc6.git2.2.fc32.x86_64 #1 [69219.822719] Hardware name: System manufacturer System Product Name/ROG STRIX X470-I GAMING, BIOS 3004 12/16/2019 [69219.822727] RIP: 0010:rtw_tx_report_purge_timer+0x20/0x50 [rtw88] [69219.822731] Code: 84 00 00 00 00 00 0f 1f 40 00 0f 1f 44 00 00 8b 47 a8 85 c0 75 01 c3 41 54 55 53 48 89 fb 48 c7 c7 20 6b 40 c1 e8 c0 18 d5 e8 <0f> 0b 4c 8d a3 50 ff ff ff 4c 89 e7 e8 5f 25 7e e9 48 8d 7b 98 48 [69219.822735] RSP: 0018:ffffa5b1c03ace48 EFLAGS: 00010286 [69219.822738] RAX: 0000000000000000 RBX: ffff8e3b92c57810 RCX: 0000000000000000 [69219.822741] RDX: ffff8e3bbb5eaf40 RSI: ffff8e3bbb5dc5b8 RDI: 0000000000000300 [69219.822744] RBP: 0000000000000101 R08: 00003ef47eeff977 R09: 0000000000000000 [69219.822748] R10: 0000000000000000 R11: 0000000000000000 R12: ffffa5b1c03aced8 [69219.822751] R13: ffffffffc139a3c0 R14: 00000001041c3868 R15: ffffffffc139a3c0 [69219.822754] FS: 0000000000000000(0000) GS:ffff8e3bbb400000(0000) knlGS:0000000000000000 [69219.822757] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [69219.822760] CR2: 00000d87813a8160 CR3: 0000000661156000 CR4: 00000000003406e0 [69219.822763] Call Trace: [69219.822767] <IRQ> [69219.822776] call_timer_fn+0xaf/0x2c0 [69219.822788] run_timer_softirq+0x1bf/0x5e0 [69219.822794] ? sched_clock_cpu+0xc/0xc0 [69219.822806] __do_softirq+0xe1/0x45d [69219.822815] irq_exit+0xf7/0x100 [69219.822820] smp_apic_timer_interrupt+0xa4/0x230 [69219.822825] apic_timer_interrupt+0xf/0x20 [69219.822828] </IRQ> [69219.822834] RIP: 0010:cpuidle_enter_state+0xce/0x400 [69219.822838] Code: 80 7c 24 0f 00 74 17 9c 58 0f 1f 44 00 00 f6 c4 02 0f 85 0b 03 00 00 31 ff e8 3e 31 8a ff e8 19 c7 91 ff fb 66 0f 1f 44 00 00 <45> 85 ed 0f 88 5c 02 00 00 49 63 d5 4c 2b 64 24 10 48 8d 04 52 48 [69219.822843] RSP: 0018:ffffa5b1c0167e68 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13 [69219.822847] RAX: ffff8e3bb6503380 RBX: ffff8e3baad93000 RCX: 0000000000000000 [69219.822850] RDX: ffff8e3bb6503380 RSI: 0000000000000006 RDI: ffff8e3bb6503380 [69219.822853] RBP: ffffffffab814d60 R08: 00003ef47eed9fb1 R09: 0000000000000000 [69219.822855] R10: 0000000000000000 R11: 0000000000000000 R12: 00003ef47eed9fb1 [69219.822858] R13: 0000000000000002 R14: 0000000000000002 R15: ffff8e3bb6503380 [69219.822871] ? cpuidle_enter_state+0xc7/0x400 [69219.822879] cpuidle_enter+0x29/0x40 [69219.822884] do_idle+0x1e9/0x290 [69219.822892] cpu_startup_entry+0x19/0x20 [69219.822896] start_secondary+0x16e/0x1c0 [69219.822902] secondary_startup_64+0xb6/0xc0 [69219.822915] irq event stamp: 534378571 [69219.822919] hardirqs last enabled at (534378570): [<ffffffffaa00396b>] trace_hardirqs_on_thunk+0x1a/0x1c [69219.822926] hardirqs last disabled at (534378571): [<ffffffffaa003987>] trace_hardirqs_off_thunk+0x1a/0x1c [69219.822929] softirqs last enabled at (534378546): [<ffffffffaa0f4138>] irq_enter+0x68/0x70 [69219.822933] softirqs last disabled at (534378547): [<ffffffffaa0f4237>] irq_exit+0xf7/0x100 [69219.822936] ---[ end trace dc2e3f2642bd6283 ]--- [69220.006376] rtw_pci 0000:05:00.0: timed out to flush queue 2 [69220.006634] rtw_pci 0000:05:00.0: sta 50:ff:20:04:c8:dc with macid 0 left [69222.707299] rtw_pci 0000:05:00.0: stop vif 80:c5:f2:74:cd:51 on port 0 [69226.866078] rtw_pci 0000:05:00.0: start vif 7e:f2:b4:c5:77:d2 on port 0 [69229.508705] rtw_pci 0000:05:00.0: stop vif 7e:f2:b4:c5:77:d2 on port 0 [69229.965361] rtw_pci 0000:05:00.0: start vif 80:c5:f2:74:cd:51 on port 0 [69232.596582] wlp5s0: authenticate with 50:ff:20:04:c8:dc [69232.596610] wlp5s0: capabilities/regulatory prevented using AP HT/VHT configuration, downgraded [69233.038518] wlp5s0: send auth to 50:ff:20:04:c8:dc (try 1/3) [69233.103760] wlp5s0: authenticate with 50:ff:20:04:c8:dc [69233.103810] wlp5s0: send auth to 50:ff:20:04:c8:dc (try 1/3) -- Best Regards, Mike Gavrilov.
