Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Announcements

Welcome to Cisco Support Community. We would love to have your feedback.

For an introduction to the new site, click here. And see here for current known issues.

New Member

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Hi!!!  Please help with the solution.

I have one 5508 with Product version 6.0.199.4 and about 7 Cisco 1140 APs.

We have a next problems. Go out of the connection on the clients PC, while physically a wireless connection to the workstations is not broken, but access to network resources is lost and restored after some time (up to about one minute).The logs on the controller at the same time see the following message:

*Jul 11 15:10:35.912: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:407 Max EAPOL-key M3 retransmissions exceeded for client 44:6d:57:36:92:c1

*Jul 11 15:10:10.843: %DOT1X-3-INVALID_WPA_KEY_MSG_STATE: 1x_eapkey.c:705 Received invalid EAPOL-key M2 msg in START state - invalid secure bit; len 22, key type 1, client 44:6d:57:36:92:c1

*Jul 11 15:10:05.970: %DOT1X-3-INVALID_WPA_KEY_MSG_STATE: 1x_eapkey.c:705 Received invalid EAPOL-key M2 msg in START state - invalid secure bit; len 22, key type 1, client 44:6d:57:36:92:c1

result of the command debug client <mac_addr>:

*Jul 12 16:53:50.148: 44:6d:57:36:92:c1 Key exchange done, data packets from mobile 44:6d:57:36:92:c1 should be forwarded shortly

*Jul 12 16:53:50.148: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.02

*Jul 12 16:53:50.149: 44:6d:57:36:92:c1 Updated broadcast key sent to mobile 44:6D:57:36:92:C1

*Jul 12 16:53:50.162: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 16:53:50.163: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 16:53:50.163: 44:6d:57:36:92:c1 Received EAPOL-key in REKEYNEGOTIATING state (message 6) from mobile 44:6d:57:36:92:c1

*Jul 12 16:53:50.163: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 Reassociation received from mobile on AP 00:3a:99:1b:65:70

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 Applying site-specific IPv6 override for station 44:6d:57:36:92:c1 - vapId 1, site 'default-group', interface 'test'

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 Applying IPv6 Interface Policy for station 44:6d:57:36:92:c1 - vlan 1914, interface id 11, interface 'test'

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 Processing RSN IE type 48, length 38 for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.544: 44:6d:57:36:92:c1 Received RSN IE with 1 PMKIDs from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.544: Received PMKID:  (16)

*Jul 12 16:54:25.544:      [0000] 2b 7d 30 f6 37 19 ac 7d 9d a6 94 f4 89 56 c9 84

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Searching for PMKID in MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 No valid PMKID found in the MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Trying to compute a PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: CCKM: Find PMK in cache: BSSID =  (6)

*Jul 12 16:54:25.545:      [0000] 00 3a 99 1b 65 70

*Jul 12 16:54:25.545: CCKM: Find PMK in cache: realAA =  (6)

*Jul 12 16:54:25.545:      [0000] 00 3a 99 1b 65 70

*Jul 12 16:54:25.545: CCKM: Find PMK in cache: PMKID =  (16)

*Jul 12 16:54:25.545:      [0000] 2b 7d 30 f6 37 19 ac 7d 9d a6 94 f4 89 56 c9 84

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Unable to compute a valid PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Searching for PMK in global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Found an entry in the global PMK cache for station 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: CCKM: AA (6)

*Jul 12 16:54:25.545:      [0000] 00 3a 99 1b 65 70

*Jul 12 16:54:25.545: CCKM: SPA (6)

*Jul 12 16:54:25.545:      [0000] 44 6d 57 36 92 c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 computed a valid PMKID from global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Creating a PKC PMKID Cache entry for station 44:6d:57:36:92:c1 (RSN 0) on BSSID 00:3a:99:1b:65:70

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Adding BSSID 00:3a:99:1b:65:70 to PMKID cache for station 44:6d:57:36:92:c1

*Jul 12 16:54:25.545: New PMKID: (16)

*Jul 12 16:54:25.545:      [0000] 2b 7d 30 f6 37 19 ac 7d 9d a6 94 f4 89 56 c9 84

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Deleted mobile LWAPP rule on AP [00:3a:99:1b:5b:20]

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 Removed NPU entry.

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 Updated location for station old AP 00:3a:99:1b:5b:20-0, new AP 00:3a:99:1b:65:70-0

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Change state to START (0) last state RUN (20)

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 START (0) Initializing policy

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:65:70 vapId 1 apVapId 1

*Jul 12 16:54:25.545: 44:6d:57:36:92:c1 apfPemAddUser2 (apf_policy.c:213) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:65:70 from Associated to Associated

*Jul 12 16:54:25.546: 44:6d:57:36:92:c1 Stopping deletion of Mobile Station: (callerId: 48)

*Jul 12 16:54:25.546: 44:6d:57:36:92:c1 Sending Assoc Response to station on BSSID 00:3a:99:1b:65:70 (status 0) Vap Id 1 Slot 0

