Client Match makes user briefly disconnect

[gvandaal]

We recently opened a new office area, with an Aruba solution.

A couple clients told me they get a brief interruption of their wireless connection sometimes, randomly.

I used one client as test subject, and setup a debug on her MAC address. I have now figured out that Client Match is causing her to connect to another access point.

Imagine the office to be a rectangle shaped open office. We have two AP's, one on each "short" side of the rectangle. The test user always sits on here steady place, and never moved her laptop, but still I'm seeing her disconnect and connect to the other AP. 

I noticed this message in the debug log:

## deauth from AP 261 (left side office)##
Jul 18 07:46:52 :501080:  <NOTI> |AP NDHAM01AP261@10.25.34.31 stm|  Deauth to sta: 34:02:86:a6:bb:3e: Ageout AP 10.25.34.31-94:b4:0f:94:c2:01-NDHAM01AP261 Client Match
Jul 18 07:46:52 :501000:  <DBUG> |AP NDHAM01AP261@10.25.34.31 stm|  Station 34:02:86:a6:bb:3e: Clearing state
Jul 18 07:46:52 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 07:46:52 :522036:  <INFO> |authmgr|  MAC=34:02:86:a6:bb:3e Station DN: BSSID=94:b4:0f:94:c2:01 ESSID=AirFlight VLAN=3000 AP-name=NDHAM01AP261
Jul 18 07:46:52 :522234:  <DBUG> |authmgr|  Setting idle timer for user 34:02:86:a6:bb:3e to 300 seconds (idle timeout: 300 ageout: 0).
Jul 18 07:46:52 :522152:  <DBUG> |authmgr|  station free: bssid=94:b4:0f:94:c2:01, @=0x0x16ca0f4.
Jul 18 07:46:52 :501000:  <DBUG> |stm|  Station 34:02:86:a6:bb:3e: Clearing state
## auth to AP 262 (right side office)##
Jul 18 07:46:57 :501093:  <NOTI> |AP NDHAM01AP262@10.25.34.30 stm|  Auth success: 34:02:86:a6:bb:3e: AP 10.25.34.30-94:b4:0f:94:38:b1-NDHAM01AP262
Jul 18 07:46:57 :501095:  <NOTI> |AP NDHAM01AP262@10.25.34.30 stm|  Assoc request @ 07:46:57.254841: 34:02:86:a6:bb:3e (SN 309): AP 10.25.34.30-94:b4:0f:94:38:b1-NDHAM01AP262
Jul 18 07:46:57 :501100:  <NOTI> |AP NDHAM01AP262@10.25.34.30 stm|  Assoc success @ 07:46:57.256046: 34:02:86:a6:bb:3e: AP 10.25.34.30-94:b4:0f:94:38:b1-NDHAM01AP262
Jul 18 07:46:57 :501100:  <NOTI> |stm|  Assoc success @ 07:46:57.271437: 34:02:86:a6:bb:3e: AP 10.25.34.30-94:b4:0f:94:38:b1-NDHAM01AP262

Can we overcome this from happening? I don't want to disable Client Match, since it's a good feature for roaming in other parts of the building.

[cjoseph]

Client match activates for three reasons:
Client is too "sticky"
Too many clients on an access point
Client is dual band and ends up on the 2.4ghz band.

You can minimize two out of the three by turning down the max tx power in the ARM profile.

What is the max tx power in your ARM profile?

[gvandaal]

Hi CJ, 

I have current ARM profiles running on the office environment. one for A and one for G

rf arm-profile "ARM_OPENOFFICE_A"
no 80MHz-support
max-tx-power 15
min-tx-power 12
ideal-coverage-index 6
backoff-time 1800
error-rate-wait-time 90
cm-unst-ageout-intvl days 0 hours 4
cm-band-g-max-signal 10
cm-steer-timeout 3
cm-max-steer-fails 5
cm-lb-client-thresh 60
!

rf arm-profile "ARM_OPENOFFICE_G"
no 80MHz-support
max-tx-power 9
min-tx-power 6
ideal-coverage-index 6
free-channel-index 40
backoff-time 1800
error-rate-threshold 70
error-rate-wait-time 90
cm-unst-ageout-intvl days 0 hours 4
cm-band-g-max-signal 10
cm-steer-timeout 3
cm-max-steer-fails 5
cm-lb-client-thresh 60
!

[cjoseph]

There are parameters that have been modified from the defaults, but nothing stands out a causing your issue specifically. On that specific client with the issue, what client match trigger happens most often?

[gvandaal]

Hi CJ,

would following output answer your question? If not, please let me know which output you need.

PS: the only time the user complaint about losing connection was around the 07:47 timestamp

