Probmel with client on wireless network

acazarkov · ‎10-26-2014

Hi,

I have use cisco wlc 2100 ( software version 7.0.250.0) and three AIR-LAP1242G-E-K9 for my wireless network. Problem that began to emerge was that my clients suddenly lose connection. Client Clients are at from 2,3 to 10 meters away from the Access point.

What could cause this behavior on my network.?

ali aqrabawi · ‎10-26-2014

Hello ,

-how frequent this issue occur ?

-does it occur on all clients at same time ?

-what is the clients type ? and what's the version of the clients ?

can you share :

show msglog

show WLAN <WLAN Id>, that face this issue ,

you can run "debug client <client MAC>" , and wait for that client to get disconnected , then look into the debug what you can see ? also if you can share the debug output?

acazarkov · ‎10-26-2014

tanks for replay.

Issue occur very frequetly.

Show mslog :

--More-- or (q)uit
*dot1xMsgTask: Oct 26 10:19:02.094: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 10:17:24.308: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*DHCP Socket Task: Oct 26 10:16:06.012: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*apfReceiveTask: Oct 26 09:55:42.209: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*DHCP Socket Task: Oct 26 09:53:37.600: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 09:49:06.256: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 09:48:41.059: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 09:48:20.663: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 09:43:04.683: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 09:42:45.685: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 09:39:43.299: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 09:39:20.303: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 09:38:29.310: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 09:38:18.312: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 09:37:45.117: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 09:25:19.189: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 48:5d:60:cd:97:3b
*apfReceiveTask: Oct 26 09:17:48.829: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 09:03:48.701: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 09:00:08.720: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 08:59:53.522: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 08:57:54.926: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M5 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 08:56:09.946: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 08:47:50.190: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92

--More-- or (q)uit
*dot1xMsgTask: Oct 26 08:43:19.018: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*apfReceiveTask: Oct 26 08:42:49.808: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 08:39:51.435: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 08:17:06.559: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:16:32.964: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:16:27.965: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:15:36.358: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:15:07.963: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:14:20.770: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 08:14:07.172: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 08:10:59.387: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:09:38.399: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*apfReceiveTask: Oct 26 08:08:39.608: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 08:06:35.012: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 08:05:44.006: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 07:58:21.046: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 07:55:58.653: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 07:54:10.270: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*DHCP Socket Task: Oct 26 07:35:43.660: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 07:12:14.498: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 07:11:55.101: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*osapi_ping_rx: Oct 26 06:58:12.257: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 06:53:40.198: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d6:1a:dc

--More-- or (q)uit
*dot1xMsgTask: Oct 26 06:50:47.010: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 54:e6:fc:d5:e5:9d
*apfReceiveTask: Oct 26 06:48:04.235: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 06:37:59.285: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:12
*dot1xMsgTask: Oct 26 06:33:59.707: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 54:e6:fc:d5:e5:9d
*osapi_ping_rx: Oct 26 06:26:23.330: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 06:14:20.602: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*apfReceiveTask: Oct 26 06:14:10.403: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on i
nterface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 06:13:11.612: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:15:70:4b:87:f0
*dot1xMsgTask: Oct 26 06:13:06.813: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*osapi_ping_rx: Oct 26 06:09:20.821: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:09:02.117: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:08:41.947: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:07:51.453: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:07:09.100: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:06:42.847: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:06:13.601: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:05:29.849: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:05:03.796: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:04:19.608: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:03:45.292: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 06:01:43.214: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 05:59:01.746: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 05:58:39.551: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.

