Problem with Radius server and WLC 1850/2850

joseecheverria · ‎03-11-2022

Hello, we have a customer that is experiencing delays when the devices associate to a 1850/2800 (Mobility express 8.8.125) ap enviroment with WPA2 enterprise autentication. I think ther is a big delay betwen the beginning of the association and the first Radius reply, but maybe i am misreading the logs.

The debug is somecing like this:

login as:

(Cisco Controller)
User: INTERMEC
Password:*********
Welcome to the Cisco Mobility Express command line interface.
Only commands which are listed in the command reference guide for this release are supported.
http://www.cisco.com/c/en/us/support/wireless/mobility-express/products-command-reference-list.html
(Cisco Controller) >
(Cisco Controller) >
(Cisco Controller) >debug client 2C:6D:C1:39:6F:43

(Cisco Controller) >*emWeb: Mar 10 15:31:26.618:
Debugging session started on Mar 10 15:31:26.618 for WLC AIR-AP2802I-E-K9 Version :8.8.125.0 SN :FGL2334LB06 Hostname WLC
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 Received EAPOL START from mobile in dot1x state = 2
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 Received EAPOL START from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Connecting state
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 Sending EAP-Request/Identity to mobile 2c:6d:c1:39:6f:43 (EAP Id 7)
*Dot1x_NW_MsgTask_0: Mar 10 15:31:28.324: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
debug client 2C:6D:C1:39:6F:43

(Cisco Controller) >*osapiBsnTimer: Mar 10 15:31:57.983: 2c:6d:c1:39:6f:43 802.1x 'txWhen' Timer expired for station 2c:6d:c1:39:6f:43 and for message = M0
*Dot1x_NW_MsgTask_0: Mar 10 15:31:57.983: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Connecting state
*Dot1x_NW_MsgTask_0: Mar 10 15:31:57.983: 2c:6d:c1:39:6f:43 Sending EAP-Request/Identity to mobile 2c:6d:c1:39:6f:43 (EAP Id
*Dot1x_NW_MsgTask_0: Mar 10 15:31:57.983: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*osapiBsnTimer: Mar 10 15:32:27.737: 2c:6d:c1:39:6f:43 802.1x 'txWhen' Timer expired for station 2c:6d:c1:39:6f:43 and for message = M0
*Dot1x_NW_MsgTask_0: Mar 10 15:32:27.737: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Connecting state
*Dot1x_NW_MsgTask_0: Mar 10 15:32:27.737: 2c:6d:c1:39:6f:43 Sending EAP-Request/Identity to mobile 2c:6d:c1:39:6f:43 (EAP Id 9)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:27.737: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*osapiBsnTimer: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 apfMsExpireCallback (apf_ms.c:657) Expiring Mobile!
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 0 PMK-remove groupcast messages sent
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 Deleted global PMK cache and MSCB PMKID/PMK cache entry for the client
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 Username entry TEST\test' is deleted for mobile from the UserName table
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 Username entry TEST\test deleted for mobile
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 apfMsAssoStateDec
*apfReceiveTask: Mar 10 15:32:40.432: 2c:6d:c1:39:6f:43 Deleting mobile on AP 74:88:bb:4f:29:e0(1)
*apfReceiveTask: Mar 10 15:32:40.455: 2c:6d:c1:39:6f:43 apf_ms.c:5590 Clearing the SGT 0 of mobile
*apfReceiveTask: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Received management frame ASSOCIATION REQUEST on BSSID 74:88:bb:4f:29:ef destination addr 74:88:bb:4f:29:ef
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Processing assoc-req station:2c:6d:c1:39:6f:43 AP:74:88:bb:4f:29:e0-01 ssid : FLORETTE thread:5e17f650
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 apfCreateMobileStationEntryWrapper (apf_ms.c:4471) Changing state for mobile 2c:6d:c1:39:6f:43 on AP 74:88:bb:4f:29:e0 from Idle to Idle

*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Adding mobile on LWAPP AP 74:88:bb:4f:29:e0(1)
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Created Acct-Session-ID (622a0c13/2c:6d:c1:39:6f:43/6203) for the mobile
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Setting hasApChnaged Flag as true. It is a fresh assoc request.

*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Setting RTTS enabled to 0
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Association received from mobile on BSSID 74:88:bb:4f:29:ec AP AP21
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Station: 2C:6D:C1:39:6F:43 trying to join WLAN with RSSI -53. Checking for XOR roam conditions on AP: 74:88:BB:4F:29:E0 Slot: 1
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Station: 2C:6D:C1:39:6F:43 is associating to AP 74:88:BB:4F:29:E0 which is not XOR roam capable
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Global 200 Clients are allowed to AP radio

*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Max Client Trap Threshold: 0 cur: 25

*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Updated local bridging VLAN to 0 while applying WLAN policy
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Updated session timeout to 0 and Sleep timeout to 720 while applying WLAN policy
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 override for default ap group, marking intgrp NULL
*apfMsConnTask_0: Mar 10 15:32:51.061: 2c:6d:c1:39:6f:43 Applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Not re-applying interface policy for local switching Client

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 After applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3284)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3304)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3325)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Values before applying NASID - interfacetype:0, ovrd:0, mscb nasid:, interface nasid:, APgrpset:0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Check before Setting the NAS Id to WLAN specific Id ''
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 apf_policy.c:2569 Assigning the SGT 0 to mobile (earlier sgt 0)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 In processSsidIE:7127 setting Central switched to FALSE
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Set Clinet MSCB as Central Association Disabled
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Applying site-specific Local Bridging override for station 2c:6d:c1:39:6f:43 - vapId 4, site 'OFICINAS', interface 'management'
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Applying Local Bridging Interface Policy for station 2c:6d:c1:39:6f:43 - vlan 0, interface id 0, interface 'management', nasId:''
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 override from ap group, removing intf group from mscb
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Applying site-specific override for station 2c:6d:c1:39:6f:43 - vapId 4, site 'OFICINAS', interface 'management'
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Not applying Local Bridge Policy because Site Specific Interface(management) Policy is already applied.

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Not re-applying interface policy for local switching Client

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 After applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3284)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3304)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3325)
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Values before applying NASID - interfacetype:0, ovrd:0, mscb nasid:, interface nasid:, APgrpset:0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Set Clinet Non AP specific WLAN apfMsAccessVlan = 120
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Cleared localSwitchingVlan, may be assigned later based on AAA override
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 STA - rates (8): 140 18 152 36 176 72 96 108 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_0: Mar 10 15:32:51.062: RSNIE in Assoc. Req.: (22)