*Jul 12 16:54:25.546: 44:6d:57:36:92:c1 apfProcessAssocReq (apf_80211.c:4389) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:65:70 from Associated to Associated

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 Initiating RSN with existing PMK to mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 Disable re-auth, use PMK lifetime.

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Force Auth state

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 Skipping EAP-Success to mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.548: Including PMKID in M1  (16)

*Jul 12 16:54:25.548:      [0000] 2b 7d 30 f6 37 19 ac 7d 9d a6 94 f4 89 56 c9 84

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 Starting key exchange to mobile 44:6d:57:36:92:c1, data packets will be dropped

*Jul 12 16:54:25.548: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Jul 12 16:54:25.554: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.554: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.554: 44:6d:57:36:92:c1 Received EAPOL-key in PTK_START state (message 2) from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.554: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.554: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:65:70 vapId 1 apVapId 1

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Reached PLUMBFASTPATH: from line 4586

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Adding Fast Path rule

  type = Airespace AP Client

  on AP 00:3a:99:1b:65:70, slot 0, interface = 13, QOS = 0

  ACL Id = 255, Jumbo Frames = NO,

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Jul 12 16:54:25.559: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 16:54:25.560: 44:6d:57:36:92:c1 10.19.26.212 Added NPU entry of type 1, dtlFlags 0x0

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP received op BOOTREQUEST (1) (len 323, port 13, encap 0xec03)

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP selecting relay 1 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP selected relay 1 - 10.16.0.101 (local address 10.19.26.3, gateway 10.19.26.1, VLAN 1914, port 13)

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP transmitting DHCP REQUEST (3)

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   xid: 0xd903e477 (3640910967), secs: 0, flags: 0

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 10.19.26.3

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP   requested ip: 10.19.26.212

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP sending REQUEST to 10.19.26.1 (len 366, port 13, vlan 1914)

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP selecting relay 2 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 16:54:25.569: 44:6d:57:36:92:c1 DHCP selected relay 2 - NONE

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP received op BOOTREPLY (2) (len 316, port 13, encap 0xec00)

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP sending REPLY to STA (len 426, port 13, vlan 1912)

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP transmitting DHCP ACK (5)

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   xid: 0xd903e477 (3640910967), secs: 0, flags: 0

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 10.19.26.212

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0

*Jul 12 16:54:25.571: 44:6d:57:36:92:c1 DHCP   server id: 1.1.1.1  rcvd server id: 10.16.0.101

*Jul 12 16:56:27.281: CCKM: Send CCKM cache entry

*Jul 12 16:57:04.146: CCKM: Send CCKM cache entry

*Jul 12 17:05:44.198: CCKM: Send CCKM cache entry

*Jul 12 17:06:35.156: CCKM: Send CCKM cache entry

*Jul 12 17:06:59.640: CCKM: Send CCKM cache entry

*Jul 12 17:10:35.404: CCKM: Send CCKM cache entry

*Jul 12 17:11:01.921: CCKM: Send CCKM cache entry

*Jul 12 17:11:45.829: CCKM: Send CCKM cache entry

*Jul 12 17:13:33.165: 44:6d:57:36:92:c1 Removing expired PMK cache entry for station 44:6d:57:36:92:c1 AKM was:APF_KEY_MGMT_80211i

*Jul 12 17:13:33.165: 44:6d:57:36:92:c1 Initiating 802.1x due to PMK Timeout Event for STA

*Jul 12 17:13:33.166: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Connecting state

*Jul 12 17:13:33.166: 44:6d:57:36:92:c1 Sending EAP-Request/Identity to mobile 44:6d:57:36:92:c1 (EAP Id 1)

*Jul 12 17:13:33.177: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.177: 44:6d:57:36:92:c1 Received Identity Response (count=1) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.177: 44:6d:57:36:92:c1 EAP State update from Connecting to Authenticating for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.177: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticating state

*Jul 12 17:13:33.177: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.189: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.189: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=2) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.189: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 2)

*Jul 12 17:13:33.193: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.193: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 2, EAP Type 25)

*Jul 12 17:13:33.193: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.199: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.199: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=3) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.199: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 3)

*Jul 12 17:13:33.205: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.205: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 3, EAP Type 25)

*Jul 12 17:13:33.205: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.230: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.230: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=6) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.230: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 3 ===> 6 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:33.230: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 6)

*Jul 12 17:13:33.234: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.234: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 6, EAP Type 25)

*Jul 12 17:13:33.234: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.239: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.239: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=7) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.239: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 7)

*Jul 12 17:13:33.244: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.244: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 7, EAP Type 25)

*Jul 12 17:13:33.244: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.249: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.249: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=8) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.249: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 8)

*Jul 12 17:13:33.253: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.253: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 8, EAP Type 25)

*Jul 12 17:13:33.254: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.267: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.267: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=9) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.267: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 9)

*Jul 12 17:13:33.276: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.276: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 9, EAP Type 25)

*Jul 12 17:13:33.276: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.285: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.285: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=10) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.285: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 10)

*Jul 12 17:13:33.290: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.290: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 10, EAP Type 25)

*Jul 12 17:13:33.290: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.297: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.297: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.297: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 10 ===> 12 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:33.297: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:33.302: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.302: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 12, EAP Type 25)

