Reasons for WLC_E_DEAUTH_IND / WLAN_REASON_PREV_AUTH_NOT_VALID when roaming

[Simon Falsig]

Hi,

I'm trying to debug an issue where Linux-based devices in some, rare cases lose WiFi connection after roaming to another access point.

Setup:
 - Stations: Embedded Linux board, running Linux 4.4, wpa_supplicant v2.8, Broadcom WiFi with bcmdhd driver
 - Access Points: Multiple Ubiquity AP-AC-Pro, running, from what I can see, hostapd v2.8 on an Atheros chipset
 - WiFi with WPA2-PSK, 5GHz only, non-DFS channels, coverage of area is not complete

The stations move around within the area, and will thus roam between the access points. In some cases, what I see is:
1. The station is connected to access point 1, but is moving out of range
2. The station thus attempts to roam to access point 2
3. It connects, but data is no longer coming through
4. After ~4 seconds, I see that the station disconnects due to WLC_E_DEAUTH_IND (reason WLAN_REASON_PREV_AUTH_NOT_VALID), received from access point 2
5. The station no longer manages to connect to any access point until rebooted (bringing the network interface down and back up might also be enough, but am not sure - have not had a chance to try this out)

What I'm trying to do now is to replicate this in a controlled environment, but have so far been unsuccessful. I'm thus trying to figure out if there are any cases where hostapd or wpa_supplicant might cause this to happen?

Until now I've tried:
- Roaming the embedded Linux board between two access points in various configurations (channels, TX power, placement of access points, minimum RSSI, de-auth attacks, etc.)
- Looking through the wpa_supplicant / hostapd code, for WLAN_REASON_PREV_AUTH_NOT_VALID, but without finding any obvious culprits (admitted, with my very limited knowledge of how things work)

I sadly don't have access to the system that exhibited the error in the first place any more, and also have a very limited number of logs from failures - I'm limited to dmesg logs from the stations, where I'd see things like this:
[ 4602.537366] CFG80211-ERROR) wl_bss_roaming_done : wl_bss_roaming_done succeeded to 74:83:c2:b5:7b:90 (ch:48)
[ 4602.547672] CFG80211-ERROR) wl_notify_connect_status : wl_bss_connect_done succeeded with 74:83:c2:b5:7b:90
[ 4602.597668] CFG80211-ERROR) wl_bss_roaming_done : wl_bss_roaming_done succeeded to 74:83:c2:b5:7b:90 (ch:48)
[ 4606.662454] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH_IND
[ 4606.669899] CFG80211-ERROR) wl_notify_connect_status : link down if wlan0 may call cfg80211_disconnected. event : 6, reason=2 from 74:83:c2:b5:7b:90
[ 4606.685715] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.703597] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.711119] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.720558] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.727996] CFG80211-ERROR) wl_is_linkdown : 
[ 4606.728501] cfg80211: World regulatory domain updated:
[ 4606.728504] cfg80211:  DFS Master region: unset<6>[ 4606.728506] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 4606.728509] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.728512] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 4606.728513] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.728516] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 4606.728518] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[ 4606.728520] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[ 4606.728522] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.728524] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[ 4606.782728] cfg80211: World regulatory domain updated:
[ 4606.782731] cfg80211:  DFS Master region: unset<6>[ 4606.782733] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 4606.782739] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.782742] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz, 92000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 4606.782744] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.782746] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 4606.782749] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[ 4606.782751] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[ 4606.782753] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[ 4606.782755] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[ 4606.931747] Link down Reason : WLC_E_DEAUTH
[ 4606.967191] CFG80211-ERROR) wl_cfg80211_cancel_scan : Scan aborted! 
[ 4606.973702] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.980859] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.987956] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4606.995104] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4607.002281] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4607.009374] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4607.016486] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
[ 4607.023627] CFG80211-ERROR) wl_is_linkdown : Link down Reason : WLC_E_DEAUTH
(...continues...)


I realize that the core issue may very well not have anything to do with hostapd / wpa_supplicant, but rather a buggy WiFi driver/firmware somewhere, but any input/hints/tips on how to get the issue reproduced would be highly appreciated.

Thanks in advance!
 - Simon