*apfMsConnTask_0: Mar 10 15:32:51.062: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f

*apfMsConnTask_0: Mar 10 15:32:51.062: [0016] ac 01 3c 00 00 00

*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Processing RSN IE type 48, length 22 for mobile 2c:6d:c1:39:6f:43
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Selected Unicast cipher CCMP128 for client device
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 RSN Capabilities: 60
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 non-11w Capable mobile
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Received RSN IE with 0 PMKIDs from mobile 2c:6d:c1:39:6f:43
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Received RSN IE with 0 PMKIDs from mobile 2c:6d:c1:39:6f:43
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Setting active key cache index 8 ---> 8
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 unsetting PmkIdValidatedByAp
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Assigning flex webauth IPv4-ACL ID :65535, IPv6-ACL ID:65535 for AP WLAN ID : 1
*apfMsConnTask_0: Mar 10 15:32:51.062: 2c:6d:c1:39:6f:43 Assigned flex post-auth IPv4-ACL ID :65535, IPv6-ACL ID:65535 for AP WLAN ID : 1
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Updating AID for REAP AP Client 74:88:bb:4f:29:e0 - AID ===> 42
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 apfVapSecurity=0x4000 L2=16384 SkipWeb=0
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 AuthenticationRequired = 1
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Encryption policy is set to 0x80000001
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Setting the action to initiate 1x 4 way handshake upon Add_Mobile_Ack for station with encrypt policy:[80000001]
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 0.0.0.0 8021X_REQD (3) DHCP required on AP 74:88:bb:4f:29:e0 vapId 4 apVapId 1for this client
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 flex webauth acl id to be sent :65535 name : client acl id :65535 name :
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 flex webauth ipv6 acl id to be sent :65535 name : client acl id :65535 name :
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Vlan while overriding the policy = -1
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535