*Jul 12 17:13:33.302: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.309: 44:6d:57:36:92:c1 Processing Access-Accept for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.309: 44:6d:57:36:92:c1 Setting re-auth timeout to 1800 seconds, got from WLAN config.

*Jul 12 17:13:33.309: 44:6d:57:36:92:c1 Station 44:6d:57:36:92:c1 setting dot1x reauth timeout = 1800

*Jul 12 17:13:33.309: 44:6d:57:36:92:c1 Creating a PKC PMKID Cache entry for station 44:6d:57:36:92:c1 (RSN 2)

*Jul 12 17:13:33.309: 44:6d:57:36:92:c1 Adding BSSID 00:3a:99:1b:65:70 to PMKID cache for station 44:6d:57:36:92:c1

*Jul 12 17:13:33.309: New PMKID: (16)

*Jul 12 17:13:33.310:      [0000] c2 95 8f a2 69 77 a0 96 62 0f 84 df 83 e0 be ee

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Disabling re-auth since PMK lifetime can take care of same.

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 PMK sent to mobility group

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Sending EAP-Success to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:33.310: Including PMKID in M1  (16)

*Jul 12 17:13:33.310:      [0000] c2 95 8f a2 69 77 a0 96 62 0f 84 df 83 e0 be ee

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Starting key exchange to mobile 44:6d:57:36:92:c1, data packets will be dropped

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.02

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Entering Backend Auth Success state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 Received Auth Success while in Authenticating state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.310: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticated state

*Jul 12 17:13:33.315: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.315: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.315: 44:6d:57:36:92:c1 Received EAPOL-key in PTK_START state (message 2) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.315: 44:6d:57:36:92:c1 EAPOL-key M2 with invalid secure bit (set) received from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:33.316: 44:6d:57:36:92:c1 Received EAPOL-key M2 with invalid MIC from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.165: 44:6d:57:36:92:c1 802.1x 'timeoutEvt' Timer expired for station 44:6d:57:36:92:c1

*Jul 12 17:13:34.165: 44:6d:57:36:92:c1 Retransmit 1 of EAPOL-Key M1 (length 121) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 Received EAPOL-key in PTK_START state (message 2) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 EAPOL-key M2 with invalid secure bit (set) received from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:34.170: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.04

*Jul 12 17:13:35.165: 44:6d:57:36:92:c1 802.1x 'timeoutEvt' Timer expired for station 44:6d:57:36:92:c1

*Jul 12 17:13:35.165: 44:6d:57:36:92:c1 Retransmit 1 of EAPOL-Key M3 (length 155) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:36.165: 44:6d:57:36:92:c1 802.1x 'timeoutEvt' Timer expired for station 44:6d:57:36:92:c1

*Jul 12 17:13:36.165: 44:6d:57:36:92:c1 Retransmit 2 of EAPOL-Key M3 (length 155) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:37.165: 44:6d:57:36:92:c1 802.1x 'timeoutEvt' Timer expired for station 44:6d:57:36:92:c1

*Jul 12 17:13:37.165: 44:6d:57:36:92:c1 Retransmit failure for EAPOL-Key M3 to mobile 44:6d:57:36:92:c1, retransmit count 3, mscb deauth count 0

*Jul 12 17:13:37.165: 44:6d:57:36:92:c1 Sent Deauthenticate to mobile on BSSID 00:3a:99:1b:65:70 slot 0(caller 1x_ptsm.c:467)

*Jul 12 17:13:37.165: 44:6d:57:36:92:c1 Scheduling deletion of Mobile Station:  (callerId: 57) in 10 seconds

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Association received from mobile on AP 00:3a:99:1b:5b:20

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Applying site-specific IPv6 override for station 44:6d:57:36:92:c1 - vapId 1, site 'default-group', interface 'test'

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Applying IPv6 Interface Policy for station 44:6d:57:36:92:c1 - vlan 1914, interface id 11, interface 'test'

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Processing RSN IE type 48, length 38 for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Received RSN IE with 1 PMKIDs from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: Received PMKID:  (16)

*Jul 12 17:13:38.058:      [0000] 57 ae 1f b6 1f 92 2d cf 8d b7 82 5e 13 c0 2e 76

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Searching for PMKID in MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 No valid PMKID found in the MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Trying to compute a PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: CCKM: Find PMK in cache: BSSID =  (6)

*Jul 12 17:13:38.058:      [0000] 00 3a 99 1b 5b 20

*Jul 12 17:13:38.058: CCKM: Find PMK in cache: realAA =  (6)

*Jul 12 17:13:38.058:      [0000] 00 3a 99 1b 5b 20

*Jul 12 17:13:38.058: CCKM: Find PMK in cache: PMKID =  (16)

*Jul 12 17:13:38.058:      [0000] 57 ae 1f b6 1f 92 2d cf 8d b7 82 5e 13 c0 2e 76

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Unable to compute a valid PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Searching for PMK in global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Found an entry in the global PMK cache for station 44:6d:57:36:92:c1

*Jul 12 17:13:38.058: CCKM: AA (6)

*Jul 12 17:13:38.058:      [0000] 00 3a 99 1b 5b 20

