Ok, now we know the cause: ath9k_htc driver
I have a TPL-LINK TL-WN722N V1 for testing purpose and it shows the same "ugly" behavior.
$ hcxdumptool -I
wlan interfaces:
f81a6718410f wlp3s0f0u2 (ath9k_htc)
$ lsusb
ID 0cf3:9271 Qualcomm Atheros Communications AR9271 802.11n
First, the driver is running fine.
$ dmesg
[80662.584198] usb 1-2: new high-speed USB device number 9 using xhci_hcd
[80662.841281] usb 1-2: New USB device found, idVendor=0cf3, idProduct=9271, bcdDevice= 1.08
[80662.841285] usb 1-2: New USB device strings: Mfr=16, Product=32, SerialNumber=48
[80662.841288] usb 1-2: Product: USB2.0 WLAN
[80662.841291] usb 1-2: Manufacturer: ATHEROS
[80662.841293] usb 1-2: SerialNumber: 12345
[80662.929928] usb 1-2: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
[80662.929984] usbcore: registered new interface driver ath9k_htc
[80664.006390] usb 1-2: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
[80664.256290] ath9k_htc 1-2:1.0: ath9k_htc: HTC initialized with 33 credits
[80664.484941] ath9k_htc 1-2:1.0: ath9k_htc: FW Version: 1.4
[80664.484944] ath9k_htc 1-2:1.0: FW RMW support: On
[80664.484946] ath: EEPROM regdomain: 0x809c
[80664.484947] ath: EEPROM indicates we should expect a country code
[80664.484948] ath: doing EEPROM country->regdmn map search
[80664.484949] ath: country maps to regdmn code: 0x52
[80664.484951] ath: Country alpha2 being used: CN
[80664.484952] ath: Regpair used: 0x52
[80664.489654] ieee80211 phy2: Atheros AR9271 Rev:1
[80664.492932] ath9k_htc 1-2:1.0 wlp3s0f0u2: renamed from wlan0
...
but after a while, it died:
[80906.620423] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.623232] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.656349] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.656360] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.734921] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.756039] ath: phy2: Short RX data len, dropping (dlen: 4)
[80912.846741] ath: phy2: Short RX data len, dropping (dlen: 4)
[80912.869528] ath: phy2: Short RX data len, dropping (dlen: 4)
[80918.663242] ath: phy2: Short RX data len, dropping (dlen: 4)
[80918.783277] ath: phy2: Short RX data len, dropping (dlen: 4)
...
[81054.042301] ath: phy2: Short RX data len, dropping (dlen: 5)
[81054.053948] ath: phy2: Short RX data len, dropping (dlen: 4)
[81054.056381] ath: phy2: Short RX data len, dropping (dlen: 4)
...
and spams dmesg log.
At this time hcxdumptool will freeze.
And the whole system died:
Jan 13 16:48:10.888655 tux1 kernel: ------------[ cut here ]------------
Jan 13 16:48:10.888795 tux1 kernel: kernel BUG at mm/slub.c:306!
Jan 13 16:48:10.888894 tux1 kernel: invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
Jan 13 16:48:10.888982 tux1 kernel: CPU: 4 PID: 82264 Comm: hcxdumptool Tainted: P C OE 5.4.10-arch1-1 #1
Jan 13 16:48:10.889027 tux1 kernel: Hardware name: Micro-Star International Co., Ltd. MS-7A33/X370 KRAIT GAMING (MS-7A33), BIOS 1.F0 11/06/2018
Jan 13 16:48:10.889064 tux1 kernel: RIP: 0010:__slab_free+0x262/0x460
Jan 13 16:48:10.889098 tux1 kernel: Code: 00 00 4d 85 c0 0f 85 da 00 00 00 80 7c 24 6b 00 79 09 45 84 c9 0f 84 a5 00 00 00 48 8d 65 d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 <0f> 0b 80 4c 24 6b 80 e9 86 fe ff ff 44 88 5c 24 3b 4c 89 44 24 08
Jan 13 16:48:10.889145 tux1 kernel: RSP: 0018:ffffbd018156bac0 EFLAGS: 00010246
Jan 13 16:48:10.889180 tux1 kernel: RAX: ffffa1792b147c00 RBX: 000000008020001e RCX: ffffa1792b147c00
Jan 13 16:48:10.889215 tux1 kernel: RDX: ffffa1792b147c00 RSI: ffffe4c9ceac5100 RDI: ffffa1798d006d80
Jan 13 16:48:10.889252 tux1 kernel: RBP: ffffbd018156bb70 R08: 0000000000000001 R09: ffffffffa716dd82
Jan 13 16:48:10.889287 tux1 kernel: R10: ffffa17988a71ed8 R11: ffffa1798edaab38 R12: ffffe4c9ceac5100
Jan 13 16:48:10.889321 tux1 kernel: R13: ffffa1792b147c00 R14: ffffa1792b147c00 R15: ffffa1798d006d80
Jan 13 16:48:10.889356 tux1 kernel: FS: 00007f04a2898b80(0000) GS:ffffa1798ed00000(0000) knlGS:0000000000000000
Jan 13 16:48:10.889391 tux1 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 13 16:48:10.889431 tux1 kernel: CR2: 0000560ae2242018 CR3: 00000003adfde000 CR4: 00000000003406e0
Jan 13 16:48:10.889466 tux1 kernel: Call Trace:
Jan 13 16:48:10.889504 tux1 kernel: ? _raw_spin_unlock_irqrestore+0x20/0x40
Jan 13 16:48:10.889532 tux1 kernel: ? try_to_wake_up+0x7a/0x750
Jan 13 16:48:10.889565 tux1 kernel: ? wake_up_q+0x3b/0x60
Jan 13 16:48:10.889599 tux1 kernel: ? ath9k_wmi_cmd+0x1a0/0x1c0 [ath9k_htc]
Jan 13 16:48:10.889634 tux1 kernel: kfree_skb+0x32/0xb0
Jan 13 16:48:10.889668 tux1 kernel: ath9k_wmi_cmd+0x1a0/0x1c0 [ath9k_htc]
Jan 13 16:48:10.889702 tux1 kernel: ath9k_htc_config+0x18b/0x620 [ath9k_htc]
Jan 13 16:48:10.889736 tux1 kernel: ieee80211_hw_config+0x7f/0x3c0 [mac80211]
Jan 13 16:48:10.889775 tux1 kernel: ieee80211_set_monitor_channel+0xf9/0x130 [mac80211]
Jan 13 16:48:10.889810 tux1 kernel: cfg80211_set_monitor_channel+0x72/0x180 [cfg80211]
Jan 13 16:48:10.889844 tux1 kernel: cfg80211_wext_siwfreq+0x10a/0x130 [cfg80211]
Jan 13 16:48:10.889878 tux1 kernel: ioctl_standard_call+0x4c/0x100
Jan 13 16:48:10.889917 tux1 kernel: wext_handle_ioctl+0xc2/0x120
Jan 13 16:48:10.889955 tux1 kernel: sock_ioctl+0x290/0x3f0
Jan 13 16:48:10.889993 tux1 kernel: do_vfs_ioctl+0x43d/0x6c0
Jan 13 16:48:10.890026 tux1 kernel: ? syscall_trace_enter+0x19c/0x2e0
Jan 13 16:48:10.890061 tux1 kernel: ksys_ioctl+0x5e/0x90
Jan 13 16:48:10.890092 tux1 kernel: __x64_sys_ioctl+0x16/0x20
Jan 13 16:48:10.890130 tux1 kernel: do_syscall_64+0x4e/0x140
Jan 13 16:48:10.890164 tux1 kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9
Jan 13 16:48:10.890198 tux1 kernel: RIP: 0033:0x7f04a29b725b
Jan 13 16:48:10.890233 tux1 kernel: Code: 0f 1e fa 48 8b 05 25 9c 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d f5 9b 0c 00 f7 d8 64 89 01 48
Jan 13 16:48:10.890268 tux1 kernel: RSP: 002b:00007ffff26689e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Jan 13 16:48:10.890303 tux1 kernel: RAX: ffffffffffffffda RBX: 0000555b6943a760 RCX: 00007f04a29b725b
Jan 13 16:48:10.890337 tux1 kernel: RDX: 0000555b693f84c0 RSI: 0000000000008b04 RDI: 0000000000000003
Jan 13 16:48:10.890371 tux1 kernel: RBP: 0000555b693f8180 R08: 0000000000000004 R09: 0032753066307333
Jan 13 16:48:10.890402 tux1 kernel: R10: 0000000000000020 R11: 0000000000000246 R12: 0000555b6943a770
Jan 13 16:48:10.890439 tux1 kernel: R13: 0000555b693f72a0 R14: 0000000000002401 R15: 0000000000000003
Jan 13 16:48:10.890474 tux1 kernel: Modules linked in: ath9k_htc ath9k_common ath9k_hw ath mt76x0u mt76x0_common mt76x02_usb mt76_usb mt76x02_lib mt76 mac80211 libarc4 r8188eu(C) lib80211 uas usb_storage nvidia_uvm(OE) fuse cfg80211 rfkill 8021q garp mrp stp snd_hda_codec_hdmi llc nvidia_drm(POE) nvidia_modeset(POE) edac_mce_amd ppdev wmi_bmof mxm_wmi nvidia(POE) snd_hda_codec_realtek kvm snd_hda_codec_generic ledtrig_audio irqbypass snd_hda_intel nls_iso8859_1 snd_intel_nhlt snd_hda_codec nls_cp437 drm_kms_helper vfat snd_hda_core snd_hwdep fat crct10dif_pclmul crc32_pclmul drm snd_pcm r8169 ghash_clmulni_intel agpgart realtek ipmi_devintf aesni_intel ccp snd_timer ipmi_msghandler sp5100_tco snd syscopyarea crypto_simd parport_pc sysfillrect cryptd sysimgblt mousedev input_leds fb_sys_fops libphy glue_helper soundcore pcspkr rng_core k10temp i2c_piix4 parport wmi pinctrl_amd gpio_amdpt evdev mac_hid acpi_cpufreq sg crypto_user ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 hid_generic usbhid hid
Jan 13 16:48:10.890537 tux1 kernel: sr_mod cdrom sd_mod ahci libahci libata xhci_pci crc32c_intel scsi_mod xhci_hcd [last unloaded: 8812au]
Jan 13 16:48:10.890574 tux1 kernel: ---[ end trace 86bae3dfd85f4aad ]---
I have a TPL-LINK TL-WN722N V1 for testing purpose and it shows the same "ugly" behavior.
$ hcxdumptool -I
wlan interfaces:
f81a6718410f wlp3s0f0u2 (ath9k_htc)
$ lsusb
ID 0cf3:9271 Qualcomm Atheros Communications AR9271 802.11n
First, the driver is running fine.
$ dmesg
[80662.584198] usb 1-2: new high-speed USB device number 9 using xhci_hcd
[80662.841281] usb 1-2: New USB device found, idVendor=0cf3, idProduct=9271, bcdDevice= 1.08
[80662.841285] usb 1-2: New USB device strings: Mfr=16, Product=32, SerialNumber=48
[80662.841288] usb 1-2: Product: USB2.0 WLAN
[80662.841291] usb 1-2: Manufacturer: ATHEROS
[80662.841293] usb 1-2: SerialNumber: 12345
[80662.929928] usb 1-2: ath9k_htc: Firmware ath9k_htc/htc_9271-1.4.0.fw requested
[80662.929984] usbcore: registered new interface driver ath9k_htc
[80664.006390] usb 1-2: ath9k_htc: Transferred FW: ath9k_htc/htc_9271-1.4.0.fw, size: 51008
[80664.256290] ath9k_htc 1-2:1.0: ath9k_htc: HTC initialized with 33 credits
[80664.484941] ath9k_htc 1-2:1.0: ath9k_htc: FW Version: 1.4
[80664.484944] ath9k_htc 1-2:1.0: FW RMW support: On
[80664.484946] ath: EEPROM regdomain: 0x809c
[80664.484947] ath: EEPROM indicates we should expect a country code
[80664.484948] ath: doing EEPROM country->regdmn map search
[80664.484949] ath: country maps to regdmn code: 0x52
[80664.484951] ath: Country alpha2 being used: CN
[80664.484952] ath: Regpair used: 0x52
[80664.489654] ieee80211 phy2: Atheros AR9271 Rev:1
[80664.492932] ath9k_htc 1-2:1.0 wlp3s0f0u2: renamed from wlan0
...
but after a while, it died:
[80906.620423] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.623232] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.656349] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.656360] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.734921] ath: phy2: Short RX data len, dropping (dlen: 4)
[80906.756039] ath: phy2: Short RX data len, dropping (dlen: 4)
[80912.846741] ath: phy2: Short RX data len, dropping (dlen: 4)
[80912.869528] ath: phy2: Short RX data len, dropping (dlen: 4)
[80918.663242] ath: phy2: Short RX data len, dropping (dlen: 4)
[80918.783277] ath: phy2: Short RX data len, dropping (dlen: 4)
...
[81054.042301] ath: phy2: Short RX data len, dropping (dlen: 5)
[81054.053948] ath: phy2: Short RX data len, dropping (dlen: 4)
[81054.056381] ath: phy2: Short RX data len, dropping (dlen: 4)
...
and spams dmesg log.
At this time hcxdumptool will freeze.
And the whole system died:
Jan 13 16:48:10.888655 tux1 kernel: ------------[ cut here ]------------
Jan 13 16:48:10.888795 tux1 kernel: kernel BUG at mm/slub.c:306!
Jan 13 16:48:10.888894 tux1 kernel: invalid opcode: 0000 [#1] PREEMPT SMP NOPTI
Jan 13 16:48:10.888982 tux1 kernel: CPU: 4 PID: 82264 Comm: hcxdumptool Tainted: P C OE 5.4.10-arch1-1 #1
Jan 13 16:48:10.889027 tux1 kernel: Hardware name: Micro-Star International Co., Ltd. MS-7A33/X370 KRAIT GAMING (MS-7A33), BIOS 1.F0 11/06/2018
Jan 13 16:48:10.889064 tux1 kernel: RIP: 0010:__slab_free+0x262/0x460
Jan 13 16:48:10.889098 tux1 kernel: Code: 00 00 4d 85 c0 0f 85 da 00 00 00 80 7c 24 6b 00 79 09 45 84 c9 0f 84 a5 00 00 00 48 8d 65 d8 5b 41 5c 41 5d 41 5e 41 5f 5d c3 <0f> 0b 80 4c 24 6b 80 e9 86 fe ff ff 44 88 5c 24 3b 4c 89 44 24 08
Jan 13 16:48:10.889145 tux1 kernel: RSP: 0018:ffffbd018156bac0 EFLAGS: 00010246
Jan 13 16:48:10.889180 tux1 kernel: RAX: ffffa1792b147c00 RBX: 000000008020001e RCX: ffffa1792b147c00
Jan 13 16:48:10.889215 tux1 kernel: RDX: ffffa1792b147c00 RSI: ffffe4c9ceac5100 RDI: ffffa1798d006d80
Jan 13 16:48:10.889252 tux1 kernel: RBP: ffffbd018156bb70 R08: 0000000000000001 R09: ffffffffa716dd82
Jan 13 16:48:10.889287 tux1 kernel: R10: ffffa17988a71ed8 R11: ffffa1798edaab38 R12: ffffe4c9ceac5100
Jan 13 16:48:10.889321 tux1 kernel: R13: ffffa1792b147c00 R14: ffffa1792b147c00 R15: ffffa1798d006d80
Jan 13 16:48:10.889356 tux1 kernel: FS: 00007f04a2898b80(0000) GS:ffffa1798ed00000(0000) knlGS:0000000000000000
Jan 13 16:48:10.889391 tux1 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 13 16:48:10.889431 tux1 kernel: CR2: 0000560ae2242018 CR3: 00000003adfde000 CR4: 00000000003406e0
Jan 13 16:48:10.889466 tux1 kernel: Call Trace:
Jan 13 16:48:10.889504 tux1 kernel: ? _raw_spin_unlock_irqrestore+0x20/0x40
Jan 13 16:48:10.889532 tux1 kernel: ? try_to_wake_up+0x7a/0x750
Jan 13 16:48:10.889565 tux1 kernel: ? wake_up_q+0x3b/0x60
Jan 13 16:48:10.889599 tux1 kernel: ? ath9k_wmi_cmd+0x1a0/0x1c0 [ath9k_htc]
Jan 13 16:48:10.889634 tux1 kernel: kfree_skb+0x32/0xb0
Jan 13 16:48:10.889668 tux1 kernel: ath9k_wmi_cmd+0x1a0/0x1c0 [ath9k_htc]
Jan 13 16:48:10.889702 tux1 kernel: ath9k_htc_config+0x18b/0x620 [ath9k_htc]
Jan 13 16:48:10.889736 tux1 kernel: ieee80211_hw_config+0x7f/0x3c0 [mac80211]
Jan 13 16:48:10.889775 tux1 kernel: ieee80211_set_monitor_channel+0xf9/0x130 [mac80211]
Jan 13 16:48:10.889810 tux1 kernel: cfg80211_set_monitor_channel+0x72/0x180 [cfg80211]
Jan 13 16:48:10.889844 tux1 kernel: cfg80211_wext_siwfreq+0x10a/0x130 [cfg80211]
Jan 13 16:48:10.889878 tux1 kernel: ioctl_standard_call+0x4c/0x100
Jan 13 16:48:10.889917 tux1 kernel: wext_handle_ioctl+0xc2/0x120
Jan 13 16:48:10.889955 tux1 kernel: sock_ioctl+0x290/0x3f0
Jan 13 16:48:10.889993 tux1 kernel: do_vfs_ioctl+0x43d/0x6c0
Jan 13 16:48:10.890026 tux1 kernel: ? syscall_trace_enter+0x19c/0x2e0
Jan 13 16:48:10.890061 tux1 kernel: ksys_ioctl+0x5e/0x90
Jan 13 16:48:10.890092 tux1 kernel: __x64_sys_ioctl+0x16/0x20
Jan 13 16:48:10.890130 tux1 kernel: do_syscall_64+0x4e/0x140
Jan 13 16:48:10.890164 tux1 kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9
Jan 13 16:48:10.890198 tux1 kernel: RIP: 0033:0x7f04a29b725b
Jan 13 16:48:10.890233 tux1 kernel: Code: 0f 1e fa 48 8b 05 25 9c 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d f5 9b 0c 00 f7 d8 64 89 01 48
Jan 13 16:48:10.890268 tux1 kernel: RSP: 002b:00007ffff26689e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Jan 13 16:48:10.890303 tux1 kernel: RAX: ffffffffffffffda RBX: 0000555b6943a760 RCX: 00007f04a29b725b
Jan 13 16:48:10.890337 tux1 kernel: RDX: 0000555b693f84c0 RSI: 0000000000008b04 RDI: 0000000000000003
Jan 13 16:48:10.890371 tux1 kernel: RBP: 0000555b693f8180 R08: 0000000000000004 R09: 0032753066307333
Jan 13 16:48:10.890402 tux1 kernel: R10: 0000000000000020 R11: 0000000000000246 R12: 0000555b6943a770
Jan 13 16:48:10.890439 tux1 kernel: R13: 0000555b693f72a0 R14: 0000000000002401 R15: 0000000000000003
Jan 13 16:48:10.890474 tux1 kernel: Modules linked in: ath9k_htc ath9k_common ath9k_hw ath mt76x0u mt76x0_common mt76x02_usb mt76_usb mt76x02_lib mt76 mac80211 libarc4 r8188eu(C) lib80211 uas usb_storage nvidia_uvm(OE) fuse cfg80211 rfkill 8021q garp mrp stp snd_hda_codec_hdmi llc nvidia_drm(POE) nvidia_modeset(POE) edac_mce_amd ppdev wmi_bmof mxm_wmi nvidia(POE) snd_hda_codec_realtek kvm snd_hda_codec_generic ledtrig_audio irqbypass snd_hda_intel nls_iso8859_1 snd_intel_nhlt snd_hda_codec nls_cp437 drm_kms_helper vfat snd_hda_core snd_hwdep fat crct10dif_pclmul crc32_pclmul drm snd_pcm r8169 ghash_clmulni_intel agpgart realtek ipmi_devintf aesni_intel ccp snd_timer ipmi_msghandler sp5100_tco snd syscopyarea crypto_simd parport_pc sysfillrect cryptd sysimgblt mousedev input_leds fb_sys_fops libphy glue_helper soundcore pcspkr rng_core k10temp i2c_piix4 parport wmi pinctrl_amd gpio_amdpt evdev mac_hid acpi_cpufreq sg crypto_user ip_tables x_tables ext4 crc32c_generic crc16 mbcache jbd2 hid_generic usbhid hid
Jan 13 16:48:10.890537 tux1 kernel: sr_mod cdrom sd_mod ahci libahci libata xhci_pci crc32c_intel scsi_mod xhci_hcd [last unloaded: 8812au]
Jan 13 16:48:10.890574 tux1 kernel: ---[ end trace 86bae3dfd85f4aad ]---