Wireless Access

Hi,

We have some 802.1x users that are disconnected even are using the computer (creating new sessions/browser internet, etc...)

The log message are:

Apr 13 11:48:34 :501105:  <NOTI> |stm|  Deauth from sta: 68:a3:c4:40:03:b1: AP 10.77.0.150-d8:c7:c8:da:d3:00-2Y-Piso1-PT01 Reason Inactive Timer expired and STA was disassociated

After 1 second, the user are reconnected again. But even in this case, all connections (SSH, Telnet, MSN, etc...) get disconnected.

Follow the complete user log:

-----------

Apr 13 11:39:47 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:48:34 :501105:  <NOTI> |stm|  Deauth from sta: 68:a3:c4:40:03:b1: AP 10.77.0.150-d8:c7:c8:da:d3:00-2Y-Piso1-PT01 Reason Inactive Timer expired and STA was disassociated
Apr 13 11:48:34 :501065:  <DBUG> |stm|  Sending STA 68:a3:c4:40:03:b1 message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr Dynamic WPA,WPA2 8021X TKIP VLAN 0xa47, wmm:1, rsn_cap:0
Apr 13 11:48:34 :500511:  <DBUG> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Received disassociation on ESSID: UFU-Institucional Mobility service ON, HA Discovery on Association Off, Fastroaming Disabled, AP: Name 2Y-Piso1-PT01 Group UFU BSSID d8:c7:c8:da:d3:00, phy g, VLAN 2631
Apr 13 11:48:34 :500010:  <NOTI> |mobileip|  Station 68:a3:c4:40:03:b1, 255.255.255.255: Mobility trail, on switch 200.131.199.130, VLAN 2631, AP 2Y-Piso1-PT01, UFU-Institucional/d8:c7:c8:da:d3:00/g
Apr 13 11:48:34 :522036:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station DN: BSSID=d8:c7:c8:da:d3:00 ESSID=UFU-Institucional VLAN=2631 AP-name=2Y-Piso1-PT01
Apr 13 11:48:34 :501000:  <DBUG> |stm|  Station 68:a3:c4:40:03:b1: Clearing state
Apr 13 11:48:35 :501095:  <NOTI> |stm|  Assoc request @ 11:48:35.475085: 68:a3:c4:40:03:b1 (SN 313): AP 10.77.0.173-d8:c7:c8:da:d2:c0-2Y-Terreo-PT03
Apr 13 11:48:35 :501100:  <NOTI> |stm|  Assoc success @ 11:48:35.477497: 68:a3:c4:40:03:b1: AP 10.77.0.173-d8:c7:c8:da:d2:c0-2Y-Terreo-PT03
Apr 13 11:48:35 :501065:  <DBUG> |stm|  Sending STA 68:a3:c4:40:03:b1 message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr Dynamic WPA,WPA2 8021X TKIP VLAN 0xa38, wmm:1, rsn_cap:0
Apr 13 11:48:35 :500511:  <DBUG> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Received association on ESSID: UFU-Institucional Mobility service ON, HA Discovery on Association Off, Fastroaming Disabled, AP: Name 2Y-Terreo-PT03 Group UFU BSSID d8:c7:c8:da:d2:c0, phy g, VLAN 2616
Apr 13 11:48:35 :500010:  <NOTI> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Mobility trail, on switch 200.131.199.130, VLAN 2616, AP 2Y-Terreo-PT03, UFU-Institucional/d8:c7:c8:da:d2:c0/g
Apr 13 11:48:35 :522035:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station UP: BSSID=d8:c7:c8:da:d2:c0 ESSID=UFU-Institucional VLAN=2616 AP-name=2Y-Terreo-PT03
Apr 13 11:48:35 :522044:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station authenticate(start): method=802.1x, role=authenticated/authenticated/, VLAN=2616/2616/2631/0/0, Derivation=1/0, Value Pair=0 
Apr 13 11:48:35 :522049:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1,IP=N/A User role updated, existing Role=authenticated/authenticated, new Role=authenticated/authenticated, reason=Station Authenticated with auth type: 4
Apr 13 11:48:35 :522050:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1,IP=N/A User data downloaded to datapath, new Role=authenticated/57, bw Contract=0/0,reason=Download driven by user role setting
Apr 13 11:48:35 :522029:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station authenticate: method=802.1x, role=authenticated/authenticated/, VLAN=2616/2616/2631/0/0, Derivation=1/0, Value Pair=0 
Apr 13 11:49:47 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:47 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:48 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:48 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:49 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:49 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:50 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:49:51 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:53:34 :501105:  <NOTI> |stm|  Deauth from sta: 68:a3:c4:40:03:b1: AP 10.77.0.173-d8:c7:c8:da:d2:c0-2Y-Terreo-PT03 Reason STA has left and is deauthenticated
Apr 13 11:53:34 :501065:  <DBUG> |stm|  Sending STA 68:a3:c4:40:03:b1 message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr Dynamic WPA,WPA2 8021X TKIP VLAN 0xa38, wmm:1, rsn_cap:0
Apr 13 11:53:34 :500511:  <DBUG> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Received disassociation on ESSID: UFU-Institucional Mobility service ON, HA Discovery on Association Off, Fastroaming Disabled, AP: Name 2Y-Terreo-PT03 Group UFU BSSID d8:c7:c8:da:d2:c0, phy g, VLAN 2616
Apr 13 11:53:34 :500010:  <NOTI> |mobileip|  Station 68:a3:c4:40:03:b1, 255.255.255.255: Mobility trail, on switch 200.131.199.130, VLAN 2616, AP 2Y-Terreo-PT03, UFU-Institucional/d8:c7:c8:da:d2:c0/g
Apr 13 11:53:34 :522036:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station DN: BSSID=d8:c7:c8:da:d2:c0 ESSID=UFU-Institucional VLAN=2616 AP-name=2Y-Terreo-PT03
Apr 13 11:53:34 :501000:  <DBUG> |stm|  Station 68:a3:c4:40:03:b1: Clearing state
Apr 13 11:53:39 :501095:  <NOTI> |stm|  Assoc request @ 11:53:39.991357: 68:a3:c4:40:03:b1 (SN 24): AP 10.77.0.150-d8:c7:c8:da:d3:00-2Y-Piso1-PT01
Apr 13 11:53:39 :501100:  <NOTI> |stm|  Assoc success @ 11:53:39.993442: 68:a3:c4:40:03:b1: AP 10.77.0.150-d8:c7:c8:da:d3:00-2Y-Piso1-PT01
Apr 13 11:53:39 :501065:  <DBUG> |stm|  Sending STA 68:a3:c4:40:03:b1 message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr Dynamic WPA,WPA2 8021X TKIP VLAN 0xa38, wmm:1, rsn_cap:0
Apr 13 11:53:39 :500511:  <DBUG> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Received association on ESSID: UFU-Institucional Mobility service ON, HA Discovery on Association Off, Fastroaming Disabled, AP: Name 2Y-Piso1-PT01 Group UFU BSSID d8:c7:c8:da:d3:00, phy g, VLAN 2616
Apr 13 11:53:39 :500010:  <NOTI> |mobileip|  Station 68:a3:c4:40:03:b1, 0.0.0.0: Mobility trail, on switch 200.131.199.130, VLAN 2616, AP 2Y-Piso1-PT01, UFU-Institucional/d8:c7:c8:da:d3:00/g
Apr 13 11:53:39 :522035:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station UP: BSSID=d8:c7:c8:da:d3:00 ESSID=UFU-Institucional VLAN=2616 AP-name=2Y-Piso1-PT01
Apr 13 11:53:40 :522038:  <INFO> |authmgr|  username=fernanda@cti.ufu.br MAC=68:a3:c4:40:03:b1 IP=0.0.0.0 Authentication result=Authentication Successful method=802.1x server=batman
Apr 13 11:53:40 :522044:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station authenticate(start): method=802.1x, role=authenticated/authenticated/, VLAN=2616/2616/2631/0/0, Derivation=1/0, Value Pair=1 
Apr 13 11:53:40 :522049:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1,IP=N/A User role updated, existing Role=authenticated/authenticated, new Role=authenticated/authenticated, reason=Station Authenticated with auth type: 4
Apr 13 11:53:40 :522050:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1,IP=N/A User data downloaded to datapath, new Role=authenticated/57, bw Contract=0/0,reason=Download driven by user role setting
Apr 13 11:53:40 :522023:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Derived VLAN 2631 from server rules: server-group=UFU-institucional
Apr 13 11:53:40 :522029:  <INFO> |authmgr|  MAC=68:a3:c4:40:03:b1 Station authenticate: method=802.1x, role=authenticated/authenticated/, VLAN=2616/2616/2631/2631/0, Derivation=1/3, Value Pair=1 
Apr 13 11:53:40 :522008:  <NOTI> |authmgr|  User Authentication Successful: username=fernanda@cti.ufu.br MAC=68:a3:c4:40:03:b1 IP=10.248.31.79 role=authenticated VLAN=2616 AP=2Y-Piso1-PT01 SSID=UFU-Institucional AAA profile=UFU-institucional-aaa_prof auth method=802.1x auth server=batman
Apr 13 11:59:51 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:51 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:51 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:51 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:53 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:53 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:54 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 
Apr 13 11:59:54 :501065:  <DBUG> |stm|   Get Next/Get Request mac is 68:a3:c4:40:03:b1 

Have some config to do?

regards,

Paulo Raponi

I'll be opening up a TAC Case today, but was curious if you ever got an answer about this (5 Year Old Post I know) - Only other post I saw concerning "Inactive Timer" was from the same year - http://community.arubanetworks.com/t5/Wireless-Access/Inactive-Timer-expired-message/td-p/27706

I've had this occur on my Android phone - and have noticed the message occur on 2-3 devices today via the "show ap client trail-info" command. My understanding is this is a different deauthentication from the "Sapcp Ageout" - although I could be wrong - this is on a 802.1X (MSCHAPv2) network running Aruba OS 6.5.3.3.

You should see how often your users get disconnected and for what reason by using the command:

show ap debug client-deauth-reason-counters

Many disconnects can be caused by poor roaming and contention.  If this reason is higher than the others, you should follow your suggestion to open a TAC case. 

Thanks Colin. Wasn't aware of that particular counter command. The "Inactivity Timer" doesn't show up under that counters - a particular issue that I've only noticed on my Android phone where I randomly get kicked off (finally bothered me enough last week to dive into further).

Thank for that command - diving into a "Ptk Challenge Failed" issue and that may come in handy. Thank you.