[Pkg-utopia-maintainers] Bug#842422: network-manager: NetworkManager fails to authenticate with old 802.11bg USB devices

Miguel A. Vallejo ea4eoz at gmail.com
Tue Dec 6 14:08:12 UTC 2016


I just take a USB wifi adapter and tried to connect to my wireless network:





Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.7586]
keyfile: add connection in-memory (7c83331f-74b7-4ef8-98a5-
67bc03e24b36,"EOZWireless2")
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.7954]
device (wlx1c7ee55ecc0a): Activation: starting connection 'EOZWireless2'
(7c83331f-74b7-4ef8-98a5-67bc03e24b36)
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.8158]
keyfile: update /etc/NetworkManager/system-connections/EOZWireless2
(7c83331f-74b7-4ef8-98a5-67bc03e24b36,"EOZWireless2") and persist connection
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.8160]
audit: op="connection-add-activate" uuid="7c83331f-74b7-4ef8-98a5-67bc03e24b36"
name="EOZWireless2" pid=1137 uid=1000 result="success"
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.8213]
device (wlx1c7ee55ecc0a): state change: disconnected -> prepare (reason
'none') [30 40 0]
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.8221]
manager: NetworkManager state is now CONNECTING
Dec  6 14:47:31 waterhole NetworkManager[562]: <info>  [1481032051.8611]
device (wlx1c7ee55ecc0a): set-hw-addr: set-cloned MAC address to
1C:7E:E5:5E:CC:0A (permanent)
Dec  6 14:47:32 waterhole kernel: [  205.121018] IPv6: ADDRCONF(NETDEV_UP):
wlx1c7ee55ecc0a: link is not ready
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0483]
device (wlx1c7ee55ecc0a): state change: prepare -> config (reason 'none')
[40 50 0]
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0494]
device (wlx1c7ee55ecc0a): Activation: (wifi) access point 'EOZWireless2'
has security, but secrets are required.
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0505]
device (wlx1c7ee55ecc0a): state change: config -> need-auth (reason 'none')
[50 60 0]
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0575]
device (wlx1c7ee55ecc0a): state change: need-auth -> prepare (reason
'none') [60 40 0]
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0585]
device (wlx1c7ee55ecc0a): state change: prepare -> config (reason 'none')
[40 50 0]
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0592]
device (wlx1c7ee55ecc0a): Activation: (wifi) connection 'EOZWireless2' has
security, and secrets exist.  No new secrets needed.
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0598]
Config: added 'ssid' value 'EOZWireless2'
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0602]
Config: added 'scan_ssid' value '1'
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0605]
Config: added 'key_mgmt' value 'WPA-PSK'
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0605]
Config: added 'auth_alg' value 'OPEN'
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0605]
Config: added 'psk' value '<omitted>'
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0625]
sup-iface[0x55680e8fe970,wlx1c7ee55ecc0a]: config: set interface ap_scan to
1
Dec  6 14:47:32 waterhole NetworkManager[562]: <info>  [1481032052.0976]
device (wlx1c7ee55ecc0a): supplicant interface state: inactive -> scanning
Dec  6 14:47:36 waterhole wpa_supplicant[614]: wlx1c7ee55ecc0a: SME: Trying
to authenticate with 4c:60:de:6b:c3:0c (SSID='EOZWireless2' freq=5200 MHz)
Dec  6 14:47:36 waterhole kernel: [  209.921607] wlx1c7ee55ecc0a:
authenticate with 4c:60:de:6b:c3:0c
Dec  6 14:47:36 waterhole kernel: [  210.000312] wlx1c7ee55ecc0a: send auth
to 4c:60:de:6b:c3:0c (try 1/3)
Dec  6 14:47:36 waterhole kernel: [  210.001329] wlx1c7ee55ecc0a:
authenticated
Dec  6 14:47:36 waterhole NetworkManager[562]: <info>  [1481032056.9302]
device (wlx1c7ee55ecc0a): supplicant interface state: scanning ->
authenticating
Dec  6 14:47:41 waterhole wpa_supplicant[614]: wlx1c7ee55ecc0a: SME: Deauth
request to the driver failed
Dec  6 14:47:41 waterhole NetworkManager[562]: <info>  [1481032061.9310]
device (wlx1c7ee55ecc0a): supplicant interface state: authenticating ->
disconnected
Dec  6 14:47:42 waterhole NetworkManager[562]: <info>  [1481032062.0313]
device (wlx1c7ee55ecc0a): supplicant interface state: disconnected ->
scanning
Dec  6 14:47:46 waterhole wpa_supplicant[614]: wlx1c7ee55ecc0a: SME: Trying
to authenticate with 4c:60:de:6b:c3:0c (SSID='EOZWireless2' freq=5200 MHz)
Dec  6 14:47:46 waterhole kernel: [  219.838794] wlx1c7ee55ecc0a:
authenticate with 4c:60:de:6b:c3:0c
Dec  6 14:47:46 waterhole kernel: [  219.916673] wlx1c7ee55ecc0a: send auth
to 4c:60:de:6b:c3:0c (try 1/3)
Dec  6 14:47:46 waterhole NetworkManager[562]: <info>  [1481032066.8465]
device (wlx1c7ee55ecc0a): supplicant interface state: scanning ->
authenticating
Dec  6 14:47:46 waterhole kernel: [  219.920717] wlx1c7ee55ecc0a:
authenticated
Dec  6 14:47:51 waterhole wpa_supplicant[614]: wlx1c7ee55ecc0a: SME: Deauth
request to the driver failed
Dec  6 14:47:51 waterhole NetworkManager[562]: <info>  [1481032071.8473]
device (wlx1c7ee55ecc0a): supplicant interface state: authenticating ->
disconnected
Dec  6 14:47:52 waterhole NetworkManager[562]: <info>  [1481032072.3478]
device (wlx1c7ee55ecc0a): supplicant interface state: disconnected ->
scanning
Dec  6 14:47:56 waterhole NetworkManager[562]: <warn>  [1481032076.9259]
device (wlx1c7ee55ecc0a): Activation: (wifi) association took too long,
failing activation
Dec  6 14:47:56 waterhole NetworkManager[562]: <info>  [1481032076.9259]
device (wlx1c7ee55ecc0a): state change: config -> failed (reason
'ssid-not-found') [50 120 53]
Dec  6 14:47:56 waterhole NetworkManager[562]: <info>  [1481032076.9262]
manager: NetworkManager state is now DISCONNECTED
Dec  6 14:47:56 waterhole NetworkManager[562]: <warn>  [1481032076.9269]
device (wlx1c7ee55ecc0a): Activation: failed for connection 'EOZWireless2'
Dec  6 14:47:57 waterhole NetworkManager[562]: <info>  [1481032077.0846]
device (wlx1c7ee55ecc0a): supplicant interface state: scanning ->
disconnected
Dec  6 14:47:57 waterhole NetworkManager[562]: <info>  [1481032077.1177]
device (wlx1c7ee55ecc0a): state change: failed -> disconnected (reason
'none') [120 30 0]
Dec  6 14:47:57 waterhole kernel: [  230.194088] IPv6: ADDRCONF(NETDEV_UP):
wlx1c7ee55ecc0a: link is not ready
Dec  6 14:47:57 waterhole NetworkManager[562]: <info>  [1481032077.1569]
device (wlx1c7ee55ecc0a): set-hw-addr: set MAC address to F2:42:9A:1D:15:0F
(scanning)
Dec  6 14:47:57 waterhole kernel: [  230.409102] IPv6: ADDRCONF(NETDEV_UP):
wlx1c7ee55ecc0a: link is not ready
Dec  6 14:48:00 waterhole wpa_supplicant[614]: wlx1c7ee55ecc0a: Reject scan
trigger since one is already pending