--More-- or (q)uit
*dot1xMsgTask: Oct 26 05:43:49.368: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 05:43:29.171: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*dot1xMsgTask: Oct 26 05:43:04.575: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*dot1xMsgTask: Oct 26 05:42:30.580: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*dot1xMsgTask: Oct 26 05:42:30.380: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*osapi_ping_rx: Oct 26 05:41:06.247: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*DHCP Socket Task: Oct 26 05:40:43.930: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 05:38:21.989: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 0c:96:bf:e2:d4:98
*osapi_ping_rx: Oct 26 05:37:48.511: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 05:37:11.206: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 05:36:26.773: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 05:30:51.043: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*DHCP Socket Task: Oct 26 05:30:40.157: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*osapi_ping_rx: Oct 26 05:29:15.982: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 05:29:11.244: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*osapi_ping_rx: Oct 26 05:28:39.698: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 05:28:15.453: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:15:70:4b:87:f0
*dot1xMsgTask: Oct 26 05:28:07.054: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*DHCP Socket Task: Oct 26 05:27:54.302: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*osapi_ping_rx: Oct 26 05:26:13.360: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 05:19:57.101: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 05:19:53.301: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*apfReceiveTask: Oct 26 05:19:40.363: %RRM-3-RRM_LOGMSG: rrmChanUtils.c:290 RRM LOG: Airewave Director: Could not find v
alid channel lists for 802.11bg

--More-- or (q)uit
*spamReceiveTask: Oct 26 05:18:40.898: %CAPWAP-3-ECHO_ERR: capwap_ac_sm.c:5430 Did not receive heartbeat reply; AP: 00:2
6:52:db:83:70
*apfReceiveTask: Oct 26 05:16:58.113: %RRM-3-RRM_LOGMSG: rrmChanUtils.c:290 RRM LOG: Airewave Director: Could not find v
alid channel lists for 802.11bg
*DHCP Socket Task: Oct 26 05:14:43.878: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*emWeb: Oct 26 05:14:22.950: %LOG-3-Q_IND: spam_lrad.c:23053 Unable to find WLAN 4 to be deleted; AP 00:26:52:db:80:10
*spamReceiveTask: Oct 26 05:14:22.947: %LWAPP-3-WLAN_ERR2: spam_lrad.c:23053 Unable to find WLAN 4 to be deleted; AP 00:
26:52:db:80:10
*spamReceiveTask: Oct 26 05:14:22.947: %LOG-3-Q_IND: spam_lrad.c:23053 Unable to find WLAN 4 to be deleted; AP 00:26:52:
db:7b:20
*spamReceiveTask: Oct 26 05:14:22.946: %LWAPP-3-WLAN_ERR2: spam_lrad.c:23053 Unable to find WLAN 4 to be deleted; AP 00:
26:52:db:7b:20
*apfReceiveTask: Oct 26 05:04:23.513: %RRM-3-RRM_LOGMSG: rrmChanUtils.c:290 RRM LOG: Airewave Director: Could not find v
alid channel lists for 802.11bg
*osapi_ping_rx: Oct 26 05:04:09.632: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:56:47.768: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*apfReceiveTask: Oct 26 04:55:45.157: %RRM-3-RRM_LOGMSG: rrmChanUtils.c:290 RRM LOG: Airewave Director: Could not find v
alid channel lists for 802.11bg
*dot1xMsgTask: Oct 26 04:53:19.845: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 30:f3:1d:72:ca:22
*dot1xMsgTask: Oct 26 04:46:59.077: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 4c:0b:3a:dd:24:c0
*dot1xMsgTask: Oct 26 04:38:21.327: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*osapi_ping_rx: Oct 26 04:33:54.534: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:33:28.349: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:33:08.161: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:31:27.246: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:31:01.927: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 04:30:58.367: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 04:30:50.569: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 04:30:35.171: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*dot1xMsgTask: Oct 26 04:28:01.380: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92

--More-- or (q)uit
*DHCP Socket Task: Oct 26 04:26:27.016: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 04:25:44.988: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*DHCP Socket Task: Oct 26 04:25:07.523: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 04:23:24.996: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*DHCP Socket Task: Oct 26 04:23:18.973: %SIM-3-DHCP_SERVER_NO_REPLY: sim_interface.c:1039 Failed to get DHCP response on
interface 'management'. Marking interface dirty.
*dot1xMsgTask: Oct 26 04:22:48.602: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:ce:c2:92
*osapi_ping_rx: Oct 26 04:19:10.730: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.

