EA3500, hostapd: WPA: group key handshake failed (RSN) after 4 tries, wlan1: AP-STA-DISCONNTED

Username: builker

Origin: https://bugs.openwrt.org/index.php?do=details&task_id=2210

SNAPSHOT r9614-b6149540, mwlwifi version 2018-12-18 c2c8244, hostapd-common - 2018-12-02-c2c6c01b-2

Run an EA3500 as AP, serving around 15 devices in a small open office. The signal level is good, SNR -ge 30. When using the default wpa_group_rekey value 600s, there were a lot of disconnections. More than 50% of App requests ended up with a timeout on some devices, such as an iPad. Trying different wpa_group_rekey in values wireless and leasetime in dhcp relieved the problem somewhat. But still many

random

connections and disconnections. The following log focuses on one device during a period of quiet time, with wpa_group_rekey being 3600s and leasetime 3600s as well. The problem/log is at least 15 times bigger/longer.

Fri Mar 29 05:02:36 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 05:02:36 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 05:03:30 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: group key handshake failed (RSN) after 4 tries Fri Mar 29 05:03:30 2019 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 11:22:33:44:55:66 Fri Mar 29 05:03:35 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: deauthenticated due to local deauth request Fri Mar 29 05:08:14 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: authenticated Fri Mar 29 05:08:14 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: associated (aid 7) Fri Mar 29 05:08:14 2019 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 11:22:33:44:55:66 Fri Mar 29 05:08:14 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: pairwise key handshake completed (RSN) Fri Mar 29 05:08:14 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 05:08:14 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 05:38:14 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 05:38:14 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 06:03:30 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: group key handshake failed (RSN) after 4 tries Fri Mar 29 06:03:30 2019 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 11:22:33:44:55:66 Fri Mar 29 06:03:35 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: deauthenticated due to local deauth request Fri Mar 29 06:04:21 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: authenticated Fri Mar 29 06:04:21 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: associated (aid 2) Fri Mar 29 06:04:21 2019 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 11:22:33:44:55:66 Fri Mar 29 06:04:21 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: pairwise key handshake completed (RSN) Fri Mar 29 06:04:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 06:04:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 06:34:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 06:34:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 07:02:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 07:02:21 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 07:03:30 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: group key handshake failed (RSN) after 4 tries Fri Mar 29 07:03:30 2019 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 11:22:33:44:55:66 Fri Mar 29 07:03:35 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: deauthenticated due to local deauth request Fri Mar 29 07:06:37 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: authenticated Fri Mar 29 07:06:37 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: associated (aid 7) Fri Mar 29 07:06:37 2019 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 11:22:33:44:55:66 Fri Mar 29 07:06:37 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: pairwise key handshake completed (RSN) Fri Mar 29 07:06:37 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 07:06:37 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 07:36:37 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 07:36:37 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad Fri Mar 29 08:03:30 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: group key handshake failed (RSN) after 4 tries Fri Mar 29 08:03:30 2019 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 11:22:33:44:55:66 Fri Mar 29 08:03:35 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: deauthenticated due to local deauth request Fri Mar 29 08:04:16 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: authenticated Fri Mar 29 08:04:16 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 IEEE 802.11: associated (aid 3) Fri Mar 29 08:04:16 2019 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 11:22:33:44:55:66 Fri Mar 29 08:04:16 2019 daemon.info hostapd: wlan1: STA 11:22:33:44:55:66 WPA: pairwise key handshake completed (RSN) Fri Mar 29 08:04:16 2019 daemon.info dnsmasq-dhcp[2946]: DHCPREQUEST(br-lan) 192.168.1.52 11:22:33:44:55:66 Fri Mar 29 08:04:16 2019 daemon.info dnsmasq-dhcp[2946]: DHCPACK(br-lan) 192.168.1.52 11:22:33:44:55:66 iPad