Windows clients dropping periodically - WLC_E_DEAUTH_IND

[dtopo]

Hello all…. 

Looking for any light you can shed on the following issue.

Environment: 

School environment. AP 230s and 250s. APs are running the latest firmware - 10.0.10.2. Very few 2.4GHZ radios enabled - w channels spaced and power turned way down. 5 ghz radio using DFS 40Mhz channels - again, power turned down to suppress loud taking\interference etc. Retries rates are healthy - tx and rx. Usage is typical web based apps - google meets etc

I’m getting some windows users experiencing drop outs in connectivity in a certain wing of one of our buildings - involves 3 APs. Logs show cycles of deauths for theses user devices. Wireless drivers are updated to newest (Intel family).

I have a clean parsed log of a particular client which is indicative of what's happening. I’ll paste it here - I will appreciate any input hugely ! 

Thanks ...Dennis

Teacher 1 – rm 153 – this is her 8:31am deauth..continuing to the new 8:32am auth ---- to about 1:15 pm… note first event is a ah_auth: aaa: [Auth]: receive driver notification[0x6, WLC_E_DEAUTH_IND] – she was connected before that for 21 minutes. So the crux of the issue is what is causing the deauth(s) ???

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]: receive driver notification[0x6, WLC_E_DEAUTH_IND] for Sta[548d:5aea:464c] at Hapd[9c5d:1246:e624, wifi1.1]

2021-03-16 08:31:14    Local6.Warning 10.2.20.28     ah_auth: misc: wifi1.1: get sta 548d:5aea:464c stats ioctl failed!

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: ah_rt_sta_del: 548d:5aea:464c

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: station_new_status_trap_force: ah_dcd_get_radio_one_sta(548d:5aea:464c) failed

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: pmksa_cache_auth_add: own_addr 9c5d:1246:e624, sta 548d:5aea:464c, 1, username Ourdomain\teacher1

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]: receive driver notification[0xc, WLC_E_DISASSOC_IND] for Sta[548d:5aea:464c] at Hapd[9c5d:1246:e624, wifi1.1]

2021-03-16 08:31:14    Local6.Info    10.2.20.28     ah_auth: aaa: sta 548d:5aea:464c is disassociated from 9c5d:1246:e624(wifi1.1) in driver

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]: receive driver notification[0xa, WLC_E_REASSOC_IND] for Sta[548d:5aea:464c] at Hapd[9c5d:1246:e624, wifi1.1]

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: pmksa_cache_auth_add: own_addr 9c5d:1246:e624, sta 548d:5aea:464c, 0, username Ourdomain\teacher1

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: station 548d:5aea:464c OS=Windows 10, flag2=48, roamed=1, set permit DHCP flag for roaming.

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: Set flag 2 to fe for station 548d:5aea:464c, os=Windows 10, flag2=48

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: add new RT sta: MAC=548d:5aea:464c, IP=10.2.20.160, hostname=KCLEFFI-X1, username=Ourdomain\teacher1 on wifi1.1

2021-03-16 08:31:24    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]STA(548d:5aea:464c) login to SSID(wifi1.1) by user_name=Ourdomain\teacher1

2021-03-16 08:31:24    Local6.Info    10.2.20.28     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp wifi1.1 upid 1 flag 0x1c03 monitor(0/0) pkt/sec ok

2021-03-16 08:31:24    Local6.Info    10.2.20.28     amrp2: misc: set VLAN ID 220 for station 548d:5aea:464c

Never get detect station --- as shown below in next attempt- get a probe request then the deauth

2021-03-16 08:31:24    Local6.Info    10.2.20.28     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 wifi1.1 flag 0x1c03

2021-03-16 08:31:24    Local6.Info    10.2.20.30     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp N/A upid 1 flag 0x1402 monitor(0/0) pkt/sec ok

021-03-16 08:31:24     Local6.Info    10.2.20.53     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp N/A upid 1 flag 0x1402 monitor(0/0) pkt/sec ok

2021-03-16 08:31:24    Local6.Info    10.2.20.53     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 n/a flag 0x1402

2021-03-16 08:31:24    Local6.Info    10.2.20.30     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 n/a flag 0x1402

2021-03-16 08:31:25    Local6.Info    10.2.20.28     kernel: [qos]: add qos user 548d:5aea:464c idx 70 uppid 1

2021-03-16 08:31:26    Local6.Info    10.2.20.28     ah_dcd: wifi: [CLT_CAPS]Send 9c5d:1246:e624[548d:5aea:464c] <PROBE REQ> trap successfully

2021-03-16 08:31:36    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]: receive driver notification[0x6, WLC_E_DEAUTH_IND] for Sta[548d:5aea:464c] at Hapd[9c5d:1246:e624, wifi1.1]

021-03-16 08:31:36     Local6.Info    10.2.20.28     ah_auth: aaa: sta 548d:5aea:464c is disassociated from 9c5d:1246:e624(wifi1.1) in driver

Trying again here- this time suscessfully

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]: receive driver notification[0xa, WLC_E_REASSOC_IND] for Sta[548d:5aea:464c] at Hapd[9c5d:1246:e624, wifi1.1]

021-03-16 08:32:02     Local6.Info    10.2.20.28     ah_auth: aaa: pmksa_cache_auth_add: own_addr 9c5d:1246:e624, sta 548d:5aea:464c, 0, username Ourdomain\teacher1

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: station 548d:5aea:464c OS=Windows 10, flag2=48, roamed=1, set permit DHCP flag for roaming.

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: Set flag 2 to fe for station 548d:5aea:464c, os=Windows 10, flag2=48

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: add new RT sta: MAC=548d:5aea:464c, IP=10.2.20.160, hostname=KCLEFFI-X1, username=Ourdomain\teacher1 on wifi1.1

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: [Auth]STA(548d:5aea:464c) login to SSID(wifi1.1) by user_name=Ourdomain\teacher1

2021-03-16 08:32:02    Local6.Info    10.2.20.28     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp wifi1.1 upid 1 flag 0x1c03 monitor(0/0) pkt/sec ok

2021-03-16 08:32:02    Local6.Info    10.2.20.28     amrp2: misc: set VLAN ID 220 for station 548d:5aea:464c

2021-03-16 08:32:02    Local6.Info    10.2.20.28     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 wifi1.1 flag 0x1c03

2021-03-16 08:32:02    Local6.Info    10.2.20.53     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp N/A upid 1 flag 0x1402 monitor(0/0) pkt/sec ok

2021-03-16 08:32:02    Local6.Info    10.2.20.30     amrp2: l2routing: set proxy route: 548d:5aea:464c -> 9c5d:1246:e600 ifp N/A upid 1 flag 0x1402 monitor(0/0) pkt/sec ok

2021-03-16 08:32:02    Local6.Info    10.2.20.53     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 n/a flag 0x1402

2021-03-16 08:32:02    Local6.Info    10.2.20.30     kernel: [mesh]: set proxy : 548d:5aea:464c 9c5d:1246:e600 n/a flag 0x1402

2021-03-16 08:32:02    Local6.Info    10.2.20.28     kernel: [qos]: add qos user 548d:5aea:464c idx 70 uppid 1

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: detect station(548d:5aea:464c) os(Windows 10) via DHCP fingerprint

2021-03-16 08:32:02    Local6.Notice  10.2.20.28     ah_auth: Station 548d:5aea:464c was authenticated on 9c5d:1246:e624 through SSID Haverford_Wireless vid 220.

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: Station 548d:5aea:464c ip 10.2.20.160 username Ourdomain\teacher1 hostname KCLEFFI-X1 OS Windows 10, flag = DHCP

2021-03-16 08:32:02    Local6.Info    10.2.20.28     ah_auth: aaa: update RT sta: MAC=548d:5aea:464c, IPv6 address number =1, username=Ourdomain\teacher1 on wifi1.1

2021-03-16 08:32:03    Local6.Info    10.2.20.28     ah_auth: aaa: update RT sta: MAC=548d:5aea:464c, IPv6 address number =1, username=Ourdomain\teacher1 on wifi1.1

2021-03-16 08:33:07    Local6.Info    10.2.20.28     ah_dcd: wifi: [CLT_CAPS]Send 9c5d:1246:e624[548d:5aea:464c] <PROBE REQ> trap successfully

2021-03-16 10:02:07    Local6.Info    10.2.20.28     ah_auth: aaa: update RT sta: MAC=548d:5aea:464c, IPv6 address number =1, username=Ourdomain\teacher1 on wifi1.1

[stevejcuk]

How did this resolve for you, in the end, I have a similar issue after upgrading to version 10?

Were you on a version below that previously?

Thanks.

Steve

[dtopo]

Thanks Sam, for putting eyes on it!--- makes sense. Not yet….I went down to 12dbm…..so yes, I’ll try that. ...maybe to 8. We have APs in every other classroom for the most part. Just hoping they will still get the coverage and throughput going lower. It does seem, however the client will have established a connection for some time, then be deauthed- loose the connection, and then probe for an AP. Not sure what would cause it to not “stick” to the initial AP and why the deauth in the first place.  Anyway...I will turn them down and post my finding here - thanks again.

[SamPirok · Accepted solution]

Hi Dennis, thank you very much for the detailed explanation and the data, that helped a lot. It looks like the client is bouncing between two APs, but not staying connected long enough to fully connect to the AP. For example: 

2021-03-16 08:31:14 Local6.Warning 10.2.20.28 ah_auth: misc: wifi1.1: get sta 548d:5aea:464c stats ioctl failed!

2021-03-16 08:31:14 Local6.Info 10.2.20.28 ah_auth: aaa: ah_rt_sta_del: 548d:5aea:464c

2021-03-16 08:31:14 Local6.Info 10.2.20.28 ah_auth: aaa: station_new_status_trap_force: ah_dcd_get_radio_one_sta(548d:5aea:464c) failed

Here we see the ioctl (input output control) fails, mostly likely because the client was no longer associated with the APs radio since we see it trying to connect to a different radio, so the AP deletes the station (client) MAC address. 

Typically, we’d recommend turning down the AP’s power to decrease signal overlap, so the client device doesn’t have multiple connection options at the same time. However, I see you’ve written that you’ve already lowered the power on your APs to account for this. It’s not unusual for APs in school environments (especially when we have an AP in almost every room) for the radio power to be turned down to 1 or 2dBm, have you gone that low yet?