*Jul 12 17:13:38.058: CCKM: SPA (6)

*Jul 12 17:13:38.058:      [0000] 44 6d 57 36 92 c1

*Jul 12 17:13:38.058: 44:6d:57:36:92:c1 Unable to compute a valid PMKID from global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Deleted mobile LWAPP rule on AP [00:3a:99:1b:65:70]

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 Removed NPU entry.

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 Updated location for station old AP 00:3a:99:1b:65:70-0, new AP 00:3a:99:1b:5b:20-0

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Change state to START (0) last state RUN (20)

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 START (0) Initializing policy

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:5b:20 vapId 1 apVapId 1

*Jul 12 17:13:38.059: 44:6d:57:36:92:c1 apfPemAddUser2 (apf_policy.c:213) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:5b:20 from Associated to Associated

*Jul 12 17:13:38.060: 44:6d:57:36:92:c1 Stopping deletion of Mobile Station: (callerId: 48)

*Jul 12 17:13:38.060: 44:6d:57:36:92:c1 Sending Assoc Response to station on BSSID 00:3a:99:1b:5b:20 (status 0) Vap Id 1 Slot 0

*Jul 12 17:13:38.060: 44:6d:57:36:92:c1 apfProcessAssocReq (apf_80211.c:4389) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:5b:20 from Associated to Associated

*Jul 12 17:13:38.062: 44:6d:57:36:92:c1 Disable re-auth, use PMK lifetime.

*Jul 12 17:13:38.062: 44:6d:57:36:92:c1 Station 44:6d:57:36:92:c1 setting dot1x reauth timeout = 1800

*Jul 12 17:13:38.062: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Connecting state

*Jul 12 17:13:38.062: 44:6d:57:36:92:c1 Sending EAP-Request/Identity to mobile 44:6d:57:36:92:c1 (EAP Id 1)

*Jul 12 17:13:38.113: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.113: 44:6d:57:36:92:c1 Received Identity Response (count=1) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.113: 44:6d:57:36:92:c1 EAP State update from Connecting to Authenticating for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.113: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticating state

*Jul 12 17:13:38.113: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.126: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.126: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=2) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.126: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 2)

*Jul 12 17:13:38.130: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.130: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 2, EAP Type 25)

*Jul 12 17:13:38.130: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.135: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.135: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=3) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.135: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 3)

*Jul 12 17:13:38.152: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.152: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 3, EAP Type 25)

*Jul 12 17:13:38.152: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.158: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.158: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=6) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.158: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 3 ===> 6 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:38.158: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 6)

*Jul 12 17:13:38.162: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.162: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 6, EAP Type 25)

*Jul 12 17:13:38.162: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.167: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.167: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=7) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.167: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 7)

*Jul 12 17:13:38.171: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.171: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 7, EAP Type 25)

*Jul 12 17:13:38.171: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.176: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.176: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=8) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.176: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 8)

*Jul 12 17:13:38.179: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.179: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 8, EAP Type 25)

*Jul 12 17:13:38.179: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.286: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.286: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=9) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.286: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 9)

*Jul 12 17:13:38.293: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.293: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 9, EAP Type 25)

*Jul 12 17:13:38.293: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.300: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.300: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=10) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.300: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 10)

*Jul 12 17:13:38.303: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.304: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 10, EAP Type 25)

*Jul 12 17:13:38.304: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.310: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.310: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.310: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 10 ===> 12 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:38.310: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:38.315: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.315: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 12, EAP Type 25)

*Jul 12 17:13:38.315: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.321: 44:6d:57:36:92:c1 Processing Access-Accept for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.321: 44:6d:57:36:92:c1 Setting re-auth timeout to 1800 seconds, got from WLAN config.

*Jul 12 17:13:38.321: 44:6d:57:36:92:c1 Station 44:6d:57:36:92:c1 setting dot1x reauth timeout = 1800

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Creating a PKC PMKID Cache entry for station 44:6d:57:36:92:c1 (RSN 2)

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Adding BSSID 00:3a:99:1b:5b:20 to PMKID cache for station 44:6d:57:36:92:c1

*Jul 12 17:13:38.322: New PMKID: (16)

*Jul 12 17:13:38.322:      [0000] e2 0a b8 de 9a 90 2a 43 c1 a3 1e b0 af 91 1f ae

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Disabling re-auth since PMK lifetime can take care of same.

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 PMK sent to mobility group

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Sending EAP-Success to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:38.322: Including PMKID in M1  (16)

*Jul 12 17:13:38.322:      [0000] e2 0a b8 de 9a 90 2a 43 c1 a3 1e b0 af 91 1f ae

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Starting key exchange to mobile 44:6d:57:36:92:c1, data packets will be dropped

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Entering Backend Auth Success state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 Received Auth Success while in Authenticating state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.322: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticated state

