ESP32 device lost WLAN, trying to disassociate, but it is not associated
Hello,
I have the following Setup:
Firmware Deco X50 - 1.1.0 Build 20230522 Rel. 68968
Fast Roaming: off
Beamforming: off
DECO OG (Master): MAC: 50-91-E3-DF-23-E4 Backhaul - LAN
IP: 192.168.1.1
DECO Carport: MAC: 3C-52-A1-49-AB-B0 Backhaul - LAN
DECO Keller: MAC: 50-91-E3-DF-25-24 Backhaul - LAN
DECO UG: MAC: 50-91-E3-DF-21-64 Backhaul - LAN
DECO Keller Zubau: MAC: 3C-52-A1-49-AB-C0 Backhaul - WLAN
ESP32
======
STA MAC: 48:31:B7:3D:CD:34
AP MAC: 48:31:B7:3D:CD:35
IP: DHCP
MQTT QoS: 1
After a while the WLAN connection got lost and it's not possible to reconnect, the ESP32 reported (2) Auth expire and try to reconnect but this is not possible and the reason is (1) Unspecified.
ESP32 LOG
==========
[11:55:32]07.292 : (205004) Info : WiFi : Best AP candidate: ghost 50:91:E3:DF:23:E6 Ch:4 (-65dBm)WPA2/PSK (bgn)
[11:55:32]07.296 : (204892) Info : WIFI : Connecting ghost 50:91:E3:DF:23:E6 Ch:4 (-65dBm)WPA2/PSK (bgn) attempt #0
[11:55:32]07.310 : (204704) Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
[11:55:32]07.318 : (199888) Info : Webserver: start
[11:55:34]09.337 : (200056) Info : WIFI : Disconnected! Reason: '(2) Auth expire' Connected for 02.029
[11:55:34]09.344 : (214700) Info : WIFI : Arduino wifi status: WL_NO_SHIELD 255 ESPeasy internal wifi status: DISCONNECTED
[11:55:34]09.448 : (217952) Info : WIFI : Connecting ghost 50:91:E3:DF:23:E6 Ch:4 (-65dBm)WPA2/PSK (bgn) attempt #1
[11:55:35]10.575 : (197788) Info : WD : Uptime 0 ConnectFailures 0 FreeMem 197936 WiFiStatus: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
[11:55:54]29.460 : (197572) Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
[11:55:54]29.464 : (197572) Info : WiFi : WifiDisconnect()
[11:55:54]29.568 : (197508) Info : WIFI : Disconnected! Reason: '(1) Unspecified'
[11:55:54]29.671 : (197412) Info : Reset WiFi.
[11:55:54]29.674 : (197348) Info : WiFi : Start network scan all channels
[11:56:00]35.688 : (196444) Info : WiFi : Scan finished, found: 12
[11:56:00]35.693 : (197012) Info : WiFi : Best AP candidate: ghost 50:91:E3:DF:23:E6 Ch:4 (-66dBm)WPA2/PSK (bgn)
[11:56:00]35.696 : (197124) Info : WiFi : Added known candidate, try to connect
[11:56:00]35.699 : (197140) Info : WiFi : WifiDisconnect()
[11:56:00]35.803 : (197172) Info : WIFI : Disconnected! Reason: '(1) Unspecified'
[11:56:00]35.806 : (197076) Info : WIFI : Arduino wifi status: WL_DISCONNECTED 6 ESPeasy internal wifi status: DISCONNECTED
...
In the DECO log is the reported for MAC: 48:31:B7:3D:CD:34 trying to disassociate, but it is not associated
Fri Feb 16 11:54:57 2024 daemon.err hostapd: hostapd_notif_disassoc num_sta 4
Fri Feb 16 11:54:57 2024 daemon.notice hostapd: Station 48:31:b7:3d:cd:34 trying to disassociate, but it is not associated
Fri Feb 16 11:54:57 2024 daemon.notice nrd[13031]: wlanifLinkEventsCmnGenerateDisassocEvent: Client 48:31:B7:3D:CD:34 disassociated on APId 255 ChanId 4 ESSId 0
Fri Feb 16 11:54:59 2024 daemon.notice nrd[13031]: ar_pat_calc_cand_datarate[line 882]: patrate for 5091E3DF23E4 is 656, txRate: 713.881836
Fri Feb 16 11:54:59 2024 daemon.notice nrd[13031]: ar_pat_calc_cand_datarate[line 882]: patrate for 5091E3DF2524 is 553, txRate: 608.014160
Fri Feb 16 11:54:59 2024 daemon.notice nrd[13031]: ar_pat_calc_cand_datarate[line 882]: patrate for 5091E3DF2164 is 532, txRate: 584.783081
Fri Feb 16 11:54:59 2024 daemon.notice nrd[13031]: ar_pat_calc_cand_datarate[line 882]: patrate for 3C52A149ABC0 is 391, txRate: 543.751465
Fri Feb 16 11:54:59 2024 daemon.notice nrd[13031]: wlanifLinkEventsCmnGenerateDisassocEvent: Client 48:31:B7:3D:CD:34 disassociated on APId 255 ChanId 4 ESSId 0
Fri Feb 16 11:54:59 2024 daemon.err hostapd: hostapd_notif_disassoc num_sta 4
Fri Feb 16 11:55:00 2024 daemon.err client_mgmt: can not parse json_obj
Fri Feb 16 11:55:00 2024 daemon.err client_mgmt: update_history_wire_type:exit failed.
Fri Feb 16 11:55:00 2024 daemon.err client_mgmt: update /tmp/client_mgmt/history_wire_type failed, offline client type recognization of link priority will be influenced.
Fri Feb 16 11:56:57 2024 daemon.notice nrd[13031]: wlanifLinkEventsCmnGenerateDisassocEvent: Client 48:31:B7:3D:CD:34 disassociated on APId 255 ChanId 4 ESSId 0
Fri Feb 16 11:56:57 2024 daemon.err hostapd: hostapd_notif_disassoc num_sta 4
When I disconnect the ESP32 device for a few hours, it can reconnect without any issues and after a while it has the same problem again.
Fri Feb 16 15:13:28 2024 daemon.notice hostapd: ath0: AP-STA-CONNECTED 48:31:b7:3d:cd:34
Fri Feb 16 15:13:28 2024 daemon.notice hostapd: ath0: ubus call access_client access '{"mac":"48-31-b7-3d-cd-34","ifname":"ath0","action":"associate"}' &
Fri Feb 16 15:13:28 2024 daemon.notice hostapd: ath0: ubus call client_mgmt access '{"mac":"48-31-B7-3D-CD-34","ifname":"ath0","action":"associate"}' &
Fri Feb 16 15:13:28 2024 daemon.notice nrd[13031]: wlanifBSteerEventsHandleNodeAssociatedInd: Node 48:31:B7:3D:CD:34 associated on APId 255 ChanId 4 ESSId 0 , Capabilities: , Max bandwidth: 0, Num of spatial streams: 1, PHY mode: 8, Max MCS: 7. Max TX power: 0
Fri Feb 16 15:13:28 2024 daemon.err client_mgmt: wireless client associate or disassociate.
Fri Feb 16 15:13:28 2024 daemon.err client_mgmt: client_mac:48-31-B7-3D-CD-34, client_ifname:ath0, client_action:associate
Fri Feb 16 15:13:28 2024 daemon.err client_mgmt: client(48-31-B7-3D-CD-34) assocaite by if(ath0).
Fri Feb 16 15:13:28 2024 daemon.err udhcpd[12903]: Received DISCOVER
Fri Feb 16 15:13:28 2024 daemon.err udhcpd[12903]: find_free_or_expired_nip
Fri Feb 16 15:13:28 2024 daemon.err udhcpd[12903]: find a new ip: 192.168.1.126, ready to arp check
Fri Feb 16 15:13:28 2024 daemon.err udhcpd[12903]: send arp packet:192.168.1.126
Fri Feb 16 15:13:29 2024 daemon.err udhcpd[12903]: Received DISCOVER
Fri Feb 16 15:13:29 2024 daemon.err udhcpd[12903]: checked a timeout node!
Fri Feb 16 15:13:29 2024 daemon.err udhcpd[12903]: Sending OFFER of 192.168.1.126
Fri Feb 16 15:13:29 2024 daemon.err udhcpd[12903]: Sending ACK to 192.168.1.126
Fri Feb 16 15:13:29 2024 daemon.err udhcpd[12903]: clear ip 7e01a8c0
The WLAN connection on the ESP32 is not bad and I would expect it to be able to reconnect when it is disconnected for whatever reason, but it looks like there is some sort of lock on the Deco that doesn't allow the MAC address to create an association for a certain period of time.
Maybe it counts the number of reconnects and when a threshold is reached it is blocked for whatever time, it looks like within 15min
Can anyone confirm this behavior of the DECO or is it a BUG in the firmware?
Thx and kind regards,
Stefan