cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
1797
Views
11
Helpful
7
Replies

WCS - Some clients never obtain an IP address

I have a multi-floor building with each floor devided into it's own AP group, with it's own respective interface and VLAN.  Everything works fine ... except for the first floor.  We have wireless carts that have two wireless cards on them.  One is built into the PC attached to the cart, and the other is part of the cart itself for management purposes.

We cannot seem to get the cart monitoring onto the network (while the Windows PC's wireless works just fine).  I have gone over the settings for the AP groups, interfaces, controllers, AP's, etc over and over again and I cannot seem to find anything wrong with the setup.  It seems to authenticate to the AP, get connected, and then never obtain an IP address.  I cannot seem to find any problem with the DHCP server or it's scope.  There are plenty of addresses left to hand out.

Here is a 'debug client' dump from the WCS controller.  Does anyone have any ideas of what I might check?

Thanks in advance for any advice offered!

*Aug 27 11:38:07.801: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:07.803: 00:06:66:13:16:17 Received EAPOL-key in PTK_START state (message 2) from mobile 00:06:66:13:16:17

*Aug 27 11:38:07.803: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:07.803: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Aug 27 11:38:07.806: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:07.806: 00:06:66:13:16:17 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:06:66:13:16:17

*Aug 27 11:38:07.806: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state DHCP_REQD (7)

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) pemAdvanceState2 4375, Adding TMP rule

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Adding Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Ju

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Aug 27 11:38:07.807: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4391, Adding TMP rule

*Aug 27 11:38:07.810: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Jumb

*Aug 27 11:38:07.810: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:07.810: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:07.810: 00:06:66:13:16:17 Key exchange done, data packets from mobile 00:06:66:13:16:17 should be forwarded shortly

*Aug 27 11:38:07.810: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

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

*Aug 27 11:38:07.810: 00:06:66:13:16:17 Sent EAPOL-Key M5 for mobile 00:06:66:13:16:17

*Aug 27 11:38:07.815: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:07.817: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:08.731: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:08.734: 00:06:66:13:16:17 Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:09.686: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:09.687: 00:06:66:13:16:17 Retransmit 2 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.641: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:10.642: 00:06:66:13:16:17 Retransmit failure for EAPOL-Key M5 to mobile 00:06:66:13:16:17, retransmit count 3, mscb deauth count 0

*Aug 27 11:38:10.642: 00:06:66:13:16:17 Sent Deauthenticate to mobile on BSSID 00:1b:2b:36:41:90 slot 0(caller 1x_ptsm.c:467)

*Aug 27 11:38:10.642: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 57) in 10 seconds

*Aug 27 11:38:10.653: 00:06:66:13:16:17 Association received from mobile on AP 00:1b:2b:36:41:90

*Aug 27 11:38:10.653: 00:06:66:13:16:17 Applying site-specific override for station 00:06:66:13:16:17 - vapId 2, site '1st-FL', interface '1st-fl-interface'

*Aug 27 11:38:10.653: 00:06:66:13:16:17 STA - rates (4): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:10.653: 00:06:66:13:16:17 STA - rates (9): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:10.653: 00:06:66:13:16:17 Processing WPA IE type 221, length 22 for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.653: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Change state to START (0) last state DHCP_REQD (7)

*Aug 27 11:38:10.653: 00:06:66:13:16:17 0.0.0.0 START (0) Initializing policy

*Aug 27 11:38:10.653: 00:06:66:13:16:17 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state DHCP_REQD (7)

*Aug 27 11:38:10.653: 00:06:66:13:16:17 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state DHCP_REQD (7)

*Aug 27 11:38:10.653: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:10.653: 00:06:66:13:16:17 apfPemAddUser2 (apf_policy.c:208) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:10.653: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 49) in 1800 seconds

*Aug 27 11:38:10.653: 00:06:66:13:16:17 Sending Assoc Response to station on BSSID 00:1b:2b:36:41:90 (status 0)

*Aug 27 11:38:10.653: 00:06:66:13:16:17 apfProcessAssocReq (apf_80211.c:4310) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:10.659: 00:06:66:13:16:17 Creating a PKC PMKID Cache entry for station 00:06:66:13:16:17 (RSN 0)