*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 74:88:bb:4f:29:e0 vapId 4 apVapId 1 flex acl-name: v6acl-name
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 apfMsAssoStateInc
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 apfPemAddUser2 (apf_policy.c:451) Changing state for mobile 2c:6d:c1:39:6f:43 on AP 74:88:bb:4f:29:e0 from Idle to Associated

*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 apfPemAddUser2:session timeout forstation 2c:6d:c1:39:6f:43 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Sending assoc-resp with status 0 station:2c:6d:c1:39:6f:43 AP:74:88:bb:4f:29:e0-01 on apVapId 1
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 VHT Operation IE: width 80/1 ch 124 freq0 42 freq1 0 msc0 0xff msc1 0xff
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 Sending Assoc Response (status: '0') to station on AP AP21 on BSSID 74:88:bb:4f:29:ef ApVapId 1 Slot 1, mobility role 0
*apfMsConnTask_0: Mar 10 15:32:51.063: 2c:6d:c1:39:6f:43 apfProcessAssocReq (apf_80211.c:12284) Changing state for mobile 2c:6d:c1:39:6f:43 on AP 74:88:bb:4f:29:e0 from Associated to Associated

*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Add SGT:0 to AP 74:88:bb:4f:29:e0
*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0
*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Flex Ipv6 pre-auth acl is not present, not Encoding Flex Ipv6 acl for add mobile Payload
*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Flex Ipv6 post auth acl is not present, not updating add mobile Payload
*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Successful transmission of LWAPP Add-Mobile to AP 74:88:bb:4f:29:e0 idx@47
*spamApTask0: Mar 10 15:32:51.064: 2c:6d:c1:39:6f:43 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 532193889) ack state for STA on AP 74:88:bb:4f:29:e0
*spamApTask0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 Received ADD_MOBILE ack - Initiating 1x to STA 2c:6d:c1:39:6f:43 (idx 47)
*spamApTask0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 APF Initiating 1x to STA 2c:6d:c1:39:6f:43
*spamApTask0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 Sent dot1x auth initiate message for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 dot1xProcessInitiate1XtoMobile to mobile station 2c:6d:c1:39:6f:43 (mscb 1, msg 1)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 1 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:47
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 EAP-PARAM Debug - eap-params for Wlan-Id :4 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 Station 2c:6d:c1:39:6f:43 setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Connecting state
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.067: 2c:6d:c1:39:6f:43 Sending EAP-Request/Identity to mobile 2c:6d:c1:39:6f:43 (EAP Id 1)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 Received EAPOL START from mobile in dot1x state = 2
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 reauth_sm state transition 1 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 Received EAPOL START from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Connecting state
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.156: 2c:6d:c1:39:6f:43 Sending EAP-Request/Identity to mobile 2c:6d:c1:39:6f:43 (EAP Id 2)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.157: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.159: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.159: 2c:6d:c1:39:6f:43 Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.159: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Received Identity Response (count=1) from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Resetting reauth count 1 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 EAP State update from Connecting to Authenticating for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Authenticating state
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Created Cisco-Audit-Session-ID for the mobile: 32013c0a00000ce7130c2a62 type: local
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:220 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 257
*aaaQueueReader: Mar 10 15:32:51.168: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 220) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:00
*radiusTransportThread: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:220
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=3) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 3)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 Allocating EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.173: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 3, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:221 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 443
*aaaQueueReader: Mar 10 15:32:51.176: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 221) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:01
*radiusTransportThread: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:221
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=4) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 4)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.180: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 4, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:222 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 277
*aaaQueueReader: Mar 10 15:32:51.184: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 222) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:02
*radiusTransportThread: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:222
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=5) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 5)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.185: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 5, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.202: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:223 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.203: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 422
*aaaQueueReader: Mar 10 15:32:51.203: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 223) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:03
*radiusTransportThread: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:223
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=6) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 6)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.205: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.233: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.233: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 6, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.233: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.233: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.233: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:224 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 277
*aaaQueueReader: Mar 10 15:32:51.234: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 224) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:04
*radiusTransportThread: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:224
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=7) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 7)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.235: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 7, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:225 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 330
*aaaQueueReader: Mar 10 15:32:51.237: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 225) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:05
*radiusTransportThread: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:225
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=8) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.238: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 8, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:226 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 330
*aaaQueueReader: Mar 10 15:32:51.249: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 226) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:06
*radiusTransportThread: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:226
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=9) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 9)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.250: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.251: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.255: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.255: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 9, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.255: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.255: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.255: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:227 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 378
*aaaQueueReader: Mar 10 15:32:51.256: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 227) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:07
*radiusTransportThread: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:227
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=10) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 10)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.258: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 10, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.260: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.261: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.261: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.261: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:228 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.261: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 314
*aaaQueueReader: Mar 10 15:32:51.261: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 228) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:08
*radiusTransportThread: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 Access-Challenge received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:228
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 Processing Access-Challenge for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 Entering Backend Auth Req state (id=12) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 WARNING: updated EAP-Identifier 10 ===> 12 for STA 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 Sending EAP Request from AAA to mobile 2c:6d:c1:39:6f:43 (EAP Id 12)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.262: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Received EAPOL EAPPKT from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Received EAP Response from mobile 2c:6d:c1:39:6f:43 (EAP Id 12, EAP Type 25)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Resetting reauth count 0 to 0 for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Entering Backend Auth Response state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 reauth_sm state transition 0 ---> 0 for mobile 2c:6d:c1:39:6f:43 at 1x_reauth_sm.c:71
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is ready 10.60.1.1 port 1812 index 0 active 1
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 radiusServerFallbackPassiveStateUpdate: RADIUS server is maybe-ready 10.60.16.1 port 1812 index 1 active 1
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Found a server : 10.60.1.1 from the WLAN server list of radius server index 1
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Send Radius Auth Request with pktId:229 into qid:3 of server at index:0
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Sending the packet to v4 host 10.60.1.1:1812 of length 378
*aaaQueueReader: Mar 10 15:32:51.264: 2c:6d:c1:39:6f:43 Successful transmission of Authentication Packet (pktId 229) to 10.60.1.1:1812 from server queue 3, proxy state 2c:6d:c1:39:6f:43-03:09
*radiusTransportThread: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Radius AVP MPPE send key decrypted key: keylen: 32

