"deauthenticated due to local deauth request" after 4 clients are connected

Hi all,

I compiled both branches 18.06.2 and snapshot today (03/29/19) from source.

Problem

I am able to associate and authenticate many clients. Max I tested was 15 clients.
But when more than 4 clients start to play video stream (youtube, twitch, netflix):

  1. all the clients loose internet connectivity
  2. all of them are de-authenticated
  3. when trying to reconnect, they connect but are disassociated immediately.
c2:44:2f:f3:3c:22  -64 dBm / -109 dBm (SNR 45)  40 ms ago
	RX: 200.0 MBit/s, VHT-MCS 9, 40MHz, VHT-NSS 1        48 Pkts.
	TX: 12.0 MBit/s                                    9 Pkts.
	expected throughput: unknown

c2:44:2f:f3:3c:22  -57 dBm / -109 dBm (SNR 52)  10 ms ago
	RX: 12.0 MBit/s                                   17 Pkts.
	TX: 12.0 MBit/s                                    5 Pkts.
	expected throughput: unknown
  1. internet on the AP works. (I am able to ping google.com)

Firmware and OS this problem occurs

  • ath10k + 18.06.2 = yes, there is this problem
  • ath10k + snapshot = yes, there is this problem
  • ath10k-ct + 18.06.2 = yes, similar problem occurs (https://github.com/greearb/ath10k-ct/issues/82)
  • ath10k-ct + snapshot = no, works fine

OpenWRT info

Release

DISTRIB_ID='OpenWrt'
DISTRIB_RELEASE='SNAPSHOT'
DISTRIB_REVISION='r9753-6df5ab89cf'
DISTRIB_TARGET='ar71xx/generic'
DISTRIB_ARCH='mips_24kc'
DISTRIB_DESCRIPTION='OpenWrt SNAPSHOT r9753-6df5ab89cf'
DISTRIB_TAINTS='no-all'

Opkgs Installed:

ath10k-firmware-qca9984 - 2018-12-16-211de167-1
kmod-ath10k - 4.14.109+4.19.23-1-5
hostapd v2.7

Logs

Include:

  • Full list of OPKGs installed: 2_opkg_installed-txt
  • Logs up to the point of crash: 3_ath10k_crash-txt
  • Logs after the crash and trying to reconnect: 4_after_crash_reconnect-txt

I am happy to run more tests :slight_smile:

Any advice?

More logs

I just noticed that the some devices stay connected :man_shrugging: and when these connected devices make a dns request, the request is reaching the DNS server but the AP is not receiving response.

I ran ping on one device and captured packets on two interfaces:

  • tcpdump -i wlan0-ap
  • tcpdump -i br-lan

ping google.com: https://gist.github.com/ironpillow/50cb0e2010ac5bc9acc7abc7e20ab910

ping 8.8.8.8: https://gist.github.com/ironpillow/97cb3dd6eb8e9d028a8231f142fae01f

Packets are not reaching wifi wlan0-ap interface.

After the crash, hostapd is logging this for any STA trying to reconnect:

Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authentication OK (open system)
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 0 notification
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-AUTHENTICATE.indication(70:48:0f:b3:2b:1a, OPEN_SYSTEM)
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:37 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authenticated
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: association OK (aid 4)
Sun Mar 31 22:25:37 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: associated (aid 4)
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-ASSOCIATE.indication(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: binding station to interface 'wlan0-ap'
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 1 notification
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:37 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:38 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:38 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:39 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:39 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: PTKSTART: Retry limit 4 reached
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 3 notification
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.1X: unauthorizing port
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DEAUTHENTICATE.indication(70:48:0f:b3:2b:1a, 2)
Sun Mar 31 22:25:40 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:45 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: deauthenticated due to local deauth request
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authentication OK (open system)
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-AUTHENTICATE.indication(70:48:0f:b3:2b:1a, OPEN_SYSTEM)
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:50 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authenticated
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: association OK (aid 4)
Sun Mar 31 22:25:50 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: associated (aid 4)
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-ASSOCIATE.indication(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: binding station to interface 'wlan0-ap'
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 1 notification
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: start authentication
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.1X: unauthorizing port
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:50 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:51 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:51 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:52 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:52 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: PTKSTART: Retry limit 4 reached
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 3 notification
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.1X: unauthorizing port
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DEAUTHENTICATE.indication(70:48:0f:b3:2b:1a, 2)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authentication OK (open system)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 0 notification
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-AUTHENTICATE.indication(70:48:0f:b3:2b:1a, OPEN_SYSTEM)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:53 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: authenticated
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: association OK (aid 4)
Sun Mar 31 22:25:53 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: associated (aid 4)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-ASSOCIATE.indication(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: binding station to interface 'wlan0-ap'
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 1 notification
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:53 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:54 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:54 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:55 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:55 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: sending 1/4 msg of 4-Way Handshake
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: EAPOL-Key timeout
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: PTKSTART: Retry limit 4 reached
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a WPA: event 3 notification
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.1X: unauthorizing port
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DEAUTHENTICATE.indication(70:48:0f:b3:2b:1a, 2)
Sun Mar 31 22:25:56 2019 daemon.debug hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a MLME: MLME-DELETEKEYS.request(70:48:0f:b3:2b:1a)
Sun Mar 31 22:26:01 2019 daemon.info hostapd: wlan0-ap: STA 70:48:0f:b3:2b:1a IEEE 802.11: deauthenticated due to local deauth request
1 Like

I have same problem. ath10k + 19.07 qca9886