Clients disconnect because of Capabilites change

[patrick.kofler]

Hi all,

recently we migrated AIR-LAP1131AG APs from a 4402 WLC running 4.1.185.0 release to a 5508 running 7.6.130.0. After we did that some clients constantly disconnected and reconnected. I strongly assume it has something to do with the additional features that were introduced between the releases.

During debugging I saw that after the client entered the RUN state that it got disconnected with the following error:

*spamApTask0: Mar 31 01:57:27.649: xx:xx:xx:xx:xx:xx Association Failed on REAP AP BSSID yy:yy:yy:yy:yy:yy (slot 0), status 1 0 Capabilities changed

Here is the whole debug output (X is the client, Y is the AP, Z are other APs for the group key)

*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Adding mobile on LWAPP AP yy:yy:yy:yy:yy:yy(0) 
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Association received from mobile on BSSID yy:yy:yy:yy:yy:yy
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Global 200 Clients are allowed to AP radio
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Max Client Trap Threshold: 0  cur: 0
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx override for default ap group, marking intgrp NULL
*apfMsConnTask_3: Mar 31 01:57:17.623: xx:xx:xx:xx:xx:xx Applying Interface policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Re-applying interface policy for client 
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2219)
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2240)
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx In processSsidIE:4850 setting Central switched to FALSE
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Applying site-specific Local Bridging override for station xx:xx:xx:xx:xx:xx - vapId 5, site 'default-group', interface 'irglbxv'
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Applying Local Bridging Interface Policy for station xx:xx:xx:xx:xx:xx - vlan 14, interface id 14, interface 'irglbxv'
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx processSsidIE  statusCode is 0 and status is 0 
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx processSsidIE  ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx STA - rates (4): 2 4 11 22 0 0 0 0 0 0 0 0 0 0 0 0
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx suppRates  statusCode is 0 and gotSuppRatesElement is 1 
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx STA - rates (12): 2 4 11 22 12 18 24 36 48 72 96 108 0 0 0 0
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx extSuppRates  statusCode is 0 and gotExtSuppRatesElement is 1 
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Processing RSN IE type 48, length 20 for mobile xx:xx:xx:xx:xx:xx
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Updating AID for REAP AP Client yy:yy:yy:yy:yy:yy - AID ===> 1
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Encryption policy is set to 0x80000001
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Central switch is FALSE
*apfMsConnTask_3: Mar 31 01:57:17.624: xx:xx:xx:xx:xx:xx Sending Local Switch flag = 1
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx 0.0.0.0 8021X_REQD (3) DHCP required on AP yy:yy:yy:yy:yy:yy vapId 5 apVapId 5for this client
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx Not Using WMM Compliance code qosCap 00
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP yy:yy:yy:yy:yy:yy vapId 5 apVapId 5 flex-acl-name: 
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx apfMsAssoStateInc
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx apfPemAddUser2 (apf_policy.c:333) Changing state for mobile xx:xx:xx:xx:xx:xx on AP yy:yy:yy:yy:yy:yy from Idle to Associated
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx apfPemAddUser2:session timeout forstation xx:xx:xx:xx:xx:xx - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is  0 
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx Sending Assoc Response to station on BSSID zz:zz:zz:zz:zz:zz (status 0) ApVapId 5 Slot 0
*apfMsConnTask_3: Mar 31 01:57:17.625: xx:xx:xx:xx:xx:xx apfProcessAssocReq (apf_80211.c:8294) Changing state for mobile xx:xx:xx:xx:xx:xx on AP yy:yy:yy:yy:yy:yy from Associated to Associated
*spamApTask0: Mar 31 01:57:17.708: xx:xx:xx:xx:xx:xx Sent 1x initiate message to multi thread task for mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.708: xx:xx:xx:xx:xx:xx Creating a PKC PMKID Cache entry for station xx:xx:xx:xx:xx:xx (RSN 2)
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Resetting MSCB PMK Cache Entry 0 for station xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Adding BSSID yy:yy:yy:yy:yy:yy to PMKID cache at index 0 for station xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: New PMKID: (16)
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709:      [0000] 95 e5 c8 10 ba cc 57 e5 1d 4c ab ae c3 eb 0c f5
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Initiating RSN PSK to mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx EAP-PARAM Debug - eap-params for Wlan-Id :5 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx dot1x - moving mobile xx:xx:xx:xx:xx:xx into Force Auth state
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Skipping EAP-Success to mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx EAPOL Header: 
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: 00000000: 02 03 00 5f                                       ..._
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Found an cache entry for BSSID yy:yy:yy:yy:yy:yy in PMKID cache at index 0 of station xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Found an cache entry for BSSID yy:yy:yy:yy:yy:yy in PMKID cache at index 0 of station xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: Including PMKID in M1  (16)
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709:      [0000] 95 e5 c8 10 ba cc 57 e5 1d 4c ab ae c3 eb 0c f5
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Starting key exchange to mobile xx:xx:xx:xx:xx:xx, data packets will be dropped
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Sending EAPOL-Key Message to mobile zz:zz:zz:zz:zz:zz
   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Sending EAPOL-Key Message to mobile zz:zz:zz:zz:zz:zz
   state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx Allocating EAP Pkt for retransmission to mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.709: xx:xx:xx:xx:xx:xx mscb->apfMsLwappLradNhMac = 00:00:0c:07:ac:01 mscb->apfMsLradSlotId = 0 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.710: xx:xx:xx:xx:xx:xx  mscb->apfMsBssid = yy:yy:yy:yy:yy:yy mscb->apfMsAddress = xx:xx:xx:xx:xx:xx mscb->apfMsApVapId = 5
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.710: xx:xx:xx:xx:xx:xx  dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = 171969037
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.710: xx:xx:xx:xx:xx:xx  mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = 173667675 mscb->apfMsLwappLradPort = 23341
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Received EAPOL-Key from mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Received EAPOL-key in PTK_START state (message 2) from mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Stopping retransmission timer for mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx EAPOL Header: 
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: 00000000: 02 03 00 5f                                       ..._
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Sending EAPOL-Key Message to mobile zz:zz:zz:zz:zz:zz
   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Sending EAPOL-Key Message to mobile zz:zz:zz:zz:zz:zz
   state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx Reusing allocated memory for  EAP Pkt for retransmission to mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx mscb->apfMsLwappLradNhMac = 00:00:0c:07:ac:01 mscb->apfMsLradSlotId = 0 mscb->apfMsLradJumbo = 0 mscb->apfMsintIfNum = 1
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.792: xx:xx:xx:xx:xx:xx  mscb->apfMsBssid = yy:yy:yy:yy:yy:yy mscb->apfMsAddress = xx:xx:xx:xx:xx:xx mscb->apfMsApVapId = 5
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.793: xx:xx:xx:xx:xx:xx  dot1xcb->snapOrg = 00 00 00 dot1xcb->eapolWepBit = 0 mscb->apfMsLwappLradVlanId = 0 mscb->apfMsLwappMwarInet.ipv4.addr = 171969037
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.793: xx:xx:xx:xx:xx:xx  mscb->apfMsLwappMwarPort = 5246 mscb->apfMsLwappLradInet.ipv4.addr = 173667675 mscb->apfMsLwappLradPort = 23341
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx Received EAPOL-Key from mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx Stopping retransmission timer for mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx Freeing EAP Retransmit Bufer for mobile xx:xx:xx:xx:xx:xx
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx apfMs1xStateInc
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.897: xx:xx:xx:xx:xx:xx 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx Central switch is FALSE
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx Sending the Central Auth Info
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx Central Auth Info Allocated PMKLen = 32
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx PMK: pmkActiveIndex = 0
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx msAssocTypeFlagsMsb = 0 msAssocTypeFlagsLsb = 2
apfMsEntryType = 0 apfMsEapType = 0
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx Sending Local Switch flag = 0
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 L2AUTHCOMPLETE (4) DHCP required on AP yy:yy:yy:yy:yy:yy vapId 5 apVapId 5for this client
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP yy:yy:yy:yy:yy:yy vapId 5 apVapId 5 flex-acl-name: 
*spamApTask0: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx spamEncodeCentralAuthInoMsPayload: msAssocTypeFlagsMsb = 0 msAssocTypeFlagsLsb = 2
apfMsEntryType = 0 pmkLen = 32
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 6178, Adding TMP rule
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
  type = Airespace AP - Learn IP address
  on AP yy:yy:yy:yy:yy:yy, slot 0, interface = 1, QOS = 0
  IPv4 ACL ID = 255, IPv
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 15206  Local Bridging Vlan = 14, Local Bridging intf id = 14
*Dot1x_NW_MsgTask_7: Mar 31 01:57:17.898: xx:xx:xx:xx:xx:xx 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255)
*pemReceiveTask: Mar 31 01:57:17.900: xx:xx:xx:xx:xx:xx 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*apfOrphanSocketTask: Mar 31 01:57:18.904: xx:xx:xx:xx:xx:xx Orphan Packet from STA - IP 10.89.246.63
*apfOrphanSocketTask: Mar 31 01:57:18.904: xx:xx:xx:xx:xx:xx apfMsRunStateInc
*apfOrphanSocketTask: Mar 31 01:57:18.904: xx:xx:xx:xx:xx:xx 10.89.246.63 DHCP_REQD (7) Change state to RUN (20) last state DHCP_REQD (7)
*apfOrphanSocketTask: Mar 31 01:57:18.904: xx:xx:xx:xx:xx:xx Assigning Address 10.89.246.63 to mobile 
*pemReceiveTask: Mar 31 01:57:18.905: xx:xx:xx:xx:xx:xx 10.89.246.63 Removed NPU entry.
*dot1xMsgTask: Mar 31 01:57:19.863: GTK Rotation Kicked in for AP: zz:zz:zz:zz:zz:zz SlotId = 0 - (0x3ff07bf8)
*dot1xMsgTask: Mar 31 01:57:19.863: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 1 
*dot1xMsgTask: Mar 31 01:57:19.863: GTK rotation for zz:zz:zz:zz:zz:zz
*dot1xMsgTask: Mar 31 01:57:19.863: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:19.863: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 2 
*dot1xMsgTask: Mar 31 01:57:19.863: GTK rotation for zz:zz:zz:zz:zz:zz
*dot1xMsgTask: Mar 31 01:57:19.864: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:19.864: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 3 
*dot1xMsgTask: Mar 31 01:57:19.864: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:19.864: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 4 
*dot1xMsgTask: Mar 31 01:57:19.864: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:19.864: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 5 
*dot1xMsgTask: Mar 31 01:57:19.865: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*mmMaListen: Mar 31 01:57:20.863: xx:xx:xx:xx:xx:xx 10.89.246.63 RUN (20) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*mmMaListen: Mar 31 01:57:20.863: xx:xx:xx:xx:xx:xx 10.89.246.63 RUN (20) Reached PLUMBFASTPATH: from line 5850
*dot1xMsgTask: Mar 31 01:57:21.263: GTK Rotation Kicked in for AP: zz:zz:zz:zz:zz:zz SlotId = 0 - (0x3ff07bf8)
*dot1xMsgTask: Mar 31 01:57:21.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 1 
*dot1xMsgTask: Mar 31 01:57:21.263: GTK rotation for zz:zz:zz:zz:zz:zz
*dot1xMsgTask: Mar 31 01:57:21.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:21.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 2 
*dot1xMsgTask: Mar 31 01:57:21.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:21.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 3 
*dot1xMsgTask: Mar 31 01:57:21.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:21.264: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 4 
*dot1xMsgTask: Mar 31 01:57:21.264: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:21.264: Generated a new group key for AP zz:zz:zz:zz:zz:zz(0) - vap 5 
*dot1xMsgTask: Mar 31 01:57:21.264: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*spamApTask0: Mar 31 01:57:27.649: xx:xx:xx:xx:xx:xx Association Failed on REAP AP BSSID yy:yy:yy:yy:yy:yy (slot 0), status 1 0 Capabilities changed 
*spamApTask0: Mar 31 01:57:27.649: xx:xx:xx:xx:xx:xx apfMsDeleteByMscb Scheduling mobile for deletion with deleteReason 8, reasonCode 1
*spamApTask0: Mar 31 01:57:27.649: xx:xx:xx:xx:xx:xx Scheduling deletion of Mobile Station:  (callerId: 30) in 1 seconds
*osapiBsnTimer: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx apfMsExpireCallback (apf_ms.c:626) Expiring Mobile!
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx apfMsExpireMobileStation (apf_ms.c:6655) Changing state for mobile xx:xx:xx:xx:xx:xx on AP yy:yy:yy:yy:yy:yy from Associated to Disassociated
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Sent Deauthenticate to mobile on BSSID yy:yy:yy:yy:yy:yy slot 0(caller apf_ms.c:6749)
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Found an cache entry for BSSID yy:yy:yy:yy:yy:yy in PMKID cache at index 0 of station xx:xx:xx:xx:xx:xx
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Removing BSSID yy:yy:yy:yy:yy:yy from PMKID cache of station xx:xx:xx:xx:xx:xx
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Resetting MSCB PMK Cache Entry 0 for station xx:xx:xx:xx:xx:xx
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Setting active key cache index 0 ---> 8
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Deleting the PMK cache when de-authenticating the client.
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx Global PMK Cache deletion failed.
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx apfMsAssoStateDec
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx apfMsExpireMobileStation (apf_ms.c:6787) Changing state for mobile xx:xx:xx:xx:xx:xx on AP yy:yy:yy:yy:yy:yy from Disassociated to Idle
*apfReceiveTask: Mar 31 01:57:28.463: xx:xx:xx:xx:xx:xx pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfReceiveTask: Mar 31 01:57:28.464: xx:xx:xx:xx:xx:xx 10.89.246.63 START (0) Deleted mobile LWAPP rule on AP [yy:yy:yy:yy:yy:yy]
*apfReceiveTask: Mar 31 01:57:28.464: xx:xx:xx:xx:xx:xx Deleting mobile on AP yy:yy:yy:yy:yy:yy(0) 
*dot1xMsgTask: Mar 31 01:57:30.263: GTK Rotation Kicked in for AP: zz:zz:zz:zz:zz:zz SlotId = 1 - (0x3ff07bf8)
*dot1xMsgTask: Mar 31 01:57:30.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(1) - vap 1 
*dot1xMsgTask: Mar 31 01:57:30.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:30.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(1) - vap 2 
*dot1xMsgTask: Mar 31 01:57:30.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:30.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(1) - vap 3 
*dot1xMsgTask: Mar 31 01:57:30.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:30.263: Generated a new group key for AP zz:zz:zz:zz:zz:zz(1) - vap 4 
*dot1xMsgTask: Mar 31 01:57:30.263: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1
*dot1xMsgTask: Mar 31 01:57:30.264: Generated a new group key for AP zz:zz:zz:zz:zz:zz(1) - vap 5 
*dot1xMsgTask: Mar 31 01:57:30.264: Sending of M5 for zz:zz:zz:zz:zz:zz is Skipped, rc = 1

