Description
I'm using a Panda Wireless PAU09 to connect to the wireless network in my house. A few months back the connection began to frequently drop about once per day (usually when I step away from the computer for any extended duration - never seen it happen while I'm actively using my browser). The kernel logs complain of "Bad frame size" and I see the standard auth/denied association dance going on whenever I try to reconnect after it drops. Usually I can get it to reconnect with some combination of unplugging the adapter and putting it back, and repeatedly running systemctl restart network-manager, but this usually takes at least a few minutes and has become a total headache. Does anyone have insight into this?
dmesg sample
[166121.015041] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 31092, forcing to 0
[166121.015048] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166121.257902] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 43885, forcing to 0
[166121.257919] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166124.940375] ieee80211 phy0: rt2x00lib_rxdone_read_signal: Warning - Frame received with unrecognized signal, mode=0x0000, signal=0x0024, type=4
[166125.281041] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 56386, forcing to 0
[166125.281057] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166125.618013] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 59985, forcing to 0
[166125.618019] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166128.777756] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 26866, forcing to 0
[166128.777761] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166129.215604] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 64990, forcing to 0
[166129.215621] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166130.579325] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 8584, forcing to 0
[166130.579342] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166136.127939] ieee80211 phy0: rt2800usb_fill_rxdone: Error - Bad frame size 4287, forcing to 0
[166136.127956] ieee80211 phy0: rt2x00lib_rxdone: Error - Wrong frame size 0 max 3840
[166139.454478] wlx9cefd5fddb75: deauthenticating from 2c:7e:81:b3:59:d6 by local choice (Reason: 3=DEAUTH_LEAVING)
[166147.207873] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[166147.230727] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[166147.248256] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[166147.281989] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[166147.303004] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[166147.533469] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d6
[166147.579565] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d6 (try 1/3)
[166147.685373] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d6 (try 2/3)
[166147.687291] wlx9cefd5fddb75: authenticated
[166147.689341] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d6 (try 1/3)
[166147.793355] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d6 (try 2/3)
[166147.797074] wlx9cefd5fddb75: deauthenticated from 2c:7e:81:b3:59:d6 while associating (Reason: 9=STA_REQ_ASSOC_WITHOUT_AUTH)
[166154.898579] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[166154.947996] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[166154.983936] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[166155.012762] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[166155.014262] wlx9cefd5fddb75: authenticated
[166155.017389] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 1/3)
[166155.051826] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 2/3)
[166155.092202] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 3/3)
[166155.139104] wlx9cefd5fddb75: association with 2c:7e:81:b3:59:d7 timed out
[166156.265183] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d6
[166156.309007] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d6 (try 1/3)
[166156.310791] wlx9cefd5fddb75: authenticated
[166156.317270] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d6 (try 1/3)
[166156.318545] wlx9cefd5fddb75: RX AssocResp from 2c:7e:81:b3:59:d6 (capab=0x431 status=1 aid=13196)
[166156.318550] wlx9cefd5fddb75: 2c:7e:81:b3:59:d6 denied association (code=1)
Relevant output from lshw -class network
*-network:1
description: Wireless interface
physical id: 3
bus info: usb@1:7
logical name: wlx9cefd5fddb75
serial: 9c:ef:d5:fd:db:75
capabilities: ethernet physical wireless
configuration: broadcast=yes driver=rt2800usb driverversion=5.11.0-46-generic firmware=0.36 ip=10.0.0.63 link=yes multicast=yes wireless=IEEE 802.11
lsusb
Bus 001 Device 006: ID 148f:5572 Ralink Technology, Corp. RT5572 Wireless Adapter
Edit
Yes, I'm using Ubuntu 20.04...
Tried fixing the BSSID in nm-connection-editor with some luck, the log now shows the same time-out pattern occurring only on one band, which I suppose is an improvement.
After coming out of suspend I had this in the dmesg:
[207659.036487] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[207659.055230] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[207659.075014] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[207659.101415] ieee80211 phy1: rt2800usb_tx_sta_fifo_read_completed: Warning - TX status read failed -75
[207660.294791] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[207660.502811] ieee80211 phy1: rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x1700 with error -110
[207660.618846] ieee80211 phy1: rt2x00usb_vendor_request: Error - Vendor Request 0x07 failed for offset 0x7010 with error -110
[207661.382734] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[207741.869138] audit: type=1400 audit(1650460423.840:48): apparmor="DENIED" operation="capable" profile="/usr/sbin/cups-browsed" pid=1325717 comm="cups-browsed" capability=23 capname="sys_nice"
[208057.100556] ieee80211 phy1: rt2800usb_tx_sta_fifo_read_completed: Warning - TX status read failed -71
[208057.100594] usb 1-7: USB disconnect, device number 6
[208057.100625] ieee80211 phy1: rt2800usb_tx_sta_fifo_read_completed: Warning - TX status read failed -71
[208057.985705] usb 1-7: new high-speed USB device number 7 using xhci_hcd
[208058.150298] usb 1-7: New USB device found, idVendor=148f, idProduct=5572, bcdDevice= 1.01
[208058.150312] usb 1-7: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[208058.150318] usb 1-7: Product: 802.11 n WLAN
[208058.150323] usb 1-7: Manufacturer: Ralink
[208058.150328] usb 1-7: SerialNumber: 1.0
[208058.282122] usb 1-7: reset high-speed USB device number 7 using xhci_hcd
[208058.439617] ieee80211 phy2: rt2x00_set_rt: Info - RT chipset 5592, rev 0222 detected
[208058.453737] ieee80211 phy2: rt2x00_set_rf: Info - RF chipset 000f detected
[208058.453992] ieee80211 phy2: Selected rate control algorithm 'minstrel_ht'
[208058.482103] rt2800usb 1-7:1.0 wlx9cefd5fddb75: renamed from wlan0
[208058.525128] ieee80211 phy2: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
[208058.525180] ieee80211 phy2: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.36
[208065.892111] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208065.914116] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208065.953895] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208065.972076] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[208065.980126] wlx9cefd5fddb75: authenticated
[208065.981692] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 1/3)
[208065.999201] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 2/3)
[208066.031087] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 3/3)
[208066.059169] wlx9cefd5fddb75: association with 2c:7e:81:b3:59:d7 timed out
[208080.876288] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208080.917640] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208081.025697] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208081.044229] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[208081.074218] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[208094.243456] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208094.263815] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208094.291287] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208094.328483] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[208094.360995] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[208116.498095] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208116.544135] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208116.549108] wlx9cefd5fddb75: authenticated
[208116.549411] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 1/3)
[208116.593163] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 2/3)
[208116.637585] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 3/3)
[208116.662568] wlx9cefd5fddb75: association with 2c:7e:81:b3:59:d7 timed out
[208151.460762] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208151.482083] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208151.528267] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208151.584398] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[208151.644985] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[208374.713106] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208374.757534] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208374.800803] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208374.834450] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 3/3)
[208374.853796] wlx9cefd5fddb75: authentication with 2c:7e:81:b3:59:d7 timed out
[208527.390109] wlx9cefd5fddb75: authenticate with 2c:7e:81:b3:59:d7
[208527.430667] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 1/3)
[208527.461753] wlx9cefd5fddb75: send auth to 2c:7e:81:b3:59:d7 (try 2/3)
[208527.468061] wlx9cefd5fddb75: authenticated
[208527.471901] wlx9cefd5fddb75: associate with 2c:7e:81:b3:59:d7 (try 1/3)
[208527.474107] wlx9cefd5fddb75: RX AssocResp from 2c:7e:81:b3:59:d7 (capab=0x411 status=0 aid=3)
[208527.480112] wlx9cefd5fddb75: associated
[208527.580785] wlx9cefd5fddb75: Limiting TX power to 27 (30 - 3) dBm as advertised by 2c:7e:81:b3:59:d7
[208528.514270] IPv6: ADDRCONF(NETDEV_CHANGE): wlx9cefd5fddb75: link becomes ready
The link only became ready after the usual fiddling (repeatedly restarting NetworkManager and pulling the adapter out and putting it back in).
