AP2802的ME模式客户端掉线问题

[CSCO12258296]

最近使用了2802I的AP做成ME模式，IOS是8.5.130，只有一个AP。
客户端是MOXA的AWK-1131A系列，模式是Client，连接了PLC，工作模式类似于思科的工作组网桥（WGB)。
采用的加密方式是WAP2/AES。
问题点：
部分客户端连接AP，每隔138750ms±50ms，会被AP强制中断连接。（从无线控制器DEBUG的结果和moxa上的日志查看确定的）
查看无线控制器里的客户端状态（通过show client summary)，客户端的Auth是NO，通过show client detail mac:xx:xx 的Policy Manager State状态是DHCP_REQD。
而没有断线的客户端Auth是Yes，Policy Manager State是Run。
断线客户端不是固定一台，可能是今天这一台，明天另一台。
补充：假如用的是普通的无线路由器（网件）是没有发生这个情况的。
用手机连接2802的AP也不会发生异常。
请问有什么可能的原因？

[HaifengLi · Accepted solution]

本帖最后由 haifeli 于 2019-11-28 22:13 编辑
可以尝试以下几种方法，看能否解决问题
1. 使用DHCP获取IP地址
2. 查看是否开启了FlexConnect Learn IP Address，关闭此功能
grep include "FlexConnect Learn IP Address" "show wlan "

configwlan flexconnect learn-ipaddr disable

3.在WLAN中开启AAA Overide和MAC Filtering, 并将客户端加入到MAC Filtering列表中

4. 查看是否开启DHCP Address Assignment Required，关闭此功能

[HaifengLi]

DHCP_REQD表明卡在DHCP阶段，可以查看一下DHCP服务器日志

[CSCO12258296]

没有搭建DHCP服务器，MOXA配置的是静态IP

[HaifengLi]

debug client 贴出来看一下

[CSCO12258296]