*osapi_ping_rx: Oct 26 04:18:17.233: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 04:16:05.049: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 4c:0b:3a:dd:24:c0
*emWeb: Oct 26 04:13:16.823: %LOG-3-Q_IND: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:26:52:db:83:70
*spamReceiveTask: Oct 26 04:13:16.815: %LWAPP-3-WLAN_ERR2: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:
26:52:db:83:70
*spamReceiveTask: Oct 26 04:13:16.815: %LOG-3-Q_IND: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:26:52:
db:80:10
*spamReceiveTask: Oct 26 04:13:16.814: %LWAPP-3-WLAN_ERR2: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:
26:52:db:80:10
*spamReceiveTask: Oct 26 04:13:16.814: %LOG-3-Q_IND: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:26:52:
db:7b:20
*spamReceiveTask: Oct 26 04:13:16.813: %LWAPP-3-WLAN_ERR2: spam_lrad.c:40816 Unable to find WLAN 2 to be deleted; AP 00:
26:52:db:7b:20
*osapi_ping_rx: Oct 26 04:07:29.513: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*osapi_ping_rx: Oct 26 04:06:19.951: %OSAPI-3-TASK_SET_TICKLE: osapi_task.c:3914 Task osapi_ping_rx requesting 5 second
timer. Minimum is 20.Setting to 20.
*dot1xMsgTask: Oct 26 04:04:49.710: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 04:03:52.705: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M3 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*Dot1x_NW_MsgTask_0: Oct 26 04:03:49.575: %DOT1X-3-INVALID_REPLAY_CTR: 1x_eapkey.c:361 Invalid replay counter from clien
t 00:a0:f8:d7:c4:08 - got 00 00 00 00 00 00 00 02, expected 00 00 00 00 00 00 00 01
*dot1xMsgTask: Oct 26 04:03:46.106: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 04:03:42.506: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08
*dot1xMsgTask: Oct 26 04:03:38.907: %DOT1X-3-MAX_EAPOL_KEY_RETRANS: 1x_ptsm.c:444 Max EAPOL-key M1 retransmissions excee
ded for client 00:a0:f8:d7:c4:08

Show wlan :

(Cisco Controller) >show wlan 2

WLAN Identifier.................................. 2
Profile Name..................................... mynet
Network Name (SSID).............................. mynet
Status........................................... Enabled
MAC Filtering.................................... Disabled
Broadcast SSID................................... Enabled
AAA Policy Override.............................. Disabled
Network Admission Control

Radius-NAC State............................... Disabled
SNMP-NAC State................................. Disabled
Quarantine VLAN................................ 0
Maximum number of Associated Clients............. 0
Number of Active Clients......................... 3
Exclusionlist Timeout............................ 60 seconds
Session Timeout.................................. 1800 seconds
CHD per WLAN..................................... Enabled
Webauth DHCP exclusion........................... Disabled
Interface........................................ management
Multicast Interface.............................. Not Configured

--More-- or (q)uit
WLAN ACL......................................... unconfigured
DHCP Server...................................... Default
DHCP Address Assignment Required................. Disabled
Static IP client tunneling....................... Disabled
Quality of Service............................... Silver (best effort)
Scan Defer Priority.............................. 4,5,6
Scan Defer Time.................................. 100 milliseconds
WMM.............................................. Allowed
WMM UAPSD Compliant Client Support............... Disabled
Media Stream Multicast-direct.................... Disabled
CCX - AironetIe Support.......................... Enabled
CCX - Gratuitous ProbeResponse (GPR)............. Disabled
CCX - Diagnostics Channel Capability............. Disabled
Dot11-Phone Mode (7920).......................... Disabled
Wired Protocol................................... None
IPv6 Support..................................... Disabled
Passive Client Feature........................... Disabled
Peer-to-Peer Blocking Action..................... Disabled
Radio Policy..................................... All
DTIM period for 802.11a radio.................... 1
DTIM period for 802.11b radio.................... 1
Radius Servers
Authentication................................ Global Servers

--More-- or (q)uit
Accounting.................................... Global Servers
Dynamic Interface............................. Disabled
Local EAP Authentication......................... Disabled
Security

