* disconnects when in AP mode @ 2023-12-28 18:19 KeithG 2023-12-28 18:42 ` KeithG 0 siblings, 1 reply; 6+ messages in thread From: KeithG @ 2023-12-28 18:19 UTC (permalink / raw) To: iwd Group, I finally gave up on getting connman to manage scanning when iwd is in AP mode. What I have done is listen to James who posted this a long time ago and I just finally figured out what he was saying. I am doing what is outlined here: https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ I am running this on RPis all with the brcmfmac adapters. I can get it all working, but when connected to the RPi on its advertised AP, I can get a connection for a bit then it disconnects, requiring a reconnect. I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS fully up to date on Bookworm I get tons of this in the log: "wiphy_estimate_data_rate() failed" and a few others but it does not seem like this is what triggers it to disconnect. I have not been able to pinpoint anything in the log where it disconnects. Any help appreciated. # uname -a Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux this is what shows at bootup Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface driver brcmfmac Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 Dec 28 11:50:48 runeaudio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled Dec 28 11:50:55 runeaudio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 28 11:51:30 runeaudio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 28 11:51:31 runeaudio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: timer expired I get this in the log: Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, WPS will not be available Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing in the kernel: Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from /etc/iwd/main.conf Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: b8:27:eb:52:cc:d0 Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: Dec 28 11:51:30 runeaudio iwd[1306]: HT40 Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: Dec 28 11:51:30 runeaudio iwd[1306]: HT40 Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz Dec 28 11:51:30 runeaudio iwd[1306]: Max RX MCS: 0-9 for NSS: 1 Dec 28 11:51:30 runeaudio iwd[1306]: Max TX MCS: 0-9 for NSS: 1 Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc station ap p2p-client p2p-go p2p-device Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the default interface Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch type 00b0: -22 Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for ifindex: 4, reason: 15 Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for ifindex: 4, reason: 15 Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for ifindex: 4, reason: 15 Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: disconnects when in AP mode 2023-12-28 18:19 disconnects when in AP mode KeithG @ 2023-12-28 18:42 ` KeithG 2023-12-29 18:53 ` KeithG 0 siblings, 1 reply; 6+ messages in thread From: KeithG @ 2023-12-28 18:42 UTC (permalink / raw) To: iwd I put iwd in debug mode and this is what happens at disconnect. Maybe better for diagnostics. If there is something else I can do to help diagnose it, please let me know Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() MLME notification New Station(19) Dec 28 12:35:13 runeaudio iwd[5127]: KEY_SEQ not returned in GET_KEY reply Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_start() Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_send_ptk_1_of_4() STA: f0:42:1c:d7:da:e8 retries=0 Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_handle_ptk_2_of_4() ifindex=4 Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_send_ptk_3_of_4() STA: f0:42:1c:d7:da:e8 retries=0 Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_ptk_3_of_4_retry() attempt 1 Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_handle_ptk_4_of_4() ifindex=4 Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_tk() ifindex=4 key_idx=0 Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_station_cb() Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:try_handshake_complete() ptk_installed: 1, gtk_installed: 1, igtk_installed: 1 Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:try_handshake_complete() nhs->complete: 0 Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:try_handshake_complete() Invoking handshake_event() Dec 28 12:35:13 runeaudio iwd[5127]: src/ap.c:ap_new_rsna() STA f0:42:1c:d7:da:e8 authenticated Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() agent register called Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() agent :1.566 path /agent/12001 Dec 28 12:35:55 runeaudio iwd[5127]: src/station.c:station_dbus_scan() Scan called from DBus Dec 28 12:35:55 runeaudio iwd[5127]: src/wiphy.c:wiphy_radio_work_insert() Inserting work item 13 Dec 28 12:35:55 runeaudio iwd[5127]: src/wiphy.c:wiphy_radio_work_next() Starting work item 13 On Thu, Dec 28, 2023 at 12:19 PM KeithG <ys3al35l@gmail.com> wrote: > > Group, > > I finally gave up on getting connman to manage scanning when iwd is in > AP mode. What I have done is listen to James who posted this a long > time ago and I just finally figured out what he was saying. > > I am doing what is outlined here: > https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ > > I am running this on RPis all with the brcmfmac adapters. I can get it > all working, but when connected to the RPi on its advertised AP, I can > get a connection for a bit then it disconnects, requiring a reconnect. > I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS > fully up to date on Bookworm > > I get tons of this in the log: "wiphy_estimate_data_rate() failed" and > a few others but it does not seem like this is what triggers it to > disconnect. I have not been able to pinpoint anything in the log where > it disconnects. > > Any help appreciated. > > # uname -a > Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian > 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux > > this is what shows at bootup > Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read > @0x18000000=0x15264345 > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: > using brcm/brcmfmac43455-sdio for chip BCM4345/6 > Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface > driver brcmfmac > Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 > 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: > Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 > (1a2f2fa CY) FWID 01-703fd60 > Dec 28 11:50:48 runeaudio kernel: brcmfmac: > brcmf_cfg80211_set_power_mgmt: power save enabled > Dec 28 11:50:55 runeaudio kernel: brcmfmac: > brcmf_cfg80211_set_power_mgmt: power save disabled > Dec 28 11:51:30 runeaudio kernel: brcmfmac: > brcmf_cfg80211_set_power_mgmt: power save disabled > Dec 28 11:51:31 runeaudio kernel: brcmfmac: > brcmf_cfg80211_set_power_mgmt: power save disabled > Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: > timer expired > > I get this in the log: > Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, > WPS will not be available > Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing > in the kernel: > Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS > Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 > Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from > /etc/iwd/main.conf > Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 > Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: > b8:27:eb:52:cc:d0 > Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz > Dec 28 11:51:30 runeaudio iwd[1306]: Max RX > MCS: 0-9 for NSS: 1 > Dec 28 11:51:30 runeaudio iwd[1306]: Max TX > MCS: 0-9 for NSS: 1 > Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP > Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc > station ap p2p-client p2p-go p2p-device > Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the > default interface > Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch > type 00b0: -22 > Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for > ifindex: 4, reason: 15 > Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for > ifindex: 4, reason: 15 > Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for > ifindex: 4, reason: 15 > Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: disconnects when in AP mode 2023-12-28 18:42 ` KeithG @ 2023-12-29 18:53 ` KeithG 2023-12-29 22:16 ` James Prestwood 2023-12-29 22:17 ` KeithG 0 siblings, 2 replies; 6+ messages in thread From: KeithG @ 2023-12-29 18:53 UTC (permalink / raw) To: iwd On Thu, Dec 28, 2023 at 12:42 PM KeithG <ys3al35l@gmail.com> wrote: > > I put iwd in debug mode and this is what happens at disconnect. Maybe > better for diagnostics. > If there is something else I can do to help diagnose it, please let me know > > Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > MLME notification Del Station(20) > Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > MLME notification Del Station(20) > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > MLME notification New Station(19) > Dec 28 12:35:13 runeaudio iwd[5127]: KEY_SEQ not returned in GET_KEY reply > Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_start() > Dec 28 12:35:13 runeaudio iwd[5127]: > src/eapol.c:eapol_send_ptk_1_of_4() STA: f0:42:1c:d7:da:e8 retries=0 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/eapol.c:eapol_handle_ptk_2_of_4() ifindex=4 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/eapol.c:eapol_send_ptk_3_of_4() STA: f0:42:1c:d7:da:e8 retries=0 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/eapol.c:eapol_ptk_3_of_4_retry() attempt 1 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/eapol.c:eapol_handle_ptk_4_of_4() ifindex=4 > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_tk() > ifindex=4 key_idx=0 > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_station_cb() > Dec 28 12:35:13 runeaudio iwd[5127]: > src/netdev.c:try_handshake_complete() ptk_installed: 1, gtk_installed: > 1, igtk_installed: 1 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/netdev.c:try_handshake_complete() nhs->complete: 0 > Dec 28 12:35:13 runeaudio iwd[5127]: > src/netdev.c:try_handshake_complete() Invoking handshake_event() > Dec 28 12:35:13 runeaudio iwd[5127]: src/ap.c:ap_new_rsna() STA > f0:42:1c:d7:da:e8 authenticated > Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() > agent register called > Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() > agent :1.566 path /agent/12001 > Dec 28 12:35:55 runeaudio iwd[5127]: src/station.c:station_dbus_scan() > Scan called from DBus > Dec 28 12:35:55 runeaudio iwd[5127]: > src/wiphy.c:wiphy_radio_work_insert() Inserting work item 13 > Dec 28 12:35:55 runeaudio iwd[5127]: > src/wiphy.c:wiphy_radio_work_next() Starting work item 13 > > On Thu, Dec 28, 2023 at 12:19 PM KeithG <ys3al35l@gmail.com> wrote: > > > > Group, > > > > I finally gave up on getting connman to manage scanning when iwd is in > > AP mode. What I have done is listen to James who posted this a long > > time ago and I just finally figured out what he was saying. > > > > I am doing what is outlined here: > > https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ > > > > I am running this on RPis all with the brcmfmac adapters. I can get it > > all working, but when connected to the RPi on its advertised AP, I can > > get a connection for a bit then it disconnects, requiring a reconnect. > > I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS > > fully up to date on Bookworm > > > > I get tons of this in the log: "wiphy_estimate_data_rate() failed" and > > a few others but it does not seem like this is what triggers it to > > disconnect. I have not been able to pinpoint anything in the log where > > it disconnects. > > > > Any help appreciated. > > > > # uname -a > > Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian > > 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux > > > > this is what shows at bootup > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read > > @0x18000000=0x15264345 > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: > > using brcm/brcmfmac43455-sdio for chip BCM4345/6 > > Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface > > driver brcmfmac > > Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 > > 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: > > Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 > > (1a2f2fa CY) FWID 01-703fd60 > > Dec 28 11:50:48 runeaudio kernel: brcmfmac: > > brcmf_cfg80211_set_power_mgmt: power save enabled > > Dec 28 11:50:55 runeaudio kernel: brcmfmac: > > brcmf_cfg80211_set_power_mgmt: power save disabled > > Dec 28 11:51:30 runeaudio kernel: brcmfmac: > > brcmf_cfg80211_set_power_mgmt: power save disabled > > Dec 28 11:51:31 runeaudio kernel: brcmfmac: > > brcmf_cfg80211_set_power_mgmt: power save disabled > > Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: > > timer expired > > > > I get this in the log: > > Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, > > WPS will not be available > > Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing > > in the kernel: > > Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS > > Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 > > Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from > > /etc/iwd/main.conf > > Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. > > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 > > Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: > > b8:27:eb:52:cc:d0 > > Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: > > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > > Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > > Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: > > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz > > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > > Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz > > Dec 28 11:51:30 runeaudio iwd[1306]: Max RX > > MCS: 0-9 for NSS: 1 > > Dec 28 11:51:30 runeaudio iwd[1306]: Max TX > > MCS: 0-9 for NSS: 1 > > Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP > > Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc > > station ap p2p-client p2p-go p2p-device > > Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface > > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the > > default interface > > Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch > > type 00b0: -22 > > Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for > > ifindex: 4, reason: 15 > > Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for > > ifindex: 4, reason: 15 > > Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for > > ifindex: 4, reason: 15 > > Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed I tried this similarly with hostapd and get similar results with disconnects. I have connman/iwd managing eth0 and wlano and created an ap0 virtual interface on wlan0 then start hostapd. It will come up but repeatedly disconnects in a similar fashion. I see these disconnects with my phone as well as with my laptop running an intel wireless card. My next investigation is to use wpa_supplicant on wlan0 and see if it is any more stable. After that, maybe looking for any more up to date firmware for the brcmfmac. Could iwd scanning in the wlan0 cause a disconnect on the virtual ap0? Any other ideas welcome. This is a snippet of the log showing iwd and hostapd: Dec 29 07:45:26 runeaudio iwd[19160]: src/station.c:station_autoconnect_next() autoconnect: Trying SSID: DemBoyz_5G Dec 29 07:45:26 runeaudio iwd[19160]: src/station.c:station_autoconnect_next() autoconnect: 'd8:07:b6:8e:97:7a' freq: 5785, rank: 13, strength: -8100 Dec 29 07:45:26 runeaudio iwd[19160]: src/station.c:station_autoconnect_next() autoconnect: network_autoconnect: No such file or directory (-2) Dec 29 07:45:26 runeaudio iwd[19160]: src/wiphy.c:wiphy_radio_work_done() Work item 12 done Dec 29 07:45:30 runeaudio iwd[19160]: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 IEEE 802.11: disassociated Dec 29 07:45:30 runeaudio iwd[19160]: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 IEEE 802.11: disassociated Dec 29 07:45:49 runeaudio iwd[19160]: src/netdev.c:netdev_mlme_notify() MLME notification New Station(19) Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 IEEE 802.11: associated Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 RADIUS: starting accounting session 28F5839359A8BF79 Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 WPA: pairwise key handshake completed (RSN) ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: disconnects when in AP mode 2023-12-29 18:53 ` KeithG @ 2023-12-29 22:16 ` James Prestwood 2023-12-29 22:17 ` KeithG 1 sibling, 0 replies; 6+ messages in thread From: James Prestwood @ 2023-12-29 22:16 UTC (permalink / raw) To: KeithG, iwd Hi Keith, On 12/29/23 10:53 AM, KeithG wrote: > On Thu, Dec 28, 2023 at 12:42 PM KeithG <ys3al35l@gmail.com> wrote: >> I put iwd in debug mode and this is what happens at disconnect. Maybe >> better for diagnostics. >> If there is something else I can do to help diagnose it, please let me know >> >> Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >> MLME notification Del Station(20) >> Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >> MLME notification Del Station(20) >> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >> MLME notification New Station(19) >> Dec 28 12:35:13 runeaudio iwd[5127]: KEY_SEQ not returned in GET_KEY reply >> Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_start() >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/eapol.c:eapol_send_ptk_1_of_4() STA: f0:42:1c:d7:da:e8 retries=0 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/eapol.c:eapol_handle_ptk_2_of_4() ifindex=4 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/eapol.c:eapol_send_ptk_3_of_4() STA: f0:42:1c:d7:da:e8 retries=0 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/eapol.c:eapol_ptk_3_of_4_retry() attempt 1 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/eapol.c:eapol_handle_ptk_4_of_4() ifindex=4 >> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_tk() >> ifindex=4 key_idx=0 >> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_station_cb() >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/netdev.c:try_handshake_complete() ptk_installed: 1, gtk_installed: >> 1, igtk_installed: 1 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/netdev.c:try_handshake_complete() nhs->complete: 0 >> Dec 28 12:35:13 runeaudio iwd[5127]: >> src/netdev.c:try_handshake_complete() Invoking handshake_event() >> Dec 28 12:35:13 runeaudio iwd[5127]: src/ap.c:ap_new_rsna() STA >> f0:42:1c:d7:da:e8 authenticated >> Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() >> agent register called >> Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() >> agent :1.566 path /agent/12001 >> Dec 28 12:35:55 runeaudio iwd[5127]: src/station.c:station_dbus_scan() >> Scan called from DBus >> Dec 28 12:35:55 runeaudio iwd[5127]: >> src/wiphy.c:wiphy_radio_work_insert() Inserting work item 13 >> Dec 28 12:35:55 runeaudio iwd[5127]: >> src/wiphy.c:wiphy_radio_work_next() Starting work item 13 >> >> On Thu, Dec 28, 2023 at 12:19 PM KeithG <ys3al35l@gmail.com> wrote: >>> Group, >>> >>> I finally gave up on getting connman to manage scanning when iwd is in >>> AP mode. What I have done is listen to James who posted this a long >>> time ago and I just finally figured out what he was saying. >>> >>> I am doing what is outlined here: >>> https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ >>> >>> I am running this on RPis all with the brcmfmac adapters. I can get it >>> all working, but when connected to the RPi on its advertised AP, I can >>> get a connection for a bit then it disconnects, requiring a reconnect. >>> I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS >>> fully up to date on Bookworm >>> >>> I get tons of this in the log: "wiphy_estimate_data_rate() failed" and >>> a few others but it does not seem like this is what triggers it to >>> disconnect. I have not been able to pinpoint anything in the log where >>> it disconnects. >>> >>> Any help appreciated. >>> >>> # uname -a >>> Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian >>> 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux >>> >>> this is what shows at bootup >>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read >>> @0x18000000=0x15264345 >>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: >>> using brcm/brcmfmac43455-sdio for chip BCM4345/6 >>> Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface >>> driver brcmfmac >>> Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 >>> 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch >>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: >>> Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 >>> (1a2f2fa CY) FWID 01-703fd60 >>> Dec 28 11:50:48 runeaudio kernel: brcmfmac: >>> brcmf_cfg80211_set_power_mgmt: power save enabled >>> Dec 28 11:50:55 runeaudio kernel: brcmfmac: >>> brcmf_cfg80211_set_power_mgmt: power save disabled >>> Dec 28 11:51:30 runeaudio kernel: brcmfmac: >>> brcmf_cfg80211_set_power_mgmt: power save disabled >>> Dec 28 11:51:31 runeaudio kernel: brcmfmac: >>> brcmf_cfg80211_set_power_mgmt: power save disabled >>> Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: >>> timer expired >>> >>> I get this in the log: >>> Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, >>> WPS will not be available >>> Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing >>> in the kernel: >>> Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS >>> Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from >>> /etc/iwd/main.conf >>> Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. >>> Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: >>> b8:27:eb:52:cc:d0 >>> Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: >>> Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): >>> Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT40 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: >>> Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 >>> Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: >>> Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): >>> Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT40 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz >>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz >>> Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: >>> Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 >>> Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: >>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz >>> Dec 28 11:51:30 runeaudio iwd[1306]: Max RX >>> MCS: 0-9 for NSS: 1 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Max TX >>> MCS: 0-9 for NSS: 1 >>> Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP >>> Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc >>> station ap p2p-client p2p-go p2p-device >>> Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface >>> Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the >>> default interface >>> Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch >>> type 00b0: -22 >>> Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>> Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for >>> ifindex: 4, reason: 15 >>> Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>> Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for >>> ifindex: 4, reason: 15 >>> Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>> Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for >>> ifindex: 4, reason: 15 >>> Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>> Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>> Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > I tried this similarly with hostapd and get similar results with > disconnects. I have connman/iwd managing eth0 and wlano and created an > ap0 virtual interface on wlan0 then start hostapd. It will come up but > repeatedly disconnects in a similar fashion. I see these disconnects > with my phone as well as with my laptop running an intel wireless > card. My next investigation is to use wpa_supplicant on wlan0 and see > if it is any more stable. After that, maybe looking for any more up to > date firmware for the brcmfmac. Could iwd scanning in the wlan0 cause > a disconnect on the virtual ap0? Any other ideas welcome. Sorry for the delay, I've been out for the holidays but could probably find time to try AP mode out again on brcmfmac next week. In your original email it seemed like there was a 4-way handshake problem, but then other logs show a connection when IWD is in AP mode and then a scan was issued after that. Without testing I'd say scanning likely is the culprit of the disconnects. If you don't scan do clients disconnect or stay connected indefinitely? The problem with creating both AP and station interfaces on the same phy is they are sharing air space. Clients expect the AP to continually send beacons every 100ms but scanning on the station interface is likely preventing the beacons from going out. Many cards support this interface combination but its questionable if they support it in a usable way from the standpoint of scanning. As far as the connman questions as I'm sure you discovered sniffing DBus, AP mode is a separate DBus interface. So this would need to be a feature added to connman in order to support it. Thanks, James > > This is a snippet of the log showing iwd and hostapd: > > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: Trying SSID: > DemBoyz_5G > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: > 'd8:07:b6:8e:97:7a' freq: 5785, rank: 13, strength: -8100 > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: > network_autoconnect: No such file or directory (-2) > Dec 29 07:45:26 runeaudio iwd[19160]: > src/wiphy.c:wiphy_radio_work_done() Work item 12 done > Dec 29 07:45:30 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) > Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: disassociated > Dec 29 07:45:30 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) > Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: disassociated > Dec 29 07:45:49 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification New Station(19) > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: associated > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > RADIUS: starting accounting session 28F5839359A8BF79 > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > WPA: pairwise key handshake completed (RSN) > ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: disconnects when in AP mode 2023-12-29 18:53 ` KeithG 2023-12-29 22:16 ` James Prestwood @ 2023-12-29 22:17 ` KeithG 2023-12-29 22:23 ` James Prestwood 1 sibling, 1 reply; 6+ messages in thread From: KeithG @ 2023-12-29 22:17 UTC (permalink / raw) To: iwd On Fri, Dec 29, 2023 at 12:53 PM KeithG <ys3al35l@gmail.com> wrote: > > On Thu, Dec 28, 2023 at 12:42 PM KeithG <ys3al35l@gmail.com> wrote: > > > > I put iwd in debug mode and this is what happens at disconnect. Maybe > > better for diagnostics. > > If there is something else I can do to help diagnose it, please let me know > > > > Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > > MLME notification Del Station(20) > > Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > > MLME notification Del Station(20) > > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() > > MLME notification New Station(19) > > Dec 28 12:35:13 runeaudio iwd[5127]: KEY_SEQ not returned in GET_KEY reply > > Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_start() > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/eapol.c:eapol_send_ptk_1_of_4() STA: f0:42:1c:d7:da:e8 retries=0 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/eapol.c:eapol_handle_ptk_2_of_4() ifindex=4 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/eapol.c:eapol_send_ptk_3_of_4() STA: f0:42:1c:d7:da:e8 retries=0 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/eapol.c:eapol_ptk_3_of_4_retry() attempt 1 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/eapol.c:eapol_handle_ptk_4_of_4() ifindex=4 > > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_tk() > > ifindex=4 key_idx=0 > > Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_station_cb() > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/netdev.c:try_handshake_complete() ptk_installed: 1, gtk_installed: > > 1, igtk_installed: 1 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/netdev.c:try_handshake_complete() nhs->complete: 0 > > Dec 28 12:35:13 runeaudio iwd[5127]: > > src/netdev.c:try_handshake_complete() Invoking handshake_event() > > Dec 28 12:35:13 runeaudio iwd[5127]: src/ap.c:ap_new_rsna() STA > > f0:42:1c:d7:da:e8 authenticated > > Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() > > agent register called > > Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() > > agent :1.566 path /agent/12001 > > Dec 28 12:35:55 runeaudio iwd[5127]: src/station.c:station_dbus_scan() > > Scan called from DBus > > Dec 28 12:35:55 runeaudio iwd[5127]: > > src/wiphy.c:wiphy_radio_work_insert() Inserting work item 13 > > Dec 28 12:35:55 runeaudio iwd[5127]: > > src/wiphy.c:wiphy_radio_work_next() Starting work item 13 > > > > On Thu, Dec 28, 2023 at 12:19 PM KeithG <ys3al35l@gmail.com> wrote: > > > > > > Group, > > > > > > I finally gave up on getting connman to manage scanning when iwd is in > > > AP mode. What I have done is listen to James who posted this a long > > > time ago and I just finally figured out what he was saying. > > > > > > I am doing what is outlined here: > > > https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ > > > > > > I am running this on RPis all with the brcmfmac adapters. I can get it > > > all working, but when connected to the RPi on its advertised AP, I can > > > get a connection for a bit then it disconnects, requiring a reconnect. > > > I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS > > > fully up to date on Bookworm > > > > > > I get tons of this in the log: "wiphy_estimate_data_rate() failed" and > > > a few others but it does not seem like this is what triggers it to > > > disconnect. I have not been able to pinpoint anything in the log where > > > it disconnects. > > > > > > Any help appreciated. > > > > > > # uname -a > > > Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian > > > 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux > > > > > > this is what shows at bootup > > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read > > > @0x18000000=0x15264345 > > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: > > > using brcm/brcmfmac43455-sdio for chip BCM4345/6 > > > Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface > > > driver brcmfmac > > > Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 > > > 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch > > > Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: > > > Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 > > > (1a2f2fa CY) FWID 01-703fd60 > > > Dec 28 11:50:48 runeaudio kernel: brcmfmac: > > > brcmf_cfg80211_set_power_mgmt: power save enabled > > > Dec 28 11:50:55 runeaudio kernel: brcmfmac: > > > brcmf_cfg80211_set_power_mgmt: power save disabled > > > Dec 28 11:51:30 runeaudio kernel: brcmfmac: > > > brcmf_cfg80211_set_power_mgmt: power save disabled > > > Dec 28 11:51:31 runeaudio kernel: brcmfmac: > > > brcmf_cfg80211_set_power_mgmt: power save disabled > > > Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: > > > timer expired > > > > > > I get this in the log: > > > Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, > > > WPS will not be available > > > Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing > > > in the kernel: > > > Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS > > > Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from > > > /etc/iwd/main.conf > > > Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. > > > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: > > > b8:27:eb:52:cc:d0 > > > Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: > > > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > > > Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > > > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > > > Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: > > > Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): > > > Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT40 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz > > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz > > > Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: > > > Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 > > > Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: > > > Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz > > > Dec 28 11:51:30 runeaudio iwd[1306]: Max RX > > > MCS: 0-9 for NSS: 1 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Max TX > > > MCS: 0-9 for NSS: 1 > > > Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP > > > Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc > > > station ap p2p-client p2p-go p2p-device > > > Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface > > > Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the > > > default interface > > > Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch > > > type 00b0: -22 > > > Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > > Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for > > > ifindex: 4, reason: 15 > > > Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > > Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for > > > ifindex: 4, reason: 15 > > > Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > > Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for > > > ifindex: 4, reason: 15 > > > Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply > > > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > > Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed > > I tried this similarly with hostapd and get similar results with > disconnects. I have connman/iwd managing eth0 and wlano and created an > ap0 virtual interface on wlan0 then start hostapd. It will come up but > repeatedly disconnects in a similar fashion. I see these disconnects > with my phone as well as with my laptop running an intel wireless > card. My next investigation is to use wpa_supplicant on wlan0 and see > if it is any more stable. After that, maybe looking for any more up to > date firmware for the brcmfmac. Could iwd scanning in the wlan0 cause > a disconnect on the virtual ap0? Any other ideas welcome. > > This is a snippet of the log showing iwd and hostapd: > > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: Trying SSID: > DemBoyz_5G > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: > 'd8:07:b6:8e:97:7a' freq: 5785, rank: 13, strength: -8100 > Dec 29 07:45:26 runeaudio iwd[19160]: > src/station.c:station_autoconnect_next() autoconnect: > network_autoconnect: No such file or directory (-2) > Dec 29 07:45:26 runeaudio iwd[19160]: > src/wiphy.c:wiphy_radio_work_done() Work item 12 done > Dec 29 07:45:30 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) > Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: disassociated > Dec 29 07:45:30 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) > Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: disassociated > Dec 29 07:45:49 runeaudio iwd[19160]: > src/netdev.c:netdev_mlme_notify() MLME notification New Station(19) > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > IEEE 802.11: associated > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > RADIUS: starting accounting session 28F5839359A8BF79 > Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 > WPA: pairwise key handshake completed (RSN) I did the test of the latest firmware from cypress while still using iwd and connman but using hostapd and get similar results. It still disconnects right after iwd makes a scan. Orig firmware on my Pi 7.45.241: Dec 29 13:18:45 runeaudio kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Dec 29 13:18:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Dec 29 13:18:45 runeaudio kernel: usbcore: registered new interface driver brcmfmac Dec 29 13:18:46 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60 This is the latest from cypress 7.45.265: ec 29 14:17:26 runeaudio kernel: brcmfmac: F1 signature read @0x18000000=0x15264345 Dec 29 14:17:26 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 Dec 29 14:17:26 runeaudio kernel: usbcore: registered new interface driver brcmfmac Dec 29 14:17:27 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Aug 29 2023 01:47:08 version 7.45.265 (28bca26 CY) FWID 01-b677b91b This is is what happens with hostapd/dnsmasq on virtual ap0 and connmanctl/iwd on wlan0. I get a disconnect as soon as iwd performs a scan. https://pastebin.com/FsepZ6PM Could iwd -station be causing this to disconnect? When I use connman/wpa_supplicant and hostapd, it is rock steady. No disconnects. I waited over an hour and it stayed connected. There is not really a way for me to use connman/wpa_supplicant and use iwctl to start the AP on the virtual interface to test this hypothesis thst it is only iwd station, but as it is, iwd ap mode does not really work for brcmfmac. ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: disconnects when in AP mode 2023-12-29 22:17 ` KeithG @ 2023-12-29 22:23 ` James Prestwood 0 siblings, 0 replies; 6+ messages in thread From: James Prestwood @ 2023-12-29 22:23 UTC (permalink / raw) To: KeithG, iwd Hi Keith, On 12/29/23 2:17 PM, KeithG wrote: > On Fri, Dec 29, 2023 at 12:53 PM KeithG <ys3al35l@gmail.com> wrote: >> On Thu, Dec 28, 2023 at 12:42 PM KeithG <ys3al35l@gmail.com> wrote: >>> I put iwd in debug mode and this is what happens at disconnect. Maybe >>> better for diagnostics. >>> If there is something else I can do to help diagnose it, please let me know >>> >>> Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >>> MLME notification Del Station(20) >>> Dec 28 12:32:37 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >>> MLME notification Del Station(20) >>> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_mlme_notify() >>> MLME notification New Station(19) >>> Dec 28 12:35:13 runeaudio iwd[5127]: KEY_SEQ not returned in GET_KEY reply >>> Dec 28 12:35:13 runeaudio iwd[5127]: src/eapol.c:eapol_start() >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/eapol.c:eapol_send_ptk_1_of_4() STA: f0:42:1c:d7:da:e8 retries=0 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/eapol.c:eapol_handle_ptk_2_of_4() ifindex=4 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/eapol.c:eapol_send_ptk_3_of_4() STA: f0:42:1c:d7:da:e8 retries=0 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/eapol.c:eapol_ptk_3_of_4_retry() attempt 1 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/eapol.c:eapol_handle_ptk_4_of_4() ifindex=4 >>> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_tk() >>> ifindex=4 key_idx=0 >>> Dec 28 12:35:13 runeaudio iwd[5127]: src/netdev.c:netdev_set_station_cb() >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/netdev.c:try_handshake_complete() ptk_installed: 1, gtk_installed: >>> 1, igtk_installed: 1 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/netdev.c:try_handshake_complete() nhs->complete: 0 >>> Dec 28 12:35:13 runeaudio iwd[5127]: >>> src/netdev.c:try_handshake_complete() Invoking handshake_event() >>> Dec 28 12:35:13 runeaudio iwd[5127]: src/ap.c:ap_new_rsna() STA >>> f0:42:1c:d7:da:e8 authenticated >>> Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() >>> agent register called >>> Dec 28 12:35:55 runeaudio iwd[5127]: src/agent.c:agent_register() >>> agent :1.566 path /agent/12001 >>> Dec 28 12:35:55 runeaudio iwd[5127]: src/station.c:station_dbus_scan() >>> Scan called from DBus >>> Dec 28 12:35:55 runeaudio iwd[5127]: >>> src/wiphy.c:wiphy_radio_work_insert() Inserting work item 13 >>> Dec 28 12:35:55 runeaudio iwd[5127]: >>> src/wiphy.c:wiphy_radio_work_next() Starting work item 13 >>> >>> On Thu, Dec 28, 2023 at 12:19 PM KeithG <ys3al35l@gmail.com> wrote: >>>> Group, >>>> >>>> I finally gave up on getting connman to manage scanning when iwd is in >>>> AP mode. What I have done is listen to James who posted this a long >>>> time ago and I just finally figured out what he was saying. >>>> >>>> I am doing what is outlined here: >>>> https://lore.kernel.org/linux-wireless/87k0dhdg0d.fsf@bang-olufsen.dk/ >>>> >>>> I am running this on RPis all with the brcmfmac adapters. I can get it >>>> all working, but when connected to the RPi on its advertised AP, I can >>>> get a connection for a bit then it disconnects, requiring a reconnect. >>>> I am running a freshly built iwd version 2.11 with ell 0.61 on RPiOS >>>> fully up to date on Bookworm >>>> >>>> I get tons of this in the log: "wiphy_estimate_data_rate() failed" and >>>> a few others but it does not seem like this is what triggers it to >>>> disconnect. I have not been able to pinpoint anything in the log where >>>> it disconnects. >>>> >>>> Any help appreciated. >>>> >>>> # uname -a >>>> Linux runeaudio 6.1.0-rpi7-rpi-v8 #1 SMP PREEMPT Debian >>>> 1:6.1.63-1+rpt1 (2023-11-24) aarch64 GNU/Linux >>>> >>>> this is what shows at bootup >>>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: F1 signature read >>>> @0x18000000=0x15264345 >>>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: >>>> using brcm/brcmfmac43455-sdio for chip BCM4345/6 >>>> Dec 28 11:50:45 runeaudio kernel: usbcore: registered new interface >>>> driver brcmfmac >>>> Dec 28 11:50:45 runeaudio kernel: Bluetooth: hci0: BCM4345C0 >>>> 'brcm/BCM4345C0.raspberrypi,3-model-b-plus.hcd' Patch >>>> Dec 28 11:50:45 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: >>>> Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 >>>> (1a2f2fa CY) FWID 01-703fd60 >>>> Dec 28 11:50:48 runeaudio kernel: brcmfmac: >>>> brcmf_cfg80211_set_power_mgmt: power save enabled >>>> Dec 28 11:50:55 runeaudio kernel: brcmfmac: >>>> brcmf_cfg80211_set_power_mgmt: power save disabled >>>> Dec 28 11:51:30 runeaudio kernel: brcmfmac: >>>> brcmf_cfg80211_set_power_mgmt: power save disabled >>>> Dec 28 11:51:31 runeaudio kernel: brcmfmac: >>>> brcmf_cfg80211_set_power_mgmt: power save disabled >>>> Dec 28 11:51:40 runeaudio kernel: ieee80211 phy0: brcmf_escan_timeout: >>>> timer expired >>>> >>>> I get this in the log: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: No Diffie-Hellman support found, >>>> WPS will not be available >>>> Dec 28 11:51:30 runeaudio iwd[1306]: The following options are missing >>>> in the kernel: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: CONFIG_KEY_DH_OPERATIONS >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Wireless daemon version 2.11 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Loaded configuration from >>>> /etc/iwd/main.conf >>>> Dec 28 11:51:30 runeaudio systemd[1]: Started iwd.service - Wireless service. >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy: 0, Name: phy0 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Permanent Address: >>>> b8:27:eb:52:cc:d0 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 2.4GHz Band: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 1.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 2.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 5.5 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 11.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT40 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 5GHz Band: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Bitrates (non-HT): >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 6.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 9.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 12.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 18.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 24.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 36.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 48.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 54.0 Mbps >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT Capabilities: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT40 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 20Mhz >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 40Mhz >>>> Dec 28 11:51:30 runeaudio iwd[1306]: HT RX MCS indexes: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: 0-7 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: VHT Capabilities: >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Short GI for 80Mhz >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Max RX >>>> MCS: 0-9 for NSS: 1 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Max TX >>>> MCS: 0-9 for NSS: 1 >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Ciphers: BIP-CMAC-128 CCMP-128 TKIP >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Supported iftypes: ad-hoc >>>> station ap p2p-client p2p-go p2p-device >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Driver Flags: DefaultInterface >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Wiphy phy0 will only use the >>>> default interface >>>> Dec 28 11:51:30 runeaudio iwd[1306]: Could not register frame watch >>>> type 00b0: -22 >>>> Dec 28 11:51:46 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:51:56 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:52:22 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:52:29 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>>> Dec 28 11:52:29 runeaudio iwd[1306]: 4-Way handshake failed for >>>> ifindex: 4, reason: 15 >>>> Dec 28 11:52:39 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>>> Dec 28 11:52:40 runeaudio iwd[1306]: 4-Way handshake failed for >>>> ifindex: 4, reason: 15 >>>> Dec 28 11:52:49 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>>> Dec 28 11:52:49 runeaudio iwd[1306]: 4-Way handshake failed for >>>> ifindex: 4, reason: 15 >>>> Dec 28 11:53:07 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:53:35 runeaudio iwd[1306]: KEY_SEQ not returned in GET_KEY reply >>>> Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >>>> Dec 28 11:54:33 runeaudio iwd[1306]: wiphy_estimate_data_rate() failed >> I tried this similarly with hostapd and get similar results with >> disconnects. I have connman/iwd managing eth0 and wlano and created an >> ap0 virtual interface on wlan0 then start hostapd. It will come up but >> repeatedly disconnects in a similar fashion. I see these disconnects >> with my phone as well as with my laptop running an intel wireless >> card. My next investigation is to use wpa_supplicant on wlan0 and see >> if it is any more stable. After that, maybe looking for any more up to >> date firmware for the brcmfmac. Could iwd scanning in the wlan0 cause >> a disconnect on the virtual ap0? Any other ideas welcome. >> >> This is a snippet of the log showing iwd and hostapd: >> >> Dec 29 07:45:26 runeaudio iwd[19160]: >> src/station.c:station_autoconnect_next() autoconnect: Trying SSID: >> DemBoyz_5G >> Dec 29 07:45:26 runeaudio iwd[19160]: >> src/station.c:station_autoconnect_next() autoconnect: >> 'd8:07:b6:8e:97:7a' freq: 5785, rank: 13, strength: -8100 >> Dec 29 07:45:26 runeaudio iwd[19160]: >> src/station.c:station_autoconnect_next() autoconnect: >> network_autoconnect: No such file or directory (-2) >> Dec 29 07:45:26 runeaudio iwd[19160]: >> src/wiphy.c:wiphy_radio_work_done() Work item 12 done >> Dec 29 07:45:30 runeaudio iwd[19160]: >> src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) >> Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 >> IEEE 802.11: disassociated >> Dec 29 07:45:30 runeaudio iwd[19160]: >> src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20) >> Dec 29 07:45:30 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 >> IEEE 802.11: disassociated >> Dec 29 07:45:49 runeaudio iwd[19160]: >> src/netdev.c:netdev_mlme_notify() MLME notification New Station(19) >> Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 >> IEEE 802.11: associated >> Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 >> RADIUS: starting accounting session 28F5839359A8BF79 >> Dec 29 07:45:49 runeaudio hostapd[1583]: ap0: STA f0:42:1c:d7:da:e8 >> WPA: pairwise key handshake completed (RSN) > I did the test of the latest firmware from cypress while still using > iwd and connman but using hostapd and get similar results. It still > disconnects right after iwd makes a scan. > Orig firmware on my Pi 7.45.241: > Dec 29 13:18:45 runeaudio kernel: brcmfmac: F1 signature read > @0x18000000=0x15264345 > Dec 29 13:18:45 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: > using brcm/brcmfmac43455-sdio for chip BCM4345/6 > Dec 29 13:18:45 runeaudio kernel: usbcore: registered new interface > driver brcmfmac > Dec 29 13:18:46 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: > Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 > (1a2f2fa CY) FWID 01-703fd60 > > This is the latest from cypress 7.45.265: > ec 29 14:17:26 runeaudio kernel: brcmfmac: F1 signature read > @0x18000000=0x15264345 > Dec 29 14:17:26 runeaudio kernel: brcmfmac: brcmf_fw_alloc_request: > using brcm/brcmfmac43455-sdio for chip BCM4345/6 > Dec 29 14:17:26 runeaudio kernel: usbcore: registered new interface > driver brcmfmac > Dec 29 14:17:27 runeaudio kernel: brcmfmac: brcmf_c_preinit_dcmds: > Firmware: BCM4345/6 wl0: Aug 29 2023 01:47:08 version 7.45.265 > (28bca26 CY) FWID 01-b677b91b > > This is is what happens with hostapd/dnsmasq on virtual ap0 and > connmanctl/iwd on wlan0. I get a disconnect as soon as iwd performs a > scan. > https://pastebin.com/FsepZ6PM > > Could iwd -station be causing this to disconnect? When I use > connman/wpa_supplicant and hostapd, it is rock steady. No disconnects. > I waited over an hour and it stayed connected. There is not really a > way for me to use connman/wpa_supplicant and use iwctl to start the AP > on the virtual interface to test this hypothesis thst it is only iwd > station, but as it is, iwd ap mode does not really work for brcmfmac. Looks like we replied at the same time :) If hostapd + wpa_supplicant doesn't cause disconnects then its likely the type of scan IWD does that causes problems. You could get an iwmon capture when wpa_supplicant is running, that would tell me what type of scan its doing versus IWD. There are active/passive scans and tons of knobs to toggle. You could also try and play around with iw and see what works and what doesn't: iw wlan0 scan active iw wlan0 scan passive etc. Thanks, James ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2023-12-29 22:24 UTC | newest] Thread overview: 6+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2023-12-28 18:19 disconnects when in AP mode KeithG 2023-12-28 18:42 ` KeithG 2023-12-29 18:53 ` KeithG 2023-12-29 22:16 ` James Prestwood 2023-12-29 22:17 ` KeithG 2023-12-29 22:23 ` James Prestwood
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox