Bug 1570903

Summary: Attribute type 213 has an invalid length
Product: [Fedora] Fedora Reporter: Vitaly <vitaly>
Component: wpa_supplicantAssignee: Davide Caratti <dcaratti>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 27CC: bgalvani, blueowl, dac-bugzilla, dcaratti, dcbw, h.reindl, john.j5live, keesdejong+dev, lkundrak, ng0177, pauloedgarcastro, rrankin, sanjay.ankur, vitaly
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: wpa_supplicant-2.6-16.fc28 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-06-28 14:08:53 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Vitaly 2018-04-23 16:40:31 UTC 
Description of problem:
Cannot run soft-AP using wpa_supplicant and Network Manager with WPA2 encryption.

Version-Release number of selected component (if applicable):
wpa_supplicant-2.6-13.fc27.x86_64

How reproducible:
Always.

Steps to Reproduce:
1. Add "Wi-Fi (shared)" network connection using Network Manager.
2. Set AP name and channel.
3. Enable WPA2 Personal Wi-Fi protection and set strong password.
4. Run created AP profile using Network Manager.
5. Try to connect to created AP from Android device or another PC/notebook.

Actual results:
Successful connection.

Expected results:
Authentication error and lot's of error messages in journalctl -b logs:

kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.

Additional info:
With disabled encryption everything works fine.
Comment 1 Davide Caratti 2018-04-24 07:00:20 UTC 
(just a guessing at the moment), but probably we need this commit:

commit a2426829c
Author: Jouni Malinen <jouni.com>
Date:   Fri Dec 1 20:22:44 2017 +0200

    nl80211: Fix NL80211_ATTR_SMPS_MODE encoding
    
I will try reproducing in the next hours and followup.

Thanks!
regards,
-- 
davide
Comment 2 ng0177 2018-05-01 15:44:14 UTC 
Hi, after creating a Hotspot via nm-connection-editor on fc28 and trying to connect to it from another device (camera), I keep seeing

kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.

and the connection fails. Any advice? Thanks!
Comment 3 Davide Caratti 2018-05-02 12:39:12 UTC 
(In reply to Davide Caratti from comment #1)
> (just a guessing at the moment), but probably we need this commit:
> 
> commit a2426829c
> Author: Jouni Malinen <jouni.com>
> Date:   Fri Dec 1 20:22:44 2017 +0200
> 
>     nl80211: Fix NL80211_ATTR_SMPS_MODE encoding
>     
> I will try reproducing in the next hours and followup.

hello,

I couldn't reproduce this using my android devices. Can you try the rpms at [1] and check if:

1) they are fixing the 'attribute 213 has invalid lenght issue?
2) they are fixing the connection failures?

thank you in advance for the collaboration!
Comment 4 Davide Caratti 2018-05-02 12:39:48 UTC 
rpms at: [1] https://koji.fedoraproject.org/koji/taskinfo?taskID=26725252
Comment 5 Vitaly 2018-05-02 13:35:22 UTC 
Rebuilt for F27 and installed:
$ rpm -qa wpa_supplicant
wpa_supplicant-2.6-14.fc27.rh1570903.x86_64

Now no errors in log, but still cannot connect from my Android devices (Android 5.1.1 and Android 6.0) due to authentication error.
Comment 6 ng0177 2018-05-02 17:23:35 UTC 
Installation of wpa_supplicant-2.6-14.fc29.rh1570903.x86_64.rpm on F28 leaves

1) unfixed

kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
wpa_supplicant[898]: wlo1: AP-STA-CONNECTED 

2) no connection when checking w/ arp -a
Comment 7 Paulo Castro 2018-05-06 19:56:13 UTC 
+1. Same here.
Comment 8 Davide Caratti 2018-05-07 17:45:57 UTC 
(In reply to ng0177 from comment #6)
> Installation of wpa_supplicant-2.6-14.fc29.rh1570903.x86_64.rpm on F28 leaves
> 
> 1) unfixed
> 
> kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
> kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
> wpa_supplicant[898]: wlo1: AP-STA-CONNECTED 
> 
> 2) no connection when checking w/ arp -a

I think that issue 2) and 1) are unrelated. Issue 2) is similar to

https://bugzilla.redhat.com/show_bug.cgi?id=1571256

I would like to understand if Issue 1) is correctly identified as per comment #1 or not. Can you please try

# systemctl restart wpa_supplicant.service

after the RPM at https://koji.fedoraproject.org/koji/taskinfo?taskID=26725252 has been updated?
thanks!
-- 
davide
Comment 9 Paulo Castro 2018-05-07 19:37:07 UTC 
Installed wpa_supplicant-2.6-14.fc29.rh1570903.x86_64.rpm. Don't see the "type 213" message anymore.
Issue is still there though and I'm starting to suspect @david is right.

NetworkManager running in debug mode doesn't spew any logging when try to connect from Android to the AP.

wpa_supplicant on the other hand...