*Aug 27 11:38:10.659: 00:06:66:13:16:17 0.0.0.0 Removed NPU entry.

*Aug 27 11:38:10.659: 00:06:66:13:16:17 Initiating WPA PSK to mobile 00:06:66:13:16:17

*Aug 27 11:38:10.661: 00:06:66:13:16:17 dot1x - moving mobile 00:06:66:13:16:17 into Force Auth state

*Aug 27 11:38:10.661: 00:06:66:13:16:17 Skipping EAP-Success to mobile 00:06:66:13:16:17

*Aug 27 11:38:10.661: 00:06:66:13:16:17 Starting key exchange to mobile 00:06:66:13:16:17, data packets will be dropped

*Aug 27 11:38:10.661: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Aug 27 11:38:10.665: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:10.667: 00:06:66:13:16:17 Received EAPOL-key in PTK_START state (message 2) from mobile 00:06:66:13:16:17

*Aug 27 11:38:10.667: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.667: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Aug 27 11:38:10.670: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:10.670: 00:06:66:13:16:17 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:06:66:13:16:17

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state DHCP_REQD (7)

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) pemAdvanceState2 4375, Adding TMP rule

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Adding Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Ju

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Aug 27 11:38:10.671: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4391, Adding TMP rule

*Aug 27 11:38:10.674: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Jumb

*Aug 27 11:38:10.674: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:10.674: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.674: 00:06:66:13:16:17 Key exchange done, data packets from mobile 00:06:66:13:16:17 should be forwarded shortly

*Aug 27 11:38:10.674: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

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

*Aug 27 11:38:10.674: 00:06:66:13:16:17 Sent EAPOL-Key M5 for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.679: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:10.681: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:11.596: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:11.597: 00:06:66:13:16:17 Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:12.551: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:12.551: 00:06:66:13:16:17 Retransmit 2 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:13.506: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:13.507: 00:06:66:13:16:17 Retransmit failure for EAPOL-Key M5 to mobile 00:06:66:13:16:17, retransmit count 3, mscb deauth count 0

*Aug 27 11:38:13.507: 00:06:66:13:16:17 Sent Deauthenticate to mobile on BSSID 00:1b:2b:36:41:90 slot 0(caller 1x_ptsm.c:467)

*Aug 27 11:38:13.507: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 57) in 10 seconds

*Aug 27 11:38:13.518: 00:06:66:13:16:17 Association received from mobile on AP 00:1b:2b:36:41:90

*Aug 27 11:38:13.518: 00:06:66:13:16:17 Applying site-specific override for station 00:06:66:13:16:17 - vapId 2, site '1st-FL', interface '1st-fl-interface'

*Aug 27 11:38:13.518: 00:06:66:13:16:17 STA - rates (4): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:13.518: 00:06:66:13:16:17 STA - rates (9): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:13.518: 00:06:66:13:16:17 Processing WPA IE type 221, length 22 for mobile 00:06:66:13:16:17

*Aug 27 11:38:13.518: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Change state to START (0) last state DHCP_REQD (7)

*Aug 27 11:38:13.518: 00:06:66:13:16:17 0.0.0.0 START (0) Initializing policy

*Aug 27 11:38:13.518: 00:06:66:13:16:17 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state DHCP_REQD (7)

*Aug 27 11:38:13.518: 00:06:66:13:16:17 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state DHCP_REQD (7)

*Aug 27 11:38:13.518: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:13.518: 00:06:66:13:16:17 apfPemAddUser2 (apf_policy.c:208) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:13.518: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 49) in 1800 seconds

*Aug 27 11:38:13.519: 00:06:66:13:16:17 Sending Assoc Response to station on BSSID 00:1b:2b:36:41:90 (status 0)

*Aug 27 11:38:13.519: 00:06:66:13:16:17 apfProcessAssocReq (apf_80211.c:4310) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:13.526: 00:06:66:13:16:17 0.0.0.0 Removed NPU entry.

*Aug 27 11:38:13.526: 00:06:66:13:16:17 Creating a PKC PMKID Cache entry for station 00:06:66:13:16:17 (RSN 0)

*Aug 27 11:38:13.527: 00:06:66:13:16:17 Initiating WPA PSK to mobile 00:06:66:13:16:17

*Aug 27 11:38:13.527: 00:06:66:13:16:17 dot1x - moving mobile 00:06:66:13:16:17 into Force Auth state

*Aug 27 11:38:13.527: 00:06:66:13:16:17 Skipping EAP-Success to mobile 00:06:66:13:16:17

*Aug 27 11:38:13.527: 00:06:66:13:16:17 Starting key exchange to mobile 00:06:66:13:16:17, data packets will be dropped

*Aug 27 11:38:13.527: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Aug 27 11:38:13.532: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:13.534: 00:06:66:13:16:17 Received EAPOL-key in PTK_START state (message 2) from mobile 00:06:66:13:16:17

*Aug 27 11:38:13.534: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:13.535: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Aug 27 11:38:13.538: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:13.538: 00:06:66:13:16:17 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:06:66:13:16:17

*Aug 27 11:38:13.538: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state DHCP_REQD (7)

*Aug 27 11:38:13.538: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:13.539: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) pemAdvanceState2 4375, Adding TMP rule

*Aug 27 11:38:13.539: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Adding Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Ju

*Aug 27 11:38:13.539: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:13.539: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Aug 27 11:38:13.539: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4391, Adding TMP rule

*Aug 27 11:38:13.541: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Jumb

*Aug 27 11:38:13.541: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:13.541: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:13.542: 00:06:66:13:16:17 Key exchange done, data packets from mobile 00:06:66:13:16:17 should be forwarded shortly

*Aug 27 11:38:13.542: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

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

*Aug 27 11:38:13.542: 00:06:66:13:16:17 Sent EAPOL-Key M5 for mobile 00:06:66:13:16:17

*Aug 27 11:38:13.547: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:13.549: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:14.461: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:14.461: 00:06:66:13:16:17 Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:15.416: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:15.417: 00:06:66:13:16:17 Retransmit 2 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:16.371: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:16.372: 00:06:66:13:16:17 Retransmit failure for EAPOL-Key M5 to mobile 00:06:66:13:16:17, retransmit count 3, mscb deauth count 0

*Aug 27 11:38:16.372: 00:06:66:13:16:17 Sent Deauthenticate to mobile on BSSID 00:1b:2b:36:41:90 slot 0(caller 1x_ptsm.c:467)

*Aug 27 11:38:16.372: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 57) in 10 seconds

*Aug 27 11:38:16.385: 00:06:66:13:16:17 Association received from mobile on AP 00:1b:2b:36:41:90

*Aug 27 11:38:16.385: 00:06:66:13:16:17 Applying site-specific override for station 00:06:66:13:16:17 - vapId 2, site '1st-FL', interface '1st-fl-interface'

*Aug 27 11:38:16.385: 00:06:66:13:16:17 STA - rates (4): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:16.385: 00:06:66:13:16:17 STA - rates (9): 2 4 11 22 12 18 24 36 48 0 0 0 0 0 0 0

*Aug 27 11:38:16.385: 00:06:66:13:16:17 Processing WPA IE type 221, length 22 for mobile 00:06:66:13:16:17

*Aug 27 11:38:16.385: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Change state to START (0) last state DHCP_REQD (7)

*Aug 27 11:38:16.385: 00:06:66:13:16:17 0.0.0.0 START (0) Initializing policy

*Aug 27 11:38:16.385: 00:06:66:13:16:17 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state DHCP_REQD (7)

*Aug 27 11:38:16.385: 00:06:66:13:16:17 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state DHCP_REQD (7)

*Aug 27 11:38:16.385: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:16.385: 00:06:66:13:16:17 apfPemAddUser2 (apf_policy.c:208) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:16.385: 00:06:66:13:16:17 Scheduling deletion of Mobile Station:  (callerId: 49) in 1800 seconds

*Aug 27 11:38:16.385: 00:06:66:13:16:17 Sending Assoc Response to station on BSSID 00:1b:2b:36:41:90 (status 0)

*Aug 27 11:38:16.385: 00:06:66:13:16:17 apfProcessAssocReq (apf_80211.c:4310) Changing state for mobile 00:06:66:13:16:17 on AP 00:1b:2b:36:41:90 from Associated to Associated

*Aug 27 11:38:16.391: 00:06:66:13:16:17 Creating a PKC PMKID Cache entry for station 00:06:66:13:16:17 (RSN 0)

*Aug 27 11:38:16.391: 00:06:66:13:16:17 0.0.0.0 Removed NPU entry.

*Aug 27 11:38:16.391: 00:06:66:13:16:17 Initiating WPA PSK to mobile 00:06:66:13:16:17

*Aug 27 11:38:16.393: 00:06:66:13:16:17 dot1x - moving mobile 00:06:66:13:16:17 into Force Auth state

*Aug 27 11:38:16.393: 00:06:66:13:16:17 Skipping EAP-Success to mobile 00:06:66:13:16:17

*Aug 27 11:38:16.393: 00:06:66:13:16:17 Starting key exchange to mobile 00:06:66:13:16:17, data packets will be dropped

*Aug 27 11:38:16.393: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

*Aug 27 11:38:16.397: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:16.399: 00:06:66:13:16:17 Received EAPOL-key in PTK_START state (message 2) from mobile 00:06:66:13:16:17

*Aug 27 11:38:16.399: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:16.400: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

                                                                                                state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

*Aug 27 11:38:16.402: 00:06:66:13:16:17 Received EAPOL-Key from mobile 00:06:66:13:16:17

*Aug 27 11:38:16.403: 00:06:66:13:16:17 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:06:66:13:16:17

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state DHCP_REQD (7)

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:1b:2b:36:41:90 vapId 2 apVapId 1

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) pemAdvanceState2 4375, Adding TMP rule

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Adding Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Ju

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)

*Aug 27 11:38:16.403: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4391, Adding TMP rule

*Aug 27 11:38:16.404: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule

  type = Airespace AP - Learn IP address

  on AP 00:1b:2b:36:41:90, slot 0, interface = 29, QOS = 0

  ACL Id = 255, Jumb

*Aug 27 11:38:16.404: 00:06:66:13:16:17 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)

*Aug 27 11:38:16.406: 00:06:66:13:16:17 Stopping retransmission timer for mobile 00:06:66:13:16:17

*Aug 27 11:38:16.406: 00:06:66:13:16:17 Key exchange done, data packets from mobile 00:06:66:13:16:17 should be forwarded shortly

*Aug 27 11:38:16.406: 00:06:66:13:16:17 Sending EAPOL-Key Message to mobile 00:06:66:13:16:17

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

*Aug 27 11:38:16.406: 00:06:66:13:16:17 Sent EAPOL-Key M5 for mobile 00:06:66:13:16:17

*Aug 27 11:38:16.410: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:16.413: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:17.326: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:17.326: 00:06:66:13:16:17 Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

7 Replies 7

Stephen Rodriguez
Cisco Employee
Cisco Employee

Does the NIC have a static IP?  It doesn't look like the device ever sends a DHCP request.

When you have the issue, can you do a route print on the client?  It could be that the cart's OS doesn't like having two WNIC trying to get on the network.

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

Hello Steve,

This client (and the others like it) are using DHCP.  Although we have also tried configuring a static IP on it to try and rule out a DHCP problem.  When it had a static IP, it would show up as "authenticated" in WCS - but with an IP address of "0.0.0.0".  We of course could not ping the static IP that it held.  Odd!!

I have done some Wireshark captures too, and I can see the occassional DHCP activity going in both directions.  These monitors only wait 2 seconds or so for a DHCP address, and then they don't seem to retry until you reboot them.

We have also had issues with laptops and tablets not being able to obtain an IP address (sporadically).  They will authenticate immediately ... btu then hang forever obtaining an IP address.  Usually after 5 to 10 minutes of retrying, they will mysteriously obtain an IP address and be good.

Again, this only occurs on this floor.  We can take these same devices to another floor - and they work fine.  :-)  It's maddening!!

