See also https://bugs.launchpad.net/ubuntu/wily/+source/network-manager/+bug/1499827
-- You received this bug notification because you are a member of Ubuntu Touch seeded packages, which is subscribed to wpa in Ubuntu. https://bugs.launchpad.net/bugs/1501588 Title: Wily's wpasupplicant frequently fails on WPA enterprise networks Status in hostap: Unknown Status in wpa package in Ubuntu: Confirmed Bug description: Ever since I upgraded from vivid to wily on my laptop, I'm running into problems when connecting to my home WPA2 enterprise network. Typically the first connection immediately after the driver is loaded works as expected, however any further reconnection and the occasional roaming between APs cause wpasupplicant to freeze entirely requiring me to kill it and most often also reload my wireless driver to get things working again. ## A failed (hanging) association looks like: Sep 30 23:31:06 castiana NetworkManager[25815]: <info> (wlan0): Activation: (wifi) connection 'stgraber.net-secure' has security, and secrets exist. No new secrets needed. Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'ssid' value 'stgraber.net-secure' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'scan_ssid' value '1' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'key_mgmt' value 'WPA-EAP' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'eap' value 'TLS' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'fragment_size' value '1300' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'ca_cert' value '/home/stgraber/data/certs/stgraber-radius/ca.crt' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'private_key' value '/home/stgraber/data/certs/stgraber-radius/castiana.p12' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'private_key_passwd' value '<omitted>' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'identity' value 'castiana' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'bgscan' value 'simple:30:-65:300' Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: added 'proactive_key_caching' value '1' Sep 30 23:31:06 castiana NetworkManager[25815]: <warn> Connection disconnected (reason -3) Sep 30 23:31:06 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: associated -> disconnected Sep 30 23:31:06 castiana NetworkManager[25815]: <warn> Failed to GDBus.Error:fi.w1.wpa_supplicant1.NotConnected: This interface is not connected: disconnect. Sep 30 23:31:06 castiana NetworkManager[25815]: <warn> Failed to GDBus.Error:fi.w1.wpa_supplicant1.NotConnected: This interface is not connected: disconnect. Sep 30 23:31:06 castiana NetworkManager[25815]: <info> Config: set interface ap_scan to 1 Sep 30 23:31:06 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: disconnected -> scanning Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: SME: Trying to authenticate with 24:a4:3c:c8:69:03 (SSID='stgraber.net-secure' freq=2412 MHz) Sep 30 23:31:07 castiana kernel: [102903.079940] wlan0: authenticate with 24:a4:3c:c8:69:03 Sep 30 23:31:07 castiana kernel: [102903.085128] wlan0: send auth to 24:a4:3c:c8:69:03 (try 1/3) Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: Trying to associate with 24:a4:3c:c8:69:03 (SSID='stgraber.net-secure' freq=2412 MHz) Sep 30 23:31:07 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: scanning -> authenticating Sep 30 23:31:07 castiana kernel: [102903.086942] wlan0: authenticated Sep 30 23:31:07 castiana kernel: [102903.090103] wlan0: associate with 24:a4:3c:c8:69:03 (try 1/3) Sep 30 23:31:07 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: authenticating -> associating Sep 30 23:31:07 castiana kernel: [102903.101962] wlan0: RX AssocResp from 24:a4:3c:c8:69:03 (capab=0x411 status=0 aid=1) Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: Associated with 24:a4:3c:c8:69:03 Sep 30 23:31:07 castiana kernel: [102903.103701] wlan0: associated Sep 30 23:31:07 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: associating -> associated Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13 Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=stgraber.net Root CA/name=stgraber.net Infrastructure Root CA/emailAddress=stgra...@stgraber.org' hash=87b9750baadddac7f05164d7fde3a0eb3d3efe0c948b430a3ecd093c629956e9 Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=radius/name=stgraber.net Infrastructure Root CA/emailAddress=stgra...@stgraber.org' hash=1fc5a4237c625f445a8eaf3794d4ee475d47dd7be31301a0215ee9701dee46e0 Sep 30 23:31:07 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=freeradius01/name=stgraber.net Internal Infrastructure Radius CA/emailAddress=stgra...@stgraber.org' hash=9fa224ec6e74510d80257cc4dd43e660e0015642959b2fdea8995cbc71c6abf8 Sep 30 23:31:07 castiana wpa_supplicant[25653]: l2_packet_send - sendto: Message too long Sep 30 23:31:28 castiana wpa_supplicant[25653]: message repeated 3 times: [ l2_packet_send - sendto: Message too long] Sep 30 23:31:31 castiana NetworkManager[25815]: <warn> (wlan0): Activation: (wifi) association took too long Sep 30 23:31:31 castiana NetworkManager[25815]: <info> (wlan0): device state change: config -> failed (reason 'no-secrets') [50 120 7] Sep 30 23:31:31 castiana NetworkManager[25815]: <info> NetworkManager state is now CONNECTED_LOCAL Sep 30 23:31:31 castiana kernel: [102927.404913] wlan0: deauthenticating from 24:a4:3c:c8:69:03 by local choice (Reason: 3=DEAUTH_LEAVING) Sep 30 23:31:31 castiana NetworkManager[25815]: <warn> (wlan0): Activation: failed for connection 'stgraber.net-secure' Sep 30 23:31:31 castiana NetworkManager[25815]: <info> (wlan0): device state change: failed -> disconnected (reason 'none') [120 30 0] Sep 30 23:31:31 castiana wpa_supplicant[25653]: wlan0: CTRL-EVENT-DISCONNECTED bssid=24:a4:3c:c8:69:03 reason=3 locally_generated=1 Sep 30 23:31:31 castiana NetworkManager[25815]: <info> Device 'wlan0' has no connection; scheduling activate_check in 0 seconds. Sep 30 23:31:31 castiana NetworkManager[25815]: <warn> Connection disconnected (reason -3) Sep 30 23:31:31 castiana NetworkManager[25815]: <info> (wlan0): supplicant interface state: associated -> disconnected Sep 30 23:31:31 castiana kernel: [102927.422121] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready Sep 30 23:31:31 castiana NetworkManager[25815]: <warn> Failed to GDBus.Error:fi.w1.wpa_supplicant1.NotConnected: This interface is not connected: disconnect. ## A successful association (as seen after restart wpasupplicant) looks like: Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): Activation: (wifi) connection 'stgraber.net-secure' has security, and secrets exist. No new secrets needed. Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'ssid' value 'stgraber.net-secure' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'scan_ssid' value '1' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'key_mgmt' value 'WPA-EAP' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'eap' value 'TLS' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'fragment_size' value '1300' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'ca_cert' value '/home/stgraber/data/certs/stgraber-radius/ca.crt' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'private_key' value '/home/stgraber/data/certs/stgraber-radius/castiana.p12' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'private_key_passwd' value '<omitted>' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'identity' value 'castiana' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'bgscan' value 'simple:30:-65:300' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: added 'proactive_key_caching' value '1' Oct 1 00:21:49 castiana NetworkManager[9615]: <info> Config: set interface ap_scan to 1 Oct 1 00:21:49 castiana kernel: [105943.745716] wlan0: authenticate with 24:a4:3c:c8:69:13 Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: SME: Trying to authenticate with 24:a4:3c:c8:69:13 (SSID='stgraber.net-secure' freq=5805 MHz) Oct 1 00:21:49 castiana kernel: [105943.756236] wlan0: send auth to 24:a4:3c:c8:69:13 (try 1/3) Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): supplicant interface state: inactive -> authenticating Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: Trying to associate with 24:a4:3c:c8:69:13 (SSID='stgraber.net-secure' freq=5805 MHz) Oct 1 00:21:49 castiana kernel: [105943.842803] wlan0: authenticated Oct 1 00:21:49 castiana kernel: [105943.845837] wlan0: associate with 24:a4:3c:c8:69:13 (try 1/3) Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: Associated with 24:a4:3c:c8:69:13 Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): supplicant interface state: authenticating -> associating Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started Oct 1 00:21:49 castiana kernel: [105943.846886] wlan0: RX AssocResp from 24:a4:3c:c8:69:13 (capab=0x11 status=0 aid=1) Oct 1 00:21:49 castiana kernel: [105943.848105] wlan0: associated Oct 1 00:21:49 castiana kernel: [105943.848134] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): supplicant interface state: associating -> associated Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13 Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=stgraber.net Root CA/name=stgraber.net Infrastructure Root CA/emailAddress=stgra...@stgraber.org' hash=87b9750baadddac7f05164d7fde3a0eb3d3efe0c948b430a3ecd093c629956e9 Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=radius/name=stgraber.net Infrastructure Root CA/emailAddress=stgra...@stgraber.org' hash=1fc5a4237c625f445a8eaf3794d4ee475d47dd7be31301a0215ee9701dee46e0 Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=CA/ST=Quebec/L=Montreal/O=stgraber.net/OU=Internal Infrastructure/CN=freeradius01/name=stgraber.net Internal Infrastructure Radius CA/emailAddress=stgra...@stgraber.org' hash=9fa224ec6e74510d80257cc4dd43e660e0015642959b2fdea8995cbc71c6abf8 Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully Oct 1 00:21:49 castiana wpa_supplicant[9608]: nl80211: Unexpected encryption algorithm 5 Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): supplicant interface state: associated -> 4-way handshake Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: WPA: Key negotiation completed with 24:a4:3c:c8:69:13 [PTK=CCMP GTK=CCMP] Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-CONNECTED - Connection to 24:a4:3c:c8:69:13 completed [id=0 id_str=] Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): supplicant interface state: 4-way handshake -> completed Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'stgraber.net-secure'. Oct 1 00:21:49 castiana NetworkManager[9615]: <info> (wlan0): device state change: config -> ip-config (reason 'none') [50 70 0] Oct 1 00:21:49 castiana gnome-session[1907]: (deja-dup-monitor:5926): GLib-CRITICAL **: Source ID 1789 was not found when attempting to remove it Oct 1 00:21:49 castiana wpa_supplicant[9608]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-63 noise=9999 txrate=9000 ProblemType: Bug DistroRelease: Ubuntu 15.10 Package: wpasupplicant 2.4-0ubuntu2 ProcVersionSignature: Ubuntu 4.2.0-11.13-generic 4.2.1 Uname: Linux 4.2.0-11-generic x86_64 NonfreeKernelModules: zfs zunicode zcommon znvpair zavl ApportVersion: 2.19-0ubuntu1 Architecture: amd64 CurrentDesktop: Unity Date: Thu Oct 1 00:24:02 2015 InstallationDate: Installed on 2015-04-23 (160 days ago) InstallationMedia: Ubuntu 15.04 "Vivid Vervet" - Release amd64 (20150422) SourcePackage: wpa UpgradeStatus: No upgrade log present (probably fresh install) To manage notifications about this bug go to: https://bugs.launchpad.net/hostap/+bug/1501588/+subscriptions -- Mailing list: https://launchpad.net/~touch-packages Post to : touch-packages@lists.launchpad.net Unsubscribe : https://launchpad.net/~touch-packages More help : https://help.launchpad.net/ListHelp
