wpa_supplicant fails to connect with EAP

[Kenny Pearce]

Hello,

I am trying to connect to a WPA enterprise network using wpa_supplicant
and NetworkManager. The authentication persistently times out. Here is
(what I take to be) the relevant portion of /var/log/syslog:

----
Aug 17 11:15:09 parmenides NetworkManager[658]: <info>  NetworkManager state is now CONNECTING
Aug 17 11:15:09 parmenides dbus[709]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Aug 17 11:15:09 parmenides systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 17 11:15:09 parmenides nm-dispatcher: Dispatching action 'down' for wlan21
Aug 17 11:15:10 parmenides NetworkManager[658]: <warn>  Connection disconnected (reason -3)
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  (wlan21): supplicant interface state: completed -> disconnected
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  (wlan21): device state change: prepare -> config (reason 'none') [40 50 0]
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  (wlan21): Activation: (wifi) connection 'VU-Secure' has security, and secrets exist.  No new secrets needed.
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'ssid' value 'VU-Secure'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'scan_ssid' value '1'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'key_mgmt' value 'WPA-EAP'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'auth_alg' value 'OPEN'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'eap' value 'TLS'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'fragment_size' value '1300'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'ca_cert' value '/home/kenny/.certificates/Secure WiFi-CA.pem'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'private_key' value '/home/kenny/.certificates/Secure_WiFiKey.pem'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'private_key_passwd' value '<omitted>'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'client_cert' value '/home/kenny/.certificates/Secure_WiFi.der'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'identity' value 'kpearce at faculty.valpo.edu'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'bgscan' value 'simple:30:-65:300'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: added 'proactive_key_caching' value '1'
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  Config: set interface ap_scan to 1
Aug 17 11:15:10 parmenides NetworkManager[658]: <info>  (wlan21): supplicant interface state: disconnected -> scanning
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: Trying to associate with d8:c7:c8:e9:69:d4 (SSID='VU-Secure' freq=2437 MHz)
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: Association request to the driver failed
Aug 17 11:15:24 parmenides NetworkManager[658]: <info>  (wlan21): supplicant interface state: scanning -> associating
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: Associated with d8:c7:c8:e9:69:d4
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-EAP-STARTED EAP authentication started
Aug 17 11:15:24 parmenides NetworkManager[658]: <info>  (wlan21): supplicant interface state: associating -> associated
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/CN=Valparaiso University Root CA I/O=Lutheran University Association/OU=Information Technology/L=Valparaiso/ST=IN/C=US/emailAddress=network.alerts at valpo.edu'
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/CN=VU-WiFi.valpo.edu/O=Lutheran University Association/OU=Information Technology/L=Valparaiso/ST=IN/C=US/emailAddress=network.alerts at valpo.edu'
Aug 17 11:15:24 parmenides wpa_supplicant[1312]: l2_packet_send - sendto: Message too long
Aug 17 11:15:29 parmenides wpa_supplicant[1312]: l2_packet_send - sendto: Message too long
Aug 17 11:15:34 parmenides wpa_supplicant[1312]: l2_packet_send - sendto: Message too long
Aug 17 11:15:35 parmenides kernel: [87824.003252] rtw_wx_set_mlme
Aug 17 11:15:35 parmenides kernel: [87824.003264] rtw_wx_set_mlme, cmd=0, reason=3
Aug 17 11:15:35 parmenides NetworkManager[658]: <warn>  (wlan21): Activation: (wifi) association took too long
Aug 17 11:15:35 parmenides NetworkManager[658]: <info>  (wlan21): device state change: config -> need-auth (reason 'none') [50 60 0]
Aug 17 11:15:35 parmenides wpa_supplicant[1312]: wlan21: CTRL-EVENT-DISCONNECTED bssid=d8:c7:c8:e9:69:d4 reason=3 locally_generated=1
Aug 17 11:15:35 parmenides NetworkManager[658]: <warn>  (wlan21): Activation: (wifi) asking for new secrets
Aug 17 11:15:35 parmenides wpa_supplicant[1312]: ioctl[SIOCSIWAP]: Operation not permitted
Aug 17 11:15:35 parmenides NetworkManager[658]: <warn>  Connection disconnected (reason -3)
Aug 17 11:15:35 parmenides NetworkManager[658]: <info>  (wlan21): supplicant interface state: associated -> disconnected
Aug 17 11:15:35 parmenides NetworkManager[658]: <warn>  Failed to GDBus.Error:fi.w1.wpa_supplicant1.NotConnected: This interface is not connected: disconnect.
----


The only thing that looks like a significant error to me in this output
is "l2_packet_send - sendto: Message too long" but Googling that message did not lead to any useful hits. Does anyone know what might cause this kind of problem, or how to fix it?

Thanks!

Kenny


-- 
Kenny Pearce
(www.kennypearce.net)
"Wherever law ends tyranny begins." - John Locke