*radiusTransportThread: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Radius AVP MPPE recv key: keylen: 32

*radiusTransportThread: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Access-Accept received from RADIUS server 10.60.1.1 (qid:3) with port:1812, pktId:229
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Processing Access-Accept for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Previous Radius Overrides:(0)

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Received MPPE_SEND_KEY: KeyLen: 32

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Received MPPE_RECV_KEY: KeyLen: 32

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Applying new AAA override for station 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Override values for station 2c:6d:c1:39:6f:43
source: 4, valid bits: 0x0
qosLevel: -1, dscp: 0xffffffff, dot1pTag: 0xffffffff, sessionTimeout: -1 Interim Interval: -1
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Override values (cont..) dataAvgC: -1, rTAvgC: -1, dataBurstC: -1, rTimeBurstC: -1
vlanIfName: '', vlanId:0, aclName: ', ipv6AclName: , avcProfileName: '

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Override values (cont..2) dataAvgCUs: -1, rTAvgCUs: -1, dataBurstCUs: -1, rTimeBurstCUs: -1
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Unable to apply override policy for station 2c:6d:c1:39:6f:43 - VapAllowRadiusOverride is FALSE.
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Local policy not enabled on. Not applying override
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Setting re-auth timeout to 1800 seconds, got from WLAN config.
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.266: 2c:6d:c1:39:6f:43 Station 2c:6d:c1:39:6f:43 setting dot1x reauth timeout = 1800
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Username entry (TEST\test) created for mobile, length = 253
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Username entry (TEST\test) created in mscb for mobile, length = 253
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Creating a PKC PMKID Cache entry for station 2c:6d:c1:39:6f:43 (RSN 2)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Resetting MSCB PMK Cache Entry @index 0 for station 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Created PMKID PMK Cache for BSSID 74:88:bb:4f:29:ef at index 0 for station 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: New PMKID: (16)

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: [0000] 4e 79 f9 39 2e c0 70 7e 99 cf 3f c3 cc 86 29 9b

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 802.11i: Create a global PMK cache entry, AKM-type = 1
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 apfCreatePmkCacheEntry: added a new pmk cache entry for 2c:6d:c1:39:6f:43

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 1x: Updated the audit-session-id of PMK-Cache from client mscb: 32013c0a00000ce7130c2a62
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Zeroize AAA Overrides from local for station
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Adding Audit session ID payload in Mobility handoff

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 0 PMK-update groupcast messages sent
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 PMK sent to mobility group
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Disabling re-auth since PMK lifetime can take care of same.
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Sending EAP-Success to mobile 2c:6d:c1:39:6f:43 (EAP Id 12)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Freeing AAACB from Dot1xCB as AAA auth is done for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 key Desc Version FT - 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Found an cache entry for BSSID 74:88:bb:4f:29:ef in PMKID cache at index 0 of station 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Found an cache entry for BSSID 74:88:bb:4f:29:ef in PMKID cache at index 0 of station 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: Including PMKID in M1 (16)

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: [0000] 4e 79 f9 39 2e c0 70 7e 99 cf 3f c3 cc 86 29 9b

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: M1 - Key Data: (22)

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: [0000] dd 14 00 0f ac 04 4e 79 f9 39 2e c0 70 7e 99 cf

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: [0016] 3f c3 cc 86 29 9b

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Starting key exchange to mobile 2c:6d:c1:39:6f:43, data packets will be dropped
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Sending EAPOL-Key Message to mobile 2c:6d:c1:39:6f:43
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Entering Backend Auth Success state (id=12) for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 Received Auth Success while in Authenticating state for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.267: 2c:6d:c1:39:6f:43 dot1x - moving mobile 2c:6d:c1:39:6f:43 into Authenticated state
*CAPWAP DATA: Mar 10 15:32:51.276: 2c:6d:c1:39:6f:43 validating eapol pkt: key version = 2
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Received EAPOL-Key from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 key Desc Version FT - 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Received EAPOL-key in PTK_START state (message 2) from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Encryption Policy: 4, PTK Key Length: 48
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Successfully computed PTK from PMK!!!
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Received valid MIC in EAPOL Key Message M2!!!!!
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 rsnieCapabilty = 3c rsnie_len =20
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Dumping RSNIE received in Association request(len = 24):
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 00000000: 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0...............
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 00000010: 00 0f ac 01 3c 00 00 00 ....<...
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Dumping RSNIE received in EAPOL M2 (len = 22):
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 00000010: ac 01 3c 00 00 00 ..<...
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Stopping retransmission timer for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 key Desc Version FT - 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 key Desc Version FT - 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Sending EAPOL-Key Message to mobile 2c:6d:c1:39:6f:43
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.277: 2c:6d:c1:39:6f:43 Reusing allocated memory for EAP Pkt for retransmission to mobile 2c:6d:c1:39:6f:43
*CAPWAP DATA: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 validating eapol pkt: key version = 2
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Received EAPOL-Key from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 key Desc Version FT - 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Stopping retransmission timer for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Freeing EAP Retransmit Bufer for mobile 2c:6d:c1:39:6f:43
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 apfMs1xStateInc
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 apfMsPeapSimReqCntInc
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 apfMsPeapSimReqSuccessCntInc
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Mobility query, PEM State: L2AUTHCOMPLETE

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 L2AUTHCOMPLETE (4) NO release MSCB
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Building Mobile Announce :

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Building Client Payload:

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Client Ip: 0.0.0.0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Client Vlan Ip: 10.60.1.50, Vlan mask : 255.255.252.0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Client Vap Security: 16384

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Virtual Ip: 192.0.2.1

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 ssid: FLORETTE

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Building VlanIpPayload.

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 L2AUTHCOMPLETE (4) DHCP required on AP 74:88:bb:4f:29:e0 vapId 4 apVapId 1for this client
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 flex webauth acl id to be sent :65535 name : client acl id :65535 name :
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 flex webauth ipv6 acl id to be sent :65535 name : client acl id :65535 name :
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Vlan while overriding the policy = -1
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 74:88:bb:4f:29:e0 vapId 4 apVapId 1 flex acl-name: v6acl-name
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)

