[Pkg-utopia-maintainers] Bug#1090181: network-manager: Wi-Fi device is randomly "unavailable" when running Linux 6.11.5+bpo
Vincas Dargis
vindrg at gmail.com
Mon Dec 16 13:57:04 GMT 2024
Package: network-manager
Version: 1.42.4-1
Severity: normal
X-Debbugs-Cc: vindrg at gmail.com
Dear Maintainer,
I use backported kernels to make TL-WN725N and other hardware to work, though I
have discovered that when using Linux 6.11.5+bpo (compared to 6.10 bpo or
official 6.1), SOMETIMES (1/10, 1/5 tries) Wifi USB dongle like WiPi (RT5370)
or TL-WN725N (RTL8188EUS) becomes "unavailable" from NetworkManager's POV after
boot or after plug-in:
nmcli d:
```
wlx000f13371b37 wifi unavailable --
```
journalctl:
```
device (wlx000f13371b37): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
```
This is this failure looks in kernel log when WiPi is beging pluged-in (shows
"associated"!?):
```
# journalctl --no-hostname --output=short-unix -f -k -n0 | tee /tmp/bad.kernel.log
1734352938.030903 kernel: usb 1-1: new high-speed USB device number 7 using xhci_hcd
1734352938.204524 kernel: usb 1-1: New USB device found, idVendor=148f, idProduct=5370, bcdDevice= 1.01
1734352938.210423 kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
1734352938.212519 kernel: usb 1-1: Product: 802.11 n WLAN
1734352938.213760 kernel: usb 1-1: Manufacturer: Ralink
1734352938.215167 kernel: usb 1-1: SerialNumber: 1.0
1734352938.355069 kernel: usb 1-1: reset high-speed USB device number 7 using xhci_hcd
1734352938.516031 kernel: ieee80211 phy2: rt2x00_set_rt: Info - RT chipset 5390, rev 0502 detected
1734352938.548966 kernel: ieee80211 phy2: rt2x00_set_rf: Info - RF chipset 5370 detected
1734352938.550224 kernel: ieee80211 phy2: Selected rate control algorithm 'minstrel_ht'
1734352938.595238 kernel: ieee80211 phy2: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
1734352938.598489 kernel: ieee80211 phy2: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.36
1734352938.826848 kernel: rt2800usb 1-1:1.0 wlx000f13371b37: renamed from wlan2 (while UP)
1734352938.991640 kernel: wlx000f13371b37: authenticate with 8e:aa:b5:f8:fa:e5 (local address=00:0f:13:37:1b:37)
1734352938.991768 kernel: wlx000f13371b37: send auth to 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352938.991803 kernel: wlx000f13371b37: authenticated
1734352939.002836 kernel: wlx000f13371b37: associate with 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352939.002956 kernel: wlx000f13371b37: RX AssocResp from 8e:aa:b5:f8:fa:e5 (capab=0x11 status=17 aid=1)
1734352939.002991 kernel: wlx000f13371b37: 8e:aa:b5:f8:fa:e5 denied association (code=17)
1734352940.719038 kernel: wlx000f13371b37: authenticate with 8e:aa:b5:f8:fa:e5 (local address=00:0f:13:37:1b:37)
1734352940.719290 kernel: wlx000f13371b37: send auth to 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352940.719522 kernel: wlx000f13371b37: authenticated
1734352940.719652 kernel: wlx000f13371b37: associate with 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352940.722936 kernel: wlx000f13371b37: RX AssocResp from 8e:aa:b5:f8:fa:e5 (capab=0x11 status=0 aid=1)
1734352940.728744 kernel: wlx000f13371b37: associated
```
And this is debug NetworkManager log at the same time:
```
# nmcli general logging level debug domains ALL
# systemctl restart NetworkManager
# journalctl --no-hostname --output=short-unix -f -u NetworkManger -n0 | tee /tmp/bad.nm.log
1734352938.579076 NetworkManager[3338]: <debug> [1734352938.5790] wifi-nl80211: NL80211_CMD_GET_WIPHY request failed
1734352938.579141 NetworkManager[3338]: <warn> [1734352938.5791] wifi-wext: can't determine interface name for ifindex 8
1734352938.579274 NetworkManager[3338]: <debug> [1734352938.5792] platform: (wlan0) signal: link added: 8: wlan0 <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver unknown rx:0,0 tx:0,0
1734352938.579359 NetworkManager[3338]: <debug> [1734352938.5793] platform: (wlan0) signal: link removed: 8: wlan0 <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver unknown rx:0,0 tx:0,0
1734352938.579509 NetworkManager[3338]: <debug> [1734352938.5794] platform: (enp2s0) signal: address 4 changed: 192.168.1.13/24 brd 192.168.1.255 lft 449sec pref 449sec lifetime 153-1[601,601] dev 3 flags noprefixroute src kernel
1734352938.579559 NetworkManager[3338]: <debug> [1734352938.5795] l3cfg[c6e917c0dca73818,ifindex=3]: obj-state: appeared in platform: [82240ce30d92d4ad, ip4-address, 192.168.1.13/24 brd* 192.168.1.255 lft 448sec pref 448sec lifetime 153-1[600,600] dev 3 src dhcp], nm-configured, in-platform
1734352938.819939 NetworkManager[3338]: <debug> [1734352938.8198] wifi-nl80211 (wlan2): don't know the meaning of NL80211_ATTR_CIPHER_SUITE 0x000fac0a.
1734352938.819989 NetworkManager[3338]: <debug> [1734352938.8199] wifi-nl80211 (wlan2): don't know the meaning of NL80211_ATTR_CIPHER_SUITE 0x000fac09.
1734352938.820029 NetworkManager[3338]: <debug> [1734352938.8200] wifi-nl80211 (wlan2): don't know the meaning of NL80211_ATTR_CIPHER_SUITE 0x000fac0d.
1734352938.820071 NetworkManager[3338]: <debug> [1734352938.8200] wifi-nl80211 (wlan2): don't know the meaning of NL80211_ATTR_CIPHER_SUITE 0x000fac0b.
1734352938.820111 NetworkManager[3338]: <debug> [1734352938.8200] wifi-nl80211 (wlan2): don't know the meaning of NL80211_ATTR_CIPHER_SUITE 0x000fac0c.
1734352938.820165 NetworkManager[3338]: <debug> [1734352938.8201] wifi-nl80211 (wlan2): using nl80211 for Wi-Fi device control
1734352938.820295 NetworkManager[3338]: <debug> [1734352938.8202] platform: (wlan2) signal: link added: 9: wlan2 <DOWN;broadcast,multicast> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.820424 NetworkManager[3338]: <debug> [1734352938.8204] platform: (wlan2) signal: link changed: 9: wlan2 <UP;broadcast,multicast,up,running> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.820658 NetworkManager[3338]: <debug> [1734352938.8206] platform-linux: UDEV event: action 'add' subsys 'net' device 'wlan0' (8); seqnum=2753
1734352938.820750 NetworkManager[3338]: <debug> [1734352938.8207] udev rfkill event: action 'add' device 'rfkill2'
1734352938.821277 NetworkManager[3338]: <info> [1734352938.8212] rfkill2: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:14.0/usb1/1-1/1-1:1.0/ieee80211/phy2/rfkill2) (driver rt2800usb)
1734352938.821664 NetworkManager[3338]: <debug> [1734352938.8216] Wi-Fi rfkill switch rfkill2 state now 1/unblocked reason: 0x0
1734352938.821694 NetworkManager[3338]: <debug> [1734352938.8216] Wi-Fi rfkill state now 'unblocked'
1734352938.821730 NetworkManager[3338]: <debug> [1734352938.8217] manager: rfkill: Wi-Fi available 1 hw-enabled 1 sw-enabled 1 os-owner 1
1734352938.828821 NetworkManager[3338]: <debug> [1734352938.8287] platform-linux: UDEV event: action 'remove' subsys 'net' device 'wlan0' (8); seqnum=2763
1734352938.828854 NetworkManager[3338]: <debug> [1734352938.8288] platform-linux: udev-remove: IFINDEX=8
1734352938.829167 NetworkManager[3338]: <debug> [1734352938.8291] platform: (wlan2) signal: link changed: 9: wlan2 <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.829510 NetworkManager[3338]: <debug> [1734352938.8294] platform: (wlx000f13371b37) signal: link changed: 9: wlx000f13371b37 <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? not-init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.829647 NetworkManager[3338]: <debug> [1734352938.8296] platform: (enp2s0) signal: address 4 changed: 192.168.1.13/24 brd 192.168.1.255 lft 448sec pref 448sec lifetime 153-1[600,600] dev 3 flags noprefixroute src kernel
1734352938.829697 NetworkManager[3338]: <debug> [1734352938.8296] l3cfg[c6e917c0dca73818,ifindex=3]: obj-state: appeared in platform: [82240ce30d92d4ad, ip4-address, 192.168.1.13/24 brd* 192.168.1.255 lft 448sec pref 448sec lifetime 153-1[600,600] dev 3 src dhcp], nm-configured, in-platform
1734352938.847675 NetworkManager[3338]: <error> [1734352938.8475] iwd-manager[0x563ad12a8a40]: if_nametoindex failed for Name wlan2 for Device at /net/connman/iwd/2/9: 19
1734352938.848885 NetworkManager[3338]: <debug> [1734352938.8488] (wlx000f13371b37) config: backend is "iwd" (iwd support enabled)
1734352938.848999 NetworkManager[3338]: <debug> [1734352938.8489] device[3e30ec222c05f943] (wlx000f13371b37): ifindex: set ifindex 9 (l3cfg: 6c9f0476619a0062)
1734352938.849599 NetworkManager[3338]: <debug> [1734352938.8495] device[3e30ec222c05f943] (wlx000f13371b37): constructed (NMDeviceIwd)
1734352938.849638 NetworkManager[3338]: <debug> [1734352938.8496] device[3e30ec222c05f943] (wlx000f13371b37): start setup of NMDeviceIwd, kernel ifindex 9
1734352938.849676 NetworkManager[3338]: <debug> [1734352938.8496] device[3e30ec222c05f943] (wlx000f13371b37): hw-addr: hardware address now 00:0F:13:37:1B:37
1734352938.849702 NetworkManager[3338]: <debug> [1734352938.8496] device[3e30ec222c05f943] (wlx000f13371b37): hw-addr: update initial MAC address 00:0F:13:37:1B:37
1734352938.849921 NetworkManager[3338]: <debug> [1734352938.8498] platform-linux: error reading net:/sys/class/net/wlx000f13371b37/phys_port_id: error reading 4096 bytes from file descriptor: Operation not supported
1734352938.850211 NetworkManager[3338]: <debug> [1734352938.8501] platform-linux: error reading net:/sys/class/net/wlx000f13371b37/device/sriov_numvfs: Failed to open file "device/sriov_numvfs" with openat: No such file or directory
1734352938.850298 NetworkManager[3338]: <debug> [1734352938.8502] manager: rfkill: Wi-Fi available 1 hw-enabled 1 sw-enabled 1 os-owner 1
1734352938.850325 NetworkManager[3338]: <debug> [1734352938.8503] device[3e30ec222c05f943] (wlx000f13371b37): device now enabled
1734352938.850351 NetworkManager[3338]: <debug> [1734352938.8503] device[3e30ec222c05f943] (wlx000f13371b37): (enable): device blocked by UNMANAGED state
1734352938.850382 NetworkManager[3338]: <debug> [1734352938.8503] device[3e30ec222c05f943] (wlx000f13371b37): unmanaged: flags set to [platform-init,!sleeping=0x4/0x5/unmanaged/unrealized], set-managed [sleeping=0x1])
1734352938.853752 NetworkManager[3338]: <info> [1734352938.8536] manager: (wlx000f13371b37): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/6)
1734352938.880208 NetworkManager[3338]: <debug> [1734352938.8801] platform-linux: UDEV event: action 'add' subsys 'net' device 'wlx000f13371b37' (9); seqnum=2764
1734352938.880571 NetworkManager[3338]: <debug> [1734352938.8805] platform: (wlx000f13371b37) signal: link changed: 9: wlx000f13371b37 <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.880632 NetworkManager[3338]: <debug> [1734352938.8806] device[3e30ec222c05f943] (wlx000f13371b37): queued link change for ifindex 9
1734352938.880933 NetworkManager[3338]: <debug> [1734352938.8809] device[3e30ec222c05f943] (wlx000f13371b37): hw-addr: read permanent MAC address '00:0F:13:37:1B:37'
1734352938.881056 NetworkManager[3338]: <debug> [1734352938.8810] device[3e30ec222c05f943] (wlx000f13371b37): unmanaged: flags set to [platform-init,!sleeping,!user-settings=0x4/0x15/unmanaged], set-managed [user-settings=0x10])
1734352938.881087 NetworkManager[3338]: <debug> [1734352938.8810] device[3e30ec222c05f943] (wlx000f13371b37): unmanaged: flags set to [!sleeping,!platform-init,!user-settings=0x0/0x15/managed], set-managed [platform-init=0x4], reason managed, transition-state)
1734352938.881120 NetworkManager[3338]: <debug> [1734352938.8810] device[3e30ec222c05f943] (wlx000f13371b37): add_pending_action (1): 'queued-state-change-unavailable'
1734352938.881152 NetworkManager[3338]: <debug> [1734352938.8811] device[3e30ec222c05f943] (wlx000f13371b37): queue-state[unavailable, reason:managed, id:1004]: queue state change
1734352938.881193 NetworkManager[3338]: <debug> [1734352938.8811] device[3e30ec222c05f943] (wlx000f13371b37): queue-state[unavailable, reason:managed, id:1004]: change state
1734352938.881219 NetworkManager[3338]: <info> [1734352938.8811] device (wlx000f13371b37): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
1734352938.881244 NetworkManager[3338]: <debug> [1734352938.8812] device[3e30ec222c05f943] (wlx000f13371b37): add_pending_action (2): 'in-state-change'
1734352938.881333 NetworkManager[3338]: <debug> [1734352938.8813] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/accept_ra: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/accept_ra": No such file or directory
1734352938.881377 NetworkManager[3338]: <debug> [1734352938.8813] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/forwarding: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/forwarding": No such file or directory
1734352938.881423 NetworkManager[3338]: <debug> [1734352938.8814] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6": No such file or directory
1734352938.881466 NetworkManager[3338]: <debug> [1734352938.8814] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/hop_limit: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/hop_limit": No such file or directory
1734352938.881508 NetworkManager[3338]: <debug> [1734352938.8814] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/use_tempaddr: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/use_tempaddr": No such file or directory
1734352938.881538 NetworkManager[3338]: <debug> [1734352938.8815] device[3e30ec222c05f943] (wlx000f13371b37): ip6: addrgenmode6: set none
1734352938.881561 NetworkManager[3338]: <debug> [1734352938.8815] platform-linux: link: change 9: user-ipv6ll: set IPv6 address generation mode to none
1734352938.881627 NetworkManager[3338]: <debug> [1734352938.8816] platform-linux: do-request-link: 9
1734352938.881668 NetworkManager[3338]: <debug> [1734352938.8816] platform-linux: rtnl: recvmsg: error message from kernel: Address family not supported by protocol (-97) for request 71
1734352938.881762 NetworkManager[3338]: <debug> [1734352938.8817] platform-linux: do-change-link[9]: failure 97 (Address family not supported by protocol)
1734352938.881787 NetworkManager[3338]: <debug> [1734352938.8817] device[3e30ec222c05f943] (wlx000f13371b37): ip6: addrgenmode6: failed to set none: (not-supported)
1734352938.881812 NetworkManager[3338]: <debug> [1734352938.8817] device[3e30ec222c05f943] (wlx000f13371b37): ip6: addrgenmode6: toggle disable_ipv6 sysctl after disabling addr-gen-mode
1734352938.881857 NetworkManager[3338]: <debug> [1734352938.8818] platform-linux: error reading /proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6: Failed to open file "/proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6": No such file or directory
1734352938.881901 NetworkManager[3338]: <debug> [1734352938.8818] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6': (2) No such file or directory
1734352938.881945 NetworkManager[3338]: <debug> [1734352938.8819] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/accept_ra': (2) No such file or directory
1734352938.881987 NetworkManager[3338]: <debug> [1734352938.8819] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/use_tempaddr': (2) No such file or directory
1734352938.882031 NetworkManager[3338]: <debug> [1734352938.8820] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/forwarding': (2) No such file or directory
1734352938.882056 NetworkManager[3338]: <debug> [1734352938.8820] device[3e30ec222c05f943] (wlx000f13371b37): bringing up device 9
1734352938.882079 NetworkManager[3338]: <debug> [1734352938.8820] platform-linux: link: change 9: flags: set 0x1/0x1 ([up] / [up])
1734352938.889799 NetworkManager[3338]: <debug> [1734352938.8897] platform-linux: do-request-link: 9
1734352938.889938 NetworkManager[3338]: <debug> [1734352938.8899] platform-linux: do-change-link[9]: success
1734352938.890019 NetworkManager[3338]: <debug> [1734352938.8899] device[3e30ec222c05f943] (wlx000f13371b37): preparing device
1734352938.890110 NetworkManager[3338]: <debug> [1734352938.8900] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/disable_ipv6': (2) No such file or directory
1734352938.890153 NetworkManager[3338]: <debug> [1734352938.8901] platform-linux: sysctl: failed to open '/proc/sys/net/ipv6/conf/wlx000f13371b37/use_tempaddr': (2) No such file or directory
1734352938.890195 NetworkManager[3338]: <debug> [1734352938.8901] global-tracker: sync ip4-route
1734352938.890231 NetworkManager[3338]: <debug> [1734352938.8902] global-tracker: sync ip6-route
1734352938.890256 NetworkManager[3338]: <debug> [1734352938.8902] global-tracker: sync mptcp-addr (reapply)
1734352938.890373 NetworkManager[3338]: <debug> [1734352938.8903] global-tracker: sync routing-rule
1734352938.896149 NetworkManager[3338]: <debug> [1734352938.8960] device[3e30ec222c05f943] (wlx000f13371b37): device not yet available for transition to DISCONNECTED
1734352938.896182 NetworkManager[3338]: <debug> [1734352938.8961] device[3e30ec222c05f943] (wlx000f13371b37): connectivity state changed from UNKNOWN to NONE
1734352938.896671 NetworkManager[3338]: <debug> [1734352938.8966] device[3e30ec222c05f943] (wlx000f13371b37): connectivity state changed from UNKNOWN to NONE
1734352938.896928 NetworkManager[3338]: <debug> [1734352938.8969] device[3e30ec222c05f943] (wlx000f13371b37): remove_pending_action (1): 'in-state-change'
1734352938.897029 NetworkManager[3338]: <debug> [1734352938.8970] device[3e30ec222c05f943] (wlx000f13371b37): remove_pending_action (0): 'queued-state-change-unavailable'
1734352938.915286 NetworkManager[3338]: <debug> [1734352938.9151] platform-linux: UDEV event: action 'move' subsys 'net' device 'wlx000f13371b37' (9); seqnum=2767
1734352938.915721 NetworkManager[3338]: <debug> [1734352938.9156] platform: (wlx000f13371b37) signal: link changed: 9: wlx000f13371b37 <UP;broadcast,multicast,up> mtu 1500 arp 1 wifi? init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:0,0 tx:0,0
1734352938.915798 NetworkManager[3338]: <debug> [1734352938.9157] device[3e30ec222c05f943] (wlx000f13371b37): queued link change for ifindex 9
1734352938.979744 NetworkManager[3338]: <debug> [1734352938.9796] device[3e30ec222c05f943] (wlx000f13371b37): wifi-ap: added 00:01:02:00:00:00 "REDACTED" [ a 2 0% __ __ W:0000 R:0188 ] 0.000s sup:/57656c636f6d65546f4368696e61436f6d72616465_psk [nm:/4]
1734352938.980488 NetworkManager[3338]: <debug> [1734352938.9804] device[3e30ec222c05f943] (wlx000f13371b37): wifi-ap: added 00:01:02:00:00:01 "REDACTED" [ a 2 0% __ __ W:0000 R:0188 ] 0.000s sup:/7674676e62632d663866616535_psk [nm:/5]
1734352938.992520 NetworkManager[3338]: <debug> [1734352938.9924] device[3e30ec222c05f943] (wlx000f13371b37): wifi-ap: added 00:01:02:00:00:02 "REDACTED" [ a 2 0% __ __ W:0000 R:0188 ] 0.000s sup:/7674676e62632d393432626666_psk [nm:/6]
1734352940.726109 NetworkManager[3338]: <debug> [1734352940.7260] platform: (wlx000f13371b37) signal: link changed: 9: wlx000f13371b37 <UP,LOWER_UP;broadcast,multicast,up,lowerup> mtu 1500 arp 1 wifi? init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:1,113 tx:0,0
1734352940.726181 NetworkManager[3338]: <debug> [1734352940.7261] device[3e30ec222c05f943] (wlx000f13371b37): queued link change for ifindex 9
1734352940.760782 NetworkManager[3338]: <debug> [1734352940.7607] platform: (wlx000f13371b37) signal: link changed: 9: wlx000f13371b37 <UP,LOWER_UP;broadcast,multicast,up,running,lowerup> mtu 1500 arp 1 wifi? init addr 00:0F:13:37:1B:37 permaddr 00:0F:13:37:1B:37 brd FF:FF:FF:FF:FF:FF driver rt2800usb rx:2,306 tx:2,284
1734352940.762325 NetworkManager[3338]: <debug> [1734352940.7608] device[3e30ec222c05f943] (wlx000f13371b37): queued link change for ifindex 9
```
I am using `wifi.backend=iwd` to avoid some issues in the past.
`wifi.powersave = 2` does not help.
Re-pluging device can make it work, or fail again. It's random.
Restarting NetworkManager might also help.
P.S.: ipv6 errors due to ipv6 being disabled in kernel args.
P.S.P.S.: This is ChatGPT analysis of good.nm.log vs bad.nm.log:
```
Key Observations
1. Device Initialization
Bad Log: The device initialization (rt2800usb) proceeds but doesn't successfully transition to a fully managed state. The device remains stuck at an "unavailable" or "disconnected" state.
Good Log: The device (rt2800usb) transitions cleanly through states: disconnected → prepare → config → ip-config → activated. The device gets an IP address (172.17.255.100) and establishes a connection.
2. Device State Changes
Bad Log: There are repeated state changes between disconnected and unavailable. The log indicates that the supplicant is disconnecting (Activation: failed for connection) early in the process.
Good Log: The device moves through the full activation sequence without any interruptions, and the supplicant successfully completes the handshake.
3. DHCP/IP Assignment
Bad Log: The connection process fails before an IP address can be assigned, and the interface doesn’t proceed to the ip-config stage.
Good Log: The interface successfully configures IPv4, obtaining 172.17.255.100/24.
4. Wi-Fi Backend
Both logs indicate the use of nl80211 for device control and highlight compatibility with the driver (rt2800usb). However:
Bad Log: The connection fails during interaction with the supplicant or hardware.
Good Log: These interactions succeed.
5. RFKill and Device Management
Both Logs: RFKill indicates the device is unblocked and available. However, the bad log seems to drop the device into an unmanaged state repeatedly.
6. NetworkManager Activation
Bad Log: The device fails at the config stage with the error Activation: failed for connection.
Good Log: The activation succeeds, the dispatcher scripts run, and the connection is marked as active (device activated).
```
-- System Information:
Debian Release: 12.8
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 6.11.5+bpo-amd64 (SMP w/2 CPU threads; PREEMPT)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) (ignored: LC_ALL set to en_US.UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
Versions of packages network-manager depends on:
ii adduser 3.134
ii dbus [default-dbus-system-bus] 1.14.10-1~deb12u1
ii libaudit1 1:3.0.9-1
ii libbluetooth3 5.66-1+deb12u2
ii libc6 2.36-9+deb12u9
ii libcurl3-gnutls 7.88.1-10+deb12u8
ii libglib2.0-0 2.74.6-2+deb12u4
ii libgnutls30 3.7.9-2+deb12u3
ii libjansson4 2.14-2
ii libmm-glib0 1.20.4-1
ii libndp0 1.8-1+deb12u1
ii libnewt0.52 0.52.23-1+b1
ii libnm0 1.42.4-1
ii libpsl5 0.21.2-1
ii libreadline8 8.2-1.3
ii libselinux1 3.4-1+b6
ii libsystemd0 252.31-1~deb12u1
ii libteamdctl0 1.31-1
ii libudev1 252.31-1~deb12u1
ii polkitd 122-3
ii udev 252.31-1~deb12u1
Versions of packages network-manager recommends:
pn dnsmasq-base <none>
ii libpam-systemd 252.31-1~deb12u1
ii modemmanager 1.20.4-1
pn ppp <none>
pn wireless-regdb <none>
pn wpasupplicant <none>
Versions of packages network-manager suggests:
pn iptables <none>
pn libteam-utils <none>
Versions of packages network-manager is related to:
ii isc-dhcp-client 4.4.3-P1-2
-- no debconf information
-------------- next part --------------
1734352938.030903 kernel: usb 1-1: new high-speed USB device number 7 using xhci_hcd
1734352938.204524 kernel: usb 1-1: New USB device found, idVendor=148f, idProduct=5370, bcdDevice= 1.01
1734352938.210423 kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
1734352938.212519 kernel: usb 1-1: Product: 802.11 n WLAN
1734352938.213760 kernel: usb 1-1: Manufacturer: Ralink
1734352938.215167 kernel: usb 1-1: SerialNumber: 1.0
1734352938.355069 kernel: usb 1-1: reset high-speed USB device number 7 using xhci_hcd
1734352938.516031 kernel: ieee80211 phy2: rt2x00_set_rt: Info - RT chipset 5390, rev 0502 detected
1734352938.548966 kernel: ieee80211 phy2: rt2x00_set_rf: Info - RF chipset 5370 detected
1734352938.550224 kernel: ieee80211 phy2: Selected rate control algorithm 'minstrel_ht'
1734352938.595238 kernel: ieee80211 phy2: rt2x00lib_request_firmware: Info - Loading firmware file 'rt2870.bin'
1734352938.598489 kernel: ieee80211 phy2: rt2x00lib_request_firmware: Info - Firmware detected - version: 0.36
1734352938.826848 kernel: rt2800usb 1-1:1.0 wlx000f13371b37: renamed from wlan2 (while UP)
1734352938.991640 kernel: wlx000f13371b37: authenticate with 8e:aa:b5:f8:fa:e5 (local address=00:0f:13:37:1b:37)
1734352938.991768 kernel: wlx000f13371b37: send auth to 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352938.991803 kernel: wlx000f13371b37: authenticated
1734352939.002836 kernel: wlx000f13371b37: associate with 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352939.002956 kernel: wlx000f13371b37: RX AssocResp from 8e:aa:b5:f8:fa:e5 (capab=0x11 status=17 aid=1)
1734352939.002991 kernel: wlx000f13371b37: 8e:aa:b5:f8:fa:e5 denied association (code=17)
1734352940.719038 kernel: wlx000f13371b37: authenticate with 8e:aa:b5:f8:fa:e5 (local address=00:0f:13:37:1b:37)
1734352940.719290 kernel: wlx000f13371b37: send auth to 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352940.719522 kernel: wlx000f13371b37: authenticated
1734352940.719652 kernel: wlx000f13371b37: associate with 8e:aa:b5:f8:fa:e5 (try 1/3)
1734352940.722936 kernel: wlx000f13371b37: RX AssocResp from 8e:aa:b5:f8:fa:e5 (capab=0x11 status=0 aid=1)
1734352940.728744 kernel: wlx000f13371b37: associated
More information about the Pkg-utopia-maintainers
mailing list