*Jul 12 17:13:38.329: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.329: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.329: 44:6d:57:36:92:c1 Received EAPOL-key in PTK_START state (message 2) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.329: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.329: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:5b:20 vapId 1 apVapId 1

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Reached PLUMBFASTPATH: from line 4586

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Adding Fast Path rule

  type = Airespace AP Client

  on AP 00:3a:99:1b:5b:20, slot 0, interface = 13, QOS = 0

  ACL Id = 255, Jumbo Frames = NO,

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:38.334: 44:6d:57:36:92:c1 10.19.26.212 Added NPU entry of type 1, dtlFlags 0x0

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP received op BOOTREQUEST (1) (len 323, port 13, encap 0xec03)

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP selecting relay 1 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP selected relay 1 - 10.16.0.101 (local address 10.19.26.3, gateway 10.19.26.1, VLAN 1914, port 13)

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP transmitting DHCP REQUEST (3)

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   xid: 0x512d474c (1361921868), secs: 1024, flags: 0

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 10.19.26.3

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP   requested ip: 10.19.26.212

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP sending REQUEST to 10.19.26.1 (len 366, port 13, vlan 1914)

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP selecting relay 2 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:38.377: 44:6d:57:36:92:c1 DHCP selected relay 2 - NONE

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP received op BOOTREPLY (2) (len 316, port 13, encap 0xec00)

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP sending REPLY to STA (len 426, port 13, vlan 1912)

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP transmitting DHCP ACK (5)

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   xid: 0x512d474c (1361921868), secs: 0, flags: 0

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 10.19.26.212

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0

*Jul 12 17:13:38.379: 44:6d:57:36:92:c1 DHCP   server id: 1.1.1.1  rcvd server id: 10.16.0.101

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP received op BOOTREQUEST (1) (len 323, port 13, encap 0xec03)

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP selecting relay 1 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP selected relay 1 - 10.16.0.101 (local address 10.19.26.3, gateway 10.19.26.1, VLAN 1914, port 13)

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP transmitting DHCP REQUEST (3)

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   xid: 0xcb79c9a6 (3413756326), secs: 0, flags: 0

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 10.19.26.3

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP   requested ip: 10.19.26.212

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP sending REQUEST to 10.19.26.1 (len 366, port 13, vlan 1914)

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP selecting relay 2 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:38.384: 44:6d:57:36:92:c1 DHCP selected relay 2 - NONE

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP received op BOOTREPLY (2) (len 316, port 13, encap 0xec00)

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP sending REPLY to STA (len 426, port 13, vlan 1912)

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP transmitting DHCP ACK (5)

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   xid: 0xcb79c9a6 (3413756326), secs: 0, flags: 0

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 10.19.26.212

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0

*Jul 12 17:13:38.386: 44:6d:57:36:92:c1 DHCP   server id: 1.1.1.1  rcvd server id: 10.16.0.101

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Reassociation received from mobile on AP 00:3a:99:1b:65:70

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Applying site-specific IPv6 override for station 44:6d:57:36:92:c1 - vapId 1, site 'default-group', interface 'test'

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Applying IPv6 Interface Policy for station 44:6d:57:36:92:c1 - vlan 1914, interface id 11, interface 'test'

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 STA - rates (8): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Processing RSN IE type 48, length 38 for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Received RSN IE with 1 PMKIDs from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.630: Received PMKID:  (16)

*Jul 12 17:13:39.630:      [0000] c2 95 8f a2 69 77 a0 96 62 0f 84 df 83 e0 be ee

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Searching for PMKID in MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 No valid PMKID found in the MSCB PMKID cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Trying to compute a PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.630: CCKM: Find PMK in cache: BSSID =  (6)

*Jul 12 17:13:39.630:      [0000] 00 3a 99 1b 65 70

*Jul 12 17:13:39.630: CCKM: Find PMK in cache: realAA =  (6)

*Jul 12 17:13:39.630:      [0000] 00 3a 99 1b 65 70

*Jul 12 17:13:39.630: CCKM: Find PMK in cache: PMKID =  (16)

*Jul 12 17:13:39.630:      [0000] c2 95 8f a2 69 77 a0 96 62 0f 84 df 83 e0 be ee

*Jul 12 17:13:39.630: 44:6d:57:36:92:c1 Unable to compute a valid PMKID from MSCB PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 Searching for PMK in global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 Found an entry in the global PMK cache for station 44:6d:57:36:92:c1

*Jul 12 17:13:39.631: CCKM: AA (6)

*Jul 12 17:13:39.631:      [0000] 00 3a 99 1b 65 70

*Jul 12 17:13:39.631: CCKM: SPA (6)

*Jul 12 17:13:39.631:      [0000] 44 6d 57 36 92 c1

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 Unable to compute a valid PMKID from global PMK cache for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Deleted mobile LWAPP rule on AP [00:3a:99:1b:5b:20]

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 Updated location for station old AP 00:3a:99:1b:5b:20-0, new AP 00:3a:99:1b:65:70-0

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Change state to START (0) last state RUN (20)

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 START (0) Initializing policy

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 START (0) Change state to AUTHCHECK (2) last state RUN (20)

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 AUTHCHECK (2) Change state to 8021X_REQD (3) last state RUN (20)

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:65:70 vapId 1 apVapId 1

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 apfPemAddUser2 (apf_policy.c:213) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:65:70 from Associated to Associated

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 Stopping deletion of Mobile Station: (callerId: 48)