*spamApTask0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Add SGT:0 to AP 74:88:bb:4f:29:e0
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 7231, Adding TMP rule
*spamApTask0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.279: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 74:88:bb:4f:29:e0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 Updating info change db with CMX bitmap 0x0000
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) NO release MSCB
*Dot1x_NW_MsgTask_0: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 Successfully Plumbed PTK session Keysfor mobile 2c:6d:c1:39:6f:43
*apfReceiveTask: Mar 10 15:32:51.280: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) mobility role update request from Unassociated to Local
Peer = 0.0.0.0, Old Anchor = 0.0.0.0, New Anchor = 10.60.1.50
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 pemAdvanceState2 (pem_api.c:6735) Changing state for mobile 2c:6d:c1:39:6f:43 on AP 74:88:bb:4f:29:e0 from Associated to Associated

*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 6869, Adding TMP rule
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 74:88:bb:4f:29:e0, slot 1, interface = 1, QOS = 0
IPv4 ACL ID = 255,
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 Updating info change db with CMX bitmap 0x0000
*apfReceiveTask: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 0.0.0.0 DHCP_REQD (7) NO release MSCB
*spamApTask0: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 Flex Ipv6 pre-auth acl is not present, not Encoding Flex Ipv6 acl for add mobile Payload
*spamApTask0: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 Flex Ipv6 post auth acl is not present, not updating add mobile Payload
*spamApTask0: Mar 10 15:32:51.281: 2c:6d:c1:39:6f:43 Successful transmission of LWAPP Add-Mobile to AP 74:88:bb:4f:29:e0 idx@48
*pemReceiveTask: Mar 10 15:32:51.283: 2c:6d:c1:39:6f:43 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Mar 10 15:32:51.283: 2c:6d:c1:39:6f:43 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*apfReceiveTask: Mar 10 15:32:51.288: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:51.288: 2c:6d:c1:39:6f:43 IPv4 Addr: 0:0:0:0

