OWRT is using hostapd from it's master branch from 22-05-2021, there have been tons of bug fixes in 7 months so maybe this bug has been fixed.
I am still unable to confirm whether it is a bug in the firmware+driver or hostapd
Try the following...
Uncheck "Disable Inactivity Polling".
Increase the value in "Station inactivity limit".
I have a couple of static devices that were getting kicked when I didn't want them kicked, so that solved it.
It is mentioned in first post, I have already tried that (multiple times); disabling activity polling will directly deauthenticate the STAs without the polling, so it is actually detrimental.
The inactivity limit is precisely always ignored if you checked the timestamps I posted in both dumps. The problem is that event 2 which means there is a mismatch somewhere at TKIP level.
This problem has nothing to do with the inactivity polling, it is just that the ap_handle_timer function is the same for all cases (whether a STA disconnects for inactivity or other reasons). This log message is re-used in hostapd and completely misleading.
Here's the third dump (check timestamps) with even more verbose debugging:
21:16:45 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED <Apple_MAC>
21:16:45 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: authorizing port
21:16:45 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> WPA: pairwise key handshake completed (RSN)
21:16:46 2021 daemon.info dnsmasq-dhcp[2159]: DHCPREQUEST(br-lan) 192.168.1.109 <Apple_MAC>
21:16:46 2021 daemon.info dnsmasq-dhcp[2159]: DHCPACK(br-lan) 192.168.1.109 <Apple_MAC> My iPhone
21:17:14 2021 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED <Apple_MAC>
21:17:14 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: event 2 notification
21:17:14 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: unauthorizing port
21:17:14 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: disassociated
21:17:14 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DISASSOCIATE.indication(<Apple_MAC>, 8)
21:17:14 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:17:15 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
21:17:15 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DEAUTHENTICATE.indication(<Apple_MAC>, 2)
21:17:15 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:19:58 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: start SAE authentication (RX commit, status=0 (SUCCESS))
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: SAE authentication (RX confirm, status=0 (SUCCESS))
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-AUTHENTICATE.indication(<Apple_MAC>, unknown)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: PMKID found from PMKSA cache eap_type=0 vlan=0
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: association OK (aid 2)
21:19:59 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: associated (aid 2)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-ASSOCIATE.indication(<Apple_MAC>)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: binding station to interface 'wlan0'
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: event 1 notification
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: start authentication
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: unauthorizing port
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: sending 1/4 msg of 4-Way Handshake
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: received EAPOL-Key frame (2/4 Pairwise)
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: sending 3/4 msg of 4-Way Handshake
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: received EAPOL-Key frame (4/4 Pairwise)
21:19:59 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED <Apple_MAC>
21:19:59 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: authorizing port
21:19:59 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> WPA: pairwise key handshake completed (RSN)
21:19:59 2021 daemon.info dnsmasq-dhcp[2159]: DHCPREQUEST(br-lan) 192.168.1.109 <Apple_MAC>
21:19:59 2021 daemon.info dnsmasq-dhcp[2159]: DHCPACK(br-lan) 192.168.1.109 <Apple_MAC> My iPhone
21:20:31 2021 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED <Apple_MAC>
21:20:31 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: event 2 notification
21:20:31 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: unauthorizing port
21:20:31 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: disassociated
21:20:31 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DISASSOCIATE.indication(<Apple_MAC>, 8)
21:20:31 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:20:32 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
21:20:32 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DEAUTHENTICATE.indication(<Apple_MAC>, 2)
21:20:32 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: start SAE authentication (RX commit, status=0 (SUCCESS))
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: SAE authentication (RX confirm, status=0 (SUCCESS))
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-AUTHENTICATE.indication(<Apple_MAC>, unknown)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: PMKID found from PMKSA cache eap_type=0 vlan=0
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: association OK (aid 2)
21:24:41 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: associated (aid 2)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-ASSOCIATE.indication(<Apple_MAC>)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: binding station to interface 'wlan0'
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: event 1 notification
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: start authentication
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: unauthorizing port
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: sending 1/4 msg of 4-Way Handshake
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: received EAPOL-Key frame (2/4 Pairwise)
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: sending 3/4 msg of 4-Way Handshake
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: received EAPOL-Key frame (4/4 Pairwise)
21:24:41 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED <Apple_MAC>
21:24:41 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: authorizing port
21:24:41 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> WPA: pairwise key handshake completed (RSN)
21:24:41 2021 daemon.info dnsmasq-dhcp[2159]: DHCPREQUEST(br-lan) 192.168.1.109 <Apple_MAC>hostapd_timer
21:24:41 2021 daemon.info dnsmasq-dhcp[2159]: DHCPACK(br-lan) 192.168.1.109 <Apple_MAC> My iPhone
21:32:19 2021 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED <Apple_MAC>
21:32:19 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> WPA: event 2 notification
21:32:19 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> IEEE 802.1X: unauthorizing port
21:32:19 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: disassociated
21:32:19 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DISASSOCIATE.indication(<Apple_MAC>, 8)
21:32:19 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
21:32:20 2021 daemon.info hostapd: wlan0: STA <Apple_MAC> IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
21:32:20 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DEAUTHENTICATE.indication(<Apple_MAC>, 2)
21:32:20 2021 daemon.debug hostapd: wlan0: STA <Apple_MAC> MLME: MLME-DELETEKEYS.request(<Apple_MAC>)
1 Like
To be clear, unchecking "Disable Inactivity Polling" enables inactivity polling.
I don't know what value you set for inactivity limit, but mine is set to well over 8 hours, and I haven't had an issue since.
You can also try increasing the value for "Time interval for rekeying GTK".
No:
if (hapd->conf->skip_inactivity_poll)
sta->timeout_next = STA_DISASSOC;
When skip_inactivity_poll is 1 (checkbox ticked in LuCI) the code block below the above will be skipped and it will run hostapd_drv_sta_disassoc() a few lines further. It will not do any polling and directly disassociate.
It is in the first post, check my option max_inactivity, it is way higher than what is happening in the logs and I already explained why this is unrelated to inactivity polling.
Already tried that, no changes in behavior.
1 Like
What exactly is your problem, besides the info log entries that tell you, that your devices suspended wifi to save power? The bug report mentions, that after some time no device can connect to the radio anymore, do you experience the same problem?
I have seen this on older R7800 builds, but on current builds I had 30+ days wifi uptime without a single interruption and I have devices that transfer 24 hours and are monitored.
1 Like
Same here.
The log entries do not tell that, I told you that in my comment e.g. that the Apple devices go to sleep. The logs tell about deauth and reauth, happening all the time every 30 seconds or few minutes. This drains battery on affected devices.
No, sometimes the Apple devices do not have internet even if they say they are connected, but it does not happen all the time. The current issue is the one mentioned before (reconnections).
check that
It is unrelated; it happens also with WPA2 only allowed.
i don't see that in your setting
I see, I didn't read the whole thread where you posted another link to the forum "#8 by wired".
OK, so on your side you have issues with apple devices, I have 3 myself and don't experience that.
But I just use defaults on my radios except encryption WPA2/WPA3.
Have you tried with dfferent SSIDs and with normal tx power, if you lower TX power, than it is possible that messages reach the AP, but won't reach the phones, as you only reduce tx power on one side.
1 Like
I use an r7500v2 with ath10k-ct and the htt firmware on master (well master with an experimental DSA patch but i don't think that's relevant). I have 5+ apple devices that use this access point and all usually don't have this issue (the android, linux, and windows devices do not currently have this symptom).
I just check my logs and saw an iphone 11 with the same symptoms you describe.
Checking this iphone, it's battery was low. As soon as i plugged in this device to charge, the frequent log deauth due to inactivity messages stopped. I suspect this case indicates the apple device turning off wifi to save power.
Even if your case is not related to a device related power save "feature", it does seem to be client related and you will have to look there. Perhaps ask "how does one determine if an apple device is initiating a wifi disconnect? (I'd answer but i don't know.)
FWIW I've seen these messages and complaints about them in the past (mostly android and iphone devices), ath10k users start by pointing the finger at the driver/firmware (ct or not), and then there is a quite update to hostapd (or I update my devices) and the symptoms disappear. It will be difficult to identify the reason for these messages with so many wifi factors to look at (router wifi driver, mac80211, hostapd, device wifi, device and router placement, wifi interfearance, etc).
You mention the "hidden node problem" I think meaning the apple devices can not see each other but can see the AP. Have you tried moving the affected apple devices near each other and within line of site of the AP?
HTH
2 Likes
I disabled WPA3 as part of my tests; for example now I run 1 AP with WPA3 possible and one only with WPA2 possible, same symptoms.
I haven't tried with different SSIDs yet; as for power: the device is 3 or 4 metres from the AP the whole day, there's just air in the line of sight between them.
Just to be clear: the malfunction is that an iPhone disconnects "AP-STA-DISCONNECTED", "WPA: event 2 notification" gets logged as well and also "MLME-DISASSOCIATE.indication", then after ~3 seconds it connects again, goes as far as getting an IP via DHCP, and then disconnects, and this is repeated for quite a while. If device is not "awaken" from its sleep, it keeps doing it.
I have previously written that this "WPA: event 2 notification" corresponds to "EVENT_MICHAEL_MIC_FAILURE" but I just manually disconnected the device and noticed that it logs as well the same log lines, so this is from the perspective of the AP a voluntary disconnection that the device initiates.
Thanks for checking; in my case one of them is an iPhone 7S+.
I am convinced that it happens while the device is in power save mode because for example it happens all night long when nobody is using it, or during the day when it is not being used for a while (I didn't miss the irony of such device disconnecting/reconnecting every ~3 seconds while supposedly being saving battery) and at least from hostapd logs it seems to be initiated by device (once again I am disappointed that in hostapd EVENT_MICHAEL_MIC_FAILURE can be used for voluntary device disconnection, in these regards some clarity on that "WPA: event 2 notification" would be great)
I have no problem to "blame the device", but I wonder if I could verify what happens with stock Netgear or TP-link firmwares, perhaps they use some trick to prevent this.
Can imagine; I did find quite a bit of such posts, for example also this one in a different forum. I was trying to diagnose the problem as best as I can here so that perhaps a patch can be attempted but I am no fool, after seeing so many threads I came to the conclusion that there is either multiple problems with same symptoms or a regression that keeps happening as you described.
Unfortunately it happens also when the devices is a few meters from AP with nothing in-between, so I don't think this could be a root cause.
FYI it is an iphone 11 not a 13, i corrected my post above.
Also this iphone is 30-40 ft from the access point, through several walls and one floor (it's up relative to the AP). Even with all this, it still prefers the 5 GHz band - it could connect to 2.4 if it wanted to. It would not surprise me that, with such a strained connection, the device would use more power to keep wifi connected continuously compared to "checking in" every 30 sec to a min.
But this is just my situation, yours is apparently different.
1 Like
Tried this and one of the iPhones kept disconnecting/reconnecting all night (while attached to a single SSID), so it's unrelated to that.
Having this problem, I tried changing to the non-ct version of the driver, but it made no difference. Problem persisted.
To which value should I increase it? Disable Inactivity Polling was already unchecked. I have same issue on OpenWRT 21.02.1 and Archer C7 v2, while GL-iNet GL-B1300 is rock stable (i am using both routers with 802.11r).
Mine is set to well over 8 hours, and I haven't had an issue since.
1 Like