*Jul 12 17:13:39.631: 44:6d:57:36:92:c1 10.19.26.212 Removed NPU entry.

*Jul 12 17:13:39.632: 44:6d:57:36:92:c1 Sending Assoc Response to station on BSSID 00:3a:99:1b:65:70 (status 0) Vap Id 1 Slot 0

*Jul 12 17:13:39.632: 44:6d:57:36:92:c1 apfProcessAssocReq (apf_80211.c:4389) Changing state for mobile 44:6d:57:36:92:c1 on AP 00:3a:99:1b:65:70 from Associated to Associated

*Jul 12 17:13:39.634: 44:6d:57:36:92:c1 Disable re-auth, use PMK lifetime.

*Jul 12 17:13:39.634: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Connecting state

*Jul 12 17:13:39.634: 44:6d:57:36:92:c1 Sending EAP-Request/Identity to mobile 44:6d:57:36:92:c1 (EAP Id 1)

*Jul 12 17:13:39.679: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.680: 44:6d:57:36:92:c1 Received Identity Response (count=1) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.680: 44:6d:57:36:92:c1 EAP State update from Connecting to Authenticating for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.680: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticating state

*Jul 12 17:13:39.680: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.690: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.690: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=2) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.690: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 2)

*Jul 12 17:13:39.697: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.697: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 2, EAP Type 25)

*Jul 12 17:13:39.698: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.702: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.702: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=3) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.703: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 3)

*Jul 12 17:13:39.708: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.708: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 3, EAP Type 25)

*Jul 12 17:13:39.708: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.714: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.714: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=6) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.714: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 3 ===> 6 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:39.714: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 6)

*Jul 12 17:13:39.717: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.717: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 6, EAP Type 25)

*Jul 12 17:13:39.718: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.722: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.722: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=7) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.722: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 7)

*Jul 12 17:13:39.727: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.727: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 7, EAP Type 25)

*Jul 12 17:13:39.727: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.731: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.731: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=8) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.731: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 8)

*Jul 12 17:13:39.742: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.742: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 8, EAP Type 25)

*Jul 12 17:13:39.742: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.752: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.752: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=9) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.752: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 9)

*Jul 12 17:13:39.767: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.767: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 9, EAP Type 25)

*Jul 12 17:13:39.767: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.773: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.773: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=10) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.773: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 10)

*Jul 12 17:13:39.776: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.776: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 10, EAP Type 25)

*Jul 12 17:13:39.776: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.784: 44:6d:57:36:92:c1 Processing Access-Challenge for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.784: 44:6d:57:36:92:c1 Entering Backend Auth Req state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.784: 44:6d:57:36:92:c1 WARNING: updated EAP-Identifer 10 ===> 12 for STA 44:6d:57:36:92:c1

*Jul 12 17:13:39.784: 44:6d:57:36:92:c1 Sending EAP Request from AAA to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:39.791: 44:6d:57:36:92:c1 Received EAPOL EAPPKT from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.791: 44:6d:57:36:92:c1 Received EAP Response from mobile 44:6d:57:36:92:c1 (EAP Id 12, EAP Type 25)

*Jul 12 17:13:39.791: 44:6d:57:36:92:c1 Entering Backend Auth Response state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Processing Access-Accept for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Setting re-auth timeout to 1800 seconds, got from WLAN config.

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Station 44:6d:57:36:92:c1 setting dot1x reauth timeout = 1800

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Creating a PKC PMKID Cache entry for station 44:6d:57:36:92:c1 (RSN 2)

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Adding BSSID 00:3a:99:1b:65:70 to PMKID cache for station 44:6d:57:36:92:c1

*Jul 12 17:13:39.797: New PMKID: (16)

*Jul 12 17:13:39.797:      [0000] 45 9e b2 e1 5c 0a b8 7d 60 13 55 16 3d f5 e8 4f

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Disabling re-auth since PMK lifetime can take care of same.

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 PMK sent to mobility group

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Sending EAP-Success to mobile 44:6d:57:36:92:c1 (EAP Id 12)

*Jul 12 17:13:39.797: Including PMKID in M1  (16)

*Jul 12 17:13:39.797:      [0000] 45 9e b2 e1 5c 0a b8 7d 60 13 55 16 3d f5 e8 4f

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Starting key exchange to mobile 44:6d:57:36:92:c1, data packets will be dropped

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Entering Backend Auth Success state (id=12) for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.797: 44:6d:57:36:92:c1 Received Auth Success while in Authenticating state for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.798: 44:6d:57:36:92:c1 dot1x - moving mobile 44:6d:57:36:92:c1 into Authenticated state

*Jul 12 17:13:39.804: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.804: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.804: 44:6d:57:36:92:c1 Received EAPOL-key in PTK_START state (message 2) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.804: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.804: 44:6d:57:36:92:c1 Sending EAPOL-Key Message to mobile 44:6d:57:36:92:c1

   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 Received EAPOL-Key from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 10.19.26.212 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:3a:99:1b:65:70 vapId 1 apVapId 1

*Jul 12 17:13:39.808: 44:6d:57:36:92:c1 10.19.26.212 L2AUTHCOMPLETE (4) Change state to RUN (20) last state RUN (20)