<log>
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: KEK - hexdump(len=16): [REMOVED]
WPA: TK - hexdump(len=16): [REMOVED]
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKCALCNEGOTIATING2
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKINITNEGOTIATING
hostapd_logger: STA 04:d6:aa:15:ca:62 - sending 3/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=1 pairwise=1 kde_len=94 keyidx=1 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 02
Plaintext EAPOL-Key Key Data - hexdump(len=104): [REMOVED]
WPA: Use EAPOL-Key timeout of 100 ms (retry counter 1)
wlp8s0: Event EAPOL_TX_STATUS (38) received
hostapd_logger: STA 04:d6:aa:15:ca:62 - EAPOL-Key timeout
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKINITNEGOTIATING
hostapd_logger: STA 04:d6:aa:15:ca:62 - sending 3/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=1 pairwise=1 kde_len=94 keyidx=1 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 03
Plaintext EAPOL-Key Key Data - hexdump(len=104): [REMOVED]
WPA: Use EAPOL-Key timeout of 1000 ms (retry counter 2)
wlp8s0: Event EAPOL_TX_STATUS (38) received
hostapd_logger: STA 04:d6:aa:15:ca:62 - EAPOL-Key timeout
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKINITNEGOTIATING
hostapd_logger: STA 04:d6:aa:15:ca:62 - sending 3/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=1 pairwise=1 kde_len=94 keyidx=1 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 04
Plaintext EAPOL-Key Key Data - hexdump(len=104): [REMOVED]
WPA: Use EAPOL-Key timeout of 1000 ms (retry counter 3)
wlp8s0: Event EAPOL_TX_STATUS (38) received
hostapd_logger: STA 04:d6:aa:15:ca:62 - EAPOL-Key timeout
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKINITNEGOTIATING
hostapd_logger: STA 04:d6:aa:15:ca:62 - sending 3/4 msg of 4-Way Handshake
WPA: Send EAPOL(version=2 secure=1 mic=1 ack=1 install=1 pairwise=1 kde_len=94 keyidx=1 encr=1)
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 05
Plaintext EAPOL-Key Key Data - hexdump(len=104): [REMOVED]
WPA: Use EAPOL-Key timeout of 1000 ms (retry counter 4)
wlp8s0: Event EAPOL_TX_STATUS (38) received
hostapd_logger: STA 04:d6:aa:15:ca:62 - EAPOL-Key timeout
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state PTKINITNEGOTIATING
hostapd_logger: STA 04:d6:aa:15:ca:62 - PTKINITNEGOTIATING: Retry limit 4 reached
WPA: 04:d6:aa:15:ca:62 WPA_PTK entering state DISCONNECT
wpa_sta_disconnect STA 04:d6:aa:15:ca:62
hostapd_wpa_auth_disconnect: WPA authenticator requests disconnect: STA 04:d6:aa:15:ca:62 reason 2
wlp8s0: ap_sta_disconnect addr 04:d6:aa:15:ca:62 reason=2
nl80211: send_mlme - da= 04:d6:aa:15:ca:62 noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
nl80211: send_mlme -> send_frame
nl80211: send_frame - Use bss->freq=2447
nl80211: send_frame -> send_frame_cmd
hostapd_logger: STA 04:d6:aa:15:ca:62 - event 3 notification
wpa_driver_nl80211_set_key: ifindex=3 (wlp8s0) alg=0 addr=0x5641abf6b7f0 key_idx=0 set_tx=1 seq_len=0 key_len=0
   addr=04:d6:aa:15:ca:62
wlp8s0: ap_sta_disconnect: reschedule ap_handle_timer timeout for 04:d6:aa:15:ca:62 (5 seconds - AP_MAX_INACTIVITY_AFTER_DEAUTH)
</log>

I'm using the same phone I was using some months ago when connecting it to the Wireless AP worked. True that in between I've upgraded Fedora and the phone software.
Comment 10 ng0177 2018-05-10 10:57:42 UTC 
systemctl restart wpa_supplicant.service following installation of wpa_supplicant-2.6-14.fc29.rh1570903.x86_64.rpm on F28 alleviates indeed "type 213" messages but connection is still not possible.

wpasupplicant 2.6-15 on Ubuntu 18.04 is working.
Comment 11 Ankur Sinha (FranciscoD) 2018-05-23 16:48:47 UTC 
Hello,

I *think* I'm seeing this too when trying to create a hotspot. 

wpa_supplicant-2.6-15.fc28.x86_64. I think this is the relevant bit:

May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.1590] device (wlp0s20u5): Activation: starting connection 'Hotspot' (d93ba6d6-fc20-493b-95b2-b4dc86f53c6d)
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <warn>  [1527093802.1606] sup-iface[0x5619b9276590,wlp0s20u5]: connection disconnected (reason -3)
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.1608] device (wlp0s20u5): supplicant interface state: completed -> disconnected
May 23 17:43:22 cs-as14aho-2-herts-ac-uk dbus-daemon[723]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.10' (uid=0 pid=796 comm="/usr/sbi>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.1654] device (wlp0s20u5): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Starting Network Manager Script Dispatcher Service...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk dbus-daemon[723]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Started Network Manager Script Dispatcher Service.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? add>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk nm-dispatcher[31435]: req:1 'down' [wlp0s20u5]: new request (6 scripts)
May 23 17:43:22 cs-as14aho-2-herts-ac-uk nm-dispatcher[31435]: req:1 'down' [wlp0s20u5]: start running ordered scripts...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Stopping Sendmail Mail Transport Client...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Stopped Sendmail Mail Transport Client.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sm-client comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? re>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Stopping Sendmail Mail Transport Agent...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Stopped Sendmail Mail Transport Agent.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sendmail comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Starting Sendmail Mail Transport Agent...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.2265] device (wlp0s20u5): set-hw-addr: reset MAC address to E8:4E:06:1A:0E:F8 (preserve)
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: CTRL-EVENT-SCAN-FAILED ret=-100
May 23 17:43:22 cs-as14aho-2-herts-ac-uk sendmail[31468]: starting daemon (8.15.2): SMTP+queueing@01:00:00
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Started Sendmail Mail Transport Agent.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sendmail comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? re>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Starting Sendmail Mail Transport Client...
May 23 17:43:22 cs-as14aho-2-herts-ac-uk sm-msp-queue[31487]: starting daemon (8.15.2): queueing@01:00:00
May 23 17:43:22 cs-as14aho-2-herts-ac-uk systemd[1]: Started Sendmail Mail Transport Client.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sm-client comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? r>
May 23 17:43:22 cs-as14aho-2-herts-ac-uk kernel: IPv6: ADDRCONF(NETDEV_UP): wlp0s20u5: link is not ready
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3510] device (wlp0s20u5): supplicant interface state: disconnected -> disabled
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3516] device (wlp0s20u5): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3518] device (wlp0s20u5): Activation: (wifi) access point 'Hotspot' has security, but secrets are required.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3518] device (wlp0s20u5): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3574] device (wlp0s20u5): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3584] device (wlp0s20u5): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3588] device (wlp0s20u5): Activation: (wifi) connection 'Hotspot' has security, and secrets exist.  No new secrets needed.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3588] Config: added 'ssid' value 'Hotspot'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3589] Config: added 'mode' value '2'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3589] Config: added 'frequency' value '2412'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3589] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3589] Config: added 'psk' value '<hidden>'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3589] Config: added 'ieee80211w' value '1'
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: Note: nl80211 driver interface is not designed to be used with ap_scan=2; this can result in connection failures
May 23 17:43:22 cs-as14aho-2-herts-ac-uk NetworkManager[796]: <info>  [1527093802.3643] device (wlp0s20u5): supplicant interface state: disabled -> disconnected
May 23 17:43:22 cs-as14aho-2-herts-ac-uk kernel: IPv6: ADDRCONF(NETDEV_UP): wlp0s20u5: link is not ready
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: Using interface wlp0s20u5 with hwaddr e8:4e:06:1a:0e:f8 and ssid "Hotspot"
May 23 17:43:22 cs-as14aho-2-herts-ac-uk kernel: netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: Interface initialization failed
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: interface state UNINITIALIZED->DISABLED
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: AP-DISABLED
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: Unable to setup interface.
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: Failed to initialize AP interface
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: interface state DISABLED->DISABLED
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: wlp0s20u5: AP-DISABLED
May 23 17:43:22 cs-as14aho-2-herts-ac-uk wpa_supplicant[1509]: hostapd_free_hapd_data: Interface wlp0s20u5 wasn't started
May 23 17:43:23 cs-as14aho-2-herts-ac-uk kernel: IPv6: ADDRCONF(NETDEV_UP): wlp0s20u5: link is not ready


