brcmfmac SAE/WPA3 negotiation - Part 2

KeithG <[email protected]>
Newsgroups dev.linux.lists.connman,dev.linux.lists.brcm80211,org.kernel.vger.linux-wireless
Message-ID <CAG17S_MwJC+h7O-htyUxEgB4zHKeGf+9B4QaQ6ZLiVStU_Egkw@mail.gmail.com>
Started a new thread as the other was already at 30! Hope this is OK
for the list.

This is on a RPi running the latest connman and iwd, with the brcmfmac
43455 chip, a patch to the brcm80211 driver from Arend and the latest
firmware from Infineon:
Firmware: BCM4345/6 wl0: Oct 28 2024 23:27:00 version 7.45.286
(be70ab3 CY) FWID 01-95efe7fa

The latest iwd (3.3 at latest commit: g4b535cee) will connect to an
SAE/WPA3 AP. It just will not do it every time. I use connman as the
manager with iwd to manage the wifi.

I have seen 2 different errors. One is 'invalid key' and the other is
'connect-failed'
The invalid key dialog in connman is:
connmanctl> connect wifi_b827eba46e0f_6465736b534145_managed_psk
Agent RequestInput wifi_b827eba46e0f_6465736b534145_managed_psk
  Passphrase = [ Type=psk, Requirement=mandatory ]
Passphrase? secret123
Agent ReportError wifi_b827eba46e0f_6465736b534145_managed_psk
  invalid-key
connmanctl> Retry (yes/no)? no
Error /net/connman/service/wifi_b827eba46e0f_6465736b534145_managed_psk:
Input/output error

This one did not connect and the iwmon log is attached as is the
journal (iwd and brcmfmac debug enabled)

The connect failed dialog in connman is:
connmanctl> connect wifi_b827eba46e0f_6465736b534145_managed_psk
Agent RequestInput wifi_b827eba46e0f_6465736b534145_managed_psk
  Passphrase = [ Type=psk, Requirement=mandatory ]
Passphrase? secret123
Agent ReportError wifi_b827eba46e0f_6465736b534145_managed_psk
  connect-failed
connmanctl> Retry (yes/no)? yes
Connected wifi_b827eba46e0f_6465736b534145_managed_psk

This 'connected' but it resulted in an AIPIA 169.254.133.42 address as
is seen in the logs.

I also attach an iwmon and journal of a successful connection with a
valid DHCP address of 192.168.5.207 that passes traffic in the case
teh comparison helps diagnose it.

I could be wrong, but I think this is related to iwd because when I
try wpa_supplicant ver 2.10-12 on the debian apt list, it connects
every time. If it is useful, I also have an iwmon and journal log of
successful connect using wpa_supplincant. I do notice that it connects
very quickly with wpa_supplicant compared to a connection with iwd.