*Jul 12 17:13:39.809: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Reached PLUMBFASTPATH: from line 4586

*Jul 12 17:13:39.809: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Adding Fast Path rule

  type = Airespace AP Client

  on AP 00:3a:99:1b:65:70, slot 0, interface = 13, QOS = 0

  ACL Id = 255, Jumbo Frames = NO,

*Jul 12 17:13:39.809: 44:6d:57:36:92:c1 10.19.26.212 RUN (20) Successfully plumbed mobile rule (ACL ID 255)

*Jul 12 17:13:39.809: 44:6d:57:36:92:c1 Stopping retransmission timer for mobile 44:6d:57:36:92:c1

*Jul 12 17:13:39.809: 44:6d:57:36:92:c1 10.19.26.212 Added NPU entry of type 1, dtlFlags 0x0

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP received op BOOTREQUEST (1) (len 323, port 13, encap 0xec03)

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP selecting relay 1 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP selected relay 1 - 10.16.0.101 (local address 10.19.26.3, gateway 10.19.26.1, VLAN 1914, port 13)

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP transmitting DHCP REQUEST (3)

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP   op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP   xid: 0xc443f1a (205799194), secs: 0, flags: 0

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:42.543: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 0.0.0.0

*Jul 12 17:13:42.544: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 10.19.26.3

*Jul 12 17:13:42.544: 44:6d:57:36:92:c1 DHCP   requested ip: 10.19.26.212

*Jul 12 17:13:42.544: 44:6d:57:36:92:c1 DHCP sending REQUEST to 10.19.26.1 (len 366, port 13, vlan 1914)

*Jul 12 17:13:42.544: 44:6d:57:36:92:c1 DHCP selecting relay 2 - control block settings:

dhcpServer: 10.16.0.101, dhcpNetmask: 255.255.254.0,

dhcpGateway: 10.19.26.1, dhcpRelay: 10.19.26.3  VLAN: 1914

*Jul 12 17:13:42.544: 44:6d:57:36:92:c1 DHCP selected relay 2 - NONE

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP received op BOOTREPLY (2) (len 316, port 13, encap 0xec00)

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP sending REPLY to STA (len 426, port 13, vlan 1912)

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP transmitting DHCP ACK (5)

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   xid: 0xc443f1a (205799194), secs: 0, flags: 0

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   chaddr: 44:6d:57:36:92:c1

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   ciaddr: 0.0.0.0,  yiaddr: 10.19.26.212

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   siaddr: 0.0.0.0,  giaddr: 0.0.0.0

*Jul 12 17:13:42.545: 44:6d:57:36:92:c1 DHCP   server id: 1.1.1.1  rcvd server id: 10.16.0.101

*Jul 12 17:15:39.182: CCKM: Send CCKM cache entry

As authentication is used NPS RADIUS server; as encryption is used WPA2/AES with Auth Key Mgmt: 802.1X.

Perform the following steps to resolve this problem:

1) Updates the driver on the client PCs.

2) Tried to disable the Fast Reconnect in Windows 7.

3) Update WLC to 7.4.100 version.

4) Used  the follwoing commands to encrease the negotiation timer between the wireless clients and the WLC for the encryption method:

           (Cisco Controller) >config advanced eap eapol-key-timeout 5000

           (Cisco Controller) >config advanced eap eapol-key-retries 4

None of the above action does not solve the problem.

With what may be the problem exists? Any suggestion?

12 REPLIES
Hall of Fame Super Silver

Re: DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Post your show WLAN of the WLAN that is the issue.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***
New Member

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

show wlan 1

WLAN Identifier.................................. 1

Profile Name..................................... test

Network Name (SSID).............................. test

Status........................................... Enabled

MAC Filtering.................................... Disabled

Broadcast SSID................................... Enabled

AAA Policy Override.............................. Disabled

Network Admission Control

  Radius-NAC State............................... Disabled

  SNMP-NAC State................................. Disabled

  Quarantine VLAN................................ 0

Maximum number of Associated Clients............. 0

Number of Active Clients......................... 0

Exclusionlist Timeout............................ 60 seconds

Session Timeout.................................. 1800 seconds

CHD per WLAN..................................... Enabled

Webauth DHCP exclusion........................... Disabled

Interface........................................ test

Multicast Interface.............................. Not Configured

--More-- or (q)uit

WLAN ACL......................................... unconfigured

DHCP Server...................................... Default

DHCP Address Assignment Required................. Enabled

Static IP client tunneling....................... Disabled

Quality of Service............................... Silver (best effort)

Scan Defer Priority.............................. 4,5,6

Scan Defer Time.................................. 100 milliseconds

WMM.............................................. Allowed

WMM UAPSD Compliant Client Support............... Disabled

Media Stream Multicast-direct.................... Disabled

CCX - AironetIe Support.......................... Enabled

CCX - Gratuitous ProbeResponse (GPR)............. Disabled

CCX - Diagnostics Channel Capability............. Disabled

Dot11-Phone Mode (7920).......................... Disabled

Wired Protocol................................... None

IPv6 Support..................................... Disabled

Passive Client Feature........................... Disabled

Peer-to-Peer Blocking Action..................... Disabled

Radio Policy..................................... All

DTIM period for 802.11a radio.................... 1

DTIM period for 802.11b radio.................... 1

Radius Servers

   Authentication................................ 10.16.0.138 1812

--More-- or (q)uit

   Authentication................................ 10.16.0.139 1812

   Accounting.................................... 10.16.0.138 1813

   Accounting.................................... 10.16.0.139 1813

   Dynamic Interface............................. Disabled

Local EAP Authentication......................... Disabled

Security

   802.11 Authentication:........................ Open System

   Static WEP Keys............................... Disabled

   802.1X........................................ Disabled

   Wi-Fi Protected Access (WPA/WPA2)............. Enabled

      WPA (SSN IE)............................... Disabled

      WPA2 (RSN IE).............................. Enabled

         TKIP Cipher............................. Disabled

         AES Cipher.............................. Enabled

                                                               Auth Key Management

         802.1x.................................. Enabled

         PSK..................................... Disabled

         CCKM.................................... Disabled

         FT(802.11r)............................. Disabled

         FT-PSK(802.11r)......................... Disabled

FT Reassociation Timeout......................... 20

FT Over-The-Air mode............................. Enabled

--More-- or (q)uit

FT Over-The-Ds mode.............................. Enabled

CCKM tsf Tolerance............................... 1000

   CKIP ......................................... Disabled

   Web Based Authentication...................... Disabled

   Web-Passthrough............................... Disabled

   Conditional Web Redirect...................... Disabled

   Splash-Page Web Redirect...................... Disabled

   Auto Anchor................................... Disabled

   H-REAP Local Switching........................ Disabled

   H-REAP Local Authentication................... Disabled

   H-REAP Learn IP Address....................... Enabled

   Client MFP.................................... Optional

   Tkip MIC Countermeasure Hold-down Timer....... 60

Call Snooping.................................... Disabled

Roamed Call Re-Anchor Policy..................... Disabled

SIP CAC Fail Send-486-Busy Policy................ Enabled

SIP CAC Fail Send Dis-Association Policy......... Disabled

Band Select...................................... Disabled

Load Balancing................................... Disabled

Mobility Anchor List

WLAN ID     IP Address            Status

-------     ---------------       ------

Hall of Fame Super Silver

Re: DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Well if that test SSID is what's giving you issues, then that looks fine. If you want to play with timers which you don't if the radius is local to the WLC, then look at this link.

https://supportforums.cisco.com/docs/DOC-12110

I would not change any of the client cards default. Fast SSID change allows you to change to a different SSID without having to wait like a minute before you are allowed.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***
New Member

Re: DOT1X-3-MAX_EAPOL_KEY_RETRANS???

As authentication is used NPS RADIUS server. I read all the articles on this topic. But the right answer on this topic I have not found it. All the same it is necessary to open TAC.

Hall of Fame Super Silver

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Well.... when you upgraded to v7.4, you also upgraded the FUS image correct?  I have no issue with 5508's and various code version with NPS.  What do you see on your radius..... Have you tried a preshared key to make sure that your clients work fine?  Typically you would test with an open wuth then a preshared key then 802.1x.  Try to eliminate what can be an issue.... might not be the WLC and might just be the radius.

Thanks,

Scott

Help out other by using the rating system and marking answered questions as "Answered"

-Scott
*** Please rate helpful posts ***
New Member

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

In our scheme to achieve the Radius server uses service port. Can be used in such a scheme connections?

Hall of Fame Super Silver

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Service port is for out of band management... radius by default wil go throught the management interface.

Thanks,

Scott

Help out other by using the rating system and marking answered questions as "Answered"

-Scott
*** Please rate helpful posts ***
New Member

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

Generally, it can cause the above problem?

Hall of Fame Super Silver

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

The problem is that its not supported.  You shouldn't have your service port connected to the network.

Thanks,

Scott

Help out other by using the rating system and marking answered questions as "Answered"

-Scott
*** Please rate helpful posts ***

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

It shouldn't casue this problem, as you are getting communication to and from the AAA server.  But like Scott said, that is not a supported method of connectivity.

What you are seeing is the client not ack-ing the M3 key, which points to either the cleint ignoring the key because it doesn't think it needs to rekey, or the AP is not hearing the reply.

you may need to get a capture in the air to see if the packets are being sent both directions and who is not hearing/replying

HTH,
Steve

------------------------------------------------------------------------------------------------
Please remember to rate useful posts, and mark questions as answered

HTH, Steve ------------------------------------------------------------------------------------------------ Please remember to rate useful posts, and mark questions as answered
New Member

DOT1X-3-MAX_EAPOL_KEY_RETRANS???

What steps can you suggest to solve this problem? Can anyone experienced this?

Hall of Fame Super Silver

Re: DOT1X-3-MAX_EAPOL_KEY_RETRANS???

First off, don't connect the service port to the network. Then add the management IP of the WLC as a AAA radius client on the radius server. Then test.

Sent from Cisco Technical Support iPhone App

-Scott
*** Please rate helpful posts ***
833
Views
0
Helpful
12
Replies