802.11 Authentication:........................ Open System
Static WEP Keys............................... Disabled
802.1X........................................ Disabled
Wi-Fi Protected Access (WPA/WPA2)............. Enabled
WPA (SSN IE)............................... Enabled
TKIP Cipher............................. Enabled
AES Cipher.............................. Enabled
WPA2 (RSN IE).............................. Enabled
TKIP Cipher............................. Enabled
AES Cipher.............................. Enabled
Auth Key Management
802.1x.................................. Disabled
PSK..................................... Enabled
CCKM.................................... Disabled
FT(802.11r)............................. Disabled
FT-PSK(802.11r)......................... Disabled
FT Reassociation Timeout......................... 20
FT Over-The-Air mode............................. Enabled

--More-- or (q)uit
FT Over-The-Ds mode.............................. Enabled
CCKM tsf Tolerance............................... 1000
CKIP ......................................... Disabled
Web Based Authentication...................... Disabled
Web-Passthrough............................... Disabled
Conditional Web Redirect...................... Disabled
Splash-Page Web Redirect...................... Disabled
Auto Anchor................................... Disabled
H-REAP Local Switching........................ Disabled
H-REAP Local Authentication................... Disabled
H-REAP Learn IP Address....................... Enabled
Client MFP.................................... Optional
Tkip MIC Countermeasure Hold-down Timer....... 60
Call Snooping.................................... Disabled
Roamed Call Re-Anchor Policy..................... Disabled
SIP CAC Fail Send-486-Busy Policy................ Enabled
SIP CAC Fail Send Dis-Association Policy......... Disabled
Band Select...................................... Disabled
Load Balancing................................... Disabled

Mobility Anchor List
WLAN ID IP Address Status
------- --------------- ------

--More-- or (q)uit

(Cisco Controller) >

ali aqrabawi · ‎10-26-2014

1) it's not recommended to have both WPA/WPA2 AES/TKIP both enabled ,

i suggest to enable only WPA2/AES , if all the client support AES .

2)we can see retransmissions (we can say that this is the cause of the issue, but it still an issue).

go to wireless tab --> 802.11a -->network , make the 11 as mandatory , and below the 11 disabled , and above as supported .

3)issue this command in the WLC CLI :

config advance eap bcast-key-interval 86400 , to increase the expiry duration for the key .

config advanced eap eapol-key-retries 4 , to increase the reties .

4)make sure that the clients adapters are upgraded to the latest versions ,

5)try to get debug client <MAC addr> , along with show client detail <client mac>, when the issue occur.

acazarkov · ‎10-26-2014

when I change data rates wireless tab --> 802.11a -->network , make the 11 as mandatory , and below the 11 disabled , and above as supported I've lost my all clients .

changing WPA+WPA2 parameters ist'n help .

acazarkov · ‎10-26-2014

debug client

Cisco Controller) >*apfMsConnTask_0: Oct 27 02:21:15.410: 48:5d:60:cd:97:3b Association received from mobile on AP 00:2
6:52:db:83:70
*apfMsConnTask_0: Oct 27 02:21:15.410: 48:5d:60:cd:97:3b Deleting client immediately since WLAN has changed
*apfMsConnTask_0: Oct 27 02:21:15.410: 48:5d:60:cd:97:3b Scheduling deletion of Mobile Station: (callerId: 50) in 1 sec
onds
*osapiBsnTimer: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b apfMsExpireCallback (apf_ms.c:609) Expiring Mobile!
*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b apfMsExpireMobileStation (apf_ms.c:5022) Changing state for mobi
le 48:5d:60:cd:97:3b on AP 00:26:52:db:83:70 from Associated to Disassociated

*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b Sent Deauthenticate to mobile on BSSID 00:26:52:db:83:70 slot 0(
caller apf_ms.c:5114)
*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b Deleting the PMK cache when de-authenticating the client.
*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b Global PMK Cache deletion failed.
*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b apfMsAssoStateDec
*apfReceiveTask: Oct 27 02:21:16.312: 48:5d:60:cd:97:3b apfMsExpireMobileStation (apf_ms.c:5152) Changing state for mobi
le 48:5d:60:cd:97:3b on AP 00:26:52:db:83:70 from Disassociated to Idle

