[FS#13] Ath9k AP stays up for connected clients but doesn't show in scan on new ones

Wed Aug 24 12:46:18 PDT 2016

The following task has a new comment added:

FS#13 - Ath9k AP stays up for connected clients but doesn't show in scan on new ones
User who did this - Martin Tippmann (glycoknob)

----------
The issue is reproducible for me when I have 2 clients that both do downloads e.g. 

running: wget -O /dev/null http://speed.hetzner.de/100MB.bin 

it's enough to have a have a few megabit downstream on both clients and the issue starts immediatly. 

Now on r1435 - here is the hostapd logfile at log_level=0 but nothing interesting to see: 

Wed Aug 24 19:34:45 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.1X: authorizing port
Wed Aug 24 19:34:45 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: pairwise key handshake completed (RSN)
Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: WPA rekeying GTK
Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: sending 1/2 msg of Group Key Handshake
Wed Aug 24 19:36:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: received EAPOL-Key frame (2/2 Group)
Wed Aug 24 19:36:39 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: group key handshake completed (RSN)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-AUTHENTICATE.indication(e8:de:27:19:b9:17, OPEN_SYSTEM)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-DELETEKEYS.request(e8:de:27:19:b9:17)
Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: authenticated
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: association OK (aid 2)
Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: associated (aid 2)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-ASSOCIATE.indication(e8:de:27:19:b9:17)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 MLME: MLME-DELETEKEYS.request(e8:de:27:19:b9:17)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.11: binding station to interface 'wlan0'
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: event 1 notification
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: start authentication
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.1X: unauthorizing port
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: sending 1/4 msg of 4-Way Handshake
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: received EAPOL-Key frame (2/4 Pairwise)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: sending 3/4 msg of 4-Way Handshake
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: received EAPOL-Key frame (4/4 Pairwise)
Wed Aug 24 19:38:22 2016 daemon.debug hostapd: wlan0: STA e8:de:27:19:b9:17 IEEE 802.1X: authorizing port
Wed Aug 24 19:38:22 2016 daemon.info hostapd: wlan0: STA e8:de:27:19:b9:17 WPA: pairwise key handshake completed (RSN)
Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 WPA: event 2 notification
Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.1X: unauthorizing port
Wed Aug 24 19:38:39 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: disassociated
Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DISASSOCIATE.indication(90:68:c3:aa:b4:80, 1)
Wed Aug 24 19:38:39 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:38:40 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Wed Aug 24 19:38:40 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DEAUTHENTICATE.indication(90:68:c3:aa:b4:80, 2)
Wed Aug 24 19:38:40 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:38:46 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:38:47 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response
Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:38:51 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:38:52 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response
Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:38:58 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:38:59 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response
Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:39:10 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:39:11 2016 daemon.info hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: disconnected due to excessive missing ACKs
Wed Aug 24 19:39:11 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response
Wed Aug 24 19:39:12 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DISASSOCIATE.indication(90:68:c3:aa:b4:80, 34)
Wed Aug 24 19:39:12 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:39:13 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:39:14 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response
Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: authentication OK (open system)
Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-AUTHENTICATE.indication(90:68:c3:aa:b4:80, OPEN_SYSTEM)
Wed Aug 24 19:39:17 2016 daemon.debug hostapd: wlan0: STA 90:68:c3:aa:b4:80 MLME: MLME-DELETEKEYS.request(90:68:c3:aa:b4:80)
Wed Aug 24 19:39:18 2016 daemon.notice hostapd: wlan0: STA 90:68:c3:aa:b4:80 IEEE 802.11: did not acknowledge authentication response

----------

More information can be found at the following URL:
https://bugs.lede-project.org/index.php?do=details&task_id=13#comment306