Controller Based WLANs

What do the different numbers mean in the 'show auth-tracebuf' command output?

Product and Software: This article applies to all Aruba controllers that run ArubaOS 3.1 and later.

 

Aruba controllers provide a powerful troubleshooting command: 'show auth-tracebuf'. Used with the 'show ap debug mgmt-frame' and 'user-debug' commands, the command provides clues to the causes of connectivity-related issues.

 

opensystem 

 

Jul 30 04:08:41 station-up * 00:19:7d:b8:b4:51 00:0b:86:ae:31:91 - - open system Jul 30 04:08:41 station-data-ready * 00:19:7d:b8:b4:51 00:00:00:00:00:00 400 -

The number "400" is the VLAN assigned to the user, which can be confirmed by enabling the 'user-debug' command.

Jul 30 04:08:41 :501095: <NOTI> |stm| Assoc request: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:91-ias Jul 30 04:08:41 :501100: <NOTI> |stm| Assoc success: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:91-ias Jul 30 04:08:41 :501065: <DBUG> |stm| Sending STA 00:19:7d:b8:b4:51 message to Auth and Mobility Unicast Encr Open Multicast Encr Open VLAN 0x190 Jul 30 04:08:41 :522035: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 Station UP: BSSID=00:0b:86:ae:31:91 ESSID=open VLAN=400 AP-name=ias Jul 30 04:08:41 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 ingress 0x104b (tunnel 11), u_encr 1, m_encr 1, slotport 0x1020 Jul 30 04:08:41 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 def_vlan 400 derive vlan: 0 auth_type 0 auth_subtype 0

 

staticwep 

 

Jul 30 04:12:47 station-up * 00:19:7d:b8:b4:51 00:0b:86:ae:31:92 - - static wep Jul 30 04:12:47 station-data-ready * 00:19:7d:b8:b4:51 00:00:00:00:00:00 400 -

 

The number "400" is the VLAN assigned to the user. The other numbers are the size of the packet.

 

user-debug 

 

Jul 30 04:12:47 :501095: <NOTI> |stm| Assoc request: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:92-ias
Jul 30 04:12:47 :501100: <NOTI> |stm| Assoc success: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:92-ias
Jul 30 04:12:47 :501065: <DBUG> |stm| Sending STA 00:19:7d:b8:b4:51 message to Auth and Mobility Unicast Encr Static WEP Multicast Encr Static WEP VLAN 0x190
Jul 30 04:12:47 :522035: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 Station UP: BSSID=00:0b:86:ae:31:92 ESSID=staticwep VLAN=400 AP-name=ias
Jul 30 04:12:47 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 ingress 0x104a (tunnel 10), u_encr 2, m_encr 2, slotport 0x1020
Jul 30 04:12:47 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 def_vlan 400 derive vlan: 0 auth_type 0 auth_subtype 0

 

wpa-psk 

 

Jul 30 04:15:31 station-up * 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - - wpapsktkip
Jul 30 04:15:31 station-data-ready * 00:19:7d:b8:b4:51 00:00:00:00:00:00 400 -
Jul 30 04:15:31 wpa-key1 <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 95
Jul 30 04:15:31 wpa-key2 -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 119
Jul 30 04:15:31 wpa-key3 <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 119
Jul 30 04:15:31 wpa-key4 -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 95
Jul 30 04:15:31 wpa-gkey1 <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 127
Jul 30 04:15:31 wpa-gkey2 -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:93 - 95

 

Again, the number "400" is the VLAN assigned to the user. The other numbers are the size of the packet.

 

 

user-debug 

 

