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

Vladimir Kudrya pzs-fs at yandex.ru
Fri Oct 28 23:15:38 UTC 2016


Package: network-manager
Version: 1.4.2-2
Severity: normal

Dear Maintainer, NetworkManager fails to connect to wireless network using 802.11bg dongles.
The bug appeared somewhere around september upgrades on stretch (unfortunately, I can not pinpoint).

I am able to connect using wpa_supplicant directly:

	# wpa_supplicant -i wlxXXXXXXXXXXXX  -c /tmp/wpapp 
	Successfully initialized wpa_supplicant
	wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	wlxXXXXXXXXXXXX: Trying to associate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	wlxXXXXXXXXXXXX: Associated with XX:XX:XX:XX:XX:XX
	wlxXXXXXXXXXXXX: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=RU
	wlxXXXXXXXXXXXX: WPA: Key negotiation completed with XX:XX:XX:XX:XX:XX [PTK=CCMP GTK=CCMP]
	wlxXXXXXXXXXXXX: CTRL-EVENT-CONNECTED - Connection to XX:XX:XX:XX:XX:XX completed [id=0 id_str=]
	wlxXXXXXXXXXXXX: WPA: Group rekeying completed with XX:XX:XX:XX:XX:XX [GTK=CCMP]
	wlxXXXXXXXXXXXX: CTRL-EVENT-DISCONNECTED bssid=XX:XX:XX:XX:XX:XX reason=2 locally_generated=1
	wlxXXXXXXXXXXXX: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
	wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	wlxXXXXXXXXXXXX: Trying to associate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	wlxXXXXXXXXXXXX: Associated with XX:XX:XX:XX:XX:XX
	wlxXXXXXXXXXXXX: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=RU
	wlxXXXXXXXXXXXX: WPA: Key negotiation completed with XX:XX:XX:XX:XX:XX [PTK=CCMP GTK=CCMP]
	wlxXXXXXXXXXXXX: CTRL-EVENT-CONNECTED - Connection to XX:XX:XX:XX:XX:XX completed [id=0 id_str=]
	wlxXXXXXXXXXXXX: WPA: Group rekeying completed with XX:XX:XX:XX:XX:XX [GTK=CCMP]
	^CwlxXXXXXXXXXXXX: CTRL-EVENT-DISCONNECTED bssid=XX:XX:XX:XX:XX:XX reason=3 locally_generated=1
	nl80211: deinit ifname=wlxXXXXXXXXXXXX disabled_11b_rates=0
	wlxXXXXXXXXXXXX: CTRL-EVENT-TERMINATING