Here is the configuration of the SSID on the 4402 and 5508 for comparison.

4402

WLAN Identifier.................................. 2
Profile Name..................................... xxxxx
Network Name (SSID).............................. xxxxx
Status........................................... Enabled
MAC Filtering.................................... Disabled
Broadcast SSID................................... Enabled
AAA Policy Override.............................. Disabled
Number of Active Clients......................... 0
Exclusionlist Timeout............................ 60 seconds
Session Timeout.................................. Infinity
Interface........................................ xxxxxx
WLAN ACL......................................... unconfigured
DHCP Server...................................... Default
DHCP Address Assignment Required................. Disabled
Quality of Service............................... Silver (best effort)
WMM.............................................. Disabled
CCX - AironetIe Support.......................... Enabled
CCX - Gratuitous ProbeResponse (GPR)............. Disabled
Dot11-Phone Mode (7920).......................... Disabled
Wired Protocol................................... None
IPv6 Support..................................... Disabled
Radio Policy..................................... All
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)............................... Enabled
         TKIP Cipher............................. Enabled
         AES Cipher.............................. Disabled
      WPA2 (RSN IE).............................. Disabled
                                                                Auth Key Management
         802.1x.................................. Disabled
         PSK..................................... Enabled
         CCKM.................................... Disabled
   CKIP ......................................... Disabled
   IP Security................................... Disabled
   IP Security Passthru.......................... Disabled
   Web Based Authentication...................... Disabled
   Web-Passthrough............................... Disabled
   Conditional Web Redirect...................... Disabled
   Auto Anchor................................... Disabled
   Cranite Passthru.............................. Disabled
   Fortress Passthru............................. Disabled
   H-REAP Local Switching........................ Disabled
   Infrastructure MFP protection................. Enabled (Global Infrastructure MFP Disabled)
   Client MFP.................................... Optional but inactive (WPA2 not configured)
   Tkip MIC Countermeasure Hold-down Timer....... 60

 Mobility Anchor List
 WLAN ID     IP Address       Status