Jul 30 04:15:37 :522026: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=10.168.121.224 User miss: ingress=0x104d, VLAN=400
Jul 30 04:15:37 :522006: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=10.168.121.224 User entry added: reason=Sibyte
Jul 30 04:15:37 :522004: <DBUG> |authmgr| Station inherit: IP=10.168.121.224 start bssid:00:00:00:00:00:00 essid: port:0x104d (0x104d)
Jul 30 04:15:37 :522004: <DBUG> |authmgr| {L3} Update role from logon to logon for IP=10.168.121.224
Jul 30 04:15:37 :522004: <DBUG> |authmgr| Reset BWM contract: IP=10.168.121.224 role=logon, contract= (0), type=Per role
Jul 30 04:15:37 :522004: <DBUG> |authmgr| station inherit IP=10.168.121.224 bssid:00:0b:86:ae:31:93 essid: wpa-psk auth:0 type: role:logon port:0x104d
Jul 30 04:15:37 :522004: <DBUG> |authmgr| {10.168.121.224} autTable (" Unauthenticated logon ")
Jul 30 04:15:37 :522004: <DBUG> |authmgr| download: ip=10.168.121.224 acl=1/0 role=logon, Ubwm=0, Dbwm=0 tunl=0x104d, PA=0, HA=1, RO=0, VPN=0

 

 

wpa2-aes 

 

Jul 30 04:21:43 station-up * 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 - - wpa2 aes
Jul 30 04:21:43 eap-id-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 1 5
Jul 30 04:21:43 eap-id-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 1 8 aaa
Jul 30 04:21:43 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 45 148
Jul 30 04:21:43 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 45 77
Jul 30 04:21:43 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 2 6
Jul 30 04:21:43 eap-nak -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 2 6
Jul 30 04:21:43 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 46 171
Jul 30 04:21:43 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 46 77
Jul 30 04:21:43 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 3 6
Jul 30 04:21:43 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 3 110
Jul 30 04:21:43 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 47 275
Jul 30 04:21:43 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 47 1175
Jul 30 04:21:43 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 4 1096
Jul 30 04:21:43 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 4 6
Jul 30 04:21:43 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 48 171
Jul 30 04:21:43 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 48 1175
Jul 30 04:21:43 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 5 1096
Jul 30 04:21:43 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 5 6
Jul 30 04:21:43 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 49 171
Jul 30 04:21:43 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 49 1175
Jul 30 04:21:43 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 6 1096
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 6 6
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 50 171
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 50 1175
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 7 1096
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 7 6
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 51 171
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 51 428
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 8 355
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 8 204
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 52 369
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 52 124
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 9 53
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 9 6
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 53 171
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 53 99
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 10 28
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 10 31
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 54 196
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 54 130
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 11 59
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 11 85
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 55 250
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 55 145
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 12 74
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 12 29
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 56 194
Jul 30 04:21:44 rad-resp<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 56 109
Jul 30 04:21:44 eap-req<- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 13 38
Jul 30 04:21:44 eap-resp -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 13 38
Jul 30 04:21:44 rad-req -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 57 203
Jul 30 04:21:44 rad-accept <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90/ias 57 283
Jul 30 04:21:44 eap-success <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 14 4
Jul 30 04:21:44 station-data-ready * 00:19:7d:b8:b4:51 00:00:00:00:00:00 400 -
Jul 30 04:21:44 wpa2-key1 <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 - 117
Jul 30 04:21:44 wpa2-key2 -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 - 117
Jul 30 04:21:44 wpa2-key3 <- 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 - 151
Jul 30 04:21:44 wpa2-key4 -> 00:19:7d:b8:b4:51 00:0b:86:ae:31:90 - 95

 

 

In the eap/rad packet, the first number is the ID. In case of EAP, the first number is the eapid. In case of RADIUS, the first number is the RADIUS packet ID. The second number is the size of the packet.

 

user-debug 

 

 