*apfReceiveTask: Oct 27 02:21:16.313: 48:5d:60:cd:97:3b pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0
.
*apfReceiveTask: Oct 27 02:21:16.313: 48:5d:60:cd:97:3b 192.168.109.123 RUN (20) Deleted mobile LWAPP rule on AP [00:26:
52:db:83:70]
*apfReceiveTask: Oct 27 02:21:16.313: 48:5d:60:cd:97:3b apfMsRunStateDec
*apfReceiveTask: Oct 27 02:21:16.313: 48:5d:60:cd:97:3b apfMs1xStateDec
*apfReceiveTask: Oct 27 02:21:16.313: 48:5d:60:cd:97:3b Deleting mobile on AP 00:26:52:db:83:70(0)
*pemReceiveTask: Oct 27 02:21:16.327: 48:5d:60:cd:97:3b 192.168.109.123 Removed NPU entry.
*spamReceiveTask: Oct 27 02:21:35.535: 48:5d:60:cd:97:3b Received Idle-Timeout from AP 00:26:52:db:83:70, slot 0 for STA
48:5d:60:cd:97:3b
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b Adding mobile on LWAPP AP 00:26:52:db:83:70(0)
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b Association received from mobile on AP 00:26:52:db:83:70
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b 0.0.0.0 START (0) Changing ACL 'none' (ACL ID 0) ===> 'none' (A
CL ID 255) --- (caller apf_policy.c:1633)
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b Applying site-specific IPv6 override for station 48:5d:60:cd:97
:3b - vapId 1, site 'default-group', interface 'management'
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b Applying IPv6 Interface Policy for station 48:5d:60:cd:97:3b -
vlan 0, interface id 0, interface 'management'
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b STA - rates (8): 130 132 139 150 12 18 24 36 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Oct 27 02:22:16.646: 48:5d:60:cd:97:3b STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0
0 0
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b Processing RSN IE type 48, length 20 for mobile 48:5d:60:cd:97:
3b
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state AUTH
CHECK (2)

*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state
8021X_REQD (3)

*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b 0.0.0.0 8021X_REQD (3) DHCP Not required on AP 00:26:52:db:83:7
0 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:26:52
:db:83:70 vapId 1 apVapId 1
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b apfMsAssoStateInc
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b apfPemAddUser2 (apf_policy.c:223) Changing state for mobile 48:
5d:60:cd:97:3b on AP 00:26:52:db:83:70 from Idle to Associated

*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b Scheduling deletion of Mobile Station: (callerId: 49) in 1800
seconds
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b Sending Assoc Response to station on BSSID 00:26:52:db:83:70 (s
tatus 0) ApVapId 1 Slot 0
*apfMsConnTask_0: Oct 27 02:22:16.647: 48:5d:60:cd:97:3b apfProcessAssocReq (apf_80211.c:5284) Changing state for mobile
48:5d:60:cd:97:3b on AP 00:26:52:db:83:70 from Associated to Associated