(And then it's gone and connected to an existing wifi network).
Comment 12 Doug 2018-05-25 17:44:31 UTC 
I'm running into the same issue after upgrading from F27 to F28 on my Lenovo W530 laptop, wifi hotspot is no longer functional...  dmesg excerpt:

[14327.781745] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[14327.880564] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[14327.882821] netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
[14327.933517] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Comment 13 Harald Reindl 2018-05-27 10:07:09 UTC 
this is a kernel issue introduced with 4.16.x or even 4.15.x and also affects hostapd - but without any real issue, all is working as expected but demsg spits useless messages

https://bugzilla.redhat.com/show_bug.cgi?id=1582839

hostapd-2.6-19.fc27.20180514.rh.x86_64
Comment 14 ng0177 2018-05-27 11:49:48 UTC 
The issue is that the creation of a hotspot in Fedora 28 fails (at least for me).
Comment 15 Kees de Jong 2018-05-31 05:45:10 UTC 
(In reply to ng0177 from comment #14)
> The issue is that the creation of a hotspot in Fedora 28 fails (at least for
> me).

Same here.
Comment 16 Doug 2018-06-11 20:53:34 UTC 
Follow on comment...

1. Running with Fedora 28, with kernel 4.16.14 on Lenovo W530

2. Not using hostapd.  Configuring ap hotspot with nm-connection-editor, with WPA2 security set; enabled wifi & hotspot from gnome-control-center.  I get the 'attribute type 212 has an invalid length' in dmesg, hotspot does not work.

[  125.982663] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[  126.062146] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[  126.063009] netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
[  126.095380] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0



3.  Ran nm-connection-editor again, but with WiFi Security set to None.  Hotspot does work in this case!   Although the 'attribute type 212 has an invalid length' is logged.  And have Wifi without any security   :-(

[ 2125.545095] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[ 2125.846339] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[ 2125.923816] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
[ 2125.924800] netlink: 'wpa_supplicant': attribute type 213 has an invalid length.
[ 2125.927637] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready


Harald is right, the msg is a red herring, but hotspot is certainly broken with security enabled.
Comment 17 Davide Caratti 2018-06-12 17:35:58 UTC 
(In reply to Doug from comment #16)
> Follow on comment...
> 
> 1. Running with Fedora 28, with kernel 4.16.14 on Lenovo W530
> 
> 2. Not using hostapd.  Configuring ap hotspot with nm-connection-editor,
> with WPA2 security set; enabled wifi & hotspot from gnome-control-center.  I
> get the 'attribute type 212 has an invalid length' in dmesg, hotspot does
> not work.
> 
> [  125.982663] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
> [  126.062146] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
> [  126.063009] netlink: 'wpa_supplicant': attribute type 213 has an invalid
> length.
> [  126.095380] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0

dmesg log is not telling enough information to us, it would be better to understand what's happening in wpa_supplicant. Please try: 

OTHER_ARGS="-s -dddddd"


in /etc/sysconfig/wpa_supplicant, then 
# systemctl restart wpa_supplicant.service
# journalctl -u wpa_supplicant -f
# <activate the hotspot using NM>

and provide the journalctl log.  


> 3.  Ran nm-connection-editor again, but with WiFi Security set to None. 
> Hotspot does work in this case!   Although the 'attribute type 212 has an
> invalid length' is logged.  And have Wifi without any security   :-(

this, together with the WPA-PSK-SHA256 setting of comment #11, makes me think it's worth seeing what happens when PMF are turned off. Can you please try 

# nmcli connection edit <name of the hotspot>
> nmcli 

> [ 2125.545095] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
> [ 2125.846339] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
> [ 2125.923816] IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
> [ 2125.924800] netlink: 'wpa_supplicant': attribute type 213 has an invalid
> length.
> [ 2125.927637] IPv6: ADDRCONF(NETDEV_CHANGE): wlp3s0: link becomes ready
> 
> 
> Harald is right, the msg is a red herring, but hotspot is certainly broken
> with security enabled.

can you try disabling PMF as follows?

 # nmcli connection edit <your hotspot>
 > set 802-11-wireless-security.pmf disable
 > save
 > activate

thanks!

--
davide
Comment 18 Harald Reindl 2018-06-12 17:49:20 UTC 
my self-built hostapd with the patch from this bugreport has no problems, config below, i even run two hostapd-instances with a faked-device on my Qualcomm Atheros AR5418 Wireless Network Adapter

----------------------------

that one creates "wlan1" and assgines for both old HP-ILO MAC's to appear as "Hewlett Packard" in scanners - to get that work you need most params like channel identical for both hostapd instances and no dynamic channel selection

well, thats a machine with 7 phyiscla NIC#s and a dozen of virtual devices playing router/firewall/switch/poe-adapter :-)

[root@srv-rhsoft:/etc/systemd/system]$ cat /etc/systemd/system/hostapd-guest-interface.service
[Unit]
Description=Wireless-AP Guest Interface
After=network.service systemd-networkd.service network-online.target network-guest-bridge.service
Before=hostapd.service hostapd-guest.service

[Service]
Type=oneshot
RemainAfterExit=yes
Environment="COUNTRY=AT"
MemoryDenyWriteExecute=yes
ExecStart=/usr/bin/true
ExecStartPre=/usr/sbin/iw reg set AT
ExecStartPost=/usr/sbin/iw phy phy0 interface add wlan1 type managed
ExecStartPost=/usr/sbin/ifconfig wlan0 hw ether 28:92:4a:2b:5d:44
ExecStartPost=/usr/sbin/ifconfig wlan1 hw ether 28:92:4a:2b:5d:45

[Install]
WantedBy=multi-user.target

----------------------------

[root@srv-rhsoft:~]$ cat /etc/hostapd/hostapd.conf
interface=wlan0
bridge=br-lan
ssid=****
wpa_passphrase=****

ap_isolate=1
macaddr_acl=1
accept_mac_file=/etc/hostapd/accept

ctrl_interface=/run/hostapd
ctrl_interface_group=0
auth_algs=1
wpa=2
rsn_pairwise=CCMP
ignore_broadcast_ssid=0
driver=nl80211
hw_mode=g
channel=12
country_code=AT
max_num_sta=30
logger_syslog=1
logger_syslog_level=2

ieee80211d=1
ieee80211h=1
ieee80211n=1
ieee80211ac=1
wme_enabled=1
wmm_enabled=1
disassoc_low_ack=1
obss_interval=2

require_ht=1
ht_capab=[HT20][HT40-][SHORT-GI-40][DSSS_CCK-40][MAX-AMSDU-3839]
Comment 19 Doug 2018-06-12 18:42:14 UTC 
(In reply to Davide Caratti from comment #17)
> dmesg log is not telling enough information to us, it would be better to
> understand what's happening in wpa_supplicant. Please try: 
> 
> OTHER_ARGS="-s -dddddd"
> 
> 
> in /etc/sysconfig/wpa_supplicant, then 
> # systemctl restart wpa_supplicant.service
> # journalctl -u wpa_supplicant -f
> # <activate the hotspot using NM>
> 
> and provide the journalctl log.  




Here's the excerpt from journalctl.
I scrubbed the system name and ssid.  Look for the "Interface initialization failed" line.


Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Interface up
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: Event INTERFACE_ENABLED (26) received
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: Interface was enabled
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: State: INTERFACE_DISABLED -> DISCONNECTED
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Set wlp3s0 operstate 0->0 (DORMANT)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: Setting scan request: 0.000000 sec
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: No enabled networks - do not scan
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: State: DISCONNECTED -> INACTIVE
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1) [ssv]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: properties_get_or_set: Set(ApScan)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: Note: nl80211 driver interface is not designed to be used with ap_scan=2; this can result in connection failures
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1) [a{sv}]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_open_read: start reading a dict entry
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: frequency
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: i
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_fill_value_from_variant: int32 value: 2412
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: frequency=2412 (0x96c)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: ssid - hexdump_ascii(len=5):
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]:      
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: PSK (ASCII passphrase) - hexdump_ascii(len=8): [REMOVED]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: ieee80211w
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: i
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_fill_value_from_variant: int32 value: 1
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: ieee80211w=1 (0x1)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: ssid
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: a
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_entry_get_array: array_type y
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: dbus: byte array contents - hexdump(len=5): [REMOVED]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: mode
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: i
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_fill_value_from_variant: int32 value: 2
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: mode=2 (0x2)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: psk
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: s
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_fill_value_from_variant: string value: [omitted]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: PSK (from passphrase) - hexdump(len=32): [REMOVED]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry key: key_mgmt
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wpa_dbus_dict_get_entry: dict entry variant content type: s
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: _wpa_dbus_dict_fill_value_from_variant: string value: [omitted]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: key_mgmt: 0x102
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1) [o]
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: Setting scan request: 0.000000 sec
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: wlp3s0: State: INACTIVE -> SCANNING
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: Setting up AP (SSID='ZZZZZ')
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 3 (AP)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Failed to set interface 3 to mode 3: -16 (Device or resource busy)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Try mode change after setting interface down
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 3 (AP)
Jun 12 13:49:11 ZZZ wpa_supplicant[13327]: nl80211: Mode change succeeded while interface is down
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Unsubscribe mgmt frames handle 0x8888dec6fa0e2c49 (start AP)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Setup AP(wlp3s0) - device_ap_sme=0 use_monitor=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Subscribe to mgmt frames with AP handle 0x564e7289ab80
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xb0 (WLAN_FC_STYPE_AUTH) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x0 (WLAN_FC_STYPE_ASSOC_REQ) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x20 (WLAN_FC_STYPE_REASSOC_REQ) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xa0 (WLAN_FC_STYPE_DISASSOC) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xc0 (WLAN_FC_STYPE_DEAUTH) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x40 (WLAN_FC_STYPE_PROBE_REQ) nl_handle=0x564e7289ab80 match=
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=04
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=0501
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=0504
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=06
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=08
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=09
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=0a
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=11
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7289ab80 match=7f
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set freq 2412 (ht_enabled=0, vht_enabled=0, bandwidth=0 MHz, cf1=0 MHz, cf2=0 MHz)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * freq=2412
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * vht_enabled=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * ht_enabled=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * channel_type=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: phy: phy0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: BSS count 1, BSSID mask 00:00:00:00:00:00 (0 bits)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Regulatory information - country=US (DFS-FCC)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 2402-2472 @ 40 MHz 30 mBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 5170-5250 @ 80 MHz 23 mBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 5250-5330 @ 80 MHz 23 mBm (DFS)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 5490-5730 @ 160 MHz 23 mBm (DFS)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: ssid - hexdump_ascii(len=5):
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:      
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 5735-5835 @ 80 MHz 30 mBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: 57240-63720 @ 2160 MHz 40 mBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Added 802.11b mode based on 802.11g information
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=1 freq=2412 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=2 freq=2417 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=3 freq=2422 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=4 freq=2427 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=5 freq=2432 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=6 freq=2437 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=7 freq=2442 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=8 freq=2447 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=9 freq=2452 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=10 freq=2457 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=11 freq=2462 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=1 freq=2412 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=2 freq=2417 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=3 freq=2422 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=4 freq=2427 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=5 freq=2432 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=6 freq=2437 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=7 freq=2442 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=8 freq=2447 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=9 freq=2452 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=10 freq=2457 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=11 freq=2462 MHz max_tx_power=30 dBm
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Completing interface initialization
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Mode: IEEE 802.11g  Channel: 1  Frequency: 2412 MHz
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: DFS 0 channels required radar detection
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set freq 2412 (ht_enabled=1, vht_enabled=0, bandwidth=20 MHz, cf1=2412 MHz, cf2=0 MHz)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * freq=2412
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * vht_enabled=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * ht_enabled=1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * sec_channel_offset=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * channel_type=1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[0] rate=10 flags=0x1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[1] rate=20 flags=0x1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[2] rate=55 flags=0x1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[3] rate=110 flags=0x1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[4] rate=60 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[5] rate=90 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[6] rate=120 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[7] rate=180 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[8] rate=240 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[9] rate=360 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[10] rate=480 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RATE[11] rate=540 flags=0x0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_setup_bss(hapd=0x564e728b2960 (wlp3s0), first=1)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Flushing old station entries
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: flush -> DEL_STATION wlp3s0 (all)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Deauthenticate all stations
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme - da= ff:ff:ff:ff:ff:ff noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme -> send_frame
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame - Use bss->freq=2412
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame -> send_frame_cmd
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: CMD_FRAME freq=2412 wait=0 no_cck=0 no_ack=0 offchanok=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: CMD_FRAME - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 02 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Frame command failed: ret=-16 (Device or resource busy) (freq=2412 wait=0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Using interface wlp3s0 with hwaddr 6c:88:14:a2:2d:74 and ssid "ZZZZZ"
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS: Use configured UUID - hexdump(len=16): 48 50 6c ee de f4 57 ae b0 87 13 b2 cc 9f 86 63
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS: Build Beacon IEs
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Wi-Fi Protected Setup State (2)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Device Name
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Primary Device Type
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS: Build Probe Response IEs
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Wi-Fi Protected Setup State (2)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Response Type (3)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * UUID-E
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Manufacturer
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Model Name
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Model Number
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Serial Number
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Primary Device Type
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Device Name
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Config Methods (3108)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Get randomness: len=32 entropy=70
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: GMK - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Get randomness: len=32 entropy=38
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Key Counter - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: Delay group state machine start until Beacon frames have been configured
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS: Building WPS IE for (Re)Association Response
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Response Type (3)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set beacon (beacon_set=0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Beacon head - hexdump(len=56): 80 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 00 00 00 00 00 00 00 00 64 00 11 
04 00 05 ff ff ff ff ff 01 08 82 84 8b 96 0c 12 18 24 03 01 01
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Beacon tail - hexdump(len=198): 2a 01 04 32 04 30 48 60 6c 30 1c 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 02 00 00 0f ac 02 00 0f
 ac 06 8c 00 dd 1a 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 04 00 50 f2 02 01 00 00 50 f2 02 2d 1a 7c 00 17 ff ff 00 00 00 00 00 00 00 00 2c 01 01 00 00 00 00 00 00 00 00 00 00 3d 16 0
1 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 08 00 00 00 00 00 00 00 40 dd 18 00 50 f2 02 01 01 00 00 03 a4 00 00 27 a4 00 00 42 43 5d 00 62 32 2e 00 dd 29 00 50 f2 
04 10 4a 00 01 10 10 44 00 01 02 10 49 00 06 00 37 2a 00 01 20 10 11 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: ifindex=3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: beacon_int=100
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: dtim_period=2
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * beacon_int=100
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:   * dtim_period=2
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: hidden SSID not in use
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: privacy=1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: auth_algs=0x3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: wpa_version=0x3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: key_mgmt_suites=0x102
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: pairwise_ciphers=0x18
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: group_cipher=0x8
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: SMPS mode - off
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: beacon_ies - hexdump(len=53): 7f 08 00 00 00 00 00 00 00 40 dd 29 00 50 f2 04 10 4a 00 01 10 10 44 00 01 02 10 49 00 06 00 37 2a 00 01 2
0 10 11 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: proberesp_ies - hexdump(len=104): 7f 08 00 00 00 00 00 00 00 40 dd 5c 00 50 f2 04 10 4a 00 01 10 10 44 00 01 02 10 3b 00 01 03 10 47 00 
10 48 50 6c ee de f4 57 ae b0 87 13 b2 cc 9f 86 63 10 21 00 01 20 10 23 00 01 20 10 24 00 01 20 10 42 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00 10 11 00 01 20 10 08 00 02 31 08 10 49 00
 06 00 37 2a 00 01 20
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: assocresp_ies - hexdump(len=36): 7f 08 00 00 00 00 00 00 00 40 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 0
1 20
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: Start group state machine to set initial keys
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state GTK_INIT (VLAN-ID 0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Get randomness: len=16 entropy=6
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: GTK - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Get randomness: len=16 entropy=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: IGTK - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state SETKEYSDONE (VLAN-ID 0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=2 addr=0x564e71c8a454 key_idx=1 set_tx=1 seq_len=0 key_len=32
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: KEY_DATA - hexdump(len=32): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:    broadcast key
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=4 addr=0x564e71c8a454 key_idx=4 set_tx=1 seq_len=0 key_len=16
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:    broadcast key
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: set_key failed; err=-22 Invalid argument)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state FATAL_FAILURE
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Flushing old station entries
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: flush -> DEL_STATION wlp3s0 (all)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Deauthenticate all stations
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme - da= ff:ff:ff:ff:ff:ff noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme -> send_frame
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame - Use bss->freq=2412
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame -> send_frame_cmd
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: CMD_FRAME freq=2412 wait=0 no_cck=0 no_ack=0 offchanok=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: CMD_FRAME - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 03 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Frame TX command accepted; cookie 0x15
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_free_hapd_data(wlp3s0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Interface initialization failed
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: interface state UNINITIALIZED->DISABLED
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: AP-DISABLED
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Unable to setup interface.
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: Failed to initialize AP interface
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_interface_deinit(0x564e728c10f0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: interface state DISABLED->DISABLED
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_bss_deinit: deinit bss wlp3s0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: Deauthenticate all stations
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme - da= ff:ff:ff:ff:ff:ff noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_mlme -> send_frame
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame - Use bss->freq=2412
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: send_frame -> send_frame_cmd
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: CMD_FRAME freq=2412 wait=0 no_cck=0 no_ack=0 offchanok=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: CMD_FRAME - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 03 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Frame TX command accepted; cookie 0x16
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: AP-DISABLED
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_cleanup(hapd=0x564e728b2960 (wlp3s0))
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_free_hapd_data: Interface wlp3s0 wasn't started
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_interface_free(0x564e728c10f0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_interface_free: free hapd 0x564e728b2960
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_cleanup_iface(0x564e728c10f0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_cleanup_iface_partial(0x564e728c10f0)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: hostapd_cleanup_iface: free iface=0x564e728c10f0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Remove beacon (ifindex=3)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 2 (STATION)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Failed to set interface 3 to mode 2: -16 (Device or resource busy)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Try mode change after setting interface down
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 2 (STATION)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Mode change succeeded while interface is down
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Teardown AP(wlp3s0) - device_ap_sme=0 use_monitor=0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Unsubscribe mgmt frames handle 0x8888dec6fa012309 (AP teardown)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Subscribe to mgmt frames with non-AP handle 0x564e7286a4c0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=040a
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=040b
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=040c
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=040d
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=090a
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=090b
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=090c
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=090d
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0409506f9a09
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=7f506f9a09
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0801
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=06
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0a07
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0a11
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=1101
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=1102
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0505
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e7286a4c0 match=0500
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: CTRL-EVENT-DISCONNECTED bssid=6c:88:14:a2:2d:74 reason=3 locally_generated=1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wlp3s0: State: SCANNING -> DISCONNECTED
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Set wlp3s0 operstate 0->0 (DORMANT)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1002 ()
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Ignore interface down event since interface wlp3s0 is up
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=5 linkmode=1 ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1002 ()
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Ignore interface down event since interface wlp3s0 is up
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=5 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Event message available
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wlp3s0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: MLME event 60 (NL80211_CMD_FRAME_TX_STATUS) on wlp3s0(6c:88:14:a2:2d:74) A1=ff:ff:ff:ff:ff:ff A2=6c:88:14:a2:2d:74
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: MLME event frame - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 03 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Frame TX status event
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Action TX status: cookie=015 (unknown) (ack=1)
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: l2_packet_receive - recvfrom: Network is down
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Event message available
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Drv Event 60 (NL80211_CMD_FRAME_TX_STATUS) received for wlp3s0
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: MLME event 60 (NL80211_CMD_FRAME_TX_STATUS) on wlp3s0(6c:88:14:a2:2d:74) A1=ff:ff:ff:ff:ff:ff A2=6c:88:14:a2:2d:74
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: MLME event frame - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 03 00
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Frame TX status event
Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: Action TX status: cookie=016 (unknown) (ack=1)
Jun 12 13:49:13 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])






> this, together with the WPA-PSK-SHA256 setting of comment #11, makes me
> think it's worth seeing what happens when PMF are turned off. Can you please
> try 
> 
> # nmcli connection edit <name of the hotspot>
> > nmcli 

> 
> can you try disabling PMF as follows?
> 
>  # nmcli connection edit <your hotspot>
>  > set 802-11-wireless-security.pmf disable
>  > save
>  > activate

That worked, with WPA2 enabled.


Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1) [o]
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: wlp3s0: Setting scan request: 0.000000 sec
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: wlp3s0: State: DISCONNECTED -> SCANNING
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: Setting up AP (SSID='ZZZZZ')
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 3 (AP)
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: nl80211: Failed to set interface 3 to mode 3: -16 (Device or resource busy)
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: nl80211: Try mode change after setting interface down
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: nl80211: Set mode ifindex 3 iftype 3 (AP)
Jun 12 14:25:35 ZZZ wpa_supplicant[13327]: nl80211: Mode change succeeded while interface is down
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Unsubscribe mgmt frames handle 0x8888dec6fa01da69 (start AP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Setup AP(wlp3s0) - device_ap_sme=0 use_monitor=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Subscribe to mgmt frames with AP handle 0x564e728bca60
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xb0 (WLAN_FC_STYPE_AUTH) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x0 (WLAN_FC_STYPE_ASSOC_REQ) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x20 (WLAN_FC_STYPE_REASSOC_REQ) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xa0 (WLAN_FC_STYPE_DISASSOC) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xc0 (WLAN_FC_STYPE_DEAUTH) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0x40 (WLAN_FC_STYPE_PROBE_REQ) nl_handle=0x564e728bca60 match=
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=04
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=0501
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=0504
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=06
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=08
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=09
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=0a
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=11
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0x564e728bca60 match=7f
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set freq 2412 (ht_enabled=0, vht_enabled=0, bandwidth=0 MHz, cf1=0 MHz, cf2=0 MHz)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * freq=2412
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * vht_enabled=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * ht_enabled=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * channel_type=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: phy: phy0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: BSS count 1, BSSID mask 00:00:00:00:00:00 (0 bits)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Regulatory information - country=US (DFS-FCC)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 2402-2472 @ 40 MHz 30 mBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 5170-5250 @ 80 MHz 23 mBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 5250-5330 @ 80 MHz 23 mBm (DFS)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 5490-5730 @ 160 MHz 23 mBm (DFS)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 5735-5835 @ 80 MHz 30 mBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: 57240-63720 @ 2160 MHz 40 mBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Added 802.11b mode based on 802.11g information
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=1 freq=2412 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: ssid - hexdump_ascii(len=5):
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:      
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=2 freq=2417 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=3 freq=2422 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=4 freq=2427 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=5 freq=2432 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=6 freq=2437 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=7 freq=2442 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=8 freq=2447 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=9 freq=2452 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=10 freq=2457 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=1 chan=11 freq=2462 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=1 freq=2412 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=2 freq=2417 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=3 freq=2422 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=4 freq=2427 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=5 freq=2432 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=6 freq=2437 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=7 freq=2442 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=8 freq=2447 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=9 freq=2452 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=10 freq=2457 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Allowed channel: mode=0 chan=11 freq=2462 MHz max_tx_power=30 dBm
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Completing interface initialization
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Mode: IEEE 802.11g  Channel: 1  Frequency: 2412 MHz
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: DFS 0 channels required radar detection
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set freq 2412 (ht_enabled=1, vht_enabled=0, bandwidth=20 MHz, cf1=2412 MHz, cf2=0 MHz)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * freq=2412
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * vht_enabled=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * ht_enabled=1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * sec_channel_offset=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * channel_type=1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[0] rate=10 flags=0x1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[1] rate=20 flags=0x1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[2] rate=55 flags=0x1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[3] rate=110 flags=0x1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[4] rate=60 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[5] rate=90 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[6] rate=120 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[7] rate=180 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[8] rate=240 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[9] rate=360 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[10] rate=480 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RATE[11] rate=540 flags=0x0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: hostapd_setup_bss(hapd=0x564e728dacf0 (wlp3s0), first=1)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: Flushing old station entries
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: flush -> DEL_STATION wlp3s0 (all)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: Deauthenticate all stations
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: send_mlme - da= ff:ff:ff:ff:ff:ff noack=0 freq=0 no_cck=0 offchanok=0 wait_time=0 fc=0xc0 (WLAN_FC_STYPE_DEAUTH) nlmode=3
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: send_mlme -> send_frame
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: send_frame - Use bss->freq=2412
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: send_frame -> send_frame_cmd
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: CMD_FRAME freq=2412 wait=0 no_cck=0 no_ack=0 offchanok=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: CMD_FRAME - hexdump(len=26): c0 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 02 00
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Frame command failed: ret=-16 (Device or resource busy) (freq=2412 wait=0)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Using interface wlp3s0 with hwaddr 6c:88:14:a2:2d:74 and ssid "ZZZZZ"
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS: Use configured UUID - hexdump(len=16): 48 50 6c ee de f4 57 ae b0 87 13 b2 cc 9f 86 63
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS: Build Beacon IEs
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Wi-Fi Protected Setup State (2)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Device Name
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Primary Device Type
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS: Build Probe Response IEs
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Wi-Fi Protected Setup State (2)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Response Type (3)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * UUID-E
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Manufacturer
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Model Name
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Model Number
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Serial Number
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Primary Device Type
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Device Name
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Config Methods (3108)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Get randomness: len=32 entropy=53
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: GMK - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Get randomness: len=32 entropy=21
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Key Counter - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPA: Delay group state machine start until Beacon frames have been configured
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS: Building WPS IE for (Re)Association Response
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Response Type (3)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set beacon (beacon_set=0)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Beacon head - hexdump(len=56): 80 00 00 00 ff ff ff ff ff ff 6c 88 14 a2 2d 74 6c 88 14 a2 2d 74 00 00 00 00 00 00 00 00 00 00 64 00 11 
04 00 05 64 63 68 61 6e 01 08 82 84 8b 96 0c 12 18 24 03 01 01
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Beacon tail - hexdump(len=194): 2a 01 04 32 04 30 48 60 6c 30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00
 dd 1a 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 04 00 50 f2 02 01 00 00 50 f2 02 2d 1a 7c 00 17 ff ff 00 00 00 00 00 00 00 00 2c 01 01 00 00 00 00 00 00 00 00 00 00 3d 16 01 00 00 00 0
0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 08 00 00 00 00 00 00 00 40 dd 18 00 50 f2 02 01 01 00 00 03 a4 00 00 27 a4 00 00 42 43 5d 00 62 32 2e 00 dd 29 00 50 f2 04 10 4a 00 
01 10 10 44 00 01 02 10 49 00 06 00 37 2a 00 01 20 10 11 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: ifindex=3
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: beacon_int=100
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: dtim_period=2
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * beacon_int=100
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:   * dtim_period=2
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: hidden SSID not in use
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: privacy=1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: auth_algs=0x3
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: wpa_version=0x3
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: key_mgmt_suites=0x2
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: pairwise_ciphers=0x18
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: group_cipher=0x8
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: SMPS mode - off
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: beacon_ies - hexdump(len=53): 7f 08 00 00 00 00 00 00 00 40 dd 29 00 50 f2 04 10 4a 00 01 10 10 44 00 01 02 10 49 00 06 00 37 2a 00 01 2
0 10 11 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: proberesp_ies - hexdump(len=104): 7f 08 00 00 00 00 00 00 00 40 dd 5c 00 50 f2 04 10 4a 00 01 10 10 44 00 01 02 10 3b 00 01 03 10 47 00 
10 48 50 6c ee de f4 57 ae b0 87 13 b2 cc 9f 86 63 10 21 00 01 20 10 23 00 01 20 10 24 00 01 20 10 42 00 01 20 10 54 00 08 00 00 00 00 00 00 00 00 10 11 00 01 20 10 08 00 02 31 08 10 49 00
 06 00 37 2a 00 01 20
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: assocresp_ies - hexdump(len=36): 7f 08 00 00 00 00 00 00 00 40 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 0
1 20
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPA: Start group state machine to set initial keys
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state GTK_INIT (VLAN-ID 0)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: Get randomness: len=16 entropy=0
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from os_get_random - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random_mix_pool - hexdump(len=20): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: random from internal pool - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: mixed random - hexdump(len=16): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: GTK - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state SETKEYSDONE (VLAN-ID 0)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=2 addr=0x564e71c8a454 key_idx=1 set_tx=1 seq_len=0 key_len=32
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: KEY_DATA - hexdump(len=32): [REMOVED]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:    broadcast key
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set wlp3s0 operstate 0->1 (UP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: interface state UNINITIALIZED->ENABLED
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: AP-ENABLED
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: State: SCANNING -> COMPLETED
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: CTRL-EVENT-CONNECTED - Connection to 6c:88:14:a2:2d:74 completed [id=0 id_str=]
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set wlp3s0 operstate 1->1 (UP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: Setup of interface done.
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1002 ()
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Ignore interface down event since interface wlp3s0 is up
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=5 linkmode=1 ifi_family=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set IF_OPER_UP again based on ifi_flags and expected operstate
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=6 (IF_OPER_UP)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: RTM_NEWLINK: ifi_index=3 ifname=wlp3s0 operstate=6 linkmode=1 ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: l2_packet_receive - recvfrom: Network is down
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Beacon event message available
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: wlp3s0: Event RX_MGMT (19) received
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: unknown vendor specific information element ignored (vendor OUI 00:03:7f len=9)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: unknown vendor specific information element ignored (vendor OUI 00:18:0a len=13)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: unknown vendor specific information element ignored (vendor OUI 00:40:96 len=5)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: unknown vendor specific information element ignored (vendor OUI 00:40:96 len=5)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: unknown vendor specific information element ignored (vendor OUI 00:40:96 len=5)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: OLBC AP detected: ba:15:44:60:3a:f6 (channel 1) - enable protection
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS: Building WPS IE for (Re)Association Response
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version (hardcoded 0x10)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Response Type (3)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: WPS:  * Version2 (0x20)
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: ssid - hexdump_ascii(len=5):
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]:      
Jun 12 14:25:36 ZZZ wpa_supplicant[13327]: nl80211: Set beacon (beacon_set=1)
Comment 20 Davide Caratti 2018-06-12 21:56:56 UTC 
(In reply to Doug from comment #19)
> (In reply to Davide Caratti from comment #17)
> > dmesg log is not telling enough information to us, it would be better to
> > understand what's happening in wpa_supplicant. Please try: 
> > 
> > OTHER_ARGS="-s -dddddd"
> > 
> > 
> > in /etc/sysconfig/wpa_supplicant, then 
> > # systemctl restart wpa_supplicant.service
> > # journalctl -u wpa_supplicant -f
> > # <activate the hotspot using NM>
> > 
> > and provide the journalctl log.  
> 
> Here's the excerpt from journalctl.
> I scrubbed the system name and ssid.  Look for the "Interface initialization
> failed" line.

hello Doug,
thanks for the prompt response!

> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:    broadcast key
> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: wpa_driver_nl80211_set_key: ifindex=3 (wlp3s0) alg=4 addr=0x564e71c8a454 key_idx=4 set_tx=1 seq_len=0 key_len=16
> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: KEY_DATA - hexdump(len=16): [REMOVED]
> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]:    broadcast key
> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: nl80211: set_key failed; err=-22 Invalid argument)
> Jun 12 13:49:12 ZZZ wpa_supplicant[13327]: WPA: group state machine entering state FATAL_FAILURE

I think the problem is the kernel refusing (i.e. returning -EINVAL) to install the IGTK key (alg=4).
 
> > can you try disabling PMF as follows?
> > 
> >  # nmcli connection edit <your hotspot>
> >  > set 802-11-wireless-security.pmf disable
> >  > save
> >  > activate
> 
> That worked, with WPA2 enabled.

set PMF to 'disable' resulted in avoiding to install the IGTK, thus circumventing the problem (which BTW is being investigated in bz1582407). Anybody else (ng0177 or keesdejong+bugs or pauloedgarcastro or sanjay.ankur [*]) can confirm this?

[*] @Harald Heindl: thank you for doing the test, in your configuration there seems to be no PMF setting at all. This confirms that 'Attribute type 213...' printout in the dmesg has nothing to do with failed connections when wpa_supplicant runs in AP mode.
Comment 21 Ankur Sinha (FranciscoD) 2018-06-13 12:49:24 UTC 
Hiya,

Yes, this works for me:

> > 
> >  # nmcli connection edit <your hotspot>
> >  > set 802-11-wireless-security.pmf disable
> >  > save
> >  > activate

Cheers!
Comment 22 Davide Caratti 2018-06-22 15:44:43 UTC 
I just pushed to f28 a fix for the uncorrect encoding of NL80211_ATTR_SMPS_MODE. 

For those experiencing failures only when PMF is enabled: please refer to bz1582407 _ an improvement in NM is being developed to handle cards that don't support PMF.

If the problem happens with encrypted EAPOLs, please refer to bz1516009.

Thanks for reporting!
Comment 23 Fedora Update System 2018-06-24 15:34:04 UTC 
wpa_supplicant-2.6-16.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-1cc52e0dd5
Comment 24 Fedora Update System 2018-06-24 22:12:34 UTC 
wpa_supplicant-2.6-16.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-1cc52e0dd5
Comment 25 Fedora Update System 2018-06-28 14:08:53 UTC 
wpa_supplicant-2.6-16.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.
Comment 26 Roy Rankin 2018-07-18 06:10:25 UTC 
I do not know if this is the same problem or not, but the workaround of "set 802-11-wireless-security.pmf disable" run on the connecting machine allowed the wifi connection to be made, without it the connection fails. I have wpa_supplicant-2.6-16.fc28 on both machines. The connection worked fine until both machines were (at the same time) upgraded to f28. The hotspot machine has
Detected Intel(R) Dual Band Wireless AC 8260, REV=0x208

The hotspot had no trouble connecting with my fairly old android tablet and a iot with an old linux kernel. 
However my probook 4330s on f28 would not connect and has the following interface
Detected Intel(R) Centrino(R) Advanced-N 6230 AGN, REV=0xB0