5508

WLAN Identifier.................................. 5
Profile Name..................................... xxxxx
Network Name (SSID).............................. xxxxx
Status........................................... Enabled
MAC Filtering.................................... Disabled
Broadcast SSID................................... Enabled
AAA Policy Override.............................. Disabled
Network Admission Control
Client Profiling Status
    Radius Profiling ............................ Disabled
     DHCP ....................................... Disabled
     HTTP ....................................... Disabled
    Local Profiling ............................. Disabled
     DHCP ....................................... Disabled
     HTTP ....................................... Disabled
  Radius-NAC State............................... Disabled
  SNMP-NAC State................................. Disabled
  Quarantine VLAN................................ 0
Maximum number of Associated Clients............. 0
Maximum number of Clients per AP Radio........... 200
Number of Active Clients......................... 3
Exclusionlist Timeout............................ 60 seconds
Session Timeout.................................. 86400 seconds
User Idle Timeout................................ Disabled
Sleep Client..................................... disable
Sleep Client Timeout............................. 12 hours
User Idle Threshold.............................. 0 Bytes
NAS-identifier................................... xxxxxxxx
CHD per WLAN..................................... Disabled
Webauth DHCP exclusion........................... Disabled
Interface........................................ xxxxxxxx
Multicast Interface.............................. Not Configured
WLAN IPv4 ACL.................................... unconfigured
WLAN IPv6 ACL.................................... unconfigured
WLAN Layer2 ACL.................................. unconfigured
mDNS Status...................................... Disabled
mDNS Profile Name................................ unconfigured
DHCP Server...................................... Default
DHCP Address Assignment Required................. Disabled
Static IP client tunneling....................... Disabled
PMIPv6 Mobility Type............................. none
    PMIPv6 MAG Profile........................... Unconfigured
    PMIPv6 Default Realm......................... Unconfigured
    PMIPv6 NAI Type.............................. Hexadecimal
