(Cisco Controller) >debug client 30:95:e3:2e:a3:81 (Cisco Controller) >debug mobility handoff enable (Cisco Controller) >show debug MAC Addr 1.................................. 30:95:E3:2E:A3:81 Flex-AP Client Debugging ................... disabled Flex-Group Client Debugging ................ disabled Debug Flags Enabled: dhcp packet enabled. Client Event enabled. dot11 mobile enabled. dot11 state enabled dot1x events enabled. dot1x states enabled. mobility global handoff enabled. mobility client handoff enabled. pem events enabled. pem state enabled. 802.11r event debug enabled. 802.11w event debug enabled. CCKM client debug enabled. (Cisco Controller) >*apfOpenDtlSocket: May 27 11:52:13.575: 30:95:e3:2e:a3:81 Received management frame REASSOCIATION REQUEST on BSSID b0:90:7e:dc:c9:62 destination addr b0:90:7e:dc:c9:62 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Processing assoc-req station:30:95:e3:2e:a3:81 AP:b0:90:7e:dc:c9:60-00 ssid : Dinamico thread:b200880 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP B0:90:7E:DC:C9:60 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Client AVC Roaming context transfer needed? NO *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Setting RTTS enabled to 0 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Reassociation received from mobile on BSSID b0:90:7e:dc:c9:62 AP AP5 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP B0:90:7E:DC:C9:60 *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: May 27 11:52:13.580: 30:95:e3:2e:a3:81 Max Client Trap Threshold: 0 cur: 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 override for default ap group, marking intgrp NULL *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Check before Setting the NAS Id to WLAN specific Id '' *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Check the client SGT 0 policy and push it to AP b0:90:7e:dc:c9:60 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 In processSsidIE:6954 setting Central switched to FALSE *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Set Client MSCB as Central Association Disabled *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Applying site-specific Local Bridging override for station 30:95:e3:2e:a3:81 - vapId 3, site 'default-group', interface 'selfscanning' *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Applying Local Bridging Interface Policy for station 30:95:e3:2e:a3:81 - vlan 249, interface id 5, interface 'selfscanning', nasId:'' *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Set Client Non AP specific WLAN apfMsAccessVlan = 249 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 This apfMsAccessVlan may be changed later from AAA after L2 Auth *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Cleared localSwitchingVlan, may be assigned later based on AAA override *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: May 27 11:52:13.581: RSNIE in Assoc. Req.: (20) *apfMsConnTask_3: May 27 11:52:13.581: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: May 27 11:52:13.581: [0016] ac 02 a8 00 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Processing RSN IE type 48, length 20 for mobile 30:95:e3:2e:a3:81 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Received 802.11i PSK key management suite, enabling Authentication *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 RSN Capabilities: 168 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 non-11w Capable mobile *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Received RSN IE with 0 PMKIDs from mobile 30:95:e3:2e:a3:81 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 1 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:4922) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Deleted mobile LWAPP rule on AP [00:7e:95:83:12:a0] *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Succesfully freed AID 6, slot 0 on AP 00:7e:95:83:12:a0, #client on this slot 57 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 New ctxOwnerMwarIp: 10.251.89.28 New ctxOwnerApMac: B0:90:7E:DC:C9:60 New ctxOwnerApEthMac: 00:7E:95:82:2B:C0 New ctxOwnerApSlotId: 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Updated location for station old AP 00:7e:95:83:12:a0 oldSlot 0, new AP b0:90:7e:dc:c9:60 newSlot 0, AID 0 MsType 0 MobilityRole 1 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Assigning flex webauth ACL ID :65535 for vlan : 3 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Updating AID for REAP AP Client b0:90:7e:dc:c9:60 - AID ===> 1 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfMsRunStateDec *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfMs1xStateDec *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 0 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:3495) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Initializing policy *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfVapSecurity=0x40004000 L2=16384 SkipWeb=0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 AuthenticationRequired = 1 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Encryption policy is set to 0x80000001 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Client already has IP 10.249.89.135, DHCP Not required on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Plumbed mobile LWAPP rule on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 flex-acl-name: *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 30:95:e3:2e:a3:81 on AP b0:90:7e:dc:c9:60 from Associated to Associated *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfPemAddUser2:session timeout forstation 30:95:e3:2e:a3:81 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Sending assoc-resp with status 0 station:30:95:e3:2e:a3:81 AP:b0:90:7e:dc:c9:60-00 on apVapId 3 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 Sending Assoc Response (status: '0') to station on AP AP5 on BSSID b0:90:7e:dc:c9:62 ApVapId 3 Slot 0, mobility role 1 *apfMsConnTask_3: May 27 11:52:13.581: 30:95:e3:2e:a3:81 apfProcessAssocReq (apf_80211.c:11962) Changing state for mobile 30:95:e3:2e:a3:81 on AP b0:90:7e:dc:c9:60 from Associated to Associated *spamApTask7: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Setting DEL_MOBILE (seqno 0, action 6) ack state for STA on AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Delete Mobile request on slot 0 sent to the AP 00:7e:95:83:12:a0 IP: 10.251.89.51:5256 *spamApTask5: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Add SGT:0 to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask5: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:13.582: 30:95:e3:2e:a3:81 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 2130713126) ack state for STA on AP b0:90:7e:dc:c9:60 *spamApTask7: May 27 11:52:13.584: 30:95:e3:2e:a3:81 apfUpdateDeleteAckInMscb (apf_api.c:54210) Expiring Mobile! *spamApTask5: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Received ADD_MOBILE ack - Initiating 1x to STA 30:95:e3:2e:a3:81 (idx 98) *spamApTask5: May 27 11:52:13.588: 30:95:e3:2e:a3:81 APF Initiating 1x to STA 30:95:e3:2e:a3:81 *spamApTask5: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Sent dot1x auth initiate message for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 dot1xProcessInitiate1XtoMobile to mobile station 30:95:e3:2e:a3:81 (mscb 2, msg 2) *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 reauth_sm state transition 1 ---> 0 for mobile 30:95:e3:2e:a3:81 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Normal psk client, full auth *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Created PKC PMK Cache entry for station 30:95:e3:2e:a3:81 (RSN 2) *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Resetting MSCB PMK Cache Entry @index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Removing BSSID 00:7e:95:83:12:a2 from PMKID cache of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Setting active key cache index 0 ---> 8 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: 30:95:e3:2e:a3:81 Created PMKID PMK Cache for BSSID b0:90:7e:dc:c9:62 at index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: New PMKID: (16) *Dot1x_NW_MsgTask_1: May 27 11:52:13.588: [0000] 01 8b 2d 4b b0 ed 39 d4 3c 8e 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Initiating RSN PSK to mobile 30:95:e3:2e:a3:81keyMgmtType : 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 EAP-PARAM Debug - eap-params for Wlan-Id :3 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 dot1x - moving mobile 30:95:e3:2e:a3:81 into Force Auth state *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Skipping EAP-Success to mobile 30:95:e3:2e:a3:81 (encryptBit:0) *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Found an cache entry for BSSID b0:90:7e:dc:c9:62 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Found an cache entry for BSSID b0:90:7e:dc:c9:62 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: Including PMKID in M1 (16) *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: [0000] 01 8b 2d 4b b0 ed 39 d4 3c 8e 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: M1 - Key Data: (22) *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: [0000] dd 14 00 0f ac 04 01 8b 2d 4b b0 ed 39 d4 3c 8e *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: [0016] 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Starting key exchange to mobile 30:95:e3:2e:a3:81, data packets will be dropped *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_1: May 27 11:52:13.589: 30:95:e3:2e:a3:81 Allocating EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:13.666: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Received EAPOL-key in PTK_START state (message 2) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 rsnieCapabilty = a8 rsnie_len =20 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Dumping RSNIE received in Association request(len = 22): *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 00000010: 00 0f ac 02 a8 00 ...... *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Dumping RSNIE received in EAPOL M2 (len = 20): *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 00000010: ac 02 a8 00 .... *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_1: May 27 11:52:13.666: 30:95:e3:2e:a3:81 Reusing allocated memory for EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:13.682: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Freeing EAP Retransmit Bufer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 apfMs1xStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Client already has IP 10.249.89.135, DHCP Not required on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 flex-acl-name: *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 apfMsRunStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Reached PLUMBFASTPATH: from line 7155, null *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_1: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Successfully Plumbed PTK session Keysfor mobile 30:95:e3:2e:a3:81 *spamApTask5: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Add SGT:0 to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask5: May 27 11:52:13.682: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP b0:90:7e:dc:c9:60 *apfReceiveTask: May 27 11:52:13.691: 30:95:e3:2e:a3:81 Recieved MS IPv4 Addr= 10.249.89.135 *apfOpenDtlSocket: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Received management frame ASSOCIATION REQUEST on BSSID b0:90:7e:dc:c9:62 destination addr b0:90:7e:dc:c9:62 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Processing assoc-req station:30:95:e3:2e:a3:81 AP:b0:90:7e:dc:c9:60-00 ssid : Dinamico thread:b200880 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP B0:90:7E:DC:C9:60 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Updating location for mobile on same AP b0:90:7e:dc:c9:60-0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Client AVC Roaming context transfer needed? NO *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Setting RTTS enabled to 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Association received from mobile on BSSID b0:90:7e:dc:c9:62 AP AP5 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP B0:90:7E:DC:C9:60 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Global 200 Clients are allowed to AP radio *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Max Client Trap Threshold: 0 cur: 1 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 override for default ap group, marking intgrp NULL *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Check before Setting the NAS Id to WLAN specific Id '' *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Check the client SGT 0 policy and push it to AP b0:90:7e:dc:c9:60 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 In processSsidIE:6954 setting Central switched to FALSE *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Set Client MSCB as Central Association Disabled *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Applying site-specific Local Bridging override for station 30:95:e3:2e:a3:81 - vapId 3, site 'default-group', interface 'selfscanning' *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Applying Local Bridging Interface Policy for station 30:95:e3:2e:a3:81 - vlan 249, interface id 5, interface 'selfscanning', nasId:'' *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Set Client Non AP specific WLAN apfMsAccessVlan = 249 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 This apfMsAccessVlan may be changed later from AAA after L2 Auth *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Cleared localSwitchingVlan, may be assigned later based on AAA override *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_3: May 27 11:52:21.748: RSNIE in Assoc. Req.: (20) *apfMsConnTask_3: May 27 11:52:21.748: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_3: May 27 11:52:21.748: [0016] ac 02 a8 00 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Processing RSN IE type 48, length 20 for mobile 30:95:e3:2e:a3:81 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Received 802.11i PSK key management suite, enabling Authentication *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 RSN Capabilities: 168 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 non-11w Capable mobile *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Received RSN IE with 0 PMKIDs from mobile 30:95:e3:2e:a3:81 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Assigning flex webauth ACL ID :65535 for vlan : 3 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 AID 1 in Assoc Req from flex AP b0:90:7e:dc:c9:60 is same as in mscb 30:95:e3:2e:a3:81 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfMsRunStateDec *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfMs1xStateDec *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 0 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:3495) *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Initializing policy *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfVapSecurity=0x40004000 L2=16384 SkipWeb=0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 AuthenticationRequired = 1 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Encryption policy is set to 0x80000001 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Client already has IP 10.249.89.135, DHCP Not required on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Plumbed mobile LWAPP rule on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 flex-acl-name: *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 30:95:e3:2e:a3:81 on AP b0:90:7e:dc:c9:60 from Associated to Associated *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 apfPemAddUser2:session timeout forstation 30:95:e3:2e:a3:81 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_3: May 27 11:52:21.748: 30:95:e3:2e:a3:81 Sending assoc-resp with status 0 station:30:95:e3:2e:a3:81 AP:b0:90:7e:dc:c9:60-00 on apVapId 3 *apfMsConnTask_3: May 27 11:52:21.749: 30:95:e3:2e:a3:81 Sending Assoc Response (status: '0') to station on AP AP5 on BSSID b0:90:7e:dc:c9:62 ApVapId 3 Slot 0, mobility role 1 *apfMsConnTask_3: May 27 11:52:21.749: 30:95:e3:2e:a3:81 apfProcessAssocReq (apf_80211.c:11962) Changing state for mobile 30:95:e3:2e:a3:81 on AP b0:90:7e:dc:c9:60 from Associated to Associated *spamApTask5: May 27 11:52:21.749: 30:95:e3:2e:a3:81 Add SGT:0 to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:21.749: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask5: May 27 11:52:21.749: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:21.749: 30:95:e3:2e:a3:81 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 2130713128) ack state for STA on AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:21.753: 30:95:e3:2e:a3:81 Received ADD_MOBILE ack - Initiating 1x to STA 30:95:e3:2e:a3:81 (idx 0) *spamApTask5: May 27 11:52:21.753: 30:95:e3:2e:a3:81 APF Initiating 1x to STA 30:95:e3:2e:a3:81 *spamApTask5: May 27 11:52:21.753: 30:95:e3:2e:a3:81 Sent dot1x auth initiate message for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.753: 30:95:e3:2e:a3:81 dot1xProcessInitiate1XtoMobile to mobile station 30:95:e3:2e:a3:81 (mscb 3, msg 3) *Dot1x_NW_MsgTask_1: May 27 11:52:21.753: 30:95:e3:2e:a3:81 reauth_sm state transition 0 ---> 0 for mobile 30:95:e3:2e:a3:81 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Normal psk client, full auth *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Created PKC PMK Cache entry for station 30:95:e3:2e:a3:81 (RSN 2) *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Resetting MSCB PMK Cache Entry @index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Removing BSSID b0:90:7e:dc:c9:62 from PMKID cache of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Setting active key cache index 0 ---> 8 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Created PMKID PMK Cache for BSSID b0:90:7e:dc:c9:62 at index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: New PMKID: (16) *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: [0000] 01 8b 2d 4b b0 ed 39 d4 3c 8e 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Initiating RSN PSK to mobile 30:95:e3:2e:a3:81keyMgmtType : 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 EAP-PARAM Debug - eap-params for Wlan-Id :3 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 dot1x - moving mobile 30:95:e3:2e:a3:81 into Force Auth state *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Skipping EAP-Success to mobile 30:95:e3:2e:a3:81 (encryptBit:0) *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Found an cache entry for BSSID b0:90:7e:dc:c9:62 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Found an cache entry for BSSID b0:90:7e:dc:c9:62 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: Including PMKID in M1 (16) *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: [0000] 01 8b 2d 4b b0 ed 39 d4 3c 8e 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: M1 - Key Data: (22) *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: [0000] dd 14 00 0f ac 04 01 8b 2d 4b b0 ed 39 d4 3c 8e *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: [0016] 3b 61 e5 c1 f9 bc *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Starting key exchange to mobile 30:95:e3:2e:a3:81, data packets will be dropped *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_1: May 27 11:52:21.754: 30:95:e3:2e:a3:81 Allocating EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:21.828: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:21.828: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.828: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.828: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.828: 30:95:e3:2e:a3:81 Received EAPOL-key in PTK_START state (message 2) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.828: 30:95:e3:2e:a3:81 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 rsnieCapabilty = a8 rsnie_len =20 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Dumping RSNIE received in Association request(len = 22): *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 00000010: 00 0f ac 02 a8 00 ...... *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Dumping RSNIE received in EAPOL M2 (len = 20): *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 00000010: ac 02 a8 00 .... *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_1: May 27 11:52:21.829: 30:95:e3:2e:a3:81 Reusing allocated memory for EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:21.836: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:21.836: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.836: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.836: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:21.836: 30:95:e3:2e:a3:81 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Freeing EAP Retransmit Bufer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 apfMs1xStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Client already has IP 10.249.89.135, DHCP Not required on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP b0:90:7e:dc:c9:60 vapId 3 apVapId 3 flex-acl-name: *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 apfMsRunStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Reached PLUMBFASTPATH: from line 7155, null *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_1: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Successfully Plumbed PTK session Keysfor mobile 30:95:e3:2e:a3:81 *spamApTask5: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Add SGT:0 to AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask5: May 27 11:52:21.837: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP b0:90:7e:dc:c9:60 *apfReceiveTask: May 27 11:52:23.171: 30:95:e3:2e:a3:81 Recieved MS IPv4 Addr= 10.249.89.135 *apfOpenDtlSocket: May 27 11:52:37.919: 30:95:e3:2e:a3:81 Received management frame REASSOCIATION REQUEST on BSSID 00:7e:95:83:12:a2 destination addr 00:7e:95:83:12:a2 *apfMsConnTask_2: May 27 11:52:37.919: 30:95:e3:2e:a3:81 Processing assoc-req station:30:95:e3:2e:a3:81 AP:00:7e:95:83:12:a0-00 ssid : Dinamico thread:b200220 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP 00:7E:95:83:12:A0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Client AVC Roaming context transfer needed? NO *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Setting RTTS enabled to 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Reassociation received from mobile on BSSID 00:7e:95:83:12:a2 AP AP1-Casse *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP 00:7E:95:83:12:A0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Global 200 Clients are allowed to AP radio *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Max Client Trap Threshold: 0 cur: 57 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 override for default ap group, marking intgrp NULL *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Check before Setting the NAS Id to WLAN specific Id '' *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Check the client SGT 0 policy and push it to AP 00:7e:95:83:12:a0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 In processSsidIE:6954 setting Central switched to FALSE *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Set Client MSCB as Central Association Disabled *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Applying site-specific Local Bridging override for station 30:95:e3:2e:a3:81 - vapId 3, site 'default-group', interface 'selfscanning' *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Applying Local Bridging Interface Policy for station 30:95:e3:2e:a3:81 - vlan 249, interface id 5, interface 'selfscanning', nasId:'' *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Set Client Non AP specific WLAN apfMsAccessVlan = 249 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 This apfMsAccessVlan may be changed later from AAA after L2 Auth *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Cleared localSwitchingVlan, may be assigned later based on AAA override *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_2: May 27 11:52:37.920: RSNIE in Assoc. Req.: (20) *apfMsConnTask_2: May 27 11:52:37.920: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_2: May 27 11:52:37.920: [0016] ac 02 a8 00 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Processing RSN IE type 48, length 20 for mobile 30:95:e3:2e:a3:81 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Received 802.11i PSK key management suite, enabling Authentication *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 RSN Capabilities: 168 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 non-11w Capable mobile *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Received RSN IE with 0 PMKIDs from mobile 30:95:e3:2e:a3:81 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 1 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:4922) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Deleted mobile LWAPP rule on AP [b0:90:7e:dc:c9:60] *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Succesfully freed AID 1, slot 0 on AP b0:90:7e:dc:c9:60, #client on this slot 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 New ctxOwnerMwarIp: 10.251.89.28 New ctxOwnerApMac: 00:7E:95:83:12:A0 New ctxOwnerApEthMac: B0:90:7E:DC:1A:20 New ctxOwnerApSlotId: 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Updated location for station old AP b0:90:7e:dc:c9:60 oldSlot 0, new AP 00:7e:95:83:12:a0 newSlot 0, AID 0 MsType 0 MobilityRole 1 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Assigning flex webauth ACL ID :65535 for vlan : 3 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Updating AID for REAP AP Client 00:7e:95:83:12:a0 - AID ===> 6 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfMsRunStateDec *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfMs1xStateDec *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 0 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:3495) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Initializing policy *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfVapSecurity=0x40004000 L2=16384 SkipWeb=0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 AuthenticationRequired = 1 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Encryption policy is set to 0x80000001 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Client already has IP 10.249.89.135, DHCP Not required on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 flex-acl-name: *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 30:95:e3:2e:a3:81 on AP 00:7e:95:83:12:a0 from Associated to Associated *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfPemAddUser2:session timeout forstation 30:95:e3:2e:a3:81 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Sending assoc-resp with status 0 station:30:95:e3:2e:a3:81 AP:00:7e:95:83:12:a0-00 on apVapId 3 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 Sending Assoc Response (status: '0') to station on AP AP1-Casse on BSSID 00:7e:95:83:12:a2 ApVapId 3 Slot 0, mobility role 1 *apfMsConnTask_2: May 27 11:52:37.920: 30:95:e3:2e:a3:81 apfProcessAssocReq (apf_80211.c:11962) Changing state for mobile 30:95:e3:2e:a3:81 on AP 00:7e:95:83:12:a0 from Associated to Associated *spamApTask5: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Setting DEL_MOBILE (seqno 0, action 6) ack state for STA on AP b0:90:7e:dc:c9:60 *spamApTask5: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Delete Mobile request on slot 0 sent to the AP b0:90:7e:dc:c9:60 IP: 10.251.89.41:5248 *spamApTask7: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Add SGT:0 to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:37.921: 30:95:e3:2e:a3:81 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 2130713130) ack state for STA on AP 00:7e:95:83:12:a0 *spamApTask5: May 27 11:52:37.924: 30:95:e3:2e:a3:81 apfUpdateDeleteAckInMscb (apf_api.c:54210) Expiring Mobile! *spamApTask7: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Received ADD_MOBILE ack - Initiating 1x to STA 30:95:e3:2e:a3:81 (idx 54) *spamApTask7: May 27 11:52:37.925: 30:95:e3:2e:a3:81 APF Initiating 1x to STA 30:95:e3:2e:a3:81 *spamApTask7: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Sent dot1x auth initiate message for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 dot1xProcessInitiate1XtoMobile to mobile station 30:95:e3:2e:a3:81 (mscb 4, msg 4) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 reauth_sm state transition 0 ---> 0 for mobile 30:95:e3:2e:a3:81 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Normal psk client, full auth *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Created PKC PMK Cache entry for station 30:95:e3:2e:a3:81 (RSN 2) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Resetting MSCB PMK Cache Entry @index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Removing BSSID b0:90:7e:dc:c9:62 from PMKID cache of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Setting active key cache index 0 ---> 8 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Created PMKID PMK Cache for BSSID 00:7e:95:83:12:a2 at index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: New PMKID: (16) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: [0000] 2d 28 4c c9 65 7b 05 52 52 ed f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Initiating RSN PSK to mobile 30:95:e3:2e:a3:81keyMgmtType : 0 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 EAP-PARAM Debug - eap-params for Wlan-Id :3 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 dot1x - moving mobile 30:95:e3:2e:a3:81 into Force Auth state *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Skipping EAP-Success to mobile 30:95:e3:2e:a3:81 (encryptBit:0) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Found an cache entry for BSSID 00:7e:95:83:12:a2 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Found an cache entry for BSSID 00:7e:95:83:12:a2 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: Including PMKID in M1 (16) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: [0000] 2d 28 4c c9 65 7b 05 52 52 ed f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: M1 - Key Data: (22) *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: [0000] dd 14 00 0f ac 04 2d 28 4c c9 65 7b 05 52 52 ed *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: [0016] f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Starting key exchange to mobile 30:95:e3:2e:a3:81, data packets will be dropped *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_1: May 27 11:52:37.925: 30:95:e3:2e:a3:81 Allocating EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:38.025: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Received EAPOL-key in PTK_START state (message 2) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 rsnieCapabilty = a8 rsnie_len =20 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Dumping RSNIE received in Association request(len = 22): *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 00000010: 00 0f ac 02 a8 00 ...... *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Dumping RSNIE received in EAPOL M2 (len = 20): *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 00000010: ac 02 a8 00 .... *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_1: May 27 11:52:38.025: 30:95:e3:2e:a3:81 Reusing allocated memory for EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:38.033: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Freeing EAP Retransmit Bufer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 apfMs1xStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Client already has IP 10.249.89.135, DHCP Not required on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 flex-acl-name: *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 apfMsRunStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Reached PLUMBFASTPATH: from line 7155, null *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_1: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Successfully Plumbed PTK session Keysfor mobile 30:95:e3:2e:a3:81 *spamApTask7: May 27 11:52:38.033: 30:95:e3:2e:a3:81 Add SGT:0 to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:38.034: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: May 27 11:52:38.034: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP 00:7e:95:83:12:a0 *apfReceiveTask: May 27 11:52:38.177: 30:95:e3:2e:a3:81 Recieved MS IPv4 Addr= 10.249.89.135 *apfOpenDtlSocket: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Received management frame ASSOCIATION REQUEST on BSSID 00:7e:95:83:12:a2 destination addr 00:7e:95:83:12:a2 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Processing assoc-req station:30:95:e3:2e:a3:81 AP:00:7e:95:83:12:a0-00 ssid : Dinamico thread:b200220 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP 00:7E:95:83:12:A0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Updating location for mobile on same AP 00:7e:95:83:12:a0-0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Client AVC Roaming context transfer needed? NO *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Setting RTTS enabled to 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Association received from mobile on BSSID 00:7e:95:83:12:a2 AP AP1-Casse *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Station: 30:95:E3:2E:A3:81 11v BSS Transition not enabled on the AP 00:7E:95:83:12:A0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Global 200 Clients are allowed to AP radio *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Max Client Trap Threshold: 0 cur: 57 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Rf profile 600 Clients are allowed to AP wlan *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 override for default ap group, marking intgrp NULL *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Check before Setting the NAS Id to WLAN specific Id '' *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Check the client SGT 0 policy and push it to AP 00:7e:95:83:12:a0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 In processSsidIE:6954 setting Central switched to FALSE *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Set Client MSCB as Central Association Disabled *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Applying site-specific Local Bridging override for station 30:95:e3:2e:a3:81 - vapId 3, site 'default-group', interface 'selfscanning' *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Applying Local Bridging Interface Policy for station 30:95:e3:2e:a3:81 - vlan 249, interface id 5, interface 'selfscanning', nasId:'' *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Set Client Non AP specific WLAN apfMsAccessVlan = 249 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 This apfMsAccessVlan may be changed later from AAA after L2 Auth *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Cleared localSwitchingVlan, may be assigned later based on AAA override *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 processSsidIE statusCode is 0 and status is 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 processSsidIE ssid_done_flag is 0 finish_flag is 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 suppRates statusCode is 0 and gotSuppRatesElement is 1 *apfMsConnTask_2: May 27 11:52:46.205: RSNIE in Assoc. Req.: (20) *apfMsConnTask_2: May 27 11:52:46.205: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f *apfMsConnTask_2: May 27 11:52:46.205: [0016] ac 02 a8 00 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Processing RSN IE type 48, length 20 for mobile 30:95:e3:2e:a3:81 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Selected Unicast cipher CCMP128 for client device *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Received 802.11i PSK key management suite, enabling Authentication *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 RSN Capabilities: 168 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 non-11w Capable mobile *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Received RSN IE with 0 PMKIDs from mobile 30:95:e3:2e:a3:81 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Assigning flex webauth ACL ID :65535 for vlan : 3 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 AID 6 in Assoc Req from flex AP 00:7e:95:83:12:a0 is same as in mscb 30:95:e3:2e:a3:81 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfMsRunStateDec *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfMs1xStateDec *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Change state to START (0) last state RUN (20) *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 pemApfAddMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0. *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 the value of url acl preserve flag is 0 for mobile 30:95:e3:2e:a3:81 (caller pem_api.c:3495) *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Initializing policy *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 START (0) Change state to AUTHCHECK (2) last state START (0) *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfVapSecurity=0x40004000 L2=16384 SkipWeb=0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 AuthenticationRequired = 1 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2) *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Encryption policy is set to 0x80000001 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Client already has IP 10.249.89.135, DHCP Not required on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 flex-acl-name: *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfPemAddUser2 (apf_policy.c:423) Changing state for mobile 30:95:e3:2e:a3:81 on AP 00:7e:95:83:12:a0 from Associated to Associated *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfPemAddUser2:session timeout forstation 30:95:e3:2e:a3:81 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Stopping deletion of Mobile Station: (callerId: 48) *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Sending assoc-resp with status 0 station:30:95:e3:2e:a3:81 AP:00:7e:95:83:12:a0-00 on apVapId 3 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Sending Assoc Response (status: '0') to station on AP AP1-Casse on BSSID 00:7e:95:83:12:a2 ApVapId 3 Slot 0, mobility role 1 *apfMsConnTask_2: May 27 11:52:46.205: 30:95:e3:2e:a3:81 apfProcessAssocReq (apf_80211.c:11962) Changing state for mobile 30:95:e3:2e:a3:81 on AP 00:7e:95:83:12:a0 from Associated to Associated *spamApTask7: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Add SGT:0 to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:46.205: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: May 27 11:52:46.206: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:46.206: 30:95:e3:2e:a3:81 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 2130713132) ack state for STA on AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Received ADD_MOBILE ack - Initiating 1x to STA 30:95:e3:2e:a3:81 (idx 57) *spamApTask7: May 27 11:52:46.211: 30:95:e3:2e:a3:81 APF Initiating 1x to STA 30:95:e3:2e:a3:81 *spamApTask7: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Sent dot1x auth initiate message for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 dot1xProcessInitiate1XtoMobile to mobile station 30:95:e3:2e:a3:81 (mscb 5, msg 5) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 reauth_sm state transition 0 ---> 0 for mobile 30:95:e3:2e:a3:81 at 1x_reauth_sm.c:53 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Normal psk client, full auth *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Created PKC PMK Cache entry for station 30:95:e3:2e:a3:81 (RSN 2) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Resetting MSCB PMK Cache Entry @index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Removing BSSID 00:7e:95:83:12:a2 from PMKID cache of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Setting active key cache index 0 ---> 8 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Setting active key cache index 8 ---> 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Created PMKID PMK Cache for BSSID 00:7e:95:83:12:a2 at index 0 for station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: New PMKID: (16) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: [0000] 2d 28 4c c9 65 7b 05 52 52 ed f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Initiating RSN PSK to mobile 30:95:e3:2e:a3:81keyMgmtType : 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 unsetting PmkIdValidatedByAp *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 EAP-PARAM Debug - eap-params for Wlan-Id :3 is disabled - applying Global eap timers and retries *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Disable re-auth, use PMK lifetime. *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 dot1x - moving mobile 30:95:e3:2e:a3:81 into Force Auth state *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Skipping EAP-Success to mobile 30:95:e3:2e:a3:81 (encryptBit:0) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Found an cache entry for BSSID 00:7e:95:83:12:a2 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Found an cache entry for BSSID 00:7e:95:83:12:a2 in PMKID cache at index 0 of station 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: Including PMKID in M1 (16) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: [0000] 2d 28 4c c9 65 7b 05 52 52 ed f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: M1 - Key Data: (22) *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: [0000] dd 14 00 0f ac 04 2d 28 4c c9 65 7b 05 52 52 ed *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: [0016] f7 f3 1f 97 c7 0d *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Starting key exchange to mobile 30:95:e3:2e:a3:81, data packets will be dropped *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00 *Dot1x_NW_MsgTask_1: May 27 11:52:46.211: 30:95:e3:2e:a3:81 Allocating EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:46.284: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Received EAPOL-key in PTK_START state (message 2) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Encryption Policy: 4, PTK Key Length: 48 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Successfully computed PTK from PMK!!! *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Received valid MIC in EAPOL Key Message M2!!!!! *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0) *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 rsnieCapabilty = a8 rsnie_len =20 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Dumping RSNIE received in Association request(len = 22): *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0............... *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 00000010: 00 0f ac 02 a8 00 ...... *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Dumping RSNIE received in EAPOL M2 (len = 20): *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................ *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 00000010: ac 02 a8 00 .... *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Sending EAPOL-Key Message to mobile 30:95:e3:2e:a3:81 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01 *Dot1x_NW_MsgTask_1: May 27 11:52:46.284: 30:95:e3:2e:a3:81 Reusing allocated memory for EAP Pkt for retransmission to mobile 30:95:e3:2e:a3:81 *dot1xSocketTask: May 27 11:52:46.293: 30:95:e3:2e:a3:81 validating eapol pkt: key version = 2 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Received EAPOL-Key from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 key Desc Version FT - 0 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Stopping retransmission timer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Freeing EAP Retransmit Bufer for mobile 30:95:e3:2e:a3:81 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 apfMs1xStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3) *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Client already has IP 10.249.89.135, DHCP Not required on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Not Using WMM Compliance code qosCap 00 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 flex webauth acl id to be sent :65535 name : client acl id : 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Vlan while overriding the policy = -1 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535 *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:7e:95:83:12:a0 vapId 3 apVapId 3 flex-acl-name: *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 apfMsRunStateInc *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 L2AUTHCOMPLETE (4) Change state to RUN (20) last state L2AUTHCOMPLETE (4) *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) Reached PLUMBFASTPATH: from line 7155, null *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) No 11v BTM *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 10.249.89.135 RUN (20) NO release MSCB *Dot1x_NW_MsgTask_1: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Successfully Plumbed PTK session Keysfor mobile 30:95:e3:2e:a3:81 *spamApTask7: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Add SGT:0 to AP 00:7e:95:83:12:a0 *spamApTask7: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0 *spamApTask7: May 27 11:52:46.293: 30:95:e3:2e:a3:81 Successful transmission of LWAPP Add-Mobile to AP 00:7e:95:83:12:a0 *apfReceiveTask: May 27 11:52:46.684: 30:95:e3:2e:a3:81 Recieved MS IPv4 Addr= 10.249.89.135