Now I add this line to /etc/udev/rules.d/70-persistent-net.rules

SUBSYSTEM=="net", ACTION=="add", DRIVERS=="?*",
ATTR{address}=="1c:7e:e5:5e:cc:0a",
ATTR{dev_id}=="0x0", ATTR{type}=="1", KERNEL=="wlan*", NAME="wlan0"

And reboot. Now I try to connect to my WiFi and:





Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.3824]
keyfile: add connection in-memory (8216cdfc-65ac-4829-a8e5-
b88c3b67f97d,"EOZWireless2")
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.4463]
device (wlan0): Activation: starting connection 'EOZWireless2'
(8216cdfc-65ac-4829-a8e5-b88c3b67f97d)
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.4948]
keyfile: update /etc/NetworkManager/system-connections/EOZWireless2
(8216cdfc-65ac-4829-a8e5-b88c3b67f97d,"EOZWireless2") and persist connection
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.4951]
audit: op="connection-add-activate" uuid="8216cdfc-65ac-4829-a8e5-b88c3b67f97d"
name="EOZWireless2" pid=1149 uid=1000 result="success"
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.5007]
device (wlan0): state change: disconnected -> prepare (reason 'none') [30
40 0]
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.5015]
manager: NetworkManager state is now CONNECTING
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.5330]
device (wlan0): set-hw-addr: set-cloned MAC address to 1C:7E:E5:5E:CC:0A
(permanent)
Dec  6 14:52:22 waterhole kernel: [  184.784731] IPv6: ADDRCONF(NETDEV_UP):
wlan0: link is not ready
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7068]
device (wlan0): supplicant interface state: inactive -> disabled
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7085]
device (wlan0): state change: prepare -> config (reason 'none') [40 50 0]
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7097]
device (wlan0): Activation: (wifi) access point 'EOZWireless2' has
security, but secrets are required.
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7103]
device (wlan0): state change: config -> need-auth (reason 'none') [50 60 0]
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7175]
device (wlan0): state change: need-auth -> prepare (reason 'none') [60 40 0]
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7184]
device (wlan0): state change: prepare -> config (reason 'none') [40 50 0]
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7190]
device (wlan0): Activation: (wifi) connection 'EOZWireless2' has security,
and secrets exist.  No new secrets needed.
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7197]
Config: added 'ssid' value 'EOZWireless2'
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7201]
Config: added 'scan_ssid' value '1'
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7205]
Config: added 'key_mgmt' value 'WPA-PSK'
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7208]
Config: added 'auth_alg' value 'OPEN'
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7211]
Config: added 'psk' value '<omitted>'
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7448]
sup-iface[0x5589a82cd970,wlan0]: config: set interface ap_scan to 1
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7454]
device (wlan0): supplicant interface state: disabled -> inactive
Dec  6 14:52:22 waterhole NetworkManager[566]: <info>  [1481032342.7874]
device (wlan0): supplicant interface state: inactive -> scanning
Dec  6 14:52:27 waterhole wpa_supplicant[623]: wlan0: SME: Trying to
authenticate with 4c:60:de:6b:c3:0c (SSID='EOZWireless2' freq=5200 MHz)
Dec  6 14:52:27 waterhole kernel: [  189.633092] wlan0: authenticate with
4c:60:de:6b:c3:0c
Dec  6 14:52:27 waterhole kernel: [  189.712344] wlan0: send auth to
4c:60:de:6b:c3:0c (try 1/3)
Dec  6 14:52:27 waterhole kernel: [  189.714213] wlan0: authenticated
Dec  6 14:52:27 waterhole wpa_supplicant[623]: wlan0: Trying to associate
with 4c:60:de:6b:c3:0c (SSID='EOZWireless2' freq=5200 MHz)
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.6396]
device (wlan0): supplicant interface state: scanning -> authenticating
Dec  6 14:52:27 waterhole kernel: [  189.720340] wlan0: associate with
4c:60:de:6b:c3:0c (try 1/3)
Dec  6 14:52:27 waterhole kernel: [  189.721555] wlan0: RX AssocResp from
4c:60:de:6b:c3:0c (capab=0x11 status=0 aid=4)
Dec  6 14:52:27 waterhole wpa_supplicant[623]: wlan0: Associated with
4c:60:de:6b:c3:0c
Dec  6 14:52:27 waterhole kernel: [  189.725727] wlan0: associated
Dec  6 14:52:27 waterhole kernel: [  189.725812] IPv6:
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.6483]
device (wlan0): supplicant interface state: authenticating -> associating
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.6522]
device (wlan0): supplicant interface state: associating -> associated
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.6611]
device (wlan0): supplicant interface state: associated -> 4-way handshake
Dec  6 14:52:27 waterhole wpa_supplicant[623]: wlan0: WPA: Key negotiation
completed with 4c:60:de:6b:c3:0c [PTK=CCMP GTK=CCMP]
Dec  6 14:52:27 waterhole wpa_supplicant[623]: wlan0: CTRL-EVENT-CONNECTED
- Connection to 4c:60:de:6b:c3:0c completed [id=0 id_str=]
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.7114]
device (wlan0): supplicant interface state: 4-way handshake -> completed
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.7115]
device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure)
successful.  Connected to wireless network 'EOZWireless2'.
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.7116]
device (wlan0): state change: config -> ip-config (reason 'none') [50 70 0]
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.7380]
dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Dec  6 14:52:27 waterhole NetworkManager[566]: <info>  [1481032347.8277]
dhcp4 (wlan0): dhclient started with pid 1330
Dec  6 14:52:27 waterhole dhclient[1330]: DHCPDISCOVER on wlan0 to
255.255.255.255 port 67 interval 7
Dec  6 14:52:34 waterhole dhclient[1330]: DHCPDISCOVER on wlan0 to
255.255.255.255 port 67 interval 12
Dec  6 14:52:34 waterhole dhclient[1330]: DHCPREQUEST of 192.168.1.2 on
wlan0 to 255.255.255.255 port 67
Dec  6 14:52:34 waterhole dhclient[1330]: DHCPOFFER of 192.168.1.2 from
192.168.1.1
Dec  6 14:52:34 waterhole dhclient[1330]: DHCPACK of 192.168.1.2 from
192.168.1.1
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7423]
dhcp4 (wlan0):   address 192.168.1.2
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7423]
dhcp4 (wlan0):   plen 24 (255.255.255.0)
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7424]
dhcp4 (wlan0):   gateway 192.168.1.1
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7424]
dhcp4 (wlan0):   server identifier 192.168.1.1
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7424]
dhcp4 (wlan0):   lease time 86400
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7424]
dhcp4 (wlan0):   nameserver '8.8.4.4'
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7425]
dhcp4 (wlan0):   nameserver '8.8.8.8'
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7425]
dhcp4 (wlan0): state changed unknown -> bound
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7473]
device (wlan0): state change: ip-config -> ip-check (reason 'none') [70 80
0]
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7488]
device (wlan0): state change: ip-check -> secondaries (reason 'none') [80
90 0]
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7495]
device (wlan0): state change: secondaries -> activated (reason 'none') [90
100 0]
Dec  6 14:52:34 waterhole dbus[542]: [system] Activating via systemd:
service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-
dispatcher.service'
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.7501]
manager: NetworkManager state is now CONNECTED_LOCAL
Dec  6 14:52:34 waterhole systemd[1]: Starting Network Manager Script
Dispatcher Service...
Dec  6 14:52:34 waterhole dbus[542]: [system] Successfully activated
service 'org.freedesktop.nm_dispatcher'
Dec  6 14:52:34 waterhole systemd[1]: Started Network Manager Script
Dispatcher Service.
Dec  6 14:52:34 waterhole nm-dispatcher: req:1 'connectivity-change': new
request (2 scripts)
Dec  6 14:52:34 waterhole nm-dispatcher: req:1 'connectivity-change': start
running ordered scripts...
Dec  6 14:52:34 waterhole dhclient[1330]: bound to 192.168.1.2 -- renewal
in 37604 seconds.
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.9715]
manager: NetworkManager state is now CONNECTED_GLOBAL
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.9716]
policy: set 'EOZWireless2' (wlan0) as default for IPv4 routing and DNS
Dec  6 14:52:34 waterhole NetworkManager[566]: <info>  [1481032354.9728]
device (wlan0): Activation: successful, device activated.
Dec  6 14:52:34 waterhole nm-dispatcher: req:2 'up' [wlan0]: new request (2
scripts)
Dec  6 14:52:34 waterhole nm-dispatcher: req:2 'up' [wlan0]: start running
ordered scripts...



Everything works just fine.

The problem seems to start here:

wpa_supplicant[614]: wlx1c7ee55ecc0a: SME: Deauth request to the driver
failed

So maybe a wpa_supplicant problem or some WiFi drivers doesn't play well
with long device file names.

I hope this helps someone.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.alioth.debian.org/pipermail/pkg-utopia-maintainers/attachments/20161206/23928f6a/attachment-0001.html>


More information about the Pkg-utopia-maintainers mailing list