各位专家,请教下这个问题,windows11使用Cisco 无线刚开机短时间无法连接网络(802.1X通过ISE进行认证),WLC上DEBUG日志如下,请烦请帮忙分析原因,谢谢!
拓扑结构,PC--CISCO AP -- CISCO WLC(版本WLC从8.5.135介级到8.5.182) -- Cisco ISE
WLC上的DEBUG日志如下:
*Dot1x_NW_MsgTask_4: Jan 20 22:22:15.192: [PA] 1x: EAPOL frame with dst MAC 2c:33:11:f3:d6:60 and BSSID 00:2c:c8:2f:69:20 discarded *apfOpenDtlSocket: Jan 20 22:22:20.855: [PA] 74:d8:3e:50:a3:16 Recevied management frame ASSOCIATION REQUEST on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:22:20.855: [PA] 74:d8:3e:50:a3:16 Processing assoc-req station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 ssid : BGY-802.1X thread:217a7640 *apfMsConnTask_3: Jan 20 22:22:20.855: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:22:20.855: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:22:20.855: [PA] 74:d8:3e:50:a3:16 Updating location for mobile on same AP 00:2c:c8:3e:a1:c0-1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Setting RTTS enabled to 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Association received from mobile on BSSID 00:2c:c8:3e:a1:cf AP TEST-1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Max Client Trap Threshold: 0 cur: 5 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6903 setting Central switched to TRUE *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Applying site-specific Local Bridging override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 STA - rates (6): 12 36 176 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] RSNIE in Assoc. Req.: (22) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] [0016] ac 01 3c 00 00 00 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Processing RSN IE type 48, length 22 for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Received 802.11i 802.1X key management suite, enabling dot1x Authentication *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 RSN Capabilities: 60 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Marking Mobile as non-11w Capable *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Removing BSSID 00:2c:c8:3e:a1:ca from PMKID cache of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Resetting MSCB PMK Cache Entry @index 0 for station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 0 ---> 8 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Assigning flex webauth ACL ID :65535 for vlan : 6 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfMsRunStateDec *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfMs1xStateDec *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Initializing policy *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfVapSecurity=0x4040 L2=16384 SkipWeb=0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 AuthenticationRequired = 1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *pemReceiveTask: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Removed NPU entry. *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Encryption policy is set to 0x80000001 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2:session timeout forstation 74:d8:3e:50:a3:16 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Sending assoc-resp with status 0 station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 on apVapId 6 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 VHT Operation IE: width 20/0 ch 149 freq0 0 freq1 0 msc0 0x3f msc1 0x3f *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Sending Assoc Response (status: '0') to station on AP TEST-1 on BSSID 00:2c:c8:3e:a1:ca ApVapId 6 Slot 1, mobility role 1 *apfMsConnTask_3: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 apfProcessAssocReq (apf_80211.c:11927) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *spamApTask7: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:20.856: [PA] 74:d8:3e:50:a3:16 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1165131888) ack state for STA on AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 Received ADD_MOBILE ack - Initiating 1x to STA 74:d8:3e:50:a3:16 (idx 84) *spamApTask7: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 APF Initiating 1x to STA 74:d8:3e:50:a3:16 *spamApTask7: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 Sent dot1x auth initiate message for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 dot1xProcessInitiate1XtoMobile to mobile station 74:d8:3e:50:a3:16 (mscb 28, msg 28) *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:22:20.858: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *apfOpenDtlSocket: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Recevied management frame ASSOCIATION REQUEST on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Processing assoc-req station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 ssid : BGY-802.1X thread:217a7640 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Updating location for mobile on same AP 00:2c:c8:3e:a1:c0-1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Setting RTTS enabled to 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Association received from mobile on BSSID 00:2c:c8:3e:a1:cf AP TEST-1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Max Client Trap Threshold: 0 cur: 5 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6903 setting Central switched to TRUE *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6906 apVapId = 6 and Split Acl Id = 65535 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Applying site-specific Local Bridging override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 STA - rates (6): 12 36 176 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] RSNIE in Assoc. Req.: (22) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] [0016] ac 01 3c 00 00 00 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Processing RSN IE type 48, length 22 for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Received 802.11i 802.1X key management suite, enabling dot1x Authentication *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 RSN Capabilities: 60 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Marking Mobile as non-11w Capable *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 8 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Assigning flex webauth ACL ID :65535 for vlan : 6 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 apfVapSecurity=0x4040 L2=16384 SkipWeb=0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 AuthenticationRequired = 1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Encryption policy is set to 0x80000001 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2:session timeout forstation 74:d8:3e:50:a3:16 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Sending assoc-resp with status 0 station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 on apVapId 6 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 VHT Operation IE: width 20/0 ch 149 freq0 0 freq1 0 msc0 0x3f msc1 0x3f *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Sending Assoc Response (status: '0') to station on AP TEST-1 on BSSID 00:2c:c8:3e:a1:ca ApVapId 6 Slot 1, mobility role 1 *apfMsConnTask_3: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 apfProcessAssocReq (apf_80211.c:11927) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *spamApTask7: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:24.403: [PA] 74:d8:3e:50:a3:16 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1165131889) ack state for STA on AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 Received ADD_MOBILE ack - Initiating 1x to STA 74:d8:3e:50:a3:16 (idx 85) *spamApTask7: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 APF Initiating 1x to STA 74:d8:3e:50:a3:16 *spamApTask7: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 Sent dot1x auth initiate message for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.405: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile in dot1x state = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 2) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.485: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.683: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.683: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 Received Identity Response (count=1) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 1 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 EAP State update from Connecting to Authenticating for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticating state *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.694: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=47) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 WARNING: updated EAP-Identifier 2 ===> 47 for STA 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 47) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 Allocating EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.697: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 47, EAP Type 3) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.703: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.704: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.704: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.704: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=48) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.704: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 48) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.704: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 48, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.727: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=49) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 49) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.733: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 49, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.748: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=50) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 50) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.749: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.836: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.837: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 50, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.837: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.837: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.837: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.837: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=51) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 51) *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:24.838: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.034: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.034: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 51, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.034: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.034: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.034: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=52) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 52) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.035: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 52, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.053: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.054: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.054: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=53) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.054: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 53) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.054: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.054: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 53, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.063: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=54) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 54) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.072: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 54, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.074: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=55) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 55) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.075: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 55, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.077: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Processing Access-Accept for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Previous Radius Overrides:(0) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 acl from 255 to 255 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 Flex acl from 65535 to 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Received MPPE_SEND_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Received MPPE_RECV_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Applying Fabric vnid override for client 74:d8:3e:50:a3:16, client->reap 1 ,over bits 0,isover FALSE *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Inserting AAA Override struct for mobile MAC: 74:d8:3e:50:a3:16, source 4 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Inserting new RADIUS override into chain for station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Setting re-auth timeout to 28800 seconds, got from WLAN config. *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Station 74:d8:3e:50:a3:16 setting dot1x reauth timeout = 28800 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Created PKC PMK Cache entry for station 74:d8:3e:50:a3:16 (RSN 2) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Resetting MSCB PMK Cache Entry @index 0 for station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 8 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Created PMKID PMK Cache for BSSID 00:2c:c8:3e:a1:ca at index 0 for station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] New PMKID: (16) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] [0000] f4 96 88 80 6b db 76 02 93 56 51 b5 f9 c8 4c e2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 802.11i: Create a global PMK cache entry, AKM-type = 1 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 PMK: Sending Flexconnect group cache delete message to spam task *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Updated existing pmk cache for client having username: liangqiguang and audit-session-id:f9100c0a0156370fc063e961 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Zeroize AAA Overrides from local for station *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Adding Audit session ID payload in Mobility handoff *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 0 PMK-update groupcast messages sent *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 PMK sent to mobility group *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Disabling re-auth since PMK lifetime can take care of same. *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Sending EAP-Success to mobile 74:d8:3e:50:a3:16 (EAP Id 55) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Freeing AAACB from Dot1xCB as AAA auth is done for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] Including PMKID in M1 (16) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] [0000] f4 96 88 80 6b db 76 02 93 56 51 b5 f9 c8 4c e2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] M1 - Key Data: (22) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] [0000] dd 14 00 0f ac 04 f4 96 88 80 6b db 76 02 93 56 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] [0016] 51 b5 f9 c8 4c e2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Starting key exchange to mobile 74:d8:3e:50:a3:16, data packets will be dropped *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Success state (id=55) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 Received Auth Success while in Authenticating state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.087: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticated state *dot1xSocketTask: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTK_START state (message 2) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Compare RSN IE in association and EAPOL-M2 frame(Skip pmkIdLen:0,and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in Association request: *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 00000000: 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 00000010: 00 0f ac 01 3c 00 00 00 ....<... *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in EAPOL M2 : *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 00000010: ac 01 3c 00 00 00 ..<... *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Not Flex client. Do not distribute PMK Key cache. *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.109: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *dot1xSocketTask: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Freeing EAP Retransmit Bufer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 apfMs1xStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.110: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 apfMsRunStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *spamApTask7: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 spamSendFabricClientRegistration: Not sending Registration for Fabric client 74:d8:3e:50:a3:16, primary and secondary MS IP is zero *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Reached PLUMBFASTPATH: from line 7154, null *spamApTask7: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 64206, IntfId = 21 Local Bridging Vlan = 151, Local Bridging intf id = 21 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) 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_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_6: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 Successfully Plumbed PTK session Keysfor mobile 74:d8:3e:50:a3:16 *pemReceiveTask: Jan 20 22:22:25.111: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Added NPU entry of type 1, dtlFlags 0x0 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREQUEST (1) (len 326,vlan 1000, port 8, encap 0xec03, xid 0xa9fecf4f) *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 1 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP mscbVapLocalAddr=10.181.31.251 mscbVapLocalNetMask= 255.255.240.0 mscbdhcpRelay=10.181.31.251 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 1 - 10.10.154.1 (local address 10.181.31.251, gateway 10.181.31.254, VLAN 151, port 8) *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP REQUEST (3) *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x4fcffea9 (1339031209), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 10.181.31.251 *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP sending REQUEST to 10.181.31.254 (len 366, port 8, vlan 151) *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 2 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:22:25.142: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 2 - NONE *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREPLY (2) (len 335,vlan 151, port 8, encap 0xec00, xid 0xa9fecf4f) *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP setting server from ACK (mscb=0x7fe8e2db37f0 ip=0xab513d5)(server 10.10.154.1, yiaddr 10.181.19.213) *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP sending REPLY to STA (len 442, port 8, vlan 1000) *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP ACK (5) *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0 *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x4fcffea9 (1339031209), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 10.181.19.213 *DHCP Socket Task: Jan 20 22:22:25.144: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0 *apfOpenDtlSocket: Jan 20 22:22:30.148: [PA] 74:d8:3e:50:a3:16 Recevied management frame ACTION on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:22:30.148: [PA] 74:d8:3e:50:a3:16 Received management action frame (category code:5) from the client. *apfMsConnTask_3: Jan 20 22:22:30.149: [PA] 74:d8:3e:50:a3:16 Found RM action category code *apfMsConnTask_3: Jan 20 22:22:30.149: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 sent 802.11K neighbor request to AP 00:2C:C8:3E:A1:C0 *apfMsConnTask_3: Jan 20 22:22:30.149: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 requested neighbors on non XOR roam capable AP 00:2C:C8:3E:A1:C0 Slot 1 *Dot1x_NW_MsgTask_5: Jan 20 22:23:53.502: [PA] 1x: EAPOL frame with dst MAC 2c:33:11:9a:1c:e0 and BSSID 00:42:5a:ac:b1:e0 discarded *apfOpenDtlSocket: Jan 20 22:25:38.105: [PA] 74:d8:3e:50:a3:16 Recevied management frame ASSOCIATION REQUEST on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:25:38.105: [PA] 74:d8:3e:50:a3:16 Processing assoc-req station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 ssid : BGY-802.1X thread:217a7640 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Updating location for mobile on same AP 00:2c:c8:3e:a1:c0-1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Setting RTTS enabled to 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Association received from mobile on BSSID 00:2c:c8:3e:a1:cf AP TEST-1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -55. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Max Client Trap Threshold: 0 cur: 5 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6903 setting Central switched to TRUE *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6906 apVapId = 6 and Split Acl Id = 65535 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Applying site-specific Local Bridging override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 STA - rates (6): 12 36 176 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] RSNIE in Assoc. Req.: (22) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] [0016] ac 01 3c 00 00 00 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Processing RSN IE type 48, length 22 for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Received 802.11i 802.1X key management suite, enabling dot1x Authentication *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 RSN Capabilities: 60 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Marking Mobile as non-11w Capable *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Removing BSSID 00:2c:c8:3e:a1:ca from PMKID cache of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Resetting MSCB PMK Cache Entry @index 0 for station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 0 ---> 8 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfMsRunStateDec *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 the value of url acl preserve flag is 0 for mobile 74:d8:3e:50:a3:16 (caller pem_api.c:3494) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfVapSecurity=0x4040 L2=16384 SkipWeb=0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 AuthenticationRequired = 1 *pemReceiveTask: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Removed NPU entry. *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Encryption policy is set to 0x80000001 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2:session timeout forstation 74:d8:3e:50:a3:16 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Sending assoc-resp with status 0 station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 on apVapId 6 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 VHT Operation IE: width 20/0 ch 149 freq0 0 freq1 0 msc0 0x3f msc1 0x3f *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Sending Assoc Response (status: '0') to station on AP TEST-1 on BSSID 00:2c:c8:3e:a1:ca ApVapId 6 Slot 1, mobility role 1 *apfMsConnTask_3: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 apfProcessAssocReq (apf_80211.c:11927) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *spamApTask7: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:38.106: [PA] 74:d8:3e:50:a3:16 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1165131891) ack state for STA on AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 Received ADD_MOBILE ack - Initiating 1x to STA 74:d8:3e:50:a3:16 (idx 89) *spamApTask7: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 APF Initiating 1x to STA 74:d8:3e:50:a3:16 *spamApTask7: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 Sent dot1x auth initiate message for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.108: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile in dot1x state = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 Reset the reauth counter since EAPOL START has been received!!! *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 2) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.254: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.731: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.731: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 Received Identity Response (count=1) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 1 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 EAP State update from Connecting to Authenticating for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticating state *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.804: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=155) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 WARNING: updated EAP-Identifier 2 ===> 155 for STA 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 155) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 Allocating EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.806: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 155, EAP Type 3) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.820: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=156) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 156) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.821: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 156, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.841: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=157) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 157) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.848: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 157, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.861: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=158) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 158) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.862: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 158, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.940: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=159) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 159) *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:38.942: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 159, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.075: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=160) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 160) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.076: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 160, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.104: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=161) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 161) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.106: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 161, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.120: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=162) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 162) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.128: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 162, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.131: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=163) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 163) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.132: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 163, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.193: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Processing Access-Accept for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 acl from 255 to 255 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 Flex acl from 65535 to 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Received MPPE_SEND_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Received MPPE_RECV_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Applying Fabric vnid override for client 74:d8:3e:50:a3:16, client->reap 1 ,over bits 0,isover FALSE *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Inserting AAA Override struct for mobile MAC: 74:d8:3e:50:a3:16, source 4 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Setting re-auth timeout to 28800 seconds, got from WLAN config. *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Station 74:d8:3e:50:a3:16 setting dot1x reauth timeout = 28800 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Created PKC PMK Cache entry for station 74:d8:3e:50:a3:16 (RSN 2) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 8 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Created PMKID PMK Cache for BSSID 00:2c:c8:3e:a1:ca at index 0 for station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] New PMKID: (16) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] [0000] 66 f8 87 56 40 1c 2d 9d 9d 3f 6c bf 97 53 a9 92 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 802.11i: Create a global PMK cache entry, AKM-type = 1 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 PMK: Sending Flexconnect group cache delete message to spam task *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Updated existing pmk cache for client having username: liangqiguang and audit-session-id:f9100c0a0156370fc063e961 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 1x: Updated the audit-session-id to PMK-Cache from client mscb: f9100c0a0156370fc063e961 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Zeroize AAA Overrides from local for station *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Adding Audit session ID payload in Mobility handoff *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 0 PMK-update groupcast messages sent *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Disabling re-auth since PMK lifetime can take care of same. *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Sending EAP-Success to mobile 74:d8:3e:50:a3:16 (EAP Id 163) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Freeing AAACB from Dot1xCB as AAA auth is done for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] Including PMKID in M1 (16) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] [0000] 66 f8 87 56 40 1c 2d 9d 9d 3f 6c bf 97 53 a9 92 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] M1 - Key Data: (22) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] [0000] dd 14 00 0f ac 04 66 f8 87 56 40 1c 2d 9d 9d 3f *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] [0016] 6c bf 97 53 a9 92 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Starting key exchange to mobile 74:d8:3e:50:a3:16, data packets will be dropped *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Success state (id=163) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.203: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticated state *dot1xSocketTask: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTK_START state (message 2) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.244: [PA] 74:d8:3e:50:a3:16 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in Association request: *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 00000000: 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 00000010: 00 0f ac 01 3c 00 00 00 ....<... *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in EAPOL M2 : *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 00000010: ac 01 3c 00 00 00 ..<... *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Not Flex client. Do not distribute PMK Key cache. *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.245: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *dot1xSocketTask: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Freeing EAP Retransmit Bufer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 apfMs1xStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqSuccessCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 apfMsRunStateInc *spamApTask7: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 spamSendFabricClientRegistration: Not sending Registration for Fabric client 74:d8:3e:50:a3:16, primary and secondary MS IP is zero *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Reached PLUMBFASTPATH: from line 7154, null *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Adding Fast Path rule type = Airespace AP Client on AP 00:2c:c8:3e:a1:c0, slot 1, interface = 8, QOS = 0 IPv4 ACL ID = 255, IPv6 ACL ID = *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 64206, IntfId = 21 Local Bridging Vlan = 151, Local Bridging intf id = 21 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) 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_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_6: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 Successfully Plumbed PTK session Keysfor mobile 74:d8:3e:50:a3:16 *pemReceiveTask: Jan 20 22:25:39.252: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Added NPU entry of type 1, dtlFlags 0x0 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREQUEST (1) (len 326,vlan 1000, port 8, encap 0xec03, xid 0x284548d6) *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 1 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP mscbVapLocalAddr=10.181.31.251 mscbVapLocalNetMask= 255.255.240.0 mscbdhcpRelay=10.181.31.251 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 1 - 10.10.154.1 (local address 10.181.31.251, gateway 10.181.31.254, VLAN 151, port 8) *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP REQUEST (3) *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0xd6484528 (3595060520), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 10.181.31.251 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP requested ip: 10.181.19.213 *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP sending REQUEST to 10.181.31.254 (len 366, port 8, vlan 151) *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 2 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:25:39.371: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 2 - NONE *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREPLY (2) (len 335,vlan 151, port 8, encap 0xec00, xid 0x284548d6) *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP setting server from ACK (mscb=0x7fe8e2db37f0 ip=0xab513d5)(server 10.10.154.1, yiaddr 10.181.19.213) *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP sending REPLY to STA (len 442, port 8, vlan 1000) *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP ACK (5) *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0xd6484528 (3595060520), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 10.181.19.213 *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:25:39.373: [PA] 74:d8:3e:50:a3:16 DHCP server id: 2.2.2.2 rcvd server id: 10.10.154.1 *apfOpenDtlSocket: Jan 20 22:25:44.302: [PA] 74:d8:3e:50:a3:16 Recevied management frame ACTION on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:25:44.302: [PA] 74:d8:3e:50:a3:16 Received management action frame (category code:5) from the client. *apfMsConnTask_3: Jan 20 22:25:44.302: [PA] 74:d8:3e:50:a3:16 Found RM action category code *apfMsConnTask_3: Jan 20 22:25:44.302: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 sent 802.11K neighbor request to AP 00:2C:C8:3E:A1:C0 *apfMsConnTask_3: Jan 20 22:25:44.302: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 requested neighbors on non XOR roam capable AP 00:2C:C8:3E:A1:C0 Slot 1 *Dot1x_NW_MsgTask_3: Jan 20 22:25:52.229: [PA] 1x: EAPOL frame with dst MAC 00:2c:c8:23:38:40 and BSSID 00:2c:c8:32:b0:e0 discarded *apfOpenDtlSocket: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Recevied management frame REASSOCIATION REQUEST on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Processing assoc-req station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 ssid : BGY-802.1X thread:217a7640 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -56. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Updating location for mobile on same AP 00:2c:c8:3e:a1:c0-1 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Setting RTTS enabled to 0 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Reassociation received from mobile on BSSID 00:2c:c8:3e:a1:cf AP TEST-1 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -56. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Max Client Trap Threshold: 0 cur: 5 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6903 setting Central switched to TRUE *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6906 apVapId = 6 and Split Acl Id = 65535 *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Applying site-specific Local Bridging override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:25:55.721: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 STA - rates (6): 12 36 176 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] RSNIE in Assoc. Req.: (38) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] [0032] 6c bf 97 53 a9 92 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Processing RSN IE type 48, length 38 for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Received 802.11i 802.1X key management suite, enabling dot1x Authentication *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 RSN Capabilities: 60 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Marking Mobile as non-11w Capable *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 1 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 1 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] Received PMKID: (16) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] [0000] 66 f8 87 56 40 1c 2d 9d 9d 3f 6c bf 97 53 a9 92 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Found a valid PMKID in the MSCB PMKID cache for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 0 ---> 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Assigning flex webauth ACL ID :65535 for vlan : 6 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfMsRunStateDec *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfMs1xStateDec *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 the value of url acl preserve flag is 0 for mobile 74:d8:3e:50:a3:16 (caller pem_api.c:3494) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Initializing policy *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfVapSecurity=0x4040 L2=16384 SkipWeb=0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 AuthenticationRequired = 1 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *pemReceiveTask: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Removed NPU entry. *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2:session timeout forstation 74:d8:3e:50:a3:16 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Sending assoc-resp with status 0 station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 on apVapId 6 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 VHT Operation IE: width 20/0 ch 149 freq0 0 freq1 0 msc0 0x3f msc1 0x3f *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Sending Assoc Response (status: '0') to station on AP TEST-1 on BSSID 00:2c:c8:3e:a1:ca ApVapId 6 Slot 1, mobility role 1 *apfMsConnTask_3: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 apfProcessAssocReq (apf_80211.c:11927) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *spamApTask7: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:55.722: [PA] 74:d8:3e:50:a3:16 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1165131893) ack state for STA on AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Received ADD_MOBILE ack - Initiating 1x to STA 74:d8:3e:50:a3:16 (idx 91) *spamApTask7: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 APF Initiating 1x to STA 74:d8:3e:50:a3:16 *spamApTask7: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Sent dot1x auth initiate message for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 dot1xProcessInitiate1XtoMobile to mobile station 74:d8:3e:50:a3:16 (mscb 31, msg 31) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Initiating RSN with existing PMK to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Force Auth state *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Skipping EAP-Success to mobile 74:d8:3e:50:a3:16 (encryptBit:0) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Username entry (liangqiguang) already exists in name table, length = 253 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Username entry (liangqiguang) created in mscb for mobile, length = 253 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] Including PMKID in M1 (16) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] M1 - Key Data: (22) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] [0016] 6c bf 97 53 a9 92 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Starting key exchange to mobile 74:d8:3e:50:a3:16, data packets will be dropped *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.724: [PA] 74:d8:3e:50:a3:16 Allocating EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *dot1xSocketTask: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTK_START state (message 2) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Compare RSN IE in association and EAPOL-M2 frame(Skip pmkIdLen:16,and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in Association request: *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000000: 30 26 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0&.............. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000010: 00 0f ac 01 3c 00 01 00 66 f8 87 56 40 1c 2d 9d ....<...f..V@.-. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000020: 9d 3f 6c bf 97 53 a9 92 .?l..S.. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in EAPOL M2 : *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000010: ac 01 3c 00 01 00 66 f8 87 56 40 1c 2d 9d 9d 3f ..<...f..V@.-..? *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 00000020: 6c bf 97 53 a9 92 l..S.. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Not Flex client. Do not distribute PMK Key cache. *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.725: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *dot1xSocketTask: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Freeing EAP Retransmit Bufer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 apfMs1xStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqSuccessCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 apfMsRunStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *spamApTask7: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 spamSendFabricClientRegistration: Not sending Registration for Fabric client 74:d8:3e:50:a3:16, primary and secondary MS IP is zero *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.726: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Adding Fast Path rule type = Airespace AP Client on AP 00:2c:c8:3e:a1:c0, slot 1, interface = 8, QOS = 0 IPv4 ACL ID = 255, IPv6 ACL ID = *spamApTask7: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 64206, IntfId = 21 Local Bridging Vlan = 151, Local Bridging intf id = 21 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_6: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 Successfully Plumbed PTK session Keysfor mobile 74:d8:3e:50:a3:16 *pemReceiveTask: Jan 20 22:25:55.727: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Added NPU entry of type 1, dtlFlags 0x0 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREQUEST (1) (len 326,vlan 1000, port 8, encap 0xec03, xid 0x82010672) *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 1 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP mscbVapLocalAddr=10.181.31.251 mscbVapLocalNetMask= 255.255.240.0 mscbdhcpRelay=10.181.31.251 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 1 - 10.10.154.1 (local address 10.181.31.251, gateway 10.181.31.254, VLAN 151, port 8) *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP REQUEST (3) *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x72060182 (1912996226), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 10.181.31.251 *DHCP Socket Task: Jan 20 22:25:55.736: [PA] 74:d8:3e:50:a3:16 DHCP requested ip: 10.181.19.213 *DHCP Socket Task: Jan 20 22:25:55.737: [PA] 74:d8:3e:50:a3:16 DHCP sending REQUEST to 10.181.31.254 (len 366, port 8, vlan 151) *DHCP Socket Task: Jan 20 22:25:55.737: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 2 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:25:55.737: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 2 - NONE *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREPLY (2) (len 335,vlan 151, port 8, encap 0xec00, xid 0x82010672) *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP setting server from ACK (mscb=0x7fe8e2db37f0 ip=0xab513d5)(server 10.10.154.1, yiaddr 10.181.19.213) *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP sending REPLY to STA (len 442, port 8, vlan 1000) *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP ACK (5) *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x72060182 (1912996226), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 10.181.19.213 *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:25:55.738: [PA] 74:d8:3e:50:a3:16 DHCP server id: 2.2.2.2 rcvd server id: 10.10.154.1 *apfOpenDtlSocket: Jan 20 22:26:00.764: [PA] 74:d8:3e:50:a3:16 Recevied management frame ACTION on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:26:00.764: [PA] 74:d8:3e:50:a3:16 Received management action frame (category code:5) from the client. *apfMsConnTask_3: Jan 20 22:26:00.764: [PA] 74:d8:3e:50:a3:16 Found RM action category code *apfMsConnTask_3: Jan 20 22:26:00.764: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 sent 802.11K neighbor request to AP 00:2C:C8:3E:A1:C0 *apfMsConnTask_3: Jan 20 22:26:00.764: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 requested neighbors on non XOR roam capable AP 00:2C:C8:3E:A1:C0 Slot 1 *apfOpenDtlSocket: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Recevied management frame ASSOCIATION REQUEST on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Processing assoc-req station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 ssid : BGY-802.1X thread:217a7640 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Updating location for mobile on same AP 00:2c:c8:3e:a1:c0-1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Setting RTTS enabled to 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Association received from mobile on BSSID 00:2c:c8:3e:a1:cf AP TEST-1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 trying to join WLAN with RSSI -53. Checking for XOR roam conditions on AP: 00:2C:C8:3E:A1:C0 Slot: 1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 is associating to AP 00:2C:C8:3E:A1:C0 which is not XOR roam capable *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Max Client Trap Threshold: 0 cur: 5 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Not re-applying interface policy for client already having IP address in Interface group vlan *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6903 setting Central switched to TRUE *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 In processSsidIE:6906 apVapId = 6 and Split Acl Id = 65535 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying site-specific Local Bridging override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying Local Bridging Interface Policy for station 74:d8:3e:50:a3:16 - vlan 151, interface id 21, interface 'bgy-802.1x-2' *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 STA - rates (6): 12 36 176 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] RSNIE in Assoc. Req.: (22) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] [0016] ac 01 3c 00 00 00 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Processing RSN IE type 48, length 22 for mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Received 802.11i 802.1X key management suite, enabling dot1x Authentication *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 RSN Capabilities: 60 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Marking Mobile as non-11w Capable *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Received RSN IE with 0 PMKIDs from mobile 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Removing BSSID 00:2c:c8:3e:a1:ca from PMKID cache of station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Resetting MSCB PMK Cache Entry @index 0 for station 74:d8:3e:50:a3:16 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 0 ---> 8 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Assigning flex webauth ACL ID :65535 for vlan : 6 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfMsRunStateDec *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfMs1xStateDec *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 the value of url acl preserve flag is 0 for mobile 74:d8:3e:50:a3:16 (caller pem_api.c:3494) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Initializing policy *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfVapSecurity=0x4040 L2=16384 SkipWeb=0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 AuthenticationRequired = 1 *pemReceiveTask: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Removed NPU entry. *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Encryption policy is set to 0x80000001 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfPemAddUser2:session timeout forstation 74:d8:3e:50:a3:16 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Sending assoc-resp with status 0 station:74:d8:3e:50:a3:16 AP:00:2c:c8:3e:a1:c0-01 on apVapId 6 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Sending Assoc Response (status: '0') to station on AP TEST-1 on BSSID 00:2c:c8:3e:a1:ca ApVapId 6 Slot 1, mobility role 1 *apfMsConnTask_3: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 apfProcessAssocReq (apf_80211.c:11927) Changing state for mobile 74:d8:3e:50:a3:16 on AP 00:2c:c8:3e:a1:c0 from Associated to Associated *spamApTask7: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:26:16.371: [PA] 74:d8:3e:50:a3:16 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1165131895) ack state for STA on AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 Received ADD_MOBILE ack - Initiating 1x to STA 74:d8:3e:50:a3:16 (idx 95) *spamApTask7: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 APF Initiating 1x to STA 74:d8:3e:50:a3:16 *spamApTask7: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 Sent dot1x auth initiate message for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 dot1xProcessInitiate1XtoMobile to mobile station 74:d8:3e:50:a3:16 (mscb 32, msg 32) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.373: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile in dot1x state = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 Reset the reauth counter since EAPOL START has been received!!! *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 Received EAPOL START from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Connecting state *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 Sending EAP-Request/Identity to mobile 74:d8:3e:50:a3:16 (EAP Id 2) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.393: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.433: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.433: [PA] 74:d8:3e:50:a3:16 Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.433: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 Received Identity Response (count=1) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 1 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 EAP State update from Connecting to Authenticating for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticating state *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.440: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=248) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 WARNING: updated EAP-Identifier 2 ===> 248 for STA 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 248) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 Allocating EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.442: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 248, EAP Type 3) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=249) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 249) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.444: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 249, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.447: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.453: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.453: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=250) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.453: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 250) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.453: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.453: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 250, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.455: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.456: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.456: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.456: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=251) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.456: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.456: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 251, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.459: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=252) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 252) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.461: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.463: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.463: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 252, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.463: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.463: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.463: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=253) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 253) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.464: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.480: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.480: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 253, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.480: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.480: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.480: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=254) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 254) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.481: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 254, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.484: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=255) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 255) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.492: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 255, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 Processing Access-Challenge for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.494: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.495: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Req state (id=1) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.495: [PA] 74:d8:3e:50:a3:16 WARNING: updated EAP-Identifier 255 ===> 1 for STA 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.495: [PA] 74:d8:3e:50:a3:16 Sending EAP Request from AAA to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.495: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.495: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 Received EAPOL EAPPKT from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 Received EAP Response from mobile 74:d8:3e:50:a3:16 (EAP Id 1, EAP Type 25) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 Resetting reauth count 0 to 0 for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Response state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.496: [PA] 74:d8:3e:50:a3:16 reauth_sm state transition 0 ---> 0 for mobile 74:d8:3e:50:a3:16 at 1x_reauth_sm.c:71 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Processing Access-Accept for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Previous Radius Overrides:(0) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 acl from 255 to 255 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Resetting web IPv4 Flex acl from 65535 to 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Received MPPE_SEND_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Received MPPE_RECV_KEY: KeyLen: 32 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Check the client SGT 0 policy and push it to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Applying site-specific override for station 74:d8:3e:50:a3:16 - vapId 1, site 'BGY-SDBGY', interface 'bgy-802.1x-2' *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Applying Interface(bgy-802.1x-2) policy on Mobile, role Local. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 151 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Re-applying interface policy for client *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3056) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3076) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3097) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Setting re-auth timeout to 28800 seconds, got from WLAN config. *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Created PKC PMK Cache entry for station 74:d8:3e:50:a3:16 (RSN 2) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Setting active key cache index 8 ---> 8 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Created PMKID PMK Cache for BSSID 00:2c:c8:3e:a1:ca at index 0 for station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] New PMKID: (16) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 802.11i: Create a global PMK cache entry, AKM-type = 1 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 PMK: Sending Flexconnect group cache delete message to spam task *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Updated existing pmk cache for client having username: liangqiguang and audit-session-id:f9100c0a0156370fc063e961 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 1x: Updated the audit-session-id to PMK-Cache from client mscb: f9100c0a0156370fc063e961 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Zeroize AAA Overrides from local for station *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 0 PMK-update groupcast messages sent *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 PMK sent to mobility group *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Disabling re-auth since PMK lifetime can take care of same. *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Sending EAP-Success to mobile 74:d8:3e:50:a3:16 (EAP Id 1) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Freeing AAACB from Dot1xCB as AAA auth is done for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Found an cache entry for BSSID 00:2c:c8:3e:a1:ca in PMKID cache at index 0 of station 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] Including PMKID in M1 (16) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] [0000] 92 41 84 55 99 07 5e 5e 10 4d ab a6 eb 55 2a 30 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] M1 - Key Data: (22) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] [0000] dd 14 00 0f ac 04 92 41 84 55 99 07 5e 5e 10 4d *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] [0016] ab a6 eb 55 2a 30 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Starting key exchange to mobile 74:d8:3e:50:a3:16, data packets will be dropped *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Entering Backend Auth Success state (id=1) for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 Received Auth Success while in Authenticating state for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.507: [PA] 74:d8:3e:50:a3:16 dot1x - moving mobile 74:d8:3e:50:a3:16 into Authenticated state *dot1xSocketTask: Jan 20 22:26:16.512: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.512: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.512: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.512: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.512: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTK_START state (message 2) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Compare RSN IE in association and EAPOL-M2 frame(Skip pmkIdLen:0,and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in Association request: *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 00000000: 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 00000010: 00 0f ac 01 3c 00 00 00 ....<... *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Dumping RSNIE received in EAPOL M2 : *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 00000010: ac 01 3c 00 00 00 ..<... *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Sending EAPOL-Key Message to mobile 74:d8:3e:50:a3:16 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.513: [PA] 74:d8:3e:50:a3:16 Reusing allocated memory for EAP Pkt for retransmission to mobile 74:d8:3e:50:a3:16 *dot1xSocketTask: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Received EAPOL-Key from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 key Desc Version FT - 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Stopping retransmission timer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Freeing EAP Retransmit Bufer for mobile 74:d8:3e:50:a3:16 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 apfMs1xStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 apfMsPeapSimReqSuccessCntInc *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent when fabric is disabled:65535 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:2c:c8:3e:a1:c0 vapId 1 apVapId 6 flex-acl-name: *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 apfMsRunStateInc *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *spamApTask7: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Add SGT:0 to AP 00:2c:c8:3e:a1:c0 *spamApTask7: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 spamSendFabricClientRegistration: Not sending Registration for Fabric client 74:d8:3e:50:a3:16, primary and secondary MS IP is zero *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Reached PLUMBFASTPATH: from line 7154, null *spamApTask7: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Successful transmission of LWAPP Add-Mobile to AP 00:2c:c8:3e:a1:c0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Adding Fast Path rule type = Airespace AP Client on AP 00:2c:c8:3e:a1:c0, slot 1, interface = 8, QOS = 0 IPv4 ACL ID = 255, IPv6 ACL ID = *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 64206, IntfId = 21 Local Bridging Vlan = 151, Local Bridging intf id = 21 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 64206 AverageRate = 0, BurstRate = 0 *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) 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_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_6: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 Successfully Plumbed PTK session Keysfor mobile 74:d8:3e:50:a3:16 *pemReceiveTask: Jan 20 22:26:16.514: [PA] 74:d8:3e:50:a3:16 10.181.19.213 Added NPU entry of type 1, dtlFlags 0x0 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREQUEST (1) (len 326,vlan 1000, port 8, encap 0xec03, xid 0x44e5da04) *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP (encap type 0xec03) mstype 0ff:ff:ff:ff:ff:ff *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 1 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP mscbVapLocalAddr=10.181.31.251 mscbVapLocalNetMask= 255.255.240.0 mscbdhcpRelay=10.181.31.251 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 1 - 10.10.154.1 (local address 10.181.31.251, gateway 10.181.31.254, VLAN 151, port 8) *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP REQUEST (3) *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x4dae544 (81454404), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 10.181.31.251 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP requested ip: 10.181.19.213 *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP sending REQUEST to 10.181.31.254 (len 366, port 8, vlan 151) *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP selecting relay 2 - control block settings: dhcpServer: 10.10.154.1, dhcpNetmask: 255.255.240.0, dhcpGateway: 10.181.31.254, dhcpRelay: 10.181.31.251 VLAN: *DHCP Socket Task: Jan 20 22:26:16.531: [PA] 74:d8:3e:50:a3:16 DHCP selected relay 2 - NONE *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP received op BOOTREPLY (2) (len 335,vlan 151, port 8, encap 0xec00, xid 0x44e5da04) *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP setting server from ACK (mscb=0x7fe8e2db37f0 ip=0xab513d5)(server 10.10.154.1, yiaddr 10.181.19.213) *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP sending REPLY to STA (len 442, port 8, vlan 1000) *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP transmitting DHCP ACK (5) *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0 *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP xid: 0x4dae544 (81454404), secs: 0, flags: 0 *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP chaddr: 74:d8:3e:50:a3:16 *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0 *DHCP Socket Task: Jan 20 22:26:16.533: [PA] 74:d8:3e:50:a3:16 DHCP server id: 2.2.2.2 rcvd server id: 10.10.154.1 *apfOpenDtlSocket: Jan 20 22:26:21.559: [PA] 74:d8:3e:50:a3:16 Recevied management frame ACTION on BSSID 00:2c:c8:3e:a1:ca destination addr 00:2c:c8:3e:a1:ca *apfMsConnTask_3: Jan 20 22:26:21.559: [PA] 74:d8:3e:50:a3:16 Received management action frame (category code:5) from the client. *apfMsConnTask_3: Jan 20 22:26:21.559: [PA] 74:d8:3e:50:a3:16 Found RM action category code *apfMsConnTask_3: Jan 20 22:26:21.559: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 sent 802.11K neighbor request to AP 00:2C:C8:3E:A1:C0 *apfMsConnTask_3: Jan 20 22:26:21.559: [PA] 74:d8:3e:50:a3:16 Station: 74:D8:3E:50:A3:16 requested neighbors on non XOR roam capable AP 00:2C:C8:3E:A1:C0 Slot 1 *Dot1x_NW_MsgTask_5: Jan 20 22:26:22.018: [PA] 1x: EAPOL frame with dst MAC 00:2c:c8:2c:61:40 and BSSID 00:42:5a:ac:b3:00 discarded on non XOR roam capable AP 00:2C:C8:3E:A1:C0 Slot 1