But when using NetworkManager, authentication fails:

	Oct 29 02:09:02 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	Oct 29 02:09:02 hostname kernel: wlxXXXXXXXXXXXX: authenticate with XX:XX:XX:XX:XX:XX
	Oct 29 02:09:02 hostname NetworkManager[8518]: <info>  [1477696142.2096] device (wlxXXXXXXXXXXXX): supplicant interface state: inactive -> authenticating
	Oct 29 02:09:02 hostname kernel: wlxXXXXXXXXXXXX: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
	Oct 29 02:09:02 hostname kernel: wlxXXXXXXXXXXXX: authenticated
	Oct 29 02:09:07 hostname kernel: wlxXXXXXXXXXXXX: aborting authentication with XX:XX:XX:XX:XX:XX by local choice (Reason: 3=DEAUTH_LEAVING)
	Oct 29 02:09:07 hostname NetworkManager[8518]: <info>  [1477696147.2352] device (wlxXXXXXXXXXXXX): supplicant interface state: authenticating -> disconnected
	Oct 29 02:09:07 hostname NetworkManager[8518]: <info>  [1477696147.3382] device (wlxXXXXXXXXXXXX): supplicant interface state: disconnected -> scanning
	Oct 29 02:09:08 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	Oct 29 02:09:08 hostname kernel: wlxXXXXXXXXXXXX: authenticate with XX:XX:XX:XX:XX:XX
	Oct 29 02:09:08 hostname kernel: wlxXXXXXXXXXXXX: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
	Oct 29 02:09:08 hostname NetworkManager[8518]: <info>  [1477696148.4705] device (wlxXXXXXXXXXXXX): supplicant interface state: scanning -> authenticating
	Oct 29 02:09:08 hostname kernel: wlxXXXXXXXXXXXX: authenticated
	Oct 29 02:09:13 hostname kernel: wlxXXXXXXXXXXXX: aborting authentication with XX:XX:XX:XX:XX:XX by local choice (Reason: 3=DEAUTH_LEAVING)
	Oct 29 02:09:13 hostname NetworkManager[8518]: <info>  [1477696153.4989] device (wlxXXXXXXXXXXXX): supplicant interface state: authenticating -> disconnected
	Oct 29 02:09:14 hostname NetworkManager[8518]: <info>  [1477696154.0034] device (wlxXXXXXXXXXXXX): supplicant interface state: disconnected -> scanning
	Oct 29 02:09:15 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	Oct 29 02:09:15 hostname kernel: wlxXXXXXXXXXXXX: authenticate with XX:XX:XX:XX:XX:XX
	Oct 29 02:09:15 hostname NetworkManager[8518]: <info>  [1477696155.1391] device (wlxXXXXXXXXXXXX): supplicant interface state: scanning -> authenticating
	Oct 29 02:09:15 hostname kernel: wlxXXXXXXXXXXXX: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
	Oct 29 02:09:15 hostname kernel: wlxXXXXXXXXXXXX: authenticated
	Oct 29 02:09:20 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Deauth request to the driver failed
	Oct 29 02:09:20 hostname NetworkManager[8518]: <info>  [1477696160.1797] device (wlxXXXXXXXXXXXX): supplicant interface state: authenticating -> disconnected
	Oct 29 02:09:21 hostname NetworkManager[8518]: <info>  [1477696161.1821] device (wlxXXXXXXXXXXXX): supplicant interface state: disconnected -> scanning
	Oct 29 02:09:22 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	Oct 29 02:09:22 hostname kernel: wlxXXXXXXXXXXXX: authenticate with XX:XX:XX:XX:XX:XX
	Oct 29 02:09:22 hostname NetworkManager[8518]: <info>  [1477696162.3196] device (wlxXXXXXXXXXXXX): supplicant interface state: scanning -> authenticating
	Oct 29 02:09:22 hostname kernel: wlxXXXXXXXXXXXX: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
	Oct 29 02:09:22 hostname kernel: wlxXXXXXXXXXXXX: authenticated
	Oct 29 02:09:27 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Deauth request to the driver failed
	Oct 29 02:09:27 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="wlanssid" auth_failures=1 duration=10 reason=CONN_FAILED
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.3597] device (wlxXXXXXXXXXXXX): supplicant interface state: authenticating -> disconnected
	Oct 29 02:09:27 hostname NetworkManager[8518]: <warn>  [1477696167.3670] device (wlxXXXXXXXXXXXX): Activation: (wifi) association took too long, failing activation
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.3670] device (wlxXXXXXXXXXXXX): state change: config -> failed (reason 'ssid-not-found') [50 120 53]
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.3672] manager: NetworkManager state is now DISCONNECTED
	Oct 29 02:09:27 hostname NetworkManager[8518]: <warn>  [1477696167.3677] device (wlxXXXXXXXXXXXX): Activation: failed for connection 'wlanssid'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.3683] device (wlxXXXXXXXXXXXX): state change: failed -> disconnected (reason 'none') [120 30 0]
	Oct 29 02:09:27 hostname kernel: IPv6: ADDRCONF(NETDEV_UP): wlxXXXXXXXXXXXX: link is not ready
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.3726] device (wlxXXXXXXXXXXXX): set-hw-addr: set MAC address to 46:D1:B8:9E:9C:0B (scanning)
	Oct 29 02:09:27 hostname kernel: IPv6: ADDRCONF(NETDEV_UP): wlxXXXXXXXXXXXX: link is not ready
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.4356] policy: auto-activating connection 'wlanssid'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.4365] device (wlxXXXXXXXXXXXX): Activation: starting connection 'wlanssid' (86cc34b6-46a0-4211-8aed-454e6481fd74)
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.4366] device (wlxXXXXXXXXXXXX): state change: disconnected -> prepare (reason 'none') [30 40 0]
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.4367] manager: NetworkManager state is now CONNECTING
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.4708] device (wlxXXXXXXXXXXXX): set-hw-addr: set-cloned MAC address to 00:1D:60:B1:B4:2D (permanent)
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5293] device (wlxXXXXXXXXXXXX): supplicant interface state: disconnected -> inactive
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5296] device (wlxXXXXXXXXXXXX): state change: prepare -> config (reason 'none') [40 50 0]
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5298] device (wlxXXXXXXXXXXXX): Activation: (wifi) access point 'wlanssid' has security, but secrets are required.
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5298] device (wlxXXXXXXXXXXXX): state change: config -> need-auth (reason 'none') [50 60 0]
	Oct 29 02:09:27 hostname kernel: IPv6: ADDRCONF(NETDEV_UP): wlxXXXXXXXXXXXX: link is not ready
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5364] device (wlxXXXXXXXXXXXX): state change: need-auth -> prepare (reason 'none') [60 40 0]
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5367] device (wlxXXXXXXXXXXXX): state change: prepare -> config (reason 'none') [40 50 0]
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5369] device (wlxXXXXXXXXXXXX): Activation: (wifi) connection 'wlanssid' has security, and secrets exist.  No new secrets needed.
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5369] Config: added 'ssid' value 'wlanssid'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5369] Config: added 'scan_ssid' value '1'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5369] Config: added 'key_mgmt' value 'WPA-PSK'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5369] Config: added 'psk' value '<omitted>'
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5391] sup-iface[0x9911f0,wlxXXXXXXXXXXXX]: config: set interface ap_scan to 1
	Oct 29 02:09:27 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: SME: Trying to authenticate with XX:XX:XX:XX:XX:XX (SSID='wlanssid' freq=2437 MHz)
	Oct 29 02:09:27 hostname kernel: wlxXXXXXXXXXXXX: authenticate with XX:XX:XX:XX:XX:XX
	Oct 29 02:09:27 hostname NetworkManager[8518]: <info>  [1477696167.5675] device (wlxXXXXXXXXXXXX): supplicant interface state: inactive -> authenticating
	Oct 29 02:09:27 hostname kernel: wlxXXXXXXXXXXXX: send auth to XX:XX:XX:XX:XX:XX (try 1/3)
	Oct 29 02:09:27 hostname kernel: wlxXXXXXXXXXXXX: authenticated
	Oct 29 02:09:32 hostname kernel: wlxXXXXXXXXXXXX: aborting authentication with XX:XX:XX:XX:XX:XX by local choice (Reason: 3=DEAUTH_LEAVING)
	Oct 29 02:09:32 hostname wpa_supplicant[22933]: wlxXXXXXXXXXXXX: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="wlanssid" auth_failures=1 duration=10 reason=CONN_FAILED
	Oct 29 02:09:32 hostname NetworkManager[8518]: <info>  [1477696172.5942] device (wlxXXXXXXXXXXXX): supplicant interface state: authenticating -> disconnected


