We recently converted autonomous 1131APs to LWAP. We have some 802.11b clients that were associated to these APs and they worked fine. Ever since we converted them to LWAP, the clients frequently disassociate and it causes alarms on these wireless clients which are used as monitors.
WCS shows the client disassociation and re-association and it says the roam reason as "unspecified". It associates to the same AP and keeps the same DHCP client address etc. I tried setting a static IP on the client but that did not help. We verified the PSK settings and they all match between the clients and the controller. The client debug shows the following information and this was after the client was associated for about an hour with no issues and after 55 minutes, I started seeing this.
*osapiBsnTimer: Apr 18 14:48:44.297: 00:1d:c9:0a:10:0b 802.1x 'reAuthWhen' Timer expired for station 00:1d:c9:0a:10:0b
*spamReceiveTask: Apr 18 14:54:17.956: CCKM: Send CCKM cache entry
*spamReceiveTask: Apr 18 15:01:30.680: CCKM: Send CCKM cache entry
*dot1xMsgTask: Apr 18 15:06:02.113: 00:1d:c9:0a:10:0b Key exchange done, data packets from mobile 00:1d:c9:0a:10:0b should be forwarded shortly
*dot1xMsgTask: Apr 18 15:06:02.114: 00:1d:c9:0a:10:0b Sending EAPOL-Key Message to mobile 00:1d:c9:0a:10:0b
state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.03
*dot1xMsgTask: Apr 18 15:06:02.114: 00:1d:c9:0a:10:0b Updated broadcast key sent to mobile 00:1D:C9:0A:10:0B
*osapiBsnTimer: Apr 18 15:06:03.111: 00:1d:c9:0a:10:0b 802.1x 'timeoutEvt' Timer expired for station 00:1d:c9:0a:10:0b
*dot1xMsgTask: Apr 18 15:06:03.112: 00:1d:c9:0a:10:0b Retransmit 1 of EAPOL-Key M5 (length 131) for mobile 00:1d:c9:0a:10:0b
*osapiBsnTimer: Apr 18 15:06:04.111: 00:1d:c9:0a:10:0b 802.1x 'timeoutEvt' Timer expired for station 00:1d:c9:0a:10:0b
*dot1xMsgTask: Apr 18 15:06:04.112: 00:1d:c9:0a:10:0b Retransmit 2 of EAPOL-Key M5 (length 131) for mobile 00:1d:c9:0a:10:0b
*osapiBsnTimer: Apr 18 15:06:05.111: 00:1d:c9:0a:10:0b 802.1x 'timeoutEvt' Timer expired for station 00:1d:c9:0a:10:0b
*dot1xMsgTask: Apr 18 15:06:05.113: 00:1d:c9:0a:10:0b Retransmit failure for EAPOL-Key M5 to mobile 00:1d:c9:0a:10:0b, retransmit count 3, mscb deauth count 0
*dot1xMsgTask: Apr 18 15:06:05.114: 00:1d:c9:0a:10:0b Sent Deauthenticate to mobile on BSSID 00:12:44:b2:81:30 slot 0(caller 1x_ptsm.c:467)
*dot1xMsgTask: Apr 18 15:06:05.115: 00:1d:c9:0a:10:0b Scheduling deletion of Mobile Station: (callerId: 57) in 10 seconds
*osapiBsnTimer: Apr 18 15:06:15.111: 00:1d:c9:0a:10:0b apfMsExpireCallback (apf_ms.c:599) Expiring Mobile!
*apfReceiveTask: Apr 18 15:06:15.111: 00:1d:c9:0a:10:0b apfMsExpireMobileStation (apf_ms.c:4897) Changing state for mobile 00:1d:c9:0a:10:0b on AP 00:12:44:b2:81:30 from Associated to Disassociated
*apfReceiveTask: Apr 18 15:06:15.111: 00:1d:c9:0a:10:0b Scheduling deletion of Mobile Station: (callerId: 45) in 10 seconds
*osapiBsnTimer: Apr 18 15:06:25.111: 00:1d:c9:0a:10:0b apfMsExpireCallback (apf_ms.c:599) Expiring Mobile!
*apfReceiveTask: Apr 18 15:06:25.114: 00:1d:c9:0a:10:0b Sent Deauthenticate to mobile on BSSID 00:12:44:b2:81:30 slot 0(caller apf_ms.c:4981)
*apfReceiveTask: Apr 18 15:06:25.114: 00:1d:c9:0a:10:0b apfMsAssoStateDec
*apfReceiveTask: Apr 18 15:06:25.114: 00:1d:c9:0a:10:0b apfMsExpireMobileStation (apf_ms.c:5018) Changing state for mobile 00:1d:c9:0a:10:0b on AP 00:12:44:b2:81:30 from Disassociated to Idle
*apfReceiveTask: Apr 18 15:06:25.114: 00:1d:c9:0a:10:0b Scheduling deletion of Mobile Station: (callerId: 47) in 10 seconds
*osapiBsnTimer: Apr 18 15:06:35.111: 00:1d:c9:0a:10:0b apfMsExpireCallback (apf_ms.c:599) Expiring Mobile!
*apfReceiveTask: Apr 18 15:06:35.112: 00:1d:c9:0a:10:0b 10.123.191.226 RUN (20) Deleted mobile LWAPP rule on AP [00:12:44:b2:81:30]
*apfReceiveTask: Apr 18 15:06:35.112: 00:1d:c9:0a:10:0b apfMsRunStateDec
*apfReceiveTask: Apr 18 15:06:35.112: 00:1d:c9:0a:10:0b apfMs1xStateDec
*apfReceiveTask: Apr 18 15:06:35.112: 00:1d:c9:0a:10:0b Deleting mobile on AP 00:12:44:b2:81:30(0)
*pemReceiveTask: Apr 18 15:06:35.128: 00:1d:c9:0a:10:0b 10.123.191.226 Removed NPU entry.
*spamReceiveTask: Apr 18 15:09:03.104: CCKM: Send CCKM cache entry
*apfMsConnTask_0: Apr 18 15:09:43.852: Deleting the client immediatly since WLAN is changed
*apfMsConnTask_0: Apr 18 15:09:45.935: Deleting the client immediatly since WLAN is changed
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Adding mobile on LWAPP AP 00:12:44:b2:81:30(0)
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Association received from mobile on AP 00:12:44:b2:81:30
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 START (0) Changing ACL 'none' (ACL ID 0) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1393)
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Applying site-specific IPv6 override for station 00:1d:c9:0a:10:0b - vapId 4, site 'default-group', interface 'bcm-monitor'
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 START (0) Changing ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:1393)
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Applying IPv6 Interface Policy for station 00:1d:c9:0a:10:0b - vlan 403, interface id 10, interface 'bcm-monitor'
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b STA - rates (4): 130 132 139 150 0 0 0 0 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Processing WPA IE type 221, length 22 for mobile 00:1d:c9:0a:10:0b
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state AUTHCHECK (2)
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state 8021X_REQD (3)
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:12:44:b2:81:30 vapId 4 apVapId 4
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b apfMsAssoStateInc
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b apfPemAddUser2 (apf_policy.c:222) Changing state for mobile 00:1d:c9:0a:10:0b on AP 00:12:44:b2:81:30 from Idle to Associated
*apfMsConnTask_0: Apr 18 15:10:30.910: 00:1d:c9:0a:10:0b Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Apr 18 15:10:30.911: 00:1d:c9:0a:10:0b Sending Assoc Response to station on BSSID 00:12:44:b2:81:30 (status 0) ApVapId 4 Slot 0
*apfMsConnTask_0: Apr 18 15:10:30.911: 00:1d:c9:0a:10:0b apfProcessAssocReq (apf_80211.c:4672) Changing state for mobile 00:1d:c9:0a:10:0b on AP 00:12:44:b2:81:30 from Associated to Associated
*dot1xMsgTask: Apr 18 15:10:30.913: 00:1d:c9:0a:10:0b Creating a PKC PMKID Cache entry for station 00:1d:c9:0a:10:0b (RSN 0)
*dot1xMsgTask: Apr 18 15:10:30.913: 00:1d:c9:0a:10:0b Initiating WPA PSK to mobile 00:1d:c9:0a:10:0b
*dot1xMsgTask: Apr 18 15:10:30.913: 00:1d:c9:0a:10:0b dot1x - moving mobile 00:1d:c9:0a:10:0b into Force Auth state
*dot1xMsgTask: Apr 18 15:10:30.913: 00:1d:c9:0a:10:0b Skipping EAP-Success to mobile 00:1d:c9:0a:10:0b
*dot1xMsgTask: Apr 18 15:10:30.914: 00:1d:c9:0a:10:0b Starting key exchange to mobile 00:1d:c9:0a:10:0b, data packets will be dropped
*dot1xMsgTask: Apr 18 15:10:30.914: 00:1d:c9:0a:10:0b Sending EAPOL-Key Message to mobile 00:1d:c9:0a:10:0b
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.928: 00:1d:c9:0a:10:0b Received EAPOL-Key from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.929: 00:1d:c9:0a:10:0b Received EAPOL-key in PTK_START state (message 2) from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.929: 00:1d:c9:0a:10:0b Stopping retransmission timer for mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.929: 00:1d:c9:0a:10:0b Sending EAPOL-Key Message to mobile 00:1d:c9:0a:10:0b
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.938: 00:1d:c9:0a:10:0b Received EAPOL-Key from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.938: 00:1d:c9:0a:10:0b Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.938: 00:1d:c9:0a:10:0b apfMs1xStateInc
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.938: 00:1d:c9:0a:10:0b 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state L2AUTHCOMPLETE (4)
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.939: 00:1d:c9:0a:10:0b 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 00:12:44:b2:81:30 vapId 4 apVapId 4
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.939: 00:1d:c9:0a:10:0b 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state DHCP_REQD (7)
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.939: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4502, Adding TMP rule
*Dot1x_NW_MsgTask_0: Apr 18 04:13:26.939: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:12:44:b2:81:30, slot 0, interface = 29, QOS = 0
ACL Id = 255, Jumbo F
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.939: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 5006 IPv6 Vlan = 403, IPv6 intf id = 10
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.939: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.940: 00:1d:c9:0a:10:0b Stopping retransmission timer for mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.940: 00:1d:c9:0a:10:0b Key exchange done, data packets from mobile 00:1d:c9:0a:10:0b should be forwarded shortly
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.940: 00:1d:c9:0a:10:0b Sending EAPOL-Key Message to mobile 00:1d:c9:0a:10:0b
state PTKINITDONE (message 5 - group), replay counter 00.00.00.00.00.00.00.02
*spamReceiveTask: Apr 18 15:10:30.941: 00:1d:c9:0a:10:0b Sent EAPOL-Key M5 for mobile 00:1d:c9:0a:10:0b
*pemReceiveTask: Apr 18 15:10:30.947: 00:1d:c9:0a:10:0b 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Apr 18 15:10:30.947: 00:1d:c9:0a:10:0b Sent an XID frame
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.948: 00:1d:c9:0a:10:0b Received EAPOL-Key from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.948: 00:1d:c9:0a:10:0b Received EAPOL-key in REKEYNEGOTIATING state (message 6) from mobile 00:1d:c9:0a:10:0b
*Dot1x_NW_MsgTask_0: Apr 18 15:10:30.948: 00:1d:c9:0a:10:0b Stopping retransmission timer for mobile 00:1d:c9:0a:10:0b
*apfReceiveTask: Apr 18 15:10:30.958: 00:1d:c9:0a:10:0b Orphan Packet from 10.123.191.226 on mobile
*apfReceiveTask: Apr 18 15:10:31.963: 00:1d:c9:0a:10:0b Orphan Packet from 10.123.191.226 on mobile
*apfReceiveTask: Apr 18 15:10:32.917: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Apr 18 15:10:32.917: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4183, Adding TMP rule
*apfReceiveTask: Apr 18 15:10:32.000: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:12:44:b2:81:30, slot 0, interface = 29, QOS = 0
ACL Id = 255, Jumb
*apfReceiveTask: Apr 18 15:10:32.917: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 5006 IPv6 Vlan = 403, IPv6 intf id = 10
*apfReceiveTask: Apr 18 15:10:32.917: 00:1d:c9:0a:10:0b 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 255)
*apfReceiveTask: Apr 18 15:10:32.917: 00:1d:c9:0a:10:0b Installing Orphan Pkt IP address 10.123.191.226 for station
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b apfMsRunStateInc
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b 10.123.191.226 DHCP_REQD (7) Change state to RUN (20) last state RUN (20)
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b 10.123.191.226 RUN (20) Reached PLUMBFASTPATH: from line 5001
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b 10.123.191.226 RUN (20) Replacing Fast Path rule
type = Airespace AP Client
on AP 00:12:44:b2:81:30, slot 0, interface = 29, QOS = 0
ACL Id = 255, Jumbo Frames =
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b 10.123.191.226 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 5006 IPv6 Vlan = 403, IPv6 intf id = 10
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b 10.123.191.226 RUN (20) Successfully plumbed mobile rule (ACL ID 255)
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b Assigning Address 10.123.191.226 to mobile
*apfReceiveTask: Apr 18 15:10:32.918: 00:1d:c9:0a:10:0b Successfully installed IP address 10.123.191.226 for station
*pemReceiveTask: Apr 18 15:10:32.925: 00:1d:c9:0a:10:0b 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Apr 18 15:10:32.926: 00:1d:c9:0a:10:0b Sent an XID frame
*pemReceiveTask: Apr 18 15:10:32.931: 00:1d:c9:0a:10:0b 10.123.191.226 Added NPU entry of type 1, dtlFlags 0x0
*pemReceiveTask: Apr 18 15:10:32.936: 00:1d:c9:0a:10:0b Sending a gratuitous ARP for 10.123.191.226, VLAN Id 403
*spamReceiveTask: Apr 18 15:18:59.735: CCKM: Send CCKM cache entry
Any ideas?
Meena