*spamReceiveTask: Oct 27 02:22:16.649: 48:5d:60:cd:97:3b Sent 1x initiate message to multi thread task for mobile 48:5d:
60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.650: 48:5d:60:cd:97:3b Creating a PKC PMKID Cache entry for station 48:5d:60:cd:97:
3b (RSN 2)
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.650: 48:5d:60:cd:97:3b Adding BSSID 00:26:52:db:83:70 to PMKID cache for station 48
:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.650: New PMKID: (16)

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.650: [0000] b1 ae 8c 4f 42 23 68 d5 00 3d 95 17 5b be 71 8b

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: 48:5d:60:cd:97:3b Initiating RSN PSK to mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: 48:5d:60:cd:97:3b dot1x - moving mobile 48:5d:60:cd:97:3b into Force Auth stat
e
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: 48:5d:60:cd:97:3b Skipping EAP-Success to mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: Including PMKID in M1 (16)

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: [0000] b1 ae 8c 4f 42 23 68 d5 00 3d 95 17 5b be 71 8b

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: 48:5d:60:cd:97:3b Starting key exchange to mobile 48:5d:60:cd:97:3b, data pack
ets will be dropped
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.651: 48:5d:60:cd:97:3b Sending EAPOL-Key Message to mobile 48:5d:60:cd:97:3b
stat
e INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.654: 48:5d:60:cd:97:3b Received EAPOL-Key from mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.654: 48:5d:60:cd:97:3b Ignoring invalid EAPOL version (1) in EAPOL-key message from
mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.654: 48:5d:60:cd:97:3b Received EAPOL-key in PTK_START state (message 2) from mobil
e 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.655: 48:5d:60:cd:97:3b Stopping retransmission timer for mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.655: 48:5d:60:cd:97:3b Sending EAPOL-Key Message to mobile 48:5d:60:cd:97:3b
stat
e PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.658: 48:5d:60:cd:97:3b Received EAPOL-Key from mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.658: 48:5d:60:cd:97:3b Ignoring invalid EAPOL version (1) in EAPOL-key message from
mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.658: 48:5d:60:cd:97:3b Received EAPOL-key in PTKINITNEGOTIATING state (message 4) f
rom mobile 48:5d:60:cd:97:3b
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.658: 48:5d:60:cd:97:3b apfMs1xStateInc
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.659: 48:5d:60:cd:97:3b 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) la
st state L2AUTHCOMPLETE (4)

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.659: 48:5d:60:cd:97:3b 0.0.0.0 L2AUTHCOMPLETE (4) DHCP Not required on AP 00:26:52:
db:83:70 vapId 1 apVapId 1for this client
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.659: 48:5d:60:cd:97:3b Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 0
0:26:52:db:83:70 vapId 1 apVapId 1
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) las
t state DHCP_REQD (7)

*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4838, Adding TMP rule
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:26:52:db:83:70, slot 0, interface = 1, QOS = 0
ACL Id = 255, Jumbo Fr
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0,
DSCP = 0, TokenID = 1506 IPv6 Vlan = 0, IPv6 intf id = 0
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.660: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL
ID 255)
*Dot1x_NW_MsgTask_0: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b Stopping retransmission timer for mobile 48:5d:60:cd:97:3b
*apfReceiveTask: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to M
obility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 4499, Adding TMP rule
*apfReceiveTask: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 00:26:52:db:83:70, slot 0, interface = 1, QOS = 0
ACL Id = 255, Jumbo
*apfReceiveTask: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP
= 0, TokenID = 1506 IPv6 Vlan = 0, IPv6 intf id = 0
*apfReceiveTask: Oct 27 02:22:16.661: 48:5d:60:cd:97:3b 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (ACL ID 2
55)
*pemReceiveTask: Oct 27 02:22:16.675: 48:5d:60:cd:97:3b 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*pemReceiveTask: Oct 27 02:22:16.675: 48:5d:60:cd:97:3b Sent an XID frame
*dtlArpTask: Oct 27 02:22:16.678: 48:5d:60:cd:97:3b Static IP client associated to interface management which can suppor
t client subnet.
*pemReceiveTask: Oct 27 02:22:16.689: 48:5d:60:cd:97:3b 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*dtlArpTask: Oct 27 02:22:16.689: 48:5d:60:cd:97:3b apfMsRunStateInc
*dtlArpTask: Oct 27 02:22:16.689: 48:5d:60:cd:97:3b 192.168.109.123 DHCP_REQD (7) Change state to RUN (20) last state RU
N (20)