*apfReceiveTask: Mar 10 15:32:51.288: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:51.288: 2c:6d:c1:39:6f:43 IPv4 Addr: 10:60:2:195

*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 dtlArpInsert: Add ARP entry IP 10.60.2.195, MAC 2c:6d:c1:39:6f:43, VLAN 0, INTF 1, Type 0, New 1 (caller apf_foreignap.c:1176)
,arp count = 209
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 dtlArpSetType: Changing ARP Type from 0 ---> 1 for station 2c:6d:c1:39:6f:43
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 apfMsRunStateInc
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 10.60.2.195 DHCP_REQD (7) Change state to RUN (20) last state DHCP_REQD (7)

*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 the value of url acl preserve flag is 0 for mobile 2c:6d:c1:39:6f:43 (caller pem_api.c:7854)
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 Initiating Accounting request(0) update for mobile
*pemReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 10.60.2.195 Removed NPU entry.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 Accounting NAI-Realm: TEST\test, from Mscb username : TEST\test
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 PemLocationConfigured [1]Adding VSA with NAS update and Role[1] with state[0]
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 10.60.2.195 RUN (20) NO release MSCB
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 Assigning Address 10.60.2.195 to mobile
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 No DHCP scope for IP scope name none.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 IPv4 Addr: 10:60:2:195

*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 No DHCP scope for IP scope name none.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 IPv4 Addr: 10:60:2:195

