Dear wpa_supplicant developers,
I have faced an issue with wpa_supplicant using NetworkManager.
I cannot decide if this behaviour is intended or a bug
but I think it is worth to mention.
I am using Ubuntu 18.04 and I tried to connect to a (WPA2 Enterprise EAP-TLS)
Wi-Fi access point using NetworkManager but it didn't work
so I have started to investigate.
My settings were something like this:
[802-11-wireless]
ssid=SOME_AP
mode=infrastructure
security=802-11-wireless-security
...
[802-1x]
eap=tls
identity=user
client-cert=/path/to/your/private/key/cert.crt
private-key=/path/to/your/private/key/private.pem
private-key-password=
Notice the empty private-key-password field.
What I have found in the logs as symptoms:
journalctl -u NetworkManager
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0361] manager: NetworkManager state is now CONNECTING
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0366] device (wlp1s0): state change: prepare -> config
(reason 'none', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0370] device (wlp1s0): Activation: (wifi) access point
'SOME_AP' has security, but secrets are required.
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0370] device (wlp1s0): state change: config -> need-auth
(reason 'none', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0409] device (wlp1s0): state change: need-auth -> prepare
(reason 'none', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0412] device (wlp1s0): state change: prepare -> config
(reason 'none', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0416] device (wlp1s0): Activation: (wifi) connection
'SOME_AP' has security, and secrets exist. No new secrets needed.
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0416] Config: added 'ssid' value 'SOME_AP'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0416] Config: added 'scan_ssid' value '1'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0416] Config: added 'bgscan' value 'simple:ff:-22:100'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0416] Config: added 'key_mgmt' value 'WPA-EAP'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'eap' value 'TLS'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'fragment_size' value '1266'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'private_key' value
'/path/to/your/private/key/private.pem'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'private_key_passwd' value '<hidden>'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'client_cert' value
'/path/to/your/private/key/cert.crt'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'identity' value 'user'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0417] Config: added 'proactive_key_caching' value '1'
aug 10 14:33:57 my_host NetworkManager[17975]: <warn>
[1565440437.0433] sup-iface[0x55c9d5fcf450,wlp1s0]:
assoc[0x7f281000bb40]: failure to add network: invalid message format
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0434] device (wlp1s0): state change: config -> failed
(reason 'supplicant-failed', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0435] manager: NetworkManager state is now CONNECTED_LOCAL
aug 10 14:33:57 my_host NetworkManager[17975]: <warn>
[1565440437.0441] device (wlp1s0): Activation: failed for connection
'SOME_AP'
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0445] device (wlp1s0): state change: failed ->
disconnected (reason 'none', sys-iface-state: 'managed')
aug 10 14:33:57 my_host NetworkManager[17975]: <info>
[1565440437.0361] manager: NetworkManager state is now CONNECTING
journalctl -u wpa_supplicant.service
aug 07 14:20:08 my_host wpa_supplicant[1035]: wlp1s0: Associated
with ff:f2:1f:dd:ac:10
aug 07 14:20:08 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
aug 07 14:20:08 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-STARTED EAP authentication started
aug 07 14:20:08 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13
aug 07 14:20:08 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
aug 07 14:20:09 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/DC=com/DC=company/CN=CA'
hash=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
aug 07 14:20:09 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-PEER-CERT depth=0
subject='/C=HU/ST=BUDAPEST/L=BUDAPEST/O=COMPANY/OU=SOMETHING/CN=company.com/emailAddress=mail@xxxxxxxxxxx'
hash=bbbbbbbbbbbbbbbbbbbbbbbbbbb
aug 07 14:20:10 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-EAP-FAILURE EAP authentication failed
aug 07 14:20:12 my_host wpa_supplicant[1035]: wlp1s0:
Authentication with ff:f2:1f:dd:ac:10 timed out.
aug 07 14:20:12 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-DISCONNECTED bssid=ff:f2:1f:dd:ac:10 reason=3
locally_generated=1
aug 07 14:20:12 my_host wpa_supplicant[1035]: wlp1s0:
CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="SOME_AP" auth_failures=2
duration=35 reason=AUTH_FAILED
Debug wpa_supplicant.log:
wpa_dbus_dict_get_entry: dict entry key: private_key_passwd
wpa_dbus_dict_get_entry: dict entry variant content type: a
_wpa_dbus_dict_entry_get_array: array_type y
dbus: byte array contents - hexdump(len=0): [REMOVED]
wpas_dbus_handler_add_network[dbus]: control interface couldn't
set network properties
dbus: Unregister network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
I have figured out that this line causes the problem:
https://w1.fi/cgit/hostap/tree/wpa_supplicant/dbus/dbus_new_handlers.c#n210
When I have only used wpa_supplicant to connect to the AP
everything worked well, because wpa_supplicant handled correctly
the password-less private key config from the file.
I think wpa_supplicant will fail every time when empty byte array will be sent
to it via DBus, but if the user creates a wpa_supplicant.conf and leaves
some config fields empty the program can proceed.
My question is: do you think it is a bug?
If it is then I would like to help to fix this issue and
I welcome any suggestions.
Best regards,
Istvan
_______________________________________________
Hostap mailing list
Hostap@xxxxxxxxxxxxxxxxxxx
http://lists.infradead.org/mailman/listinfo/hostap