Keith
journal_invalid_key_SAE.txt (text/plain, 727.5 KB) - not displayed
journal_connected_SAE.txt (text/plain, 14 KB)
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 01 00 00 00 01 00 5e 00 00 01                    ......^...
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 37 expected 37
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_set ifidx=1, name=allmulti, len=4
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 00 00 00 00                                      ....
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune systemd-journald[128]: Data hash table of /run/log/journal/215ced3354fa49179a9b648da35482b2/system.journal has a fill level at 75.0 (3142 of 4188 items, 2412544 file size, 767 bytes per hash table item), suggesting rotation.
Jan 04 12:02:38 jackrune systemd-journald[128]: /run/log/journal/215ced3354fa49179a9b648da35482b2/system.journal: Journal header limits reached or header out-of-date, rotating.
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 29 expected 29
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_cmd_int_set ifidx=1, cmd=10, value=0
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_cmd_data_set ifidx=1, cmd=10, len=4
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 00 00 00 00                                      ....
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 20 expected 20
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_set ifidx=1, name=arp_ol, len=4
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 09 00 00 00                                      ....
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 27 expected 27
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_set ifidx=1, name=arpoe, len=4
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 01 00 00 00                                      ....
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 26 expected 26
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_configure_arp_nd_offload successfully configured (1) ARP offload to 0x9
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_set ifidx=1, name=ndoe, len=4
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 01 00 00 00                                      ....
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 25 expected 25
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_configure_arp_nd_offload successfully configured (1) ND offload to 0x9
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_kso_control Enter: on=0
Jan 04 12:02:38 jackrune iwd[19274]: src/netdev.c:netdev_mlme_notify() MLME notification Disconnect(48)
Jan 04 12:02:38 jackrune iwd[19274]: src/netdev.c:netdev_link_notify() event 16 on ifindex 3
Jan 04 12:02:38 jackrune iwd[19274]: src/module.c:iwd_modules_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap.c:__eap_method_disable()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-wsc.c:eap_wsc_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-md5.c:eap_md5_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-tls.c:eap_tls_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-ttls.c:eap_ttls_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-mschapv2.c:eap_mschapv2_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-sim.c:eap_sim_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-aka.c:eap_aka_prime_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-aka.c:eap_aka_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-peap.c:eap_peap_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-gtc.c:eap_gtc_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/eap-pwd.c:eap_pwd_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/udev.c:udev_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/dpp.c:dpp_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/offchannel.c:offchannel_exit()
Jan 04 12:02:38 jackrune iwd[19274]: src/wsc.c:wsc_exit()
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_net_setcarrier Enter, bsscfgidx=1 carrier=0
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_txflowblock_if enter: bsscfgidx=1 stop=0x4 reason=4 state=1
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_kso_control Enter: on=1
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_get ifidx=0, name=country, len=12, err=0
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 55 53 00 00 00 00 00 00 55 53 00 00              US......US..
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_txctl Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl Enter
Jan 04 12:02:38 jackrune connmand[19277]: Interface wlan0 [ wifi ] state is idle
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_isr Enter
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_bus_rxctl resumed on rxctl frame, got 36 expected 36
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_fil_iovar_data_get ifidx=0, name=country, len=12, err=0
Jan 04 12:02:38 jackrune kernel: brcmutil: data
Jan 04 12:02:38 jackrune kernel: 00000000: 55 53 00 00 00 00 00 00 55 53 00 00              US......US..
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_cfg80211_reg_notifier Enter: initiator=1, alpha=US
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_translate_country_code Country code already set
Jan 04 12:02:38 jackrune iwd[19274]: src/wiphy.c:wiphy_free() Freeing wiphy phy0[0]
Jan 04 12:02:38 jackrune iwd[19274]: D-Bus disconnected, quitting...
Jan 04 12:02:38 jackrune systemd[1]: iwd.service: Deactivated successfully.
Jan 04 12:02:38 jackrune systemd[1]: Stopped iwd.service - Wireless service.
Jan 04 12:02:38 jackrune dbus-daemon[354]: [system] Activating via systemd: service name='net.connman.iwd' unit='iwd.service' requested by ':1.677' (uid=0 pid=19277 comm="/usr/sbin/connmand -n")
Jan 04 12:02:38 jackrune avahi-daemon[351]: Withdrawing address record for 192.168.2.148 on eth0.
Jan 04 12:02:38 jackrune connmand[19277]: Interface eth0 [ ethernet ] state is disconnect
Jan 04 12:02:38 jackrune avahi-daemon[351]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.2.148.
Jan 04 12:02:38 jackrune avahi-daemon[351]: Interface eth0.IPv4 no longer relevant for mDNS.
Jan 04 12:02:38 jackrune connmand[19277]: Interface eth0 [ ethernet ] state is idle
Jan 04 12:02:38 jackrune connmand[19277]: Remove interface eth0 [ ethernet ]
Jan 04 12:02:38 jackrune connmand[19277]: Remove interface wlan0 [ wifi ]
Jan 04 12:02:38 jackrune kernel: lan78xx 1-1.1.1:1.0 eth0: Link is Down
Jan 04 12:02:38 jackrune systemd-resolved[324]: eth0: Bus client reset DNS server list.
Jan 04 12:02:38 jackrune connmand[19277]: eth0 {remove} index 2
Jan 04 12:02:38 jackrune kernel: brcmfmac: brcmf_sdio_kso_control Enter: on=0
Jan 04 12:02:38 jackrune systemd[1]: Starting iwd.service - Wireless service...
Jan 04 12:02:38 jackrune connmand[19277]: ap0 {remove} index 4
Jan 04 12:02:38 jackrune connmand[19277]: wlan0 {remove} index 3
Jan 04 12:02:38 jackrune connmand[19277]: Exit
Jan 04 12:02:38 jackrune systemd[1]: connman.service: Deactivated successfully.
Jan 04 12:02:38 jackrune systemd[1]: Stopped connman.service - Connection service.
Jan 04 12:02:38 jackrune systemd[1]: connman.service: Consumed 1.300s CPU time.
Jan 04 12:02:38 jackrune systemd[1]: Starting connman.service - Connection service...
Jan 04 12:02:38 jackrune iwd[19886]: Wireless daemon version 3.3
Jan 04 12:02:38 jackrune iwd[19886]: src/main.c:main() Using configuration directory /etc/iwd
Jan 04 12:02:38 jackrune iwd[19886]: Loaded configuration from /etc/iwd/main.conf
Jan 04 12:02:38 jackrune iwd[19886]: src/storage.c:storage_create_dirs() Using state directory /var/lib/iwd
Jan 04 12:02:38 jackrune dbus-daemon[354]: [system] Successfully activated service 'net.connman.iwd'
Jan 04 12:02:38 jackrune systemd[1]: Started iwd.service - Wireless service.
Jan 04 12:02:38 jackrune iwd[19886]: src/main.c:nl80211_appeared() Found nl80211 interface
Jan 04 12:02:38 jackrune iwd[19886]: src/module.c:iwd_modules_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/wsc.c:wsc_init()
Jan 04 12:02:38 jackrune iwd[19886]: [General].UseDefaultInterface is deprecated, please use [DriverQuirks].DefaultInterface instead
Jan 04 12:02:38 jackrune iwd[19886]: src/udev.c:udev_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap.c:__eap_method_enable()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-wsc.c:eap_wsc_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-md5.c:eap_md5_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-tls.c:eap_tls_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-ttls.c:eap_ttls_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-mschapv2.c:eap_mschapv2_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-sim.c:eap_sim_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-aka.c:eap_aka_prime_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-aka.c:eap_aka_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-peap.c:eap_peap_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-gtc.c:eap_gtc_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/eap-pwd.c:eap_pwd_init()
Jan 04 12:02:38 jackrune iwd[19886]: src/manager.c:manager_wiphy_dump_callback() New wiphy phy0 added (0)
Jan 04 12:02:38 jackrune iwd[19886]: src/manager.c:manager_wiphy_dump_done()
Jan 04 12:02:38 jackrune iwd[19886]: src/manager.c:manager_filtered_wiphy_dump_done()
Jan 04 12:02:38 jackrune iwd[19886]: Wiphy: 0, Name: phy0
Jan 04 12:02:38 jackrune iwd[19886]:         Permanent Address: b8:27:eb:a4:6e:0f
Jan 04 12:02:38 jackrune iwd[19886]:         2.4GHz Band:
Jan 04 12:02:38 jackrune iwd[19886]:                 Bitrates (non-HT):
Jan 04 12:02:38 jackrune iwd[19886]:                          1.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                          2.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                          5.5 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         11.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                          6.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                          9.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         12.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         18.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         24.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         36.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         48.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         54.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                 HT Capabilities:
Jan 04 12:02:38 jackrune iwd[19886]:                         HT40
Jan 04 12:02:38 jackrune iwd[19886]:                         Short GI for 20Mhz
Jan 04 12:02:38 jackrune iwd[19886]:                 HT RX MCS indexes:
Jan 04 12:02:38 jackrune iwd[19886]:                         0-7
Jan 04 12:02:38 jackrune iwd[19886]:         5GHz Band:
Jan 04 12:02:38 jackrune iwd[19886]:                 Bitrates (non-HT):
Jan 04 12:02:38 jackrune iwd[19886]:                          6.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                          9.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         12.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         18.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         24.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         36.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         48.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                         54.0 Mbps
Jan 04 12:02:38 jackrune iwd[19886]:                 HT Capabilities:
Jan 04 12:02:38 jackrune iwd[19886]:                         HT40
Jan 04 12:02:38 jackrune iwd[19886]:                         Short GI for 20Mhz
Jan 04 12:02:38 jackrune iwd[19886]:                         Short GI for 40Mhz
Jan 04 12:02:38 jackrune iwd[19886]:                 HT RX MCS indexes:
Jan 04 12:02:38 jackrune iwd[19886]:                         0-7
Jan 04 12:02:38 jackrune iwd[19886]:                 VHT Capabilities:
Jan 04 12:02:38 jackrune iwd[19886]:                         Short GI for 80Mhz
Jan 04 12:02:38 jackrune iwd[19886]:                         Max RX MCS: 0-9 for NSS: 1
Jan 04 12:02:38 jackrune iwd[19886]:                         Max TX MCS: 0-9 for NSS: 1
Jan 04 12:02:38 jackrune iwd[19886]:         Ciphers: BIP-CMAC-128 CCMP-128 TKIP
Jan 04 12:02:38 jackrune iwd[19886]:         Supported iftypes: ad-hoc station ap p2p-client p2p-go p2p-de
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.