*dtlArpTask: Oct 27 02:22:16.689: 48:5d:60:cd:97:3b 192.168.109.123 RUN (20) Reached PLUMBFASTPATH: from line 5359
*dtlArpTask: Oct 27 02:22:16.690: 48:5d:60:cd:97:3b 192.168.109.123 RUN (20) Replacing Fast Path rule
type = Airespace AP Client
on AP 00:26:52:db:83:70, slot 0, interface = 1, QOS = 0
ACL Id = 255, Jumbo Frames =
*dtlArpTask: Oct 27 02:22:16.690: 48:5d:60:cd:97:3b 192.168.109.123 RUN (20) Fast Path rule (contd...) 802.1P = 0, DSCP
= 0, TokenID = 1506 IPv6 Vlan = 0, IPv6 intf id = 0
*dtlArpTask: Oct 27 02:22:16.690: 48:5d:60:cd:97:3b 192.168.109.123 RUN (20) Successfully plumbed mobile rule (ACL ID 25
5)
*dtlArpTask: Oct 27 02:22:16.690: 48:5d:60:cd:97:3b Assigning Address 192.168.109.123 to mobile
*pemReceiveTask: Oct 27 02:22:16.691: 48:5d:60:cd:97:3b Sent an XID frame
*apfOrphanSocketTask: Oct 27 02:22:16.691: 48:5d:60:cd:97:3b Orphan Packet from DS - IP 192.168.109.123
*pemReceiveTask: Oct 27 02:22:16.704: 48:5d:60:cd:97:3b 192.168.109.123 Added NPU entry of type 1, dtlFlags 0x0
*pemReceiveTask: Oct 27 02:22:16.704: 48:5d:60:cd:97:3b Sending a gratuitous ARP for 192.168.109.123, VLAN Id 0
*DHCP Socket Task: Oct 27 02:22:21.578: 48:5d:60:cd:97:3b DHCP received op BOOTREQUEST (1) (len 324,vlan 0, port 1, enca
p 0xec03)
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP selecting relay 1 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 0.0.0.0 VLAN: 0
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP selected relay 1 - 192.168.109.6 (local address 192.168.1
09.25, gateway 192.168.109.6, VLAN 0, port 1)
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 5, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.579: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 192.168.109.25
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP requested ip: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP sending REQUEST to 192.168.109.6 (len 362, port 1, vlan 0
)
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP selecting relay 2 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 192.168.109.25 VLAN: 0
*DHCP Socket Task: Oct 27 02:22:21.580: 48:5d:60:cd:97:3b DHCP selected relay 2 - 172.16.173.1 (local address 192.168.10
9.25, gateway 192.168.109.7, VLAN 0, port 1)
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 2
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 5, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 192.168.109.25
*DHCP Socket Task: Oct 27 02:22:21.581: 48:5d:60:cd:97:3b DHCP requested ip: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP sending REQUEST to 192.168.109.7 (len 362, port 1, vlan 0
)
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP received op BOOTREQUEST (1) (len 324,vlan 0, port 1, enca
p 0xec03)
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP selecting relay 1 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 192.168.109.25 VLAN: 0
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP selected relay 1 - 192.168.109.6 (local address 192.168.1
09.25, gateway 192.168.109.6, VLAN 0, port 1)
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Oct 27 02:22:21.582: 48:5d:60:cd:97:3b DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 1
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 5, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 192.168.109.25
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP requested ip: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.583: 48:5d:60:cd:97:3b DHCP sending REQUEST to 192.168.109.6 (len 362, port 1, vlan 0
)
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP selecting relay 2 - control block settings:
dhcpServer: 0.0.0.0, dhcpNetmask: 0.0.0.0,
dhcpGateway: 0.0.0.0, dhcpRelay: 192.168.109.25 VLAN: 0
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP selected relay 2 - 172.16.173.1 (local address 192.168.10
9.25, gateway 192.168.109.7, VLAN 0, port 1)
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP transmitting DHCP REQUEST (3)
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP op: BOOTREQUEST, htype: Ethernet, hlen: 6, hops: 2
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 5, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.584: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 192.168.109.25
*DHCP Socket Task: Oct 27 02:22:21.585: 48:5d:60:cd:97:3b DHCP requested ip: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.585: 48:5d:60:cd:97:3b DHCP sending REQUEST to 192.168.109.7 (len 362, port 1, vlan 0
)
*DHCP Socket Task: Oct 27 02:22:21.585: 48:5d:60:cd:97:3b DHCP received op BOOTREPLY (2) (len 309,vlan 0, port 1, encap
0xec00)
*DHCP Socket Task: Oct 27 02:22:21.585: 48:5d:60:cd:97:3b DHCP setting server from ACK (server 192.168.109.6, yiaddr 192
.168.109.123)
*DHCP Socket Task: Oct 27 02:22:21.585: 48:5d:60:cd:97:3b DHCP sending REPLY to STA (len 414, port 1, vlan 0)
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP transmitting DHCP ACK (5)
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 0, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP server id: 1.1.1.1 rcvd server id: 192.168.109.6
*DHCP Socket Task: Oct 27 02:22:21.586: 48:5d:60:cd:97:3b DHCP received op BOOTREPLY (2) (len 309,vlan 0, port 1, encap
0xec00)
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP sending REPLY to STA (len 414, port 1, vlan 0)
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP transmitting DHCP ACK (5)
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP xid: 0x96e49b08 (2531564296), secs: 0, flags: 80
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP chaddr: 48:5d:60:cd:97:3b
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP ciaddr: 0.0.0.0, yiaddr: 192.168.109.123
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP siaddr: 0.0.0.0, giaddr: 0.0.0.0
*DHCP Socket Task: Oct 27 02:22:21.587: 48:5d:60:cd:97:3b DHCP server id: 1.1.1.1 rcvd server id: 192.168.109.6