*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 10 15:32:51.289: 2c:6d:c1:39:6f:43 No DHCP scope for IP scope name none.
*apfReceiveTask: Mar 10 15:32:51.322: 2c:6d:c1:39:6f:43 Recieved MS IPv4 Addr= 10.60.2.195
*apfReceiveTask: Mar 10 15:32:51.323: 2c:6d:c1:39:6f:43 Updating MS IPv6[1] Addr= fe80:0000:0000:0000:4d4a:7afe:e75a:11bd
*apfReceiveTask: Mar 10 15:32:51.323: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 2, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:51.323: 2c:6d:c1:39:6f:43 IPv4 Addr: 10:60:2:195

*apfReceiveTask: Mar 10 15:32:51.323: 2c:6d:c1:39:6f:43 Static IP client associated to interface management which can support client subnet.
*apfReceiveTask: Mar 10 15:32:51.323: 2c:6d:c1:39:6f:43 No DHCP scope for IP scope name none.
*apfReceiveTask: Mar 10 15:32:54.491: 2c:6d:c1:39:6f:43 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 2, add_or_delete 1
*apfReceiveTask: Mar 10 15:32:54.491: 2c:6d:c1:39:6f:43 IPv4 Addr: 10:60:2:195

*apfReceiveTask: Mar 10 15:32:54.491: 2c:6d:c1:39:6f:43 Static IP client associated to interface management which can support client subnet.
*apfReceiveTask: Mar 10 15:32:54.491: 2c:6d:c1:39:6f:43 No DHCP scope for IP scope name none.
*apfReceiveTask: Mar 10 15:32:56.285: 2c:6d:c1:39:6f:43 Received management frame ACTION on BSSID 74:88:bb:4f:29:ef destination addr 74:88:bb:4f:29:ef
*apfMsConnTask_0: Mar 10 15:32:56.286: 2c:6d:c1:39:6f:43 Got action frame from the client (ActionCategory:5), payloadLen:3
*apfMsConnTask_0: Mar 10 15:32:56.286: 2c:6d:c1:39:6f:43 Found RM action category code
*apfMsConnTask_0: Mar 10 15:32:56.286: 2c:6d:c1:39:6f:43 Station: 2C:6D:C1:39:6F:43 sent 802.11K neighbor request to AP 74:88:BB:4F:29:E0

(Cisco Controller) >disable-all

Incorrect usage. Use the '?' or <TAB> key to list commands.

(Cisco Controller) >

marce1000 · ‎03-11-2022

- Below you will find output from your debug file when processed with : https://cway.cisco.com/wireless-debug-analyzer/ , it succeeds in the end but there seem to be a bit several attempts to get answer from the radius server. Check radius-server logs too ,look for problem indicators - if any :

Show Time

Show Task

Show Translated

Show Original

Show Prior First Connection

Show All

TimeTaskTranslated