Jul 18 07:08:49 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 07:20:03 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 81
Jul 18 07:46:25 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 07:46:52 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 07:47:42 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 07:52:23 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 81
Jul 18 08:13:05 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:25:36 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:27:04 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:27:47 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:28:19 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 08:31:56 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:33:07 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:41:50 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:42:42 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:46:36 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 1
Jul 18 08:57:29 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 1
Jul 18 08:58:58 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:59:10 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:59:24 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 08:59:35 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 09:00:56 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 09:01:26 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 09:03:42 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 09:14:17 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 09:28:34 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 09:37:19 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:04:14 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:04:32 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 22
Jul 18 10:22:08 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:22:19 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:22:22 :522289:  <DBUG> |authmgr|  Auth GSM : MAC_USER mu_delete publish for mac 34:02:86:a6:bb:3e bssid 94:b4:0f:94:d4:a1 vlan 3000 type 1 data-ready 0 deauth-reason 52
Jul 18 10:22:22 :501106:  <NOTI> |stm|  Deauth to sta: 34:02:86:a6:bb:3e: Ageout AP 10.25.34.32-94:b4:0f:94:d4:a1-NDHAM01AP263 wifi_deauth_sta
Jul 18 10:22:22 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 52
Jul 18 10:22:24 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:22:25 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:22:26 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:22:29 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:23:00 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:23:59 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 0 deauth_reason 68
Jul 18 10:40:47 :522296:  <DBUG> |authmgr|  Auth GSM : USER_STA delete event for user 34:02:86:a6:bb:3e age 1000 deauth_reason 56

[cjoseph]

Please try this command:

show ap arm client-match history client-mac<client-mac>

[gvandaal]

(NDEMHAM01WD1WC01) #show ap arm client-match history client-mac 34:02:86:a6:bb:3e

S: Source, T: Target, A: Actual
BTM-ACC: 11v BTM Accept, BTM-REJ#: 11v-BTM Reject with reason #, BTM-TO: 11v-BTM Timeout, BTM-FA: 11v-BTM False Accept
Unit of Roam Time: second
Unit of Signal: dBm

ARM Client match History
-------------------------
Time of Change       Station            Reason      Status/Roam Time/Mode           Signal(S/T/A)  Band(S/T/A)   Radio Bssid(S/T/A)                                     AP Name(S/T/A)
--------------       -------            ------      ---------------------           -------------  -----------   ------------------                                     --------------
2016-07-18 10:04:32  34:02:86:a6:bb:3e  Band-steer  Success/0/Deauth                -40/-56/-56    2.4G/5G/5G    94:b4:0f:94:38:a0/94:b4:0f:94:38:b0/94:b4:0f:94:38:b0  NDHAM01AP262/NDHAM01AP262/NDHAM01AP262
2016-07-18 09:01:29  34:02:86:a6:bb:3e  Band-steer  Acceptable/3/Deauth             -52/-59/-44    2.4G/5G/5G    94:b4:0f:94:38:a0/94:b4:0f:94:38:b0/94:b4:0f:94:c2:10  NDHAM01AP262/NDHAM01AP262/NDHAM01AP261
2016-07-18 09:01:01  34:02:86:a6:bb:3e  Band-steer  Wrong-Radio/5/Deauth            -51/-60/-51    2.4G/5G/2.4G  94:b4:0f:94:38:a0/94:b4:0f:94:38:b0/94:b4:0f:94:38:a0  NDHAM01AP262/NDHAM01AP262/NDHAM01AP262
2016-07-18 08:28:25  34:02:86:a6:bb:3e  Band-steer  Uncontrolled-Radio(I)/6/Deauth  -83/-72/-      2.4G/5G/5G    94:b4:0f:94:d4:a0/94:b4:0f:94:d4:b0/94:b4:0f:94:d7:70  NDHAM01AP263/NDHAM01AP263/NDHAM01AP264
2016-07-18 07:46:57  34:02:86:a6:bb:3e  Band-steer  Wrong-Radio/5/Deauth            -39/-42/-58    2.4G/5G/5G    94:b4:0f:94:c2:00/94:b4:0f:94:c2:10/94:b4:0f:94:38:b0  NDHAM01AP261/NDHAM01AP261/NDHAM01AP262

[cjoseph]

If your clients are repeatedly being band steered, that means there is not enough separation between the 2.4ghz and the 5ghz.  The 5ghz should be stronger than the 2.4ghz so that the client does not keep going back...

[gvandaal]

Hi CJ,

should I then play around with the min/max TX values of the ARM profile for 5ghz?

[cjoseph]

The arm profile min/max for 5ghz should be at least 3 higher than the 2.4ghz. 5ghz max should not be over 18, however. You might have to reduce the 2.4ghz to accomplish this.