Jul 30 04:21:43 :501095: <NOTI> |stm| Assoc request: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:90-ias
Jul 30 04:21:43 :501100: <NOTI> |stm| Assoc success: 00:19:7d:b8:b4:51: AP 10.168.121.238-00:0b:86:ae:31:90-ias
Jul 30 04:21:43 :501065: <DBUG> |stm| Sending STA 00:19:7d:b8:b4:51 message to Auth and Mobility Unicast Encr WPA2 8021X AES Multicast Encr WPA2 8021X AES VLAN 0x190
Jul 30 04:21:43 :522035: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 Station UP: BSSID=00:0b:86:ae:31:90 ESSID=ias VLAN=400 AP-name=ias
Jul 30 04:21:43 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 ingress 0x104c (tunnel 12), u_encr 64, m_encr 64, slotport 0x1020
Jul 30 04:21:44 :522039: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=0.0.0.0 Authentication result=Authentication Successful method=802.1x server=ias
Jul 30 04:21:44 :522016: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=0.0.0.0 Derived role 'userauth-ias' from Aruba VSA
Jul 30 04:21:44 :522004: <DBUG> |authmgr| {L2} authenticated from profile "ias"
Jul 30 04:21:44 :522004: <DBUG> |authmgr| {L2} Update role from logon to authenticated for IP=0.0.0.0
Jul 30 04:21:44 :522004: <DBUG> |authmgr| download: ip=0.0.0.0 acl=31/0 role=authenticated, Ubwm=0, Dbwm=0 tunl=0x104c, PA=0, HA=1, RO=0, VPN=0
Jul 30 04:21:44 :522004: <DBUG> |authmgr| MAC=00:19:7d:b8:b4:51 def_vlan 400 derive vlan: 0 auth_type 4 auth_subtype 4
Jul 30 04:21:44 :522029: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 Station authenticated: method=802.1x, role=authenticated, VLAN=400/400/0
Jul 30 04:21:44 :522004: <DBUG> |authmgr| {0.0.0.0} autTable ("aaa Authenticated 802.1x authenticated ")
Jul 30 04:21:47 :522026: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=10.168.121.224 User miss: ingress=0x104c, VLAN=400
Jul 30 04:21:47 :522006: <INFO> |authmgr| MAC=00:19:7d:b8:b4:51 IP=10.168.121.224 User entry added: reason=Sibyte
Jul 30 04:21:47 :522004: <DBUG> |authmgr| Station inherit: IP=10.168.121.224 start bssid:00:00:00:00:00:00 essid: port:0x104c (0x104c)
Jul 30 04:21:47 :522004: <DBUG> |authmgr| {L3} Update role from logon to authenticated for IP=10.168.121.224
Jul 30 04:21:47 :522004: <DBUG> |authmgr| Reset BWM contract: IP=10.168.121.224 role=authenticated, contract= (0), type=Per role
Jul 30 04:21:47 :522004: <DBUG> |authmgr| download: ip=10.168.121.224 acl=31/0 role=authenticated, Ubwm=0, Dbwm=0 tunl=0x104c, PA=0, HA=1, RO=0, VPN=0
Jul 30 04:21:47 :522008: <NOTI> |authmgr| MAC=00:19:7d:b8:b4:51 IP=10.168.121.224 User authenticated: method=802.1x, server=ias, role=authenticated
Jul 30 04:21:47 :522004: <DBUG> |authmgr| station inherit IP=10.168.121.224 bssid:00:0b:86:ae:31:90 essid: ias auth:1 type:802.1x role:authenticated port:0x104c
Jul 30 04:21:47 :522004: <DBUG> |authmgr| {10.168.121.224} autTable ("aaa Authenticated 802.1x authenticated ")
Jul 30 04:21:47 :522004: <DBUG> |authmgr| download: ip=10.168.121.224 acl=31/0 role=authenticated, Ubwm=0, Dbwm=0 tunl=0x104c, PA=0, HA=1, RO=0, VPN=0

Version History
Revision #:
1 of 1
Last update:
‎07-02-2014 06:33 AM
Updated by:
 
Labels (1)
Contributors
Tags (1)
Search Airheads
Showing results for 
Search instead for 
Did you mean: 
Is this a frequent problem?

Request an official Aruba knowledge base article to be written by our experts.