Mar 10 15:32:51.061	*apfMsConnTask_0	Client made new Association to AP/BSSID BSSID 74:88:bb:4f:29:ec AP AP21
Mar 10 15:32:51.062	*apfMsConnTask_0	The WLC/AP has found from client association request Information Element that claims PMKID Caching support
Mar 10 15:32:51.062	*apfMsConnTask_0	The Reassociation Request from the client comes with 0 PMKID
Mar 10 15:32:51.062	*apfMsConnTask_0	The Reassociation Request from the client comes with 0 PMKID
Mar 10 15:32:51.063	*apfMsConnTask_0	Client is entering the 802.1x or PSK Authentication state
Mar 10 15:32:51.063	*apfMsConnTask_0	Client has successfully cleared AP association phase
Mar 10 15:32:51.063	*apfMsConnTask_0	WLC/AP is sending an Association Response to the client with status code 0 = Successful association
Mar 10 15:32:51.067	*Dot1x_NW_MsgTask_0	Client will be required to Reauthenticate in 1800 seconds
Mar 10 15:32:51.067	*Dot1x_NW_MsgTask_0	WLC/AP is sending EAP-Identity-Request to the client
Mar 10 15:32:51.156	*Dot1x_NW_MsgTask_0	WLC/AP is sending EAP-Identity-Request to the client
Mar 10 15:32:51.168	*Dot1x_NW_MsgTask_0	Client sent EAP-Identity-Response to WLC/AP
Mar 10 15:32:51.168	*aaaQueueReader	Radius request with ID 220 sent to 10.60.1.1.
Mar 10 15:32:51.173	*radiusTransportThread	Radius request with ID 220 sent to 10.60.1.1.
Mar 10 15:32:51.176	*aaaQueueReader	Radius request with ID 221 sent to 10.60.1.1.
Mar 10 15:32:51.180	*radiusTransportThread	Radius request with ID 221 sent to 10.60.1.1.
Mar 10 15:32:51.184	*aaaQueueReader	Radius request with ID 222 sent to 10.60.1.1.
Mar 10 15:32:51.185	*radiusTransportThread	Radius request with ID 222 sent to 10.60.1.1.
Mar 10 15:32:51.203	*aaaQueueReader	Radius request with ID 223 sent to 10.60.1.1.
Mar 10 15:32:51.205	*radiusTransportThread	Radius request with ID 223 sent to 10.60.1.1.
Mar 10 15:32:51.234	*aaaQueueReader	Radius request with ID 224 sent to 10.60.1.1.
Mar 10 15:32:51.235	*radiusTransportThread	Radius request with ID 224 sent to 10.60.1.1.
Mar 10 15:32:51.237	*aaaQueueReader	Radius request with ID 225 sent to 10.60.1.1.
Mar 10 15:32:51.238	*radiusTransportThread	Radius request with ID 225 sent to 10.60.1.1.
Mar 10 15:32:51.249	*aaaQueueReader	Radius request with ID 226 sent to 10.60.1.1.
Mar 10 15:32:51.250	*radiusTransportThread	Radius request with ID 226 sent to 10.60.1.1.
Mar 10 15:32:51.256	*aaaQueueReader	Radius request with ID 227 sent to 10.60.1.1.
Mar 10 15:32:51.258	*radiusTransportThread	Radius request with ID 227 sent to 10.60.1.1.
Mar 10 15:32:51.261	*aaaQueueReader	Radius request with ID 228 sent to 10.60.1.1.
Mar 10 15:32:51.262	*radiusTransportThread	Radius request with ID 228 sent to 10.60.1.1.
Mar 10 15:32:51.264	*aaaQueueReader	Radius request with ID 229 sent to 10.60.1.1.
Mar 10 15:32:51.266	*Dot1x_NW_MsgTask_0	RADIUS Server permitted access
Mar 10 15:32:51.266	*Dot1x_NW_MsgTask_0	Client will be required to Reauthenticate in 1800 seconds
Mar 10 15:32:51.267	*Dot1x_NW_MsgTask_0	4-Way PTK Handshake, Sending M1
Mar 10 15:32:51.277	*Dot1x_NW_MsgTask_0	4-Way PTK Handshake, Received M2
Mar 10 15:32:51.277	*Dot1x_NW_MsgTask_0	4-Way PTK Handshake, Sending M3
Mar 10 15:32:51.279	*Dot1x_NW_MsgTask_0	4-Way PTK Handshake, Received M4
Mar 10 15:32:51.279	*Dot1x_NW_MsgTask_0	Client has completed PSK Dot1x or WEP authentication phase
Mar 10 15:32:51.279	*Dot1x_NW_MsgTask_0	Client has entered DHCP Required state
Mar 10 15:32:51.289	*apfReceiveTask	Client has entered RUN state
Mar 10 15:32:51.289	*apfReceiveTask	Received DHCP ACK, assigning IP Address 10.60.2.195

-- Each morning when I wake up and look into the mirror I always say ' Why am I so brilliant ? '
When the mirror will then always repond to me with ' The only thing that exceeds your brilliance is your beauty! '

ammahend · ‎03-13-2022

Based on logs from association request to run state it took 228ms, I think the problem is somewhere else. End user will most likely would not see performance issue with this delay.

-hope this helps-