这是前几天的DEBUG信息，mac和IP等信息进行里替换处理。
================================================================
apfReceiveTask: Nov 25 11:49:18.309: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*Dot1x_NW_MsgTask_0: Nov 25 11:51:05.187: Sending Mobile Announce for client 00:90:e8:78:12:34
*apfReceiveTask: Nov 25 11:51:17.043: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) DHCP Policy timeout. Number of DHCP Discover 0, DHCP Request 0 from client
*apfReceiveTask: Nov 25 11:51:17.043: 00:90:e8:12:34:56 Interface Group was NULL.Number of DHCP Discovery 0 from client
*apfReceiveTask: Nov 25 11:51:17.043: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Pem timed out, Try to delete client in 10 secs.
*apfReceiveTask: Nov 25 11:51:17.043: 00:90:e8:12:34:56 Scheduling deletion of Mobile Station: (callerId: 12) in 10 seconds
*osapiBsnTimer: Nov 25 11:51:26.960: 00:90:e8:12:34:56 apfMsExpireCallback (apf_ms.c:650) Expiring Mobile!
*apfReceiveTask: Nov 25 11:51:26.960: 00:90:e8:12:34:56 apfMsExpireMobileStation (apf_ms.c:7890) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Associated to Disassociated
*apfReceiveTask: Nov 25 11:51:26.961: 00:90:e8:12:34:56 Scheduling deletion of Mobile Station: (callerId: 45) in 10 seconds
*osapiBsnTimer: Nov 25 11:51:36.878: 00:90:e8:12:34:56 apfMsExpireCallback (apf_ms.c:650) Expiring Mobile!
*apfReceiveTask: Nov 25 11:51:36.878: 00:90:e8:12:34:56 Succesfully freed AID 55, slot 0 on AP 74:88:bb:12:34:56, #client on this slot 0
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 apfSendDisAssocMsgDebug (apf_80211.c:3831) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Disassociated to Disassociated
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Sent Disassociate to mobile on AP 74:88:bb:12:34:56-0 on BSSID 74:88:bb:12:34:56(reason 1, caller apf_ms.c:7974)
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Resetting MSCB PMK Cache Entry @index 0 for station 00:90:e8:12:34:56
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Removing BSSID 74:88:bb:12:34:56 from PMKID cache of station 00:90:e8:12:34:56
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Setting active key cache index 0 ---> 8
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Deleting the PMK cache when de-authenticating the client.
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Global PMK Cache deletion failed.
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Sent Deauthenticate to mobile on BSSID 74:88:bb:12:34:56 slot 0(caller apf_ms.c:7982)
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 apfMsAssoStateDec
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 apfMsWepPskStateDec
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 apfMsExpireMobileStation (apf_ms.c:8040) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Disassociated to Idle
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 the value of url acl preserve flag is 0 for mobile 00:90:e8:12:34:56 (caller pem_api.c:4932)
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 0.0.0.0 START (0) Deleted mobile LWAPP rule on AP [74:88:bb:12:34:56]
*apfReceiveTask: Nov 25 11:51:36.879: 00:90:e8:12:34:56 Deleting mobile on AP 74:88:bb:12:34:56(0)
*pemReceiveTask: Nov 25 11:51:36.947: 00:90:e8:12:34:56 0.0.0.0 Removed NPU entry.
*spamApTask0: Nov 25 11:51:36.948: 00:90:e8:12:34:56 Setting DEL_MOBILE (seqno 0, action 6) ack state for STA on AP 74:88:bb:12:34:56
*spamApTask0: Nov 25 11:51:36.948: 00:90:e8:12:34:56 Delete Mobile request on slot 0 sent to the AP 74:88:bb:12:34:56 IP: 192.168.100.2:5248
*apfReceiveTask: Nov 25 11:51:36.957: 00:90:e8:12:34:56 apf_ms.c:5532 Clearing the SGT 0 of mobile
*spamApTask0: Nov 25 11:51:36.958: 00:90:e8:12:34:56 apfUpdateDeleteAckInMscb (apf_api.c:54425) Expiring Mobile!
*Dot1x_NW_MsgTask_0: Nov 25 11:51:47.105: Sending Mobile Announce for client 00:90:e8:56:78:90
*Dot1x_NW_MsgTask_0: Nov 25 11:51:47.702: Sending Mobile Announce for client 00:90:e8:90:12:34
*apfReceiveTask: Nov 25 11:51:49.877: 00:90:e8:12:34:56 Received management frame ASSOCIATION REQUEST on BSSID 74:88:bb:12:34:56 destination addr 74:88:bb:12:34:56
*apfMsConnTask_0: Nov 25 11:51:49.878: 00:90:e8:12:34:56 Processing assoc-req station:00:90:e8:12:34:56 AP:74:88:bb:12:34:56-00 ssid : ABCDEFG thread:8b53e80
*apfMsConnTask_0: Nov 25 11:51:49.878: 00:90:e8:12:34:56 apfCreateMobileStationEntryWrapper (apf_ms.c:4434) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Idle to Idle
*apfMsConnTask_0: Nov 25 11:51:49.878: 00:90:e8:12:34:56 Adding mobile on LWAPP AP 74:88:bb:12:34:56(0)
*apfMsConnTask_0: Nov 25 11:51:49.878: 00:90:e8:12:34:56 Created Acct-Session-ID (5ddb4fd5/00:90:e8:12:34:56/339) for the mobile
*apfMsConnTask_0: Nov 25 11:51:49.878: 00:90:e8:12:34:56 Client AVC Roaming context transfer needed? NO
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Setting RTTS enabled to 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Association received from mobile on BSSID 74:88:bb:12:34:56 AP ABCDEFG-AP01
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Station: 00:90:e8:12:34:56 trying to join WLAN with RSSI -29. Checking for XOR roam conditions on AP: 74:88:bb:12:34:56 Slot: 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Station: 00:90:e8:12:34:56 is associating to AP 74:88:bb:12:34:56 which is not XOR roam capable
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Global 200 Clients are allowed to AP radio
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Max Client Trap Threshold: 0 cur: 2
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 override for default ap group, marking intgrp NULL
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Not re-applying interface policy for local switching Client
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3140)
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 0.0.0.0 START (0) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3160)
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3181)
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Values before applying NASID - interfacetype:0, ovrd:0, mscb nasid:, interface nasid:, APgrpset:0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Check before Setting the NAS Id to WLAN specific Id ''
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 apf_policy.c:2454 Assigning the SGT 0 to mobile (earlier sgt 0)
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 In processSsidIE:6998 setting Central switched to FALSE
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Set Client MSCB as Central Association Disabled
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Applying site-specific Local Bridging override for station 00:90:e8:12:34:56 - vapId 1, site 'default-group', interface 'management'
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 Applying Local Bridging Interface Policy for station 00:90:e8:12:34:56 - vlan 0, interface id 0, interface 'management', nasId:''
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 STA - rates (8): 150 12 18 24 36 48 72 96 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 STA - rates (9): 150 12 18 24 36 48 72 96 108 0 0 0 0 0 0 0
*apfMsConnTask_0: Nov 25 11:51:49.879: 00:90:e8:12:34:56 extSuppRates statusCode is 0 and gotExtSuppRatesElement is 1
*apfMsConnTask_0: Nov 25 11:51:49.880: RSNIE in Assoc. Req.: (20)
*apfMsConnTask_0: Nov 25 11:51:49.880: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f
*apfMsConnTask_0: Nov 25 11:51:49.880: [0016] ac 02 00 00
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Processing RSN IE type 48, length 20 for mobile 00:90:e8:12:34:56
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Selected Unicast cipher CCMP128 for client device
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Received 802.11i PSK key management suite, enabling Authentication
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 RSN Capabilities: 0
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 non-11w Capable mobile
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Received RSN IE with 0 PMKIDs from mobile 00:90:e8:12:34:56
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Assigning flex webauth ACL ID :65535 for vlan : 1
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Updating AID for REAP AP Client 74:88:bb:12:34:56 - AID ===> 58
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 apfVapSecurity=0x40004000 L2=16384 SkipWeb=0
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 AuthenticationRequired = 1
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Encryption policy is set to 0x80000001
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 0.0.0.0 8021X_REQD (3) DHCP required on AP 74:88:bb:12:34:56 vapId 1 apVapId 1for this client
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 flex webauth acl id to be sent :65535 name : client acl id : 65535
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Vlan while overriding the policy = -1
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 74:88:bb:12:34:56 vapId 1 apVapId 1 flex-acl-name:
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 apfMsAssoStateInc
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 apfMsWepPskStateInc
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 apfPemAddUser2 (apf_policy.c:438) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Idle to Associated
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 apfPemAddUser2:session timeout forstation 00:90:e8:12:34:56 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0
*apfMsConnTask_0: Nov 25 11:51:49.880: 00:90:e8:12:34:56 Sending assoc-resp with status 0 station:00:90:e8:12:34:56 AP:74:88:bb:12:34:56-00 on apVapId 1
*apfMsConnTask_0: Nov 25 11:51:49.882: 00:90:e8:12:34:56 Sending Assoc Response (status: '0') to station on AP ABCDEFG-AP01 on BSSID 74:88:bb:12:34:56 ApVapId 1 Slot 0, mobility role 0
*apfMsConnTask_0: Nov 25 11:51:49.882: 00:90:e8:12:34:56 apfProcessAssocReq (apf_80211.c:12012) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Associated to Associated
*spamApTask0: Nov 25 11:51:49.883: 00:90:e8:12:34:56 Add SGT:0 to AP 74:88:bb:12:34:56
*spamApTask0: Nov 25 11:51:49.883: 00:90:e8:12:34:56 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0
*spamApTask0: Nov 25 11:51:49.883: 00:90:e8:12:34:56 Successful transmission of LWAPP Add-Mobile to AP 74:88:bb:12:34:56
*spamApTask0: Nov 25 11:51:49.883: 00:90:e8:12:34:56 Setting ADD_MOBILE (idx 0, seqno 0, action 1, count 1138496282) ack state for STA on AP 74:88:bb:12:34:56
*spamApTask0: Nov 25 11:51:49.885: 00:90:e8:12:34:56 Received ADD_MOBILE ack - Initiating 1x to STA 00:90:e8:12:34:56 (idx 6)
*spamApTask0: Nov 25 11:51:49.885: 00:90:e8:12:34:56 APF Initiating 1x to STA 00:90:e8:12:34:56
*spamApTask0: Nov 25 11:51:49.885: 00:90:e8:12:34:56 Sent dot1x auth initiate message for mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 dot1xProcessInitiate1XtoMobile to mobile station 00:90:e8:12:34:56 (mscb 1, msg 1)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 reauth_sm state transition 0 ---> 1 for mobile 00:90:e8:12:34:56 at 1x_reauth_sm.c:47
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Normal psk client, full auth
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Created PKC PMK Cache entry for station 00:90:e8:12:34:56 (RSN 2)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Resetting MSCB PMK Cache Entry @index 0 for station 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Setting active key cache index 8 ---> 8
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Setting active key cache index 8 ---> 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Created PMKID PMK Cache for BSSID 74:88:bb:12:34:56 at index 0 for station 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: New PMKID: (16)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: [0000] d7 d9 f5 3d eb 5a fc bd 26 af e9 e4 67 73 da 9e
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Initiating RSN PSK to mobile 00:90:e8:12:34:56keyMgmtType : 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 unsetting PmkIdValidatedByAp
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 dot1x - moving mobile 00:90:e8:12:34:56 into Force Auth state
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Skipping EAP-Success to mobile 00:90:e8:12:34:56 (encryptBit:0)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 key Desc Version FT - 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Found an cache entry for BSSID 74:88:bb:12:34:56 in PMKID cache at index 0 of station 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Found an cache entry for BSSID 74:88:bb:12:34:56 in PMKID cache at index 0 of station 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: Including PMKID in M1 (16)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: [0000] d7 d9 f5 3d eb 5a fc bd 26 af e9 e4 67 73 da 9e
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: M1 - Key Data: (22)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: [0000] dd 14 00 0f ac 04 d7 d9 f5 3d eb 5a fc bd 26 af
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: [0016] e9 e4 67 73 da 9e
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Starting key exchange to mobile 00:90:e8:12:34:56, data packets will be dropped
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Sending EAPOL-Key Message to mobile 00:90:e8:12:34:56
state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.886: 00:90:e8:12:34:56 Allocating EAP Pkt for retransmission to mobile 00:90:e8:12:34:56
*CAPWAP DATA: Nov 25 11:51:49.894: 00:90:e8:12:34:56 validating eapol pkt: key version = 2
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 Received EAPOL-Key from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 key Desc Version FT - 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 Received EAPOL-key in PTK_START state (message 2) from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 Encryption Policy: 4, PTK Key Length: 48
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.894: 00:90:e8:12:34:56 Successfully computed PTK from PMK!!!
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Received valid MIC in EAPOL Key Message M2!!!!!
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Compare RSN IE in association and EAPOL-M2 frame(rsnie_len :20, and grpMgmtCipherLen:0)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 rsnieCapabilty = 0 rsnie_len =20
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Dumping RSNIE received in Association request(len = 22):
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00000000: 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 0...............
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00000010: 00 0f ac 02 00 00 ......
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Dumping RSNIE received in EAPOL M2 (len = 20):
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00000000: 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ................
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00000010: ac 02 00 00 ....
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Stopping retransmission timer for mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 key Desc Version FT - 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 key Desc Version FT - 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Sending EAPOL-Key Message to mobile 00:90:e8:12:34:56
state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.895: 00:90:e8:12:34:56 Reusing allocated memory for EAP Pkt for retransmission to mobile 00:90:e8:12:34:56
*CAPWAP DATA: Nov 25 11:51:49.898: 00:90:e8:12:34:56 validating eapol pkt: key version = 2
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Received EAPOL-Key from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Ignoring invalid EAPOL version (1) in EAPOL-key message from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 key Desc Version FT - 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Stopping retransmission timer for mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Freeing EAP Retransmit Bufer for mobile 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 apfMs1xStateInc
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 8021X_REQD (3) Change state to L2AUTHCOMPLETE (4) last state 8021X_REQD (3)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Mobility query, PEM State: L2AUTHCOMPLETE
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 L2AUTHCOMPLETE (4) NO release MSCB
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Building Mobile Announce :
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Building Client Payload:
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Client Ip: 0.0.0.0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Client Vlan Ip: 192.168.100.5, Vlan mask : 255.255.255.0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Client Vap Security: 1073758208
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Virtual Ip: 192.0.2.1
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 ssid: ABCDEFG
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Building VlanIpPayload.
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: Sending Mobile Announce for client 00:90:e8:12:34:56
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 L2AUTHCOMPLETE (4) DHCP required on AP 74:88:bb:12:34:56 vapId 1 apVapId 1for this client
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Not Using WMM Compliance code qosCap 00
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 flex webauth acl id to be sent :65535 name : client acl id : 65535
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Vlan while overriding the policy = -1
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP 74:88:bb:12:34:56 vapId 1 apVapId 1 flex-acl-name:
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 7010, Adding TMP rule
*spamApTask0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Add SGT:0 to AP 74:88:bb:12:34:56
*spamApTask0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP 74:88:bb:12:34:56, slot 0, interface = 1, QOS = 0
IPv4 ACL ID = 255, IPv
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) NO release MSCB
*Dot1x_NW_MsgTask_0: Nov 25 11:51:49.899: 00:90:e8:12:34:56 Successfully Plumbed PTK session Keysfor mobile 00:90:e8:12:34:56
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) mobility role update request from Unassociated to Local
Peer = 0.0.0.0, Old Anchor = 0.0.0.0, New Anchor = 192.168.100.5
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 pemAdvanceState2 (pem_api.c:6511) Changing state for mobile 00:90:e8:12:34:56 on AP 74:88:bb:12:34:56 from Associated to Associated
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 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: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 6648, Adding TMP rule
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP 74:88:bb:12:34:56, slot 0, interface = 1, QOS = 0
IPv4 ACL ID = 255,
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 0, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*apfReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 DHCP_REQD (7) NO release MSCB
*pemReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*spamApTask0: Nov 25 11:51:49.900: 00:90:e8:12:34:56 Successful transmission of LWAPP Add-Mobile to AP 74:88:bb:12:34:56
*pemReceiveTask: Nov 25 11:51:49.900: 00:90:e8:12:34:56 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*apfReceiveTask: Nov 25 11:51:49.912: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.12
*apfReceiveTask: Nov 25 11:51:49.912: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Nov 25 11:51:50.002: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.65
*apfReceiveTask: Nov 25 11:51:50.002: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Nov 25 11:51:50.005: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.12
*apfReceiveTask: Nov 25 11:51:50.005: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Nov 25 11:51:50.711: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.65
*apfReceiveTask: Nov 25 11:51:50.711: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Nov 25 11:51:59.130: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.12
*apfReceiveTask: Nov 25 11:51:59.130: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Nov 25 11:51:59.207: 00:90:e8:12:34:56 Recieved MS IPv4 Addr= 192.168.100.65
de*apfReceiveTask: Nov 25 11:51:59.207: 00:90:e8:12:34:56 Not updating IPv4 Addr, as client is not in RUN state
*Dot1x_NW_MsgTask_0: Nov 25 11:53:34.485: Sending Mobile Announce for client 00:90:e8:78:12:34

[CSCO12258296]

好的，我测试看看

[CSCO12258296]

谢谢答复，经过测试，关闭flexconnect learn IP address，可以避免该问题的发生。

[Yanli Sun]

CSCO12258296 发表于 2019-12-2 08:52
谢谢答复，经过测试，关闭flexconnect learn IP address，可以避免该问题的发生。

感谢楼主分享解决方案:handshake

[fangzhiwei]

我遇到的问题和你类似，客户端也是Moxa的1137C-EU,设备有5个。所在区域只有一个AP，AP是通过WLC管理，Moxa会经常掉线然后重新连接,重新连接的过程忠会关联到其它区域的AP。