Quality of Service............................... Silver
Per-SSID Rate Limits............................. Upstream      Downstream
Average Data Rate................................   0             0
Average Realtime Data Rate.......................   0             0
Burst Data Rate..................................   0             0
Burst Realtime Data Rate.........................   0             0
Per-Client Rate Limits........................... Upstream      Downstream
Average Data Rate................................   0             0
Average Realtime Data Rate.......................   0             0
Burst Data Rate..................................   0             0
Burst Realtime Data Rate.........................   0             0
Scan Defer Priority.............................. 4,5,6
Scan Defer Time.................................. 100 milliseconds
WMM.............................................. Disabled
WMM UAPSD Compliant Client Support............... Disabled
Media Stream Multicast-direct.................... Disabled
CCX - AironetIe Support.......................... Disabled
CCX - Gratuitous ProbeResponse (GPR)............. Disabled
CCX - Diagnostics Channel Capability............. Disabled
Dot11-Phone Mode (7920).......................... Disabled
Wired Protocol................................... None
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................................ Disabled
   Accounting.................................... Disabled
   Dynamic Interface............................. Disabled
   Dynamic Interface Priority.................... wlan
Local EAP Authentication......................... Disabled
Security

   802.11 Authentication:........................ Open System
   FT Support.................................... Disabled
   Static WEP Keys............................... Disabled
   802.1X........................................ Disabled
   Wi-Fi Protected Access (WPA/WPA2)............. Enabled
      WPA (SSN IE)............................... Enabled
         TKIP Cipher............................. Enabled
         AES Cipher.............................. Disabled
      WPA2 (RSN IE).............................. Disabled
                                                                Auth Key Management
         802.1x.................................. Disabled
         PSK..................................... Enabled
         CCKM.................................... Disabled
         FT-1X(802.11r).......................... Disabled
         FT-PSK(802.11r)......................... Disabled
         PMF-1X(802.11w)......................... Disabled
         PMF-PSK(802.11w)........................ Disabled
      FT Reassociation Timeout................... 20
      FT Over-The-DS mode........................ Disabled
      GTK Randomization.......................... Disabled
      SKC Cache Support.......................... Disabled
      CCKM TSF Tolerance......................... 1000
   WAPI.......................................... Disabled
   Wi-Fi Direct policy configured................ Disabled
   EAP-Passthrough............................... Disabled
   CKIP ......................................... Disabled
   Web Based Authentication...................... Disabled
   Web-Passthrough............................... Disabled
   Conditional Web Redirect...................... Disabled
   Splash-Page Web Redirect...................... Disabled
   Auto Anchor................................... Disabled
   FlexConnect Local Switching................... Enabled
   flexconnect Central Dhcp Flag................. Disabled
   flexconnect nat-pat Flag...................... Disabled
   flexconnect Dns Override Flag................. Disabled
   flexconnect PPPoE pass-through................ Disabled
   flexconnect local-switching IP-source-guar.... Disabled
   FlexConnect Vlan based Central Switching ..... Disabled
   FlexConnect Local Authentication.............. Disabled
   FlexConnect Learn IP Address.................. Enabled
   Client MFP.................................... Optional but inactive (WPA2 not configured)
   PMF........................................... Disabled
   PMF Association Comeback Time................. 1
   PMF SA Query RetryTimeout..................... 200
   Tkip MIC Countermeasure Hold-down Timer....... 60
   Eap-params.................................... Disabled
AVC Visibilty.................................... Disabled
AVC Profile Name................................. None
Flow Monitor Name................................ None
Split Tunnel (Printers).......................... Disabled
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
KTS based CAC Policy............................. Disabled
Assisted Roaming Prediction Optimization......... Disabled
802.11k Neighbor List............................ Disabled
802.11k Neighbor List Dual Band.................. Disabled
Band Select...................................... Disabled
Load Balancing................................... Disabled
Multicast Buffer................................. Disabled

Does anybody have an idea where else I could look at?

Regards,
Patrick

[Leo Laohoo]

Can you post the serial number of the AP?  Maybe the MIC has expired.

[patrick.kofler]

The certificate expires in August 2016. By that time we will have replaced the 1130s.

Regards,
Patrick

[Scott Fella]

When upgrading from older code like what you have to a newer code, the issue I have seen many time is that the client drivers are old and need to be upgraded. I would look at some of these clients and upgrade the drivers and test. Really affects many Intel NIC cards and some Broadcomm. 

-Scott

[patrick.kofler]

I thought the same that those devices simply are too old. However I would like to know what causes this capabilities change. We want to get rid of the old H/W, but at the moment it looks as if we would need to revert back to the 4402 in order to get those things working again.

I have not enough information, but those devices are some kind of handhelds. Their MAC OUI belongs to Newport Electronics.

Regards,
Patrick