This affects devices:
	07d1:3c0d D-Link System DWA-125 Wireless N 150 Adapter(rev.A1) [Ralink RT3070] (rt2800usb)
	0b05:1723 ASUSTek Computer, Inc. WL-167G v2 802.11g Adapter [Ralink RT2571W] (rt73usb)

Same connection profile works fine for:
	14e4:4727 Network controller: Broadcom Corporation BCM4313 802.11bgn Wireless Network Adapter (rev 01) (bcma-pci-bridge)


-- System Information:
Debian Release: stretch/sid
  APT prefers testing
  APT policy: (900, 'testing'), (400, 'unstable'), (300, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.7.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=ru_RU.UTF-8, LC_CTYPE=ru_RU.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages network-manager depends on:
ii  adduser                3.115
ii  dbus                   1.10.12-1
ii  init-system-helpers    1.45
ii  libaudit1              1:2.6.7-1
ii  libbluetooth3          5.36-1+b3
ii  libc6                  2.24-5
ii  libglib2.0-0           2.50.1-1
ii  libgnutls30            3.5.5-2
ii  libgudev-1.0-0         230-3
ii  libmm-glib0            1.6.2-1
ii  libndp0                1.6-1
ii  libnewt0.52            0.52.19-1
ii  libnl-3-200            3.2.27-1
ii  libnm0                 1.4.2-2
ii  libpam-systemd         231-9
ii  libpolkit-agent-1-0    0.105-17
ii  libpolkit-gobject-1-0  0.105-17
ii  libreadline7           7.0-1
ii  libselinux1            2.5-3
ii  libsoup2.4-1           2.56.0-1
ii  libsystemd0            231-9
ii  libteamdctl0           1.26-1
ii  libuuid1               2.28.2-1
ii  lsb-base               9.20161016
ii  policykit-1            0.105-17
ii  udev                   231-9
ii  wpasupplicant          2.5-2+v2.4-3+b1

Versions of packages network-manager recommends:
ii  crda             3.13-1+b1
ii  dnsmasq-base     2.76-4
ii  iptables         1.6.0-4
pn  iputils-arping   <none>
ii  isc-dhcp-client  4.3.5~b1-1
ii  modemmanager     1.6.2-1
ii  ppp              2.4.7-1+3

Versions of packages network-manager suggests:
pn  libteam-utils  <none>

-- Configuration Files:
/etc/NetworkManager/NetworkManager.conf changed [not included]

-- no debconf information



More information about the Pkg-utopia-maintainers mailing list