acazarkov · ‎10-26-2014

(Cisco Controller) >debug client 00:a0:f8:d7:c4:08

(Cisco Controller) >*DHCP Socket Task: Oct 26 16:10:44.649: 00:a0:f8:d7:c4:12 Failed to get response for 3 dhcp attempts
from client.Total DHCP failed count for the interface management : 8
*spamReceiveTask: Oct 26 16:20:59.243: 00:a0:f8:d7:c4:08 Received Idle-Timeout from AP 00:26:52:db:83:70, slot 0 for STA
00:a0:f8:d7:c4:08
*spamReceiveTask: Oct 26 16:20:59.243: 00:a0:f8:d7:c4:08 apfMsDeleteByMscb Scheduling mobile for deletion with deleteRea
son 4, reasonCode 4

*spamReceiveTask: Oct 26 16:20:59.243: 00:a0:f8:d7:c4:08 Scheduling deletion of Mobile Station: (callerId: 30) in 1 sec
onds
*osapiBsnTimer: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 apfMsExpireCallback (apf_ms.c:609) Expiring Mobile!
*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 apfMsExpireMobileStation (apf_ms.c:5022) Changing state for mobi
le 00:a0:f8:d7:c4:08 on AP 00:26:52:db:83:70 from Associated to Disassociated

*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 Sent Deauthenticate to mobile on BSSID 00:26:52:db:83:70 slot 0(
caller apf_ms.c:5114)
*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 Deleting the PMK cache when de-authenticating the client.
*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 Global PMK Cache deletion failed.
*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 apfMsAssoStateDec
*apfReceiveTask: Oct 26 16:21:00.170: 00:a0:f8:d7:c4:08 apfMsExpireMobileStation (apf_ms.c:5152) Changing state for mobi
le 00:a0:f8:d7:c4:08 on AP 00:26:52:db:83:70 from Disassociated to Idle

*apfReceiveTask: Oct 26 16:21:00.171: 00:a0:f8:d7:c4:08 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0
.
*apfReceiveTask: Oct 26 16:21:00.171: 00:a0:f8:d7:c4:08 192.168.109.205 RUN (20) Deleted mobile LWAPP rule on AP [00:26:
52:db:83:70]
*apfReceiveTask: Oct 26 16:21:00.171: 00:a0:f8:d7:c4:08 apfMsRunStateDec
*apfReceiveTask: Oct 26 16:21:00.171: 00:a0:f8:d7:c4:08 apfMs1xStateDec
*apfReceiveTask: Oct 26 16:21:00.171: 00:a0:f8:d7:c4:08 Deleting mobile on AP 00:26:52:db:83:70(0)

ali aqrabawi · ‎10-26-2014

in this debugs the client got disconnected due to idle timeout ,

then i strongly recommend to disable idle timeout /session timeout/client exclusion

acazarkov · ‎11-25-2014

Creating vlan I solve the problem

acazarkov · ‎12-24-2014

Hi,

creating Vlan I have solve the problem.