All basic configuration has been created from following related posts. This post will focus on some other configuration or troubleshooting happened in real environment.
Relate Posts:
- Cisco Wireless Controller 5508 Configuration Step by Step – Part 1 (CLI and GUI) –
- Cisco Wireless Controller 5508 Configuration Step by Step – Part 2 (User/Machine Auth) –
- Cisco Wireless Controller 5508 Configuration Step by Step – Part 3 (Certs Auth and Other Settings)
- Cisco Wireless Controller 5508 Configuration – Tips and Tricks
in this example, we are having two SSID : myoffice-t and myoffice-m
1.2 create a new AP Group
1.3 Apply new WLAN to new AP Group
You can assign new create WLAN SSID myoffice-m for new new AP Group
Also you will have to assign which WLC Interface will be used for this new AP group.
1.4 Assign AP into this new AP group.
The new assigned AP(s) will reboot it by itself to apply the changes.
2. Check Mac Address used by AP
Cisco Wireless AP Mac address could be found from AP properties. But that is not all mac addresses they are using.
As you can see from following screenshot, there are two mac addresses: AP Mac Address and base radio mac.
Actually, there are more but you will have to go to WLC command line.
(Cisco Controller) User: admin Password:********** (Cisco Controller) > (Cisco Controller) >show ap summary Number of APs.................................... 5 Global AP User Name.............................. admin Global AP Dot1x User Name........................ Not Configured AP Name Slots AP Model Ethernet MAC Location Country IP Address Clients ------------------ ----- -------------------- ----------------- ---------------- ------- --------------- ------- AP0078.88b9.3a1c-T1 2 AIR-CAP1702I-A-K9 00:78:88:b9:3a:1c default location US 10.9.19.12 2 AP00c1.64b5.8e34-T2 2 AIR-CAP1702I-A-K9 00:c1:64:b5:8e:34 default location US 10.9.19.14 5 AP0042.68db.5858-V2 2 AIR-CAP1702I-A-K9 00:42:68:db:58:58 default location US 10.9.32.25 1 AP0078.88b9.9fd0-V1 2 AIR-CAP1702I-A-K9 00:78:88:b9:9f:d0 default location US 10.9.32.26 1 AP0078.8892.1974-M1 2 AIR-CAP1702I-A-K9 00:78:88:92:19:74 default location US 10.19.2.40 0 (Cisco Controller) >show ap wlan 802.11a AP0078.8892.1974-M1 Site Name........................................ default-group Site Description................................. <none> WLAN ID Interface BSSID ------- ----------- -------------------------- 1 commercial e0:0e:da:08:8b:1f (Cisco Controller) >show ap wlan 802.11b AP0078.8892.1974-M1 Site Name........................................ default-group Site Description................................. <none> WLAN ID Interface BSSID ------- ----------- -------------------------- 1 commercial e0:0e:da:08:8b:10
3. Troubleshooting AP Joining into WLC issue
There was an issue for one of APs to join into our WLC 10.9.19.10.
After SSH-ed into LAP and executed some debug commands , we found this LAP is sending request to two WLCs 10.1.4.11 and 10.9.19.10. But 10.1.4.11 has been set as master controller. And we want this specific AP to join into non master controller 10.9.19.10.
In controller software release 5.2 or later, Cisco lightweight access points use the IETF standard Control and Provisioning of Wireless Access Points protocol (CAPWAP) in order to communicate between the controller and other lightweight access points on the network. Controller software releases prior to 5.2 use the Lightweight Access Point Protocol (LWAPP) for these communications.
CAPWAP, which is based on LWAPP, is a standard, interoperable protocol that enables a controller to manage a collection of wireless access points.
In a CAPWAP environment, a lightweight access point discovers a controller by using CAPWAP discovery mechanisms and then sends the controller a CAPWAP join request. The controller sends the access point a CAPWAP join response allowing the access point to join the controller. When the access point joins the controller, the controller manages its configuration, firmware, control transactions, and data transactions.
CAPWAP is using UDP ports 5246 and 5247 (similar to the LWAPP UDP ports 12222 and 12223). Both ports are not blocked by an intermediate device that could prevent an access point from joining the controller.
The access points use a random UDP source port to reach these destination ports on the controller. After 60 seconds of trying to join a controller with CAPWAP, the access point falls back to using LWAPP. If it cannot find a controller using LWAPP within 60 seconds, it tries again to join a controller using CAPWAP. The access point repeats this cycle of switching from CAPWAP to LWAPP and back again every 60 seconds until it joins a controller.
AP0078.8892.1974-M1#debug capwap client ?
avc CAPWAP Client AVC
cli CAPWAP Client Cli Messages
config CAPWAP Client Config Messages
detail CAPWAP Client Detail Messages
error CAPWAP Client Error Messages
event CAPWAP Client Event Messages
fwd CAPWAP Client dot11 forwarding
hexdump CAPWAP Client Hexdump Messages
info CAPWAP Client Info Messages
lsc CAPWAP Client LSC Events
mgmt CAPWAP Client dot11 mgmt
packet CAPWAP Client Packets
payload CAPWAP Client Payload Messages
predownload CAPWAP Client Predownload Messages
probe CAPWAP Client dot11 probe
qos CAPWAP Client QoS
reassembly CAPWAP Client Fragment Reassembly
tcp-mss-adjust CAPWAP client MSS adjust
tcp-mss-print CAPWAP Client MSS print
AP0078.8892.1974-M1#debug capwap client even
CAPWAP Client EVENT display debugging is on
AP0078.8892.1974-M1#debug capwap client err
CAPWAP Client ERROR display debugging is on
AP0078.8892.1974-M1#terminal monitor
AP0078.8892.1974-M1#
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Calling wtpGetAcToJoin from timer expiry.
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: !mwarname
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: !mwarname
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: !mwarname
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Selected MWAR 'wlc-muc1pm3' (index 1).
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Ap mgr count=1
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Controller: wlc-muc1pm3. ApMgr count is 1 ipTransportTried 0 prefer-mode 1
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Adding Ipv4 AP manager 10.1.4.11 to least load
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: IPv4 Pref mode. Choosing AP Mgr with index 0, IP = 10.1.4.11, load = 99..
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: capwapSetTransportAddr returning: index=1, apMgrCount = 0
*Nov 8 16:23:07.343: AP has SHA2 MIC certificate - Using SHA2 MIC certificate for DTLS.
*Nov 8 16:23:07.343: %CAPWAP-3-EVENTLOG: Synchronizing time with AC time.
*Nov 8 16:23:08.000: %CAPWAP-3-EVENTLOG: Setting time to 16:23:08 UTC Nov 8 2016
*Nov 8 16:23:08.000: %CAPWAP-5-DTLSREQSEND: DTLS connection request sent peer_ip: 10.1.4.11 peer_port: 5246
*Nov 8 16:23:08.000: %CAPWAP-3-EVENTLOG: CAPWAP State: DTLS Setup.
*Nov 8 16:23:08.000: %CAPWAP-3-EVENTLOG: Setting default MTU: MTU discovery can start with 576
*Nov 8 16:23:08.815: %CAPWAP-5-DTLSREQSUCC: DTLS connection created sucessfully peer_ip: 10.1.4.11 peer_port: 5246
*Nov 8 16:23:08.815: %CAPWAP-3-EVENTLOG: Dtls Session Established with the AC 10.1.4.11,port= 5246
*Nov 8 16:23:08.815: %CAPWAP-3-EVENTLOG: CAPWAP State: Join.
*Nov 8 16:23:08.815: %CAPWAP-3-EVENTLOG: Join request: version=134251776
*Nov 8 16:23:08.815: %CAPWAP-3-EVENTLOG: Join request: hasMaximum Message Payload
*Nov 8 16:23:08.815: %CAPWAP-3-EVENTLOG: Sending Join Request Path MTU payload, Length 1376
*Nov 8 16:23:08.819: %CAPWAP-5-SENDJOIN: sending Join Request to 10.1.4.11
*Nov 8 16:23:13.815: %CAPWAP-3-EVENTLOG: Join request: version=134251776
*Nov 8 16:23:13.815: %CAPWAP-3-EVENTLOG: Join request: hasMaximum Message Payload
*Nov 8 16:23:13.815: %CAPWAP-5-SENDJOIN: sending Join Request to 10.1.4.11
*Nov 8 16:23:13.919: %CAPWAP-3-EVENTLOG: Join Response from 10.1.4.11
*Nov 8 16:23:13.919: %CAPWAP-3-EVENTLOG: New Mwar DTLS capability 1 Old Mwar DTLS capability 1
*Nov 8 16:23:13.995: %CAPWAP-3-EVENTLOG: New Mwar DTLS capability 1 is same from the prev Mwar
*Nov 8 16:23:13.995: %CAPWAP-3-EVENTLOG: Starting Post Join timer
*Nov 8 16:23:13.995: %CAPWAP-3-EVENTLOG: CAPWAP State: Image Data.
*Nov 8 16:23:14.003: %CAPWAP-3-EVENTLOG: CAPWAP State: Configure.
*Nov 8 16:23:14.043: %CAPWAP-3-EVENTLOG: AP Dissociated due to LinkFailure, while sending message type 5
*Nov 8 16:23:14.119: %CAPWAP-3-EVENTLOG: ap sw version 15.3(3)JA8$
*Nov 8 16:23:14.119: %CAPWAP-3-EVENTLOG: lwapp_encode_ap_reset_button_payload: reset button state on
*Nov 8 16:23:14.199: %CAPWAP-3-EVENTLOG: Sending packet to AC
*Nov 8 16:23:14.199: %CAPWAP-3-EVENTLOG: Configuration Status sent to 10.1.4.11
*Nov 8 16:23:14.199: %CAPWAP-3-EVENTLOG: Current image is good. Connecting to the controller.
*Nov 8 16:23:17.199: %CAPWAP-3-EVENTLOG: Retransmission Count= 0 Max Re-Transmission Value=5
*Nov 8 16:23:17.199: %CAPWAP-3-EVENTLOG: Sending packet to AC
AP0078.8892.1974-M1#no debug all
All possible debugging has been turned off
When there is a master controller enabled, all newly added access points with no primary, secondary, or tertiary controllers assigned associate with the master controller on the same subnet. This allows the operator to verify the access point configuration and assign primary, secondary, and tertiary controllers to the access point using the All APs > Details page.
The master controller is normally used only when adding new access points to the Cisco Wireless LAN solution. When no more access points are being added to the network, Cisco WLAN solution recommends that you disable the master controller.
To make sure this AP to join into 10.9.19.10 this WLC, we put one command into AP configuration. This time, debug shows it is only sent request to 10.9.19.10.
AP0078.8892.1974-M1#capwap ap controller ip add 10.9.19.10 AP0078.8892.1974-M1#debug capwap console cli This command is meant only for debugging/troubleshooting Any configuration change may result in different behavior from centralized configuration. CAPWAP console CLI allow/disallow debugging is on AP0078.8892.1974-M1#test capwap restart restart capwap AP0078.8892.1974-M1#debug capwap client event CAPWAP Client EVENT display debugging is on AP0078.8892.1974-M1#debug capwap client err CAPWAP Client ERROR display debugging is on AP0078.8892.1974-M1#term mon AP0078.8892.1974-M1# *Nov 8 16:43:32.907: %CAPWAP-3-EVENTLOG: CAPWAP State: DTLS Teardown. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: DTLS session cleanup completed. Restarting capwap state machine. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Previous CAPWAP state was DTLS Setup,numOfCapwapDiscoveryResp = 3. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Attempting to join next controller *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Go Join the next controller *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Calling wtpGetAcToJoin from timer expiry. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Selected MWAR 'wlc-muc1pm3' (index 2). *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Ap mgr count=0 *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Go Join the next controller *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Remove discovery response at index 2 *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Calling wtpGetAcToJoin from timer expiry. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: !mwarname *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Selected MWAR 'WLC-TEST1-1' (index 0). *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Ap mgr count=1 *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Controller: WLC-TEST1-1. ApMgr count is 1 ipTransportTried 0 prefer-mode 1 *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Adding Ipv4 AP manager 10.9.19.10 to least load *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: IPv4 Pref mode. Choosing AP Mgr with index 0, IP = 10.9.19.10, load = 4.. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: capwapSetTransportAddr returning: index=0, apMgrCount = 0 *Nov 8 16:43:37.907: AP has SHA2 MIC certificate - Using SHA2 MIC certificate for DTLS. *Nov 8 16:43:37.907: %CAPWAP-3-EVENTLOG: Synchronizing time with AC time. *Nov 8 16:43:38.000: %CAPWAP-3-EVENTLOG: Setting time to 16:43:38 UTC Nov 8 2016 *Nov 8 16:43:38.000: %CAPWAP-5-DTLSREQSEND: DTLS connection request sent peer_ip: 10.9.19.10 peer_port: 5246 *Nov 8 16:43:38.000: %CAPWAP-3-EVENTLOG: CAPWAP State: DTLS Setup. *Nov 8 16:43:38.000: %CAPWAP-3-EVENTLOG: Setting default MTU: MTU discovery can start with 576 *Nov 8 16:43:38.535: %CAPWAP-5-DTLSREQSUCC: DTLS connection created sucessfully peer_ip: 10.9.19.10 peer_port: 5246 *Nov 8 16:43:38.535: %CAPWAP-3-EVENTLOG: Dtls Session Established with the AC 10.9.19.10,port= 5246 *Nov 8 16:43:38.535: %CAPWAP-3-EVENTLOG: CAPWAP State: Join. *Nov 8 16:43:38.535: %CAPWAP-3-EVENTLOG: Join request: version=134253568 *Nov 8 16:43:38.535: %CAPWAP-3-EVENTLOG: Join request: hasMaximum Message Payload *Nov 8 16:43:38.535: %CAPWAP-3-EVENTLOG: Sending Join Request Path MTU payload, Length 1376 *Nov 8 16:43:38.535: %CAPWAP-5-SENDJOIN: sending Join Request to 10.9.19.10 *Nov 8 16:43:43.535: %CAPWAP-3-EVENTLOG: Join request: version=134253568 *Nov 8 16:43:43.535: %CAPWAP-3-EVENTLOG: Join request: hasMaximum Message Payload *Nov 8 16:43:43.535: %CAPWAP-5-SENDJOIN: sending Join Request to 10.9.19.10 *Nov 8 16:43:43.551: %CAPWAP-3-EVENTLOG: Join Response from 10.9.19.10 *Nov 8 16:43:43.551: %CAPWAP-3-EVENTLOG: New Mwar DTLS capability 1 Old Mwar DTLS capability 1 *Nov 8 16:43:43.627: %CAPWAP-3-EVENTLOG: New Mwar DTLS capability 1 is same from the prev Mwar *Nov 8 16:43:43.627: %CAPWAP-3-EVENTLOG: Starting Post Join timer *Nov 8 16:43:43.627: %CAPWAP-3-EVENTLOG: CAPWAP State: Image Data.perform archive download capwap:/ap3g2 tar file *Nov 8 16:43:43.639: %CAPWAP-6-AP_IMG_DWNLD: Required image not found on AP. Downloading image from Controller. *Nov 8 16:43:43.639: %CAPWAP-3-EVENTLOG: Sending packet to AC *Nov 8 16:43:43.639: %CAPWAP-3-EVENTLOG: Stopping Post Join Timer and Starting HeartBeat Timer *Nov 8 16:43:43.639: %CAPWAP-3-EVENTLOG: Image Data Request sent to 10.9.19.10 *Nov 8 16:43:43.659: %CAPWAP-3-EVENTLOG: Resetting reTransmissionCnt to 0 *Nov 8 16:43:43.659: %CAPWAP-3-EVENTLOG: Queue Empty. *Nov 8 16:43:43.659: %CAPWAP-3-EVENTLOG: Image Data Response from 10.9.19.10 *Nov 8 16:43:43.659: %CAPWAP-3-EVENTLOG: Starting image download............. *Nov 8 16:44:13.643: %CAPWAP-3-EVENTLOG: Echo Interval Expired. *Nov 8 16:44:13.643: %CAPWAP-3-EVENTLOG: Sending packet to AC *Nov 8 16:44:13.643: %CAPWAP-3-EVENTLOG: Echo Request sent to 10.9.19.10 *Nov 8 16:44:13.675: %CAPWAP-3-EVENTLOG: Resetting reTransmissionCnt to 0 *Nov 8 16:44:13.675: %CAPWAP-3-EVENTLOG: Queue Empty. *Nov 8 16:44:13.675: %CAPWAP-3-EVENTLOG: Echo Response from 10.9.19.10 *Nov 8 16:44:43.643: %CAPWAP-3-EVENTLOG: Echo Interval Expired. *Nov 8 16:44:43.643: %CAPWAP-3-EVENTLOG: Sending packet to AC
4. Manually Configure AP IP Configuration
4.1. To see all static config on the AP: AP0022.9090.e859#sh capwap ip config LWAPP Static IP Configuration 4.2. Static config AP0022.9090.e859#capwap ap ip address 192.168.1.2 255.255.255.0 AP0022.9090.e859#capwap ap ip default-gateway 192.168.1.1 Telling the AP the controller to join- AP0022.9090.e859#capwap ap controller ip address 192.168.1.10 AP0022.9090.e859#sh capwap ip config LWAPP Static IP Configuration IP Address 192.168.1.2 IP netmask 255.255.255.0 Default Gateway 192.168.1.1 Primary Controller 192.168.1.10 To view the AP private-config: AP0022.9090.e859#show capwap client config configMagicMark 0xF1E2D3C4 chkSumV2 4204 chkSumV1 33089 swVer 7.2.110.0 adminState ADMIN_ENABLED(1) name AP0022.9090.e859 location default location group name mwarName mwarIPAddress 192.168.1.10 mwarName mwarIPAddress 0.0.0.0 mwarName mwarIPAddress 0.0.0.0 ssh status Disabled Telnet status Disabled numOfSlots 2 spamRebootOnAssert 1 spamStatTimer 180 randSeed 0x5B3B transport SPAM_TRANSPORT_L3(2) transportCfg SPAM_TRANSPORT_DEFAULT(0) initialisation SPAM_PRODUCTION_DISCOVERY(1) ApMode Local ApSubMode Not Configured AP Rogue Detection Mode Enabled OfficeExtend AP [0] Disabled OfficeExtend AP JoinMode[0] Standard Discovery Timer 10 secs Heart Beat Timer 30 secs Led State Enabled 1 Primed Interval 0 AP ILP Pre-Standard Switch Support Disabled AP Power Injector Disabled Infrastructure MFP validation Disabled Configured Switch 1 Addr 192.168.75.48 Configured Switch 2 Addr 192.168.75.52 non-occupancy channels: Ethernet (Duplex/Speed) auto/auto 4.3. To clear the config AP0022.9090.e859#clear capwap ap ip address AP0022.9090.e859#clear capwap ap ip default-gateway AP0022.9090.e859#clear capwap ap hostname AP0022.9090.e859#clear capwap ap controller ip address To clear the AP private config- AP0022.9090.e859#clear capwap private-config AP0022.9090.e859#show capwap client config 4.4. Normally, if the AP cannot find a controller to join, it will automatically reboot. To prevent it from rebooting,- AP0022.9090.e859#debug capwap cli no-reload 4.5. Prior to configuring the AP: Before the Access Point will allow configuration changes, it is first necessary to enter the following debug command: AP0022.9090.e859#debug capwap console cli This command is meant only for debugging/troubleshooting Any configuration change may result in different behavior from centralized configuration. CAPWAP console CLI allow/disallow debugging is on 4.6.To upgrade the rcv image on the AP AP0022.9090.e859#debug capwap console cli archive download-sw /overwrite /force-reload tftp://<TFTP SERVER>/<file name> e.g- archive download-sw /overwrite /force-reload tftp://192.168.5.12/ap3g1-rcvk9w8-tar.124-23c.JA3.tar default password: Cisco The AP should boot up with the lightweight code; "sh version" on the AP will have a "k9w8" in it instead of a "k9w7" which stands for autonomous. 4.7. Debug commands to monitor the discovery process: AP0022.9090.e859#debug ip udp To view the AP detail (controller ip, operational state, software version): AP0022.9090.e859#show capwap client rcb AdminState : ADMIN_ENABLED SwVer : 7.2.110.0 NumFilledSlots : 2 Name : AP0022.9090.e859 Location : default location MwarName : 5508-5 MwarApMgrIp : 192.168.75.48 MwarHwVer : 0.0.0.0 ApMode : Local ApSubMode : Not Configured OperationState : UP CAPWAP Path MTU : 1485 LinkAuditing : disabled AP Rogue Detection Mode : Enabled AP Tcp Mss Adjust : Disabled Band Direct : Enabled Predownload Status : None Auto Immune Status : Disabled RA Guard Status : Enabled Efficient Upgrade State : Disabled Efficient Upgrade Role : None TFTP Server : Disabled 802.11bg(0) Radio GPR Period : 10 Beacon Period : 100 DTIM Period : 0 World Mode : 1 VoceraFix : 0 Fragmentation Threshold : 2346 Current Tx Power Level : 7 Current Channel : 6 802.11a(1) Radio GPR Period : 10 Beacon Period : 100 DTIM Period : 0 World Mode : 1 VoceraFix : 0 Fragmentation Threshold : 2346 Current Tx Power Level : 0 Current Channel : 165
5. Wireless Connection Performance Issue
5.2 Test Result Before Change
From Laptop to Server1 through WiFi, I only got 52Mbits/sec
C:\TEMP\iperf-3.1.3-win64>iperf3.exe -c 10.9.1.66 Connecting to host 10.9.4.66, port 5201 [ 4] local 10.9.18.120 port 52427 connected to 10.9.4.66 port 5201 [ ID] Interval Transfer Bandwidth [ 4] 0.00-1.00 sec 7.38 MBytes 61.9 Mbits/sec [ 4] 1.00-2.00 sec 6.38 MBytes 53.5 Mbits/sec [ 4] 2.00-3.00 sec 8.88 MBytes 74.4 Mbits/sec [ 4] 3.00-4.00 sec 8.12 MBytes 68.2 Mbits/sec [ 4] 4.00-5.00 sec 7.62 MBytes 64.0 Mbits/sec [ 4] 5.00-6.00 sec 6.12 MBytes 51.4 Mbits/sec [ 4] 6.00-7.00 sec 2.50 MBytes 21.0 Mbits/sec [ 4] 7.00-8.00 sec 2.88 MBytes 24.1 Mbits/sec [ 4] 8.00-9.00 sec 3.12 MBytes 26.2 Mbits/sec [ 4] 9.00-10.00 sec 9.38 MBytes 78.6 Mbits/sec - - - - - - - - - - - - - - - - - - - - - - - - - [ ID] Interval Transfer Bandwidth [ 4] 0.00-10.00 sec 62.4 MBytes 52.3 Mbits/sec sender [ 4] 0.00-10.00 sec 62.3 MBytes 52.2 Mbits/sec receiver iperf Done.
From Desktop to Server 1 through wired connection, I could get 722Mbits/Sec
C:\TEMP\iperf-3.1.3-win64>iperf3.exe -s ----------------------------------------------------------- Server listening on 5201 ----------------------------------------------------------- Accepted connection from 10.9.200.14, port 52683 [ 5] local 10.9.18.120 port 5201 connected to 10.9.200.14 port 52684 [ ID] Interval Transfer Bandwidth [ 5] 0.00-1.00 sec 69.5 MBytes 583 Mbits/sec [ 5] 1.00-2.00 sec 82.3 MBytes 690 Mbits/sec [ 5] 2.00-3.00 sec 88.9 MBytes 746 Mbits/sec [ 5] 3.00-4.00 sec 89.0 MBytes 746 Mbits/sec [ 5] 4.00-5.00 sec 87.4 MBytes 733 Mbits/sec [ 5] 5.00-6.00 sec 88.7 MBytes 744 Mbits/sec [ 5] 6.00-7.00 sec 89.0 MBytes 747 Mbits/sec [ 5] 7.00-8.00 sec 88.8 MBytes 745 Mbits/sec [ 5] 8.00-9.00 sec 89.3 MBytes 749 Mbits/sec [ 5] 9.00-10.00 sec 87.3 MBytes 733 Mbits/sec [ 5] 10.00-10.22 sec 18.6 MBytes 725 Mbits/sec - - - - - - - - - - - - - - - - - - - - - - - - - [ ID] Interval Transfer Bandwidth [ 5] 0.00-10.22 sec 0.00 Bytes 0.00 bits/sec sender [ 5] 0.00-10.22 sec 879 MBytes 722 Mbits/sec receiver ----------------------------------------------------------- Server listening on 5201 ----------------------------------------------------------- iperf3: interrupt - the server has terminated
Based on Data Sheet, 802.11n and 802.11ac should be able to achieve more on throughput.
After reviewed configuration, I found by default, all APs has been set to 20Mhz channel width.
Changed to 40Mhz or 80Mhz will require network disabled first to update Channel Width configuration.
We can change the channel width from 20 MHz to 80 MHz from the controller’s GUI: Wireless>>802.11a/n/ac>>RRM>>DCA>>Channel width. But, first, you need to actually disable the 5 GHz Network, apply the change and re-enable the Network.
Or, if you want to just manually change one AP, you can go to Wireless>>Access Points>>Radios>>802.11a/n/ac>>select the AP by hovering over the blue icon and then select configure.
(Cisco Controller) User: admin Password:********** (Cisco Controller) >ena Incorrect usage. Use the '?' or <TAB> key to list commands. (Cisco Controller) >config advanced 802.11a channel d? dca delete device (Cisco Controller) >config advanced 802.11a channel dca chan-width-11n 80 802.11a network must be disable (Cisco Controller) >config 802.11a disable network Disabling the 802.11a network may strand mesh APs. Are you sure you want to continue? (y/n)y (Cisco Controller) > (Cisco Controller) >config advanced 802.11a channel dca chan-width-11n 80 (Cisco Controller) >config 802.11a enable network (Cisco Controller) >save config Are you sure you want to save? (y/n) y Configuration Saved! (Cisco Controller) > (Cisco Controller) >
Now the laptop connection is changed from 170mbps to 702mbps.
5.3. Test Result After Change
Iperf also can achieve more than 200Mbits/sec.
C:\TEMP\iperf-3.1.3-win64>iperf3.exe -c 10.9.4.66
Connecting to host 10.9.4.66, port 5201
[ 4] local 10.9.18.120 port 57207 connected to 10.9.4.66 port 5201
[ ID] Interval Transfer Bandwidth
[ 4] 0.00-1.00 sec 24.8 MBytes 208 Mbits/sec
[ 4] 1.00-2.00 sec 26.1 MBytes 219 Mbits/sec
[ 4] 2.00-3.00 sec 27.1 MBytes 228 Mbits/sec
[ 4] 3.00-4.00 sec 24.5 MBytes 206 Mbits/sec
[ 4] 4.00-5.00 sec 25.2 MBytes 212 Mbits/sec
[ 4] 5.00-6.00 sec 24.9 MBytes 209 Mbits/sec
[ 4] 6.00-7.00 sec 22.5 MBytes 189 Mbits/sec
[ 4] 7.00-8.00 sec 22.9 MBytes 192 Mbits/sec
[ 4] 8.00-9.00 sec 22.0 MBytes 185 Mbits/sec
[ 4] 9.00-10.00 sec 22.4 MBytes 188 Mbits/sec
- - - - - - - - - - - - - - - - - - - - - - - - -
[ ID] Interval Transfer Bandwidth
[ 4] 0.00-10.00 sec 242 MBytes 203 Mbits/sec sender
[ 4] 0.00-10.00 sec 242 MBytes 203 Mbits/sec receiver
iperf Done.
6. Reset WLC to Factory Default Settings
- Enter reset system at the command prompt.
- At the prompt that asks whether you need to save changes to the configuration, enter Y or N. The unit reboots.
- When you are prompted for a username, enter recover-config to restore the factory default configuration.
The WLC reboots and displays the Welcome to the Cisco WLAN Solution Wizard Configuration Tool message. - Use the configuration wizard to enter configuration settings.
(Cisco Controller)
Enter User Name (or 'Recover-Config' this one-time only to reset configuration to factory defaults)
User:
7. Debug Command and Debug disable-all
Here is client debug for authentication failure message at WLC monitor page.
(Cisco Controller) >debug client b8:8a:60:a4:0a:dd
(Cisco Controller) >*osapiBsnTimer: Aug 20 14:18:38.801: b8:8a:60:a4:0a:dd 802.1x 'txWhen' Timer expired for station b8:8a:60:a4:0a:dd and for message = M0
*apfMsConnTask_2: Aug 20 14:18:47.426: b8:8a:60:a4:0a:dd Processing assoc-req station:b8:8a:60:a4:0a:dd AP:00:3a:7d:13:be:20-01 thread:18f31790
*apfMsConnTask_2: Aug 20 14:18:47.426: b8:8a:60:a4:0a:dd Station: B8:8A:60:A4:0A:DD 11v BSS Transition not enabled on the AP 00:3A:7D:13:BE:20
*apfMsConnTask_2: Aug 20 14:18:47.426: b8:8a:60:a4:0a:dd Association received from mobile on BSSID 00:3a:7d:13:be:2f AP AP00c1.64b5.8e34-TEST2
*apfMsConnTask_2: Aug 20 14:18:47.426: b8:8a:60:a4:0a:dd Station: B8:8A:60:A4:0A:DD 11v BSS Transition not enabled on the AP 00:3A:7D:13:BE:20
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Global 200 Clients are allowed to AP radio
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Max Client Trap Threshold: 0 cur: 2
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd override for default ap group, marking intgrp NULL
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Applying Interface(commercial) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 4
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Re-applying interface policy for client
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2710)
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2731)
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Setting the NAS Id to WLAN specific Id 'C-TEST1-WLC1'
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd In processSsidIE:6329 setting Central switched to TRUE
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd In processSsidIE:6332 apVapId = 1 and Split Acl Id = 65535
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Applying site-specific Local Bridging override for station b8:8a:60:a4:0a:dd - vapId 1, site 'TEST-TEST1', interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Applying Local Bridging Interface Policy for station b8:8a:60:a4:0a:dd - vlan 4, interface id 12, interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd override from ap group, removing intf group from mscb
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Applying site-specific override for station b8:8a:60:a4:0a:dd - vapId 1, site 'TEST-TEST1', interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Applying Interface(commercial) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 4
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Re-applying interface policy for client
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2710)
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2731)
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd Setting the NAS Id to AP group specific Id 'WLC-TEST1-1'
*apfMsConnTask_2: Aug 20 14:18:47.427: b8:8a:60:a4:0a:dd processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_2: Aug 20 14:18:47.428: RSNIE in Assoc. Req.: (22)
*apfMsConnTask_2: Aug 20 14:18:47.428: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f
*apfMsConnTask_2: Aug 20 14:18:47.428: [0016] ac 01 3c 00 00 00
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Processing RSN IE type 48, length 22 for mobile b8:8a:60:a4:0a:dd
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd RSN Capabilities: 60
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Marking Mobile as non-11w Capable
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Received RSN IE with 0 PMKIDs from mobile b8:8a:60:a4:0a:dd
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Setting active key cache index 8 ---> 8
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd unsetting PmkIdValidatedByAp
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Encryption policy is set to 0x80000001
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Not Using WMM Compliance code qosCap 00
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:3a:7d:13:be:20 vapId 1 apVapId 1 flex-acl-name:
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd apfPemAddUser2 (apf_policy.c:362) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Associated to Associated
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd apfPemAddUser2:session timeout forstation b8:8a:60:a4:0a:dd - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_2: Aug 20 14:18:47.428: b8:8a:60:a4:0a:dd Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0
*apfMsConnTask_2: Aug 20 14:18:47.429: b8:8a:60:a4:0a:dd Sending assoc-resp with status 0 station:b8:8a:60:a4:0a:dd AP:00:3a:7d:13:be:20-01 on apVapId 1
*apfMsConnTask_2: Aug 20 14:18:47.429: b8:8a:60:a4:0a:dd VHT Operation IE: width 80/1 ch 36 freq0 42 freq1 0 msc0 0x3f msc1 0x3f
*apfMsConnTask_2: Aug 20 14:18:47.429: b8:8a:60:a4:0a:dd Sending Assoc Response to station on BSSID 00:3a:7d:13:be:2f (status 0) ApVapId 1 Slot 1
*apfMsConnTask_2: Aug 20 14:18:47.429: b8:8a:60:a4:0a:dd apfProcessAssocReq (apf_80211.c:10521) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Associated to Associated
*spamApTask5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd Sent dot1x auth initiate message for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Connecting state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.431: b8:8a:60:a4:0a:dd Sending EAP-Request/Identity to mobile b8:8a:60:a4:0a:dd (EAP Id 1)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Received EAPOL START, dot1x state = 2
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Received EAPOL START from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Connecting state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Sending EAP-Request/Identity to mobile b8:8a:60:a4:0a:dd (EAP Id 2)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.457: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd Received Identity Response (count=1) from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd Resetting reauth count 1 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd EAP State update from Connecting to Authenticating for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Authenticating state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.461: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.472: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.472: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.472: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=3) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.472: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 3)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.473: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.473: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 3, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.478: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=4) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 4)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.488: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 4, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.491: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=5) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 5)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.494: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 5, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.510: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=6) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 6)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.512: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.514: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.514: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 6, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.514: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.514: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.515: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.515: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=7) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.529: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 7, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.531: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd Processing Access-Reject for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd 0 PMK-remove groupcast messages sent
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd Removing PMK cache due to EAP-Failure for mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd Sending EAP-Failure to mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd Entering Backend Auth Failure state (id=7) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd Setting quiet timer for 5 seconds for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Unknown state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:47.533: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Processing assoc-req station:b8:8a:60:a4:0a:dd AP:00:3a:7d:13:be:20-01 thread:18f31790
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Station: B8:8A:60:A4:0A:DD 11v BSS Transition not enabled on the AP 00:3A:7D:13:BE:20
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Association received from mobile on BSSID 00:3a:7d:13:be:2f AP AP00c1.64b5.8e34-TEST2
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Station: B8:8A:60:A4:0A:DD 11v BSS Transition not enabled on the AP 00:3A:7D:13:BE:20
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Global 200 Clients are allowed to AP radio
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Max Client Trap Threshold: 0 cur: 2
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Rf profile 600 Clients are allowed to AP wlan
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd override for default ap group, marking intgrp NULL
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Applying Interface(commercial) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 4
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Re-applying interface policy for client
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2710)
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2731)
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Setting the NAS Id to WLAN specific Id 'C-TEST1-WLC1'
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd In processSsidIE:6329 setting Central switched to TRUE
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd In processSsidIE:6332 apVapId = 1 and Split Acl Id = 65535
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Applying site-specific Local Bridging override for station b8:8a:60:a4:0a:dd - vapId 1, site 'TEST-TEST1', interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:48.955: b8:8a:60:a4:0a:dd Applying Local Bridging Interface Policy for station b8:8a:60:a4:0a:dd - vlan 4, interface id 12, interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd override from ap group, removing intf group from mscb
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Applying site-specific override for station b8:8a:60:a4:0a:dd - vapId 1, site 'TEST-TEST1', interface 'commercial'
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Applying Interface(commercial) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 4
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Re-applying interface policy for client
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2710)
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:2731)
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Setting the NAS Id to AP group specific Id 'WLC-TEST1-1'
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd STA - rates (6): 152 36 48 72 96 108 0 0 0 0 0 0 0 0 0 0
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_2: Aug 20 14:18:48.956: RSNIE in Assoc. Req.: (22)
*apfMsConnTask_2: Aug 20 14:18:48.956: [0000] 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f
*apfMsConnTask_2: Aug 20 14:18:48.956: [0016] ac 01 3c 00 00 00
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Processing RSN IE type 48, length 22 for mobile b8:8a:60:a4:0a:dd
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Received 802.11i 802.1X key management suite, enabling dot1x Authentication
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd RSN Capabilities: 60
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Marking Mobile as non-11w Capable
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Received RSN IE with 0 PMKIDs from mobile b8:8a:60:a4:0a:dd
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Setting active key cache index 8 ---> 8
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd unsetting PmkIdValidatedByAp
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Initializing policy
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Change state to AUTHCHECK (2) last state 8021X_REQD (3)
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Encryption policy is set to 0x80000001
*apfMsConnTask_2: Aug 20 14:18:48.956: b8:8a:60:a4:0a:dd Not Using WMM Compliance code qosCap 00
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Plumbed mobile LWAPP rule on AP 00:3a:7d:13:be:20 vapId 1 apVapId 1 flex-acl-name:
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd apfPemAddUser2 (apf_policy.c:362) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Associated to Associated
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd apfPemAddUser2:session timeout forstation b8:8a:60:a4:0a:dd - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd Sending assoc-resp with status 0 station:b8:8a:60:a4:0a:dd AP:00:3a:7d:13:be:20-01 on apVapId 1
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd VHT Operation IE: width 80/1 ch 36 freq0 42 freq1 0 msc0 0x3f msc1 0x3f
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd Sending Assoc Response to station on BSSID 00:3a:7d:13:be:2f (status 0) ApVapId 1 Slot 1
*apfMsConnTask_2: Aug 20 14:18:48.957: b8:8a:60:a4:0a:dd apfProcessAssocReq (apf_80211.c:10521) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Associated to Associated
*spamApTask5: Aug 20 14:18:48.959: b8:8a:60:a4:0a:dd Sent dot1x auth initiate message for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.959: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.959: b8:8a:60:a4:0a:dd EAP-PARAM Debug - eap-params for Wlan-Id :1 is disabled - applying Global eap timers and retries
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.959: b8:8a:60:a4:0a:dd Disable re-auth, use PMK lifetime.
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.959: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Connecting state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.960: b8:8a:60:a4:0a:dd Sending EAP-Request/Identity to mobile b8:8a:60:a4:0a:dd (EAP Id 1)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd Received EAPOL START, dot1x state = 2
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd Reset the reauth counter since EAPOL START has been received!!!
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:53
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd Received EAPOL START from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Connecting state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd Sending EAP-Request/Identity to mobile b8:8a:60:a4:0a:dd (EAP Id 2)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.975: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.980: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.980: b8:8a:60:a4:0a:dd Received EAP Response packet with mismatching id (currentid=2, eapid=1) from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.980: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd Received Identity Response (count=1) from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd Resetting reauth count 1 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd EAP State update from Connecting to Authenticating for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Authenticating state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.983: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=3) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 3)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.993: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 3, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:48.996: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=4) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 4)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.004: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.006: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.006: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 4, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.006: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.006: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.006: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.007: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.008: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.008: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.009: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=5) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.009: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 5)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.009: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.009: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.036: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.036: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 5, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.036: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.036: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.036: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.037: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=6) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 6)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.042: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 6, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.044: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd Processing Access-Challenge for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd Entering Backend Auth Req state (id=7) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd Sending EAP Request from AAA to mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd Reusing allocated memory for EAP Pkt for retransmission to mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.058: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd Received EAPOL EAPPKT from mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd Received EAP Response from mobile b8:8a:60:a4:0a:dd (EAP Id 7, EAP Type 13)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd Resetting reauth count 0 to 0 for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd Entering Backend Auth Response state for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.060: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd Processing Access-Reject for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd 0 PMK-remove groupcast messages sent
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd Removing PMK cache due to EAP-Failure for mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd Sending EAP-Failure to mobile b8:8a:60:a4:0a:dd (EAP Id 7)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd Entering Backend Auth Failure state (id=7) for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd apfBlacklistMobileStationEntry2 (apf_ms.c:6582) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Associated to Exclusion-list (1)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd Scheduling deletion of Mobile Station: (callerId: 44) in 10 seconds
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd 0.0.0.0 8021X_REQD (3) Change state to START (0) last state 8021X_REQD (3)
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.062: b8:8a:60:a4:0a:dd 0.0.0.0 START (0) Reached FAILURE: from line 5765
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd Scheduling deletion of Mobile Station: (callerId: 9) in 10 seconds
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd Max AAA failure for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd Setting quiet timer for 5 seconds for mobile b8:8a:60:a4:0a:dd
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd dot1x - moving mobile b8:8a:60:a4:0a:dd into Unknown state
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*Dot1x_NW_MsgTask_5: Aug 20 14:18:49.063: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*osapiBsnTimer: Aug 20 14:18:54.001: b8:8a:60:a4:0a:dd 802.1x 'quiteWhile' Timer expired for station b8:8a:60:a4:0a:dd and for message = M0
*Dot1x_NW_MsgTask_5: Aug 20 14:18:54.001: b8:8a:60:a4:0a:dd reauth_sm state transition 0 ---> 0 for mobile b8:8a:60:a4:0a:dd at 1x_reauth_sm.c:71
*osapiBsnTimer: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd apfMsExpireCallback (apf_ms.c:638) Expiring Mobile!
*apfReceiveTask: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd Freeing EAP Retransmit Bufer for mobile b8:8a:60:a4:0a:dd
*apfReceiveTask: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd Scheduling deletion of Mobile Station: (callerId: 46) in 60 seconds
*apfReceiveTask: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd apfMsExpireMobileStation (apf_ms.c:7520) Changing state for mobile b8:8a:60:a4:0a:dd on AP 00:3a:7d:13:be:20 from Exclusion-list (1) to Exclusion-list (2)
*apfReceiveTask: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd pemApfDeleteMobileStation2: APF_MS_PEM_WAIT_L2_AUTH_COMPLETE = 0.
*apfReceiveTask: Aug 20 14:18:59.001: b8:8a:60:a4:0a:dd 0.0.0.0 START (0) Deleted mobile LWAPP rule on AP [00:3a:7d:13:be:20]
(Cisco Controller) >debug disable-all
Reference: