11 Replies Latest reply: Nov 6, 2014 4:20 PM by dimage1
BillLoss Level 1 Level 1 (0 points)

We are using iPhones and iPads in our workplace that consists of Cisco 3502 Access Points LWAPP connected to Cisco 5508 WLC.  The iPhones (and iPads) running iOS v5.0.1 connect fine, but when it comes time for key rotation between the AP controller and the device the iPhone is not responding and then deauthenticated, dropped.     In order to use the wireless connection again, the user must re-authenticate many times during the day.    I have an open ticket open with Cisco TAC,   support requested I check with Apple.

 

Anyone else seeing the same problem,  have a solution?

 

<pre>

debug client 8C:58:77:35:AE:03

(Cisco Controller) >*pemReceiveTask: Feb 20 08:53:39.709: 8c:58:77:35:ae:03 10.3
.10.8 RUN (20) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (ca
ller apf_policy.c:1626)
*pemReceiveTask: Feb 20 08:53:39.709: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Repla
cing Fast Path rule
  type = Airespace AP Client
  on AP 64:a0:e7:dc:60:10, slot 0, interface = 13, QOS = 0
  ACL Id = 255, Jumbo Frames = NO
*pemReceiveTask: Feb 20 08:53:39.709: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Fast
Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006  IPv6 Vlan = 10, IPv6
intf id = 11
*pemReceiveTask: Feb 20 08:53:39.709: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Succe
ssfully plumbed mobile rule (ACL ID 255)
*pemReceiveTask: Feb 20 08:53:39.709: 8c:58:77:35:ae:03 10.3.10.8 Added NPU entr
y of type 1, dtlFlags 0x0
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 Reassociation received
from mobile on AP 24:b6:57:f8:c7:80
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Chan
ging ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1
626)
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 Applying site-specific
IPv6 override for station 8c:58:77:35:ae:03 - vapId 1, site 'default-group', int
erface 'nysenatenet'
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 Applying IPv6 Interface
Policy for station 8c:58:77:35:ae:03 - vlan 10, interface id 11, interface 'nys
enatenet'
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 STA - rates (8): 130 13
2 139 150 36 48 72 108 12 18 24 96 0 0 0 0
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 STA - rates (12): 130 1
32 139 150 36 48 72 108 12 18 24 96 0 0 0 0
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 Processing RSN IE type
48, length 20 for mobile 8c:58:77:35:ae:03
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Dele
ted mobile LWAPP rule on AP [64:a0:e7:dc:60:10]
*pemReceiveTask: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 10.3.10.8 Removed NPU en
try.
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 Updated location for st
ation old AP 64:a0:e7:dc:60:10-0, new AP 24:b6:57:f8:c7:80-0
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 apfMsRunStateDec
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 apfMs1xStateDec
*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Chan
ge state to START (0) last state RUN (20)

*apfMsConnTask_2: Feb 20 08:54:34.302: 8c:58:77:35:ae:03 10.3.10.8 START (0) Ini
tializing policy
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 10.3.10.8 START (0) Cha
nge state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 10.3.10.8 AUTHCHECK (2)
Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD (3
) DHCP required on AP 24:b6:57:f8:c7:80 vapId 1 apVapId 1for this client
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 Not Using WMM Complianc
e code qosCap 00
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD (3
) Plumbed mobile LWAPP rule on AP 24:b6:57:f8:c7:80 vapId 1 apVapId 1
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 apfPemAddUser2 (apf_pol
icy.c:223) Changing state for mobile 8c:58:77:35:ae:03 on AP 24:b6:57:f8:c7:80 f
rom Associated to Associated

*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 Scheduling deletion of
Mobile Station:  (callerId: 49) in 43200 seconds
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 Sending Assoc Response
to station on BSSID 24:b6:57:f8:c7:80 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_2: Feb 20 08:54:34.303: 8c:58:77:35:ae:03 apfProcessAssocReq (apf
_80211.c:5237) Changing state for mobile 8c:58:77:35:ae:03 on AP 24:b6:57:f8:c7:
80 from Associated to Associated

*dot1xMsgTask: Feb 20 08:54:34.305: 8c:58:77:35:ae:03 Creating a PKC PMKID Cache
entry for station 8c:58:77:35:ae:03 (RSN 2)
*dot1xMsgTask: Feb 20 08:54:34.305: 8c:58:77:35:ae:03 Adding BSSID 24:b6:57:f8:c
7:80 to PMKID cache for station 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:34.305: New PMKID: (16)

*dot1xMsgTask: Feb 20 08:54:34.305:      [0000] fa fe bc ca 02 b7 e3 20 ee 73 f6
d3 53 3b ea 17

*dot1xMsgTask: Feb 20 08:54:34.305: 8c:58:77:35:ae:03 Initiating RSN PSK to mobi
le 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:34.306: 8c:58:77:35:ae:03 dot1x - moving mobile 8c:5
8:77:35:ae:03 into Force Auth state
*dot1xMsgTask: Feb 20 08:54:34.306: 8c:58:77:35:ae:03 Skipping EAP-Success to mo
bile 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:34.306: Including PMKID in M1  (16)

*dot1xMsgTask: Feb 20 08:54:34.306:      [0000] fa fe bc ca 02 b7 e3 20 ee 73 f6
d3 53 3b ea 17

*dot1xMsgTask: Feb 20 08:54:34.306: 8c:58:77:35:ae:03 Starting key exchange to m
obile 8c:58:77:35:ae:03, data packets will be dropped
*dot1xMsgTask: Feb 20 08:54:34.306: 8c:58:77:35:ae:03 Sending EAPOL-Key Message
to mobile 8c:58:77:35:ae:03
                              state INITPMK (message 1), replay counter 00.00.00
.00.00.00.00.00
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.312: 8c:58:77:35:ae:03 Received EAPOL-Key f
rom mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.313: 8c:58:77:35:ae:03 Received EAPOL-key i
n PTK_START state (message 2) from mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.313: 8c:58:77:35:ae:03 Stopping retransmiss
ion timer for mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.313: 8c:58:77:35:ae:03 Sending EAPOL-Key Me
ssage to mobile 8c:58:77:35:ae:03
                                    state PTKINITNEGOTIATING (message 3), replay
counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.318: 8c:58:77:35:ae:03 Received EAPOL-Key f
rom mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.318: 8c:58:77:35:ae:03 Received EAPOL-key i
n PTKINITNEGOTIATING state (message 4) from mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.318: 8c:58:77:35:ae:03 apfMs1xStateInc
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.318: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD
(3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.319: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) DHCP required on AP 24:b6:57:f8:c7:80 vapId 1 apVapId 1for this client
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.319: 8c:58:77:35:ae:03 Not Using WMM Compli
ance code qosCap 00
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.319: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) Plumbed mobile LWAPP rule on AP 24:b6:57:f8:c7:80 vapId 1 apVapId 1
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.319: 8c:58:77:35:ae:03 apfMsRunStateInc
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.319: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) R
eached PLUMBFASTPATH: from line 4918
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) A
dding Fast Path rule
  type = Airespace AP Client
  on AP 24:b6:57:f8:c7:80, slot 0, interface = 13, QOS = 0
  ACL Id = 255, Jumbo Frames = NO
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) F
ast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006  IPv6 Vlan = 10, I
Pv6 intf id = 11
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) S
uccessfully plumbed mobile rule (ACL ID 255)
*Dot1x_NW_MsgTask_3: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 Stopping retransmiss
ion timer for mobile 8c:58:77:35:ae:03
*pemReceiveTask: Feb 20 08:54:34.320: 8c:58:77:35:ae:03 10.3.10.8 Added NPU entr
y of type 1, dtlFlags 0x0
*apfMsConnTask_7: Feb 20 08:54:48.531: 8c:58:77:35:ae:03 Reassociation received
from mobile on AP 64:a0:e7:dc:60:10
*apfMsConnTask_7: Feb 20 08:54:48.531: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Chan
ging ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1
626)
*apfMsConnTask_7: Feb 20 08:54:48.531: 8c:58:77:35:ae:03 Applying site-specific
IPv6 override for station 8c:58:77:35:ae:03 - vapId 1, site 'default-group', int
erface 'nysenatenet'
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Applying IPv6 Interface
Policy for station 8c:58:77:35:ae:03 - vlan 10, interface id 11, interface 'nys
enatenet'
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 STA - rates (8): 130 13
2 139 150 36 48 72 108 12 18 24 96 0 0 0 0
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 STA - rates (12): 130 1
32 139 150 36 48 72 108 12 18 24 96 0 0 0 0
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Processing RSN IE type
48, length 20 for mobile 8c:58:77:35:ae:03
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Dele
ted mobile LWAPP rule on AP [24:b6:57:f8:c7:80]
*pemReceiveTask: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 Removed NPU en
try.
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Updated location for st
ation old AP 24:b6:57:f8:c7:80-0, new AP 64:a0:e7:dc:60:10-0
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 apfMsRunStateDec
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 apfMs1xStateDec
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Chan
ge state to START (0) last state RUN (20)

*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 START (0) Ini
tializing policy
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 START (0) Cha
nge state to AUTHCHECK (2) last state RUN (20)

*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 AUTHCHECK (2)
Change state to 8021X_REQD (3) last state RUN (20)

*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD (3
) DHCP required on AP 64:a0:e7:dc:60:10 vapId 1 apVapId 1for this client
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Not Using WMM Complianc
e code qosCap 00
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD (3
) Plumbed mobile LWAPP rule on AP 64:a0:e7:dc:60:10 vapId 1 apVapId 1
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 apfPemAddUser2 (apf_pol
icy.c:223) Changing state for mobile 8c:58:77:35:ae:03 on AP 64:a0:e7:dc:60:10 f
rom Associated to Associated

*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Scheduling deletion of
Mobile Station:  (callerId: 49) in 43200 seconds
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 Sending Assoc Response
to station on BSSID 64:a0:e7:dc:60:10 (status 0) ApVapId 1 Slot 0
*apfMsConnTask_7: Feb 20 08:54:48.532: 8c:58:77:35:ae:03 apfProcessAssocReq (apf
_80211.c:5237) Changing state for mobile 8c:58:77:35:ae:03 on AP 64:a0:e7:dc:60:
10 from Associated to Associated

*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Creating a PKC PMKID Cache
entry for station 8c:58:77:35:ae:03 (RSN 2)
*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Adding BSSID 64:a0:e7:dc:6
0:10 to PMKID cache for station 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:48.535: New PMKID: (16)

*dot1xMsgTask: Feb 20 08:54:48.535:      [0000] 8e b3 87 c9 e6 cf 22 5c d6 86 91
fe b6 a5 fb fc

*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Initiating RSN PSK to mobi
le 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 dot1x - moving mobile 8c:5
8:77:35:ae:03 into Force Auth state
*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Skipping EAP-Success to mo
bile 8c:58:77:35:ae:03
*dot1xMsgTask: Feb 20 08:54:48.535: Including PMKID in M1  (16)

*dot1xMsgTask: Feb 20 08:54:48.535:      [0000] 8e b3 87 c9 e6 cf 22 5c d6 86 91
fe b6 a5 fb fc

*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Starting key exchange to m
obile 8c:58:77:35:ae:03, data packets will be dropped
*dot1xMsgTask: Feb 20 08:54:48.535: 8c:58:77:35:ae:03 Sending EAPOL-Key Message
to mobile 8c:58:77:35:ae:03
                              state INITPMK (message 1), replay counter 00.00.00
.00.00.00.00.00
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.542: 8c:58:77:35:ae:03 Received EAPOL-Key f
rom mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.542: 8c:58:77:35:ae:03 Received EAPOL-key i
n PTK_START state (message 2) from mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.542: 8c:58:77:35:ae:03 Stopping retransmiss
ion timer for mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.542: 8c:58:77:35:ae:03 Sending EAPOL-Key Me
ssage to mobile 8c:58:77:35:ae:03
                                    state PTKINITNEGOTIATING (message 3), replay
counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 Received EAPOL-Key f
rom mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 Received EAPOL-key i
n PTKINITNEGOTIATING state (message 4) from mobile 8c:58:77:35:ae:03
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 apfMs1xStateInc
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 10.3.10.8 8021X_REQD
(3) Change state to L2AUTHCOMPLETE (4) last state RUN (20)

*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) DHCP required on AP 64:a0:e7:dc:60:10 vapId 1 apVapId 1for this client
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 Not Using WMM Compli
ance code qosCap 00
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) Plumbed mobile LWAPP rule on AP 64:a0:e7:dc:60:10 vapId 1 apVapId 1
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 apfMsRunStateInc
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.549: 8c:58:77:35:ae:03 10.3.10.8 L2AUTHCOMP
LETE (4) Change state to RUN (20) last state RUN (20)

*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.550: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) R
eached PLUMBFASTPATH: from line 4918
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.551: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) A
dding Fast Path rule
  type = Airespace AP Client
  on AP 64:a0:e7:dc:60:10, slot 0, interface = 13, QOS = 0
  ACL Id = 255, Jumbo Frames = NO
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.551: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) F
ast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 7006  IPv6 Vlan = 10, I
Pv6 intf id = 11
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.551: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) S
uccessfully plumbed mobile rule (ACL ID 255)
*Dot1x_NW_MsgTask_3: Feb 20 08:54:48.551: 8c:58:77:35:ae:03 Stopping retransmiss
ion timer for mobile 8c:58:77:35:ae:03
*pemReceiveTask: Feb 20 08:54:48.551: 8c:58:77:35:ae:03 10.3.10.8 Added NPU entr
y of type 1, dtlFlags 0x0
*osapiBsnTimer: Feb 20 09:24:48.414: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 09:54:48.202: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 10:24:48.214: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 10:54:47.993: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 11:24:47.997: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 11:54:47.761: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 12:24:47.777: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 12:54:47.551: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 13:24:47.559: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 13:54:47.334: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*osapiBsnTimer: Feb 20 14:24:47.350: 8c:58:77:35:ae:03 802.1x 'reAuthWhen' Timer
expired for station 8c:58:77:35:ae:03 and for message = M4
*dot1xMsgTask: Feb 20 14:46:49.523: 8c:58:77:35:ae:03 Key exchange done, data pa
ckets from mobile 8c:58:77:35:ae:03 should be forwarded shortly
*dot1xMsgTask: Feb 20 14:46:49.523: 8c:58:77:35:ae:03 Sending EAPOL-Key Message
to mobile 8c:58:77:35:ae:03
                              state PTKINITDONE (message 5 - group), replay coun
ter 00.00.00.00.00.00.00.02
*dot1xMsgTask: Feb 20 14:46:49.523: 8c:58:77:35:ae:03 Updated broadcast key sent
to mobile 8C:58:77:35:AE:03
*osapiBsnTimer: Feb 20 14:46:50.722: 8c:58:77:35:ae:03 802.1x 'timeoutEvt' Timer
expired for station 8c:58:77:35:ae:03 and for message = M5
*dot1xMsgTask: Feb 20 14:46:50.723: 8c:58:77:35:ae:03 Retransmit 1 of EAPOL-Key
M5 (length 147) for mobile 8c:58:77:35:ae:03
*osapiBsnTimer: Feb 20 14:46:51.722: 8c:58:77:35:ae:03 802.1x 'timeoutEvt' Timer
expired for station 8c:58:77:35:ae:03 and for message = M5
*dot1xMsgTask: Feb 20 14:46:51.723: 8c:58:77:35:ae:03 Retransmit 2 of EAPOL-Key
M5 (length 147) for mobile 8c:58:77:35:ae:03
*osapiBsnTimer: Feb 20 14:46:52.722: 8c:58:77:35:ae:03 802.1x 'timeoutEvt' Timer
expired for station 8c:58:77:35:ae:03 and for message = M5
*dot1xMsgTask: Feb 20 14:46:52.723: 8c:58:77:35:ae:03 Retransmit failure for EAP
OL-Key M5 to mobile 8c:58:77:35:ae:03, retransmit count 3, mscb deauth count 0
*dot1xMsgTask: Feb 20 14:46:52.724: 8c:58:77:35:ae:03 Sent Deauthenticate to mob
ile on BSSID 64:a0:e7:dc:60:10 slot 0(caller 1x_ptsm.c:534)
*dot1xMsgTask: Feb 20 14:46:52.724: 8c:58:77:35:ae:03 Scheduling deletion of Mob
ile Station:  (callerId: 57) in 10 seconds
*osapiBsnTimer: Feb 20 14:47:02.722: 8c:58:77:35:ae:03 apfMsExpireCallback (apf_
ms.c:608) Expiring Mobile!
*apfReceiveTask: Feb 20 14:47:02.723: 8c:58:77:35:ae:03 apfMsExpireMobileStation
(apf_ms.c:5009) Changing state for mobile 8c:58:77:35:ae:03 on AP 64:a0:e7:dc:6
0:10 from Associated to Disassociated

*apfReceiveTask: Feb 20 14:47:02.723: 8c:58:77:35:ae:03 Scheduling deletion of M
obile Station:  (callerId: 45) in 10 seconds
*osapiBsnTimer: Feb 20 14:47:12.722: 8c:58:77:35:ae:03 apfMsExpireCallback (apf_
ms.c:608) Expiring Mobile!
*apfReceiveTask: Feb 20 14:47:12.724: 8c:58:77:35:ae:03 Sent Deauthenticate to m
obile on BSSID 64:a0:e7:dc:60:10 slot 0(caller apf_ms.c:5101)
*apfReceiveTask: Feb 20 14:47:12.724: 8c:58:77:35:ae:03 apfMsAssoStateDec
*apfReceiveTask: Feb 20 14:47:12.724: 8c:58:77:35:ae:03 apfMsExpireMobileStation
(apf_ms.c:5139) Changing state for mobile 8c:58:77:35:ae:03 on AP 64:a0:e7:dc:6
0:10 from Disassociated to Idle

*apfReceiveTask: Feb 20 14:47:12.724: 8c:58:77:35:ae:03 Scheduling deletion of M
obile Station:  (callerId: 47) in 10 seconds
*osapiBsnTimer: Feb 20 14:47:22.722: 8c:58:77:35:ae:03 apfMsExpireCallback (apf_
ms.c:608) Expiring Mobile!
*apfReceiveTask: Feb 20 14:47:22.724: 8c:58:77:35:ae:03 10.3.10.8 RUN (20) Delet
ed mobile LWAPP rule on AP [64:a0:e7:dc:60:10]
*apfReceiveTask: Feb 20 14:47:22.724: 8c:58:77:35:ae:03 apfMsRunStateDec
*apfReceiveTask: Feb 20 14:47:22.724: 8c:58:77:35:ae:03 apfMs1xStateDec
*apfReceiveTask: Feb 20 14:47:22.724: 8c:58:77:35:ae:03 Deleting mobile on AP 64
:a0:e7:dc:60:10(0)

</pre>


iPhone 4, iOS 5.0.1, seeing this also with iPad2
  • DrVenture Level 2 Level 2 (180 points)

    It looks like the iPhone is not resonding to the 1st key:

     

    *dot1xMsgTask: Feb 20 14:46:50.723: 8c:58:77:35:ae:03 Retransmit 1 of EAPOL-Key

    M5 (length 147) for mobile 8c:58:77:35:ae:03


    *dot1xMsgTask: Feb 20 14:46:51.723: 8c:58:77:35:ae:03 Retransmit 2 of EAPOL-Key

    M5 (length 147) for mobile 8c:58:77:35:ae:03

     

    *dot1xMsgTask: Feb 20 14:46:52.723: 8c:58:77:35:ae:03 Retransmit failure for EAP

     

    Then the WLC Deauth's it:

     

    *dot1xMsgTask: Feb 20 14:46:52.724: 8c:58:77:35:ae:03 Sent Deauthenticate to mob

    ile on BSSID 64:a0:e7:dc:60:10 slot 0(caller 1x_ptsm.c:534)

     

    I have a 5508 and a 1262 in my test lab. I will see if I can recreate it, but I need to know what version of WLC software you are running.


     


  • BillLoss Level 1 Level 1 (0 points)

    thanks for reply, WLC running v7.0.220.0

  • DrVenture Level 2 Level 2 (180 points)

    I am running v7.0.230.0 and I cannot reproduce what you are are seeing. I have an iPhone connected to a WLAN with WPA2 PSK AES only. I then start some video on the iPhone that would play for a couple of hours. I then have a few other client doing sleep wakes on the same WLAN. When the Group Key rotates, the iPhone remains connected.

     

    Have you tried upgrade to iOS 5.01 on your iPhones and IOS (LOL) 7.0.203.0 on your controller?

  • BillLoss Level 1 Level 1 (0 points)

    V5.0.1 is running on our iPhone 4 devices - that is the latest code for this mode (?)

     

    Cisco tac did not suggest the v7.0.230.0 code - but might be worth a try, also have a bug report with apple as it looked to me that the iPhone was not replying as it should have in my debug log repeatedly

     

    Thank you

  • DrVenture Level 2 Level 2 (180 points)

    I was running 5.0.1 as well (did not upgrade to 5.1 yet on the iphone).

     

    I just noticed that I have both AES and TKIP enabled for my testing WLAN. That means the unicast key is going AES and the multicast is going TKIP. Just for a comparision, can you try turning on both TKIP and AES and see what happens?

     

    It "could" be the multicast key rotation (EAPOL) packet going to the iPhone is screwed up. The problem is when the rekey event happens, the packet is encrypted so you can't decode it with a sniffer.

  • BillLoss Level 1 Level 1 (0 points)

    am gonna see if iOS v5.1 helps at all,  we have our WLC configured to use WPA / TKIP and WPA2 / AES

    thanks,

  • DrVenture Level 2 Level 2 (180 points)

    Another test you can try is to turn off the session timeout for that WLAN on your WLC and see if your iPhones still get the boot. Go to WLANs ->Edit ->Advanced and look for Enable Session Timeout (default is checked and 1800 sec). Uncheck the box.

     

    Now the controller will no longer force client to reauthenticate every 1800 seconds.

     

    If you need this security, turn it up to a high value to like 3600 and then see if the iPhone lasts longer (3600 seconds) until it gets booted off.

  • BillLoss Level 1 Level 1 (0 points)

    great idea to test,  I had earlier increased the default to 12hrs -- it did lengthen the cycle -- but I just unchecked the session timeout completely.  (I had been somewhat concerned with continuing to carry devices no longer needing to be connected)  that might be better than fighting the key rotation, mac, iphone issues  -- and make end users happy,  thanks,

  • DrVenture Level 2 Level 2 (180 points)

    So in thinking about this some more, the removing session timeout will help somewhat, but the crux of the problem seems to be when the WLC decides to update the group key for each client. If you look at the 802.11 spec, it really only defines how the group key should be rotated, not really when. That seems to be up to the vendor. In the only documentation I can find states the WLC rotates the group key every hour. It DOES NOT state, if their are other conditions in which the group key rotates, such as other clients joining or leaving the WLAN.

     

    Very annoying.

     

    I did see you can manipulate the eapol key timings with the following commands:

     

    http://www.cisco.com/en/US/products/ps6366/products_qanda_item09186a00808b4c61.s html

     

    A. The ability to configure the WPA-Handshake timeout through the WLCs was integrated in software release 4.2 and later. You do not need this option in earlier WLC software versions.

     

    These commands can be used to change the WPA Handshake timeout:

     

        config advanced eap eapol-key-timeout <value>

        config advanced eap eapol-key-retries <value>

    The default values continue to reflect the WLCs current behavior.

     

       - the default value for eapol-key-timeout is 1 second.

       - the default value for eapol-key-retries is 2 retries

    Note: On IOS APs, this setting is configurable with the dot11 wpa handshake command.

     

    You can also configure the other EAP parameters with the options under the config advanced eap command.

     

    (Cisco Controller) >config advanced eap ?

     

    eapol-key-timeout

       Configures EAPOL-Key Timeout in seconds.

    eapol-key-retries

       Configures EAPOL-Key Max Retries.

    identity-request-timeout

       Configures EAP-Identity-Request Timeout in seconds.

    identity-request-retries

       Configures EAP-Identity-Request Max Retries.

    key-index

       Configure the key index used for

       dynamic WEP(802.1x) unicast key (PTK).

    max-login-ignore-identity-response 

       Configure to ignore the same username count

       reaching max in the EAP identity response

    request-timeout

       Configures EAP-Request Timeout in seconds.

    request-retries

     

     

    But again, these timings are during an authentication for the uni-cast key, not the group key (multicast/broadcast key).

     

    I also found this article on it:

     

    http://wirelessccie.blogspot.com/2009/12/wpawpa2-broadcast-key-rotation-on.html

     

    I looked up the bug with my CCO account and found they finally implemented a CLI configuration for the group key. You cannot disable it of course, but you sure as heck can delay if for a while! Not sure if you will be able to read the link for the bug, but here is the meat of it:

     

    CSCsi27596 Bug Details

     

    WLC lacks support for controlling the group key rotation interval
    Symptom:

     

    The WLC system lacks a supported way to configure the
    group key (broadcast key) rotation interval. Instead,
    it is hardcoded to a group key rotation interval of
    3600 seconds (1 hour).

     

    Workaround:

     

    On the console (this command will not work in an SSH or TELNET
    session), configure the hidden command
    devshell dot1xUpdateBroadcastRekeyTimer(seconds)

     

    This setting does not survive a reboot.

     

    Example:

     

    (Cisco Controller) >devshell dot1xUpdateBroadcastRekeyTimer(86400)

     

    value = 0 = 0x0

     

    Further Problem Description:

     

    This is a functional regression from autonomous IOS, which provides
    a supported "broadcast key change " CLI command (and
    corresponding GUI option.)

     

    From version 7.0.116.0 and newer use:

     

    config advanced eap bcast-key-interval

     

    where is a value between 120 and 86400

     

    WLC rotates group key on static WEP WLAN and disconnects clients
    Symptom:Static WEP clients get disconnected every 63 minutes when the group key is rotated. Conditions:version 4.0.179.11, WLAN with static wep Workaround:configure key rotation to be larger value You must be directly on the console for these commands. Telnet or ssh sessions will not be able to enter the command. devshell dot1xUpdateBroadcastRekeyTimer(seconds) For example 86400 seconds = 1 day. devshell dot1xUpdateBroadcastRekeyTimer(86400) NOTE: this change does not survive a reboot as it is not in the configuration.Further Problem Description:The controller will rotate the group key on a static wep WLAN every 63 minutes. This causes clients to disconnect until they are rebooted or recover on their own and initiate a new association.. There is no normal CLI command to set the group key interval on the controller which is saved in the configuration. This special command configures the software directly bypassing the CLI and the normal configuration file. This is a functional regression from autonomous APs since you can set the group key rotation interval.

     

    Message was edited by: DrVenture

  • DrVenture Level 2 Level 2 (180 points)

    One more thing Bill, Why are you using WPA + TKIP and WPA2 + AES? If you environment can supported it, dunmp WPA and TKIP. Just go for WPA2 and AES.

  • dimage1 Level 1 Level 1 (0 points)

    Did you find a solution to this problem?  We experience the problem when using WPA2/AES 802.1x configured.  When we test using WPA2/AES with PSK, no problems.