** EDIT: Also I should note that the two wireless devices on these carts operate independently.  The non-PC card is used to track the location of the cart in the building, and the status of the battery that is connected **

For testing, use the wlc as a dhcp and see if the devices get an ip address or not.

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

Amjad Abdullah
VIP Alumni
VIP Alumni

Are you using different AP models for your first floor? Are all floor APs join same WLC?
What model and software version used with your WLC/WLCs?

in the debug client it shows:

*Aug 27 11:38:07.810: 00:06:66:13:16:17 Sent EAPOL-Key M5 for mobile 00:06:66:13:16:17

*Aug 27 11:38:07.815: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:07.817: 00:06:66:13:16:17 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0

*Aug 27 11:38:08.731: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:08.734: 00:06:66:13:16:17 Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:09.686: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:09.687: 00:06:66:13:16:17 Retransmit 2 of EAPOL-Key M5 (length 131) for mobile 00:06:66:13:16:17

*Aug 27 11:38:10.641: 00:06:66:13:16:17 802.1x 'timeoutEvt' Timer expired for station 00:06:66:13:16:17

*Aug 27 11:38:10.642: 00:06:66:13:16:17 Retransmit failure for EAPOL-Key M5 to mobile 00:06:66:13:16:17, retransmit count 3, mscb deauth count 0

It is obvious that the AP is trying to send KEAPOL-key Message 5 to the client but it does not reply. It tries three times then the timer expries and the AP deauthenticates the client.

In first glance, this is a client issue. I've seen this misbehavior with many such clients like yours when people tried to move from old non 802.11n APs to new 802.11n APs (mainly 1252 and 1142). The clients do not connect to new APs. It was always client issue and people had to upgrade the devices firmware or wireless driver on the client.

One unlucky customer had his clients (wireless guns) out of support so he had to replace them all to get them to work with the new APs. I hope your device is not out of support yet.

HTH

Amjad

You want to say "Thank you"?
Don't. Just rate the useful answers,
that is more useful than "Thank you".

Rating useful replies is more useful than saying "Thank you"

Hello Amjad,

You may be onto something there.  We have mostly AIR-LAP1242AG-A-K9 AP's and a few AIR-LAP1142N-A-K9's.  The problems seem to be centered around the AIR-LAP1142N-A-K9 models.

These carts seem to work if we take them 'away' to another floor consisting only of the older AIR-LAP1242AG-A-K9 AP's.  I talked with one of our guys here and he said that there is newer firmware for the carts, but it couldn't be deployed because they were not on the network!  I am going to suggest moving them to another area in the building, get them connected, and then upgrade the firmware of the cart to see if that helps.

Should I be looking at upgrading the firmware of the AP's?  From what I understand, that would mean updating the WCS and the controllers, correct?  It may be time to do that.  We are still on 6.0.

Hello,

Good that we narrowed down the problem.

You don't have to upgrade the WLC. only on the wireless clients.

Let us cross our fingers that upgrading the firmware will resolve the issue because, as per my experience with such issues, the only solution was to let the client fit well with the AP by upgrading its driver with a driver that understands the new AP model's dictionary.

keep us updated if new firmware mitigates the issue.

Cheers,

Amjad

You want to say "Thank you"?
Don't. Just rate the useful answers,
that is more useful than "Thank you".

Rating useful replies is more useful than saying "Thank you"

SOLUTION

I was finally able to fix these issues.  I'm not sure what I did that ended up correcting it, so here is what I did.

1) Rebooted each controller.  I noticed on TWO of the controllers that after rebooting them, they showed an incorrect IP address for the interfaces.  Initially when I created the Interfaces I gave them the same IP address across the board (a mistake).  When rebooting the controllers, the old IP address came back like a ghost in a few places.  Odd?  I set it right, and rebooted them again.  This time it "stuck".

2) Updated WCS to the latest version in my branch (6).  Also installed all Windows 2003 Server updates.  Rebooted several times in the process.  Then updated to the latest version available in the v7 branch.  Rebooted again.

3) Updated the software on each controller, one at a time.  Then waited for all access points to update themselves (about 10 at a time). 

That took the better part of a day ... but the problem seems to have gone away!

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: