802.11r and inability to associate station

perceival · April 3, 2020, 5:29pm

TL;DR 802.11r (or one of accompanying features) is causing disconnects if ranges of different APs are overlapping.

Since a few months one of 5G WiFi clients was few times a day loosing its connection and for some time after was unable to reestablish it. I had no time for troubleshooting then so I was every now and than increasing TX power on one of R7800 acting as an AP assuming maybe that particular client is having problems with an antenna connection and is requiring stronger signal.
The result was surprising: the frequency of disconnects increased and gradually more and more clients exhibited the same behavior. When the station installed just a meter away from the AP lost almost permanently WiFi connection I started to investigate.
I have started with testing different firmware versions both from @gearbest (ct) and non-ct. Still the same.
After going through logs I associated the first appearance of the issue with the moment I've added second R7800 to my network as an AP. Specifically the moment I've finalized setting up 802.11r.
After significantly reducing 5G transmit power on the AP and slightly reducing it on R7800 router problem is no longer there.
Further steps to identify whether any specific feature is having impact:

disable 802.11v
disable 802.11r static keys
...
Typical problematic association attempt (yesterday there were 140 like that on the router and 800 on the AP):

Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authentication OK (open system)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-AUTHENTICATE.indication(xx:xx:xx:xx:xx:xx, OPEN_SYSTEM)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-DELETEKEYS.request(xx:xx:xx:xx:xx:xx)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: Drop repeated authentication frame seq_ctrl=0x94c0
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: Drop repeated authentication frame seq_ctrl=0x94c0
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: association OK (aid 4)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: associated (aid 4)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-ASSOCIATE.indication(xx:xx:xx:xx:xx:xx)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx MLME: MLME-DELETEKEYS.request(xx:xx:xx:xx:xx:xx)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: binding station to interface 'wlan0'
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: event 1 notification
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: start authentication
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: unauthorizing port
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: did not Ack EAPOL-Key frame (unicast index=51)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 1/4 msg of 4-Way Handshake
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: received EAPOL-Key frame (2/4 Pairwise)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 3/4 msg of 4-Way Handshake
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: did not Ack EAPOL-Key frame (unicast index=51)
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 3/4 msg of 4-Way Handshake
Apr  3 09:57:12 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: did not Ack EAPOL-Key frame (unicast index=51)
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: EAPOL-Key timeout
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: sending 3/4 msg of 4-Way Handshake
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: received EAPOL-Key frame (4/4 Pairwise)
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.1X: authorizing port
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx RADIUS: starting accounting session 170D8C9F5C2DAFD6
Apr  3 09:57:13 AP hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)

Relevant part of router /etc/config/wireless:

config wifi-device 'radio0'
	option type 'mac80211'
	option hwmode '11a'
	option path 'soc/1b500000.pci/pci0000:00/0000:00:00.0/0000:01:00.0'
	option legacy_rates '0'
	option country 'PL'
	option htmode 'VHT80'
	option channels '64 116'
	option log_level '0'
	option channel '116'
	option txpower '5'

config wifi-iface 'wifinet1'
	option device 'radio0'
	option mode 'ap'
	option ssid 'ssid'
	option network 'lan'
	option key 'key'
	option dtim_period '5'
	option macfilter 'deny'
	option ft_over_ds '1'
	option ieee80211r '1'
	option mobility_domain '400d'
	option pmk_r1_push '1'
	option r1_key_holder 'B07FB9xxxxxx'
	option nasid 'B07FB9xxxxxx'
	list r0kh '8C:3B:AD:xx:xx:xx,8C3BADxxxxxx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r0kh 'B0:7F:B9:xx:xx:xx,B07FB9xxxxxx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r1kh '8C:3B:AD:xx:xx:xx,8C:3B:AD:xx:xx:xx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r1kh 'B0:7F:B9:xx:x:xx,B0:7F:B9:xx:xx:xx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	option skip_inactivity_poll '1'
	option ft_psk_generate_local '0'
	option encryption 'psk2+ccmp'
	option ieee80211k '1'
	option bss_transition '1'
	option ieee80211v '1'
	option wpa_group_rekey '86400'
	option max_inactivity '3600'

and AP:

config wifi-device 'radio0'
	option type 'mac80211'
	option hwmode '11a'
	option path 'soc/1b500000.pci/pci0000:00/0000:00:00.0/0000:01:00.0'
	option htmode 'VHT80'
	option legacy_rates '0'
	option country 'PL'
	option log_level '0'
	option channel '64'
	option txpower '10'

config wifi-iface 'default_radio0'
	option device 'radio0'
	option network 'lan'
	option ssid 'ssid'
	option key 'key'
	option mode 'ap'
	option ft_over_ds '1'
	option mobility_domain '400d'
	option ieee80211r '1'
	option pmk_r1_push '1'
	option r1_key_holder '8C3BADxxxxxx'
	option nasid '8C3BADxxxxxx'
	list r0kh '8C:3B:AD:xx:xx:xx,8C3BADxxxxxx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r0kh 'B0:7F:B9:xx:xx:xx,B07FB9xxxxxx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r1kh '8C:3B:AD:xx:xx:xx,8C:3B:AD:xx:xx:xx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	list r1kh 'B0:7F:B9:xx:xx:xx,B0:7F:B9:xx:xx:xx,xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx'
	option skip_inactivity_poll '1'
	option ft_psk_generate_local '0'
	option encryption 'psk2+ccmp'
	option ieee80211k '1'
	option bss_transition '1'
	option ieee80211v '1'
	option wpa_group_rekey '86400'
	option max_inactivity '3600'

Previously AP was running full throttle.

krazeh · April 3, 2020, 5:49pm

Have you tried generating the PMK locally? Rather than using the r0 and r1 keys?

perceival · April 3, 2020, 5:54pm

I've started with generated keys but now unable to recreate the timeline. Planning to test it once I will have time and once nobody will be using WiFi.

krazeh · April 3, 2020, 6:07pm

I had a similar issue with my R7800 and an AP. My android phone kept dropping off 5G and either needed to wait for some time before it'd reconnect or I could force a reconnect by restarting the phone wifi. This was while I had a 802.11r setup running. I seemed to have solved it a few days ago by clearing the entire config and starting afresh with the bare minimum. So NAS ID on each device, a mobility domain, and generating PMK locally.

perceival · April 4, 2020, 6:44am

With PMK generated locally there is no change. So far the only impact had lowering the TX power.
Another idea:
Since I am searching through logs for seq_ctrl string and enabled more detailed logging around the beginning of the problem maybe it was there before but that particular message containing seq_ctrl string wasn't logged with default logging level?

joba-1 · July 16, 2021, 12:36pm

over a year passed. Have you found a solution?

It looks like I could have the same problem:

https://forum.openwrt.org/t/roaming-issues-xiaomi-ax3600