When it comes to client troubleshooting in AireOS WLCs you pretty much had one CLI command “debug client <client_mac_addr>”. You have to actively SSH into WLC & issue that command to get CLI output to see what is going on.
In 9800, you have a different approach. By default 9800 collects logs across all the processes, however, it is only collecting “notification” level messages. This is called an “Always-on” trace. If you want to do proper troubleshooting, you need to get debug level output. This is known as “Radioactive Tracing” or “conditional debugging“. In this post, we will look at “radioactive tracing” which will be greatly helpful for client troubleshooting (or even AP join failures, mobility peering issues, etc). On a Cisco 9800, you can go to the “Troubleshooting” menu and you will find the “Radioactive Trace” option there.
In this example, I got a client’s MAC address (f8e4.e372.6cda) that has an issue connecting (enforced configuration error to illustrate the point). The client is connecting to an AP managed by 3504 (AireOS WLC) and the SSID is anchored to Cisco 9800.
In 9800 GUI, You can go to “Troubleshooting > Radioactive Trace” & add the MAC address of the client to the list as shown below.
Once you do that you need to start conditional debugging by clicking the “Start” button.
Once you do that you need to reproduce the issue (client connectivity issue in my case). The client is unable to connect in this case. Then you have to stop the debugging by clicking the “Stop” button.
Once stopped, you can generate debug file by clicking the “Generate” button. By default, it will go back 10 minutes and you can change it. There is a checkbox for “internal logs” which is only applicable to generate certain logs for developers, so you do not want to check that box unless TAC is instructed to do so.
Once the file is generated, you can download it. Here is the file (debugTrace_f8e4.e372.6cda-1.txt) if you need to have a look closely.
If you look at the collected output, you will see clearly two error messages indicating reason for failure. “Export anchor required but wlan not configured as mobility export anchor for: Wlan-Profile: QoS_1X, Policy Profile: QoS_1X, client MAC: f8e4.e372.6cda”
2022/07/08 16:15:56.957433 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received mobile_announce, sub type: 0 of XID (63253) from (ipv4: 192.168.225.100 ) 2022/07/08 16:15:57.949434 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received mobile_announce, sub type: 0 of XID (63253) from (ipv4: 192.168.225.100 ) 2022/07/08 16:15:58.941471 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received export_anchor_req, sub type: 0 of XID (63254) from (ipv4: 192.168.225.100 ) 2022/07/08 16:15:58.941932 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Number of client is BELOW wlan limit 2022/07/08 16:15:58.941942 {mobilityd_R0-0}{1}: [mm-transition] [18337]: (info): MAC: f8e4.e372.6cda MMFSM transition: S_MC_INIT -> S_MC_ANCHOR_EXP_ANC_REQ_RCVD_TR on E_MC_EXP_ANC_REQ_RCVD from ipv4: 192.168.225.100 2022/07/08 16:15:58.942072 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Anchor Load Balancing: selected wncd[0]. 2022/07/08 16:15:58.942161 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Add MCC by tdl mac: client_ifid 0xa0000003 is assigned to client 2022/07/08 16:15:58.942202 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Export Anchor Request successfully processed. 2022/07/08 16:15:58.942243 {mobilityd_R0-0}{1}: [mm-client] [18337]: (info): MAC: f8e4.e372.6cda Forwarding export_anchor_req, sub type: 0 of XID (63254) from (ipv4: 192.168.225.100 ) to (WNCD[0]) 2022/07/08 16:15:58.942297 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Sending export_anchor_req of XID (63254) to (WNCD[0]) 2022/07/08 16:15:58.942647 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Received export_anchor_req, sub type: 0 of XID (63254) from (MobilityD[0]) 2022/07/08 16:15:58.943504 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): MAC: f8e4.e372.6cda CO anchor: Policy profile QoS_1X is not configured for export anchor 2022/07/08 16:15:58.943642 {wncd_x_R0-0}{1}: [errmsg] [17028]: (warn): %CLIENT_ORCH_LOG-4-ANCHOR_NOT_EXPORT_WLAN: R0/0: wncd: Export anchor required but wlan not configured as mobility export anchor for: Wlan-Profile: QoS_1X, Policy Profile: QoS_1X, client MAC: f8e4.e372.6cda 2022/07/08 16:15:58.943716 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Export Anchor Request event scheduled. 2022/07/08 16:15:58.943736 {wncd_x_R0-0}{1}: [mm-transition] [17028]: (info): MAC: f8e4.e372.6cda MMIF FSM transition: S_MA_INIT -> S_MA_ANCHORING_ASSOC_RESP_PROCESSED_TR on E_MA_CO_EXP_ANCHOR_REQ_ASSOC_RCVD 2022/07/08 16:15:58.943752 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Processed Association Response from Client Orchestrator. Association denied. Reason: profile mismatch 2022/07/08 16:15:58.943785 {wncd_x_R0-0}{1}: [errmsg] [17028]: (warn): %MMIF_LOG-4-ANCHOR_RESP_PROFILE_MISMATCH: R0/0: wncd: Export anchor required but config is incorrect, sending export anchor deny mismatch for: Wlan-Profile: QoS_1X, Policy Profile: QoS_1X, client mac: f8:e4:e3:72:6c:da 2022/07/08 16:15:58.943826 {wncd_x_R0-0}{1}: [ewlc-infra-evq] [17028]: (ERR): Exp-MMIF: export_anchor_req: EXP_CLIENT_PROFILE_MISMATCH 2022/07/08 16:15:58.943843 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Sending Export Anchor Response Deny 2022/07/08 16:15:58.943938 {wncd_x_R0-0}{1}: [dot11] [17028]: (ERR): MAC: f8e4.e372.6cda unable to get dot11 bssid handle 2022/07/08 16:15:58.943946 {wncd_x_R0-0}{1}: [dot11] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to dot11 get client bssid hndl. DOT11 fsm dm is not allocated yet. 2022/07/08 16:15:58.943947 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): MAC: f8e4.e372.6cda unable to get bssid handle 2022/07/08 16:15:58.943965 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to encode co parameters for Export Anchor rsp , error:14, Bad address 2022/07/08 16:15:58.944010 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Sending export_anchor_rsp of XID (63254) to (MobilityD[0]) 2022/07/08 16:15:58.944127 {wncd_x_R0-0}{1}: [dot11] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to dot11 get client bssid hndl. DOT11 fsm dm is not allocated yet. 2022/07/08 16:15:58.944138 {wncd_x_R0-0}{1}: [dot11] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to dot11 get client bssid hndl. DOT11 fsm dm is not allocated yet. 2022/07/08 16:15:58.944139 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): MAC: f8e4.e372.6cda Easy PSK EAPOL M2 free: Failed to obtain the BSSID handle 2022/07/08 16:15:58.944199 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (info): MAC: f8e4.e372.6cda Deleting the client, reason: 23, CO_CLIENT_DELETE_REASON_MOBILITY_FAILURE, Client state S_CO_INIT 2022/07/08 16:15:58.944218 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): Guest-Lan client: oper data is NULL 2022/07/08 16:15:58.944244 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (note): MAC: f8e4.e372.6cda Client delete initiated. Reason: CO_CLIENT_DELETE_REASON_MOBILITY_FAILURE, details: , fsm-state transition 00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|00|97| 2022/07/08 16:15:58.944388 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to send client delete mobile. delete reason: 23, CO_CLIENT_DELETE_REASON_MOBILITY_FAILURE 2022/07/08 16:15:58.944403 {wncd_x_R0-0}{1}: [apmgr-bssid] [17028]: (ERR): Invalid bssid hdl arg. Failed to get wtp mac
You can fix that problem under WLAN Policy Profile (check that box) for “Export Anchor”, You can confirm it under the policy profile “QoS_1X” as shown below.
Let’s try to connect the client and see logs this time. Since we have stopped the debug you have to enable it again. Let’s try to do that via CLI this time. You can use “debug platform condition feature wireless” with either MAC or IP address as a filter. Typically you need to use MAC address as wireless operates in layer 2.
Once enable the debug condition, you have to start it using the “debug platform condition start” CLI command. Then you have to try to connect with the client (or reproduce your connectivity issue). In my case client is able to connect and got IP Address this time. Before downloading the trace file, you have to stop debugging using the “debug platform condition stop” CLI command.
You can use “show logging profile wireless [counter |[last]{x days/hours} | filter mac{<mac address>} [to-file]{<destination>}” to save that output to a file in bootflash.
C9800-2#debug platform condition feature wireless mac f8e4.e372.6cda C9800-2#debug platform condition start . . C9800-2#debug platform condition stop C9800-2#show logging profile wireless start last 30 minutes to-file bootflash:debugTrace_f8e4.e372.6cda-2.txt
You can download the file from your bootflash using “Administration > Management > File Manager > bootflash:” & right-click on the filename & download option.
If you want to export debug output to an external FTP server, you can do it in one go. By default, it will send 30 min to debug to your FTP server configured.
9800-1#debug wireless mac f8e4.e372.6cda ? ftp-server Move log file to FTP server, temporary storage: "flash:/" internal Collect all logs.(Default: only customer curated logs) level Select logs above specific level (Default: debug) monitor-time Max time to trace the condition (Default: 30min) to-file File path in internal storage, default storage: "flash:/" <cr> <cr> 9800-1#debug wireless mac f8e4.e372.6cda ftp-server 192.168.99.100 / monitor-time 10
In this case, you can see all the details related to my client. Noticed that you get all the debug level output specific to this client across all the controller processes. CLI command you entered can be seen in the “IOSRP_R0-0” process. Mobility-related information can be seen in the “mobilityd_R0-0” process. Wireless client associations related debug output in the “wncd_x_R0-0” process. Here is the “debugTrace_f8e4.e372.6cda-2.txt” file for your reference. Here are successful client connectivity-related messages.
2022/07/08 16:37:18.073824 {IOSRP_R0-0}{1}: [parser_cmd] [30020]: (note): id= 192.168.129.102@vty0:user=rasika cmd: 'debug platform condition feature wireless mac f8e4.e372.6cda' SUCCESS 2022/07/08 16:37:18.071 AEST 2022/07/08 16:38:05.216203 {IOSRP_R0-0}{1}: [parser_cmd] [30020]: (note): id= 192.168.129.102@vty0:user=rasika cmd: 'debug platform condition start ' SUCCESS 2022/07/08 16:38:05.215 AEST 2022/07/08 16:38:36.720212 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received mobile_announce, sub type: 0 of XID (63313) from (ipv4: 192.168.225.100 ) 2022/07/08 16:38:37.712145 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received mobile_announce, sub type: 0 of XID (63313) from (ipv4: 192.168.225.100 ) 2022/07/08 16:38:38.704228 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received export_anchor_req, sub type: 0 of XID (63315) from (ipv4: 192.168.225.100 ) 2022/07/08 16:38:38.704543 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Number of client is BELOW wlan limit 2022/07/08 16:38:38.704552 {mobilityd_R0-0}{1}: [mm-transition] [18337]: (info): MAC: f8e4.e372.6cda MMFSM transition: S_MC_INIT -> S_MC_ANCHOR_EXP_ANC_REQ_RCVD_TR on E_MC_EXP_ANC_REQ_RCVD from ipv4: 192.168.225.100 2022/07/08 16:38:38.704627 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Anchor Load Balancing: selected wncd[0]. 2022/07/08 16:38:38.704694 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Add MCC by tdl mac: client_ifid 0xa0000003 is assigned to client 2022/07/08 16:38:38.704725 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Export Anchor Request successfully processed. 2022/07/08 16:38:38.704745 {mobilityd_R0-0}{1}: [mm-client] [18337]: (info): MAC: f8e4.e372.6cda Forwarding export_anchor_req, sub type: 0 of XID (63315) from (ipv4: 192.168.225.100 ) to (WNCD[0]) 2022/07/08 16:38:38.704785 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Sending export_anchor_req of XID (63315) to (WNCD[0]) 2022/07/08 16:38:38.704947 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Received export_anchor_req, sub type: 0 of XID (63315) from (MobilityD[0]) 2022/07/08 16:38:38.705547 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Export Anchor Request event scheduled. 2022/07/08 16:38:38.705664 {wncd_x_R0-0}{1}: [apmgr-bssid] [17028]: (ERR): Get ap enet mac. Failed to fetch wtp data 2022/07/08 16:38:38.705664 {wncd_x_R0-0}{1}: [apmgr-bssid] [17028]: (ERR): Failed to Get AP MAC from bssid handle while adding record co add ap mac ssid info record 2022/07/08 16:38:38.705873 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_INIT -> S_CO_ASSOCIATING 2022/07/08 16:38:38.706130 {wncd_x_R0-0}{1}: [dot11] [17028]: (info): MAC: f8e4.e372.6cda Dot11 process export anchor client info. Sending assoc status:CO_CLIENT_ASSOC_STATUS_SUCCESS to client orchestrator. 2022/07/08 16:38:38.706135 {wncd_x_R0-0}{1}: [dot11] [17028]: (info): MAC: f8e4.e372.6cda DOT11 state transition: S_DOT11_INIT -> S_DOT11_ASSOCIATED 2022/07/08 16:38:38.706151 {wncd_x_R0-0}{1}: [apmgr-db] [17028]: (ERR): 0000.0000.0000 Failed to get radio oper stat record. Invalid stats record for slot=0 error:0 2022/07/08 16:38:38.706155 {wncd_x_R0-0}{1}: [apmgr-db] [17028]: (ERR): 0000.0000.0000 Failed to update per radio per slot clients count in stats record, did not get record, error No such file or directory 2022/07/08 16:38:38.706328 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_ASSOCIATING -> S_CO_CREATE_SM_SESSION_IN_PROGRESS 2022/07/08 16:38:38.706440 {wncd_x_R0-0}{1}: [apmgr-db] [17028]: (ERR): 0000.0000.0000 Failed to get bssid opctxt by slot bssid. Get radio opctxt for 0 error 2022/07/08 16:38:38.706441 {wncd_x_R0-0}{1}: [apmgr-bssid] [17028]: (ERR): Failed to Get bssid hdl. Apmgr opctxt bssid handle is NULL.0000.0000.0000 2022/07/08 16:38:38.706444 {wncd_x_R0-0}{1}: [client-auth] [17028]: (ERR): MAC: 0000.0000.0000 Failed to get client orch ft session timeout. Fetch BSSID 0000.0000.0000 handle error:2, No such file or directory 2022/07/08 16:38:38.706562 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Session Start event called from SANET-SHIM, vlan: 0 2022/07/08 16:38:38.706590 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Wireless session sequence, create context with method Dot1X 2022/07/08 16:38:38.706596 {wncd_x_R0-0}{1}: [auth-mgr-feat_wireless] [17028]: (info): Wireless dot1x configs: EAPID req max retries = 2 EAP req max retries = 2 EAPID req timeout = 30 Supp Timeout = 30 2022/07/08 16:38:38.706629 {wncd_x_R0-0}{1}: [auth-mgr-feat_wireless] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] - authc_list: Not present under wlan configuration 2022/07/08 16:38:38.706631 {wncd_x_R0-0}{1}: [auth-mgr-feat_wireless] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] - authz_list: Not present under wlan configuration 2022/07/08 16:38:38.706668 {wncd_x_R0-0}{1}: [client-auth] [17028]: (info): MAC: f8e4.e372.6cda Client auth-interface state transition: S_AUTHIF_INIT -> S_AUTHIF_AWAIT_PUSH_START_RESP 2022/07/08 16:38:38.706914 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:unknown] auth mgr attr add/change notification is received for attr iif-id(952) 2022/07/08 16:38:38.706987 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] auth mgr attr add/change notification is received for attr swbidb(1263) 2022/07/08 16:38:38.707036 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] auth mgr attr add/change notification is received for attr aaa-unique-id(220) 2022/07/08 16:38:38.707111 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] auth mgr attr add/change notification is received for attr iif-id(952) 2022/07/08 16:38:38.707124 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Retrieved Client IIF ID 0xfe0002e1 2022/07/08 16:38:38.707199 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Allocated audit session id 0000000000000021DC88222B 2022/07/08 16:38:38.707692 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Applying policy for WlanId: 103, bssid : 0000.0000.0000, slotid: 0 bssid hdl : 12364632849758814946 2022/07/08 16:38:38.707698 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Wlan vlan-id from bssid hdl 0 2022/07/08 16:38:38.707719 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Applying Svc Templ wlan_svc_QoS_1X_local (ML:NONE) 2022/07/08 16:38:38.708362 {wncd_x_R0-0}{1}: [epm] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Vlan tag name is TEST, pref is 1048575 vlan num is 200 2022/07/08 16:38:38.708425 {wncd_x_R0-0}{1}: [epm] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Feature (EPM Vlan PLUG-IN) has been started (status Success) 2022/07/08 16:38:38.708448 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] SM Reauth Plugin: Received valid timeout = 1800, effective timeout = 1800 2022/07/08 16:38:38.708492 {wncd_x_R0-0}{1}: [epm] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Feature (SM Reauth PLUG-IN) has been started (status Success) 2022/07/08 16:38:38.708557 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Response of epm is SYNC with return code Success 2022/07/08 16:38:38.708645 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Raising ext evt Template Activated (9) on this session, client (unknown) (0) 2022/07/08 16:38:38.708912 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link-local bridging not enabled for this client, not checking VLAN validity 2022/07/08 16:38:38.709134 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Initialising auth state 2022/07/08 16:38:38.709165 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Setting Auth state to disconnected 2022/07/08 16:38:38.709172 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Entering restart state 2022/07/08 16:38:38.709182 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Entering init state 2022/07/08 16:38:38.709190 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Entering idle state 2022/07/08 16:38:38.709198 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Dot1x authentication started for (f8e4.e372.6cda) 2022/07/08 16:38:38.709206 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Pushing authen_result to SM for client 0x1100000E 2022/07/08 16:38:38.709218 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Authc success from Dot1X, Auth event success 2022/07/08 16:38:38.709239 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Raised event APPLY_USER_PROFILE (14) 2022/07/08 16:38:38.709249 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Raised event RX_METHOD_AUTHC_SUCCESS (3) 2022/07/08 16:38:38.709261 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Context changing state from 'Idle' to 'Running' 2022/07/08 16:38:38.709276 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Method dot1x changing state from 'Not run' to 'Running' 2022/07/08 16:38:38.709297 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] SM will not send event Template Activated to PRE for 0xE8000017 2022/07/08 16:38:38.709362 {wncd_x_R0-0}{1}: [client-auth] [17028]: (info): MAC: f8e4.e372.6cda Client auth-interface state transition: S_AUTHIF_AWAIT_PUSH_START_RESP -> S_AUTHIF_SESSION_PUSH_PENDING 2022/07/08 16:38:38.709367 {wncd_x_R0-0}{1}: [ewlc-infra-evq] [17028]: (note): Authentication Success. Resolved Policy bitmap:11 for client f8e4.e372.6cda 2022/07/08 16:38:38.709430 {wncd_x_R0-0}{1}: [client-auth] [17028]: (info): MAC: f8e4.e372.6cda Client auth-interface state transition: S_AUTHIF_SESSION_PUSH_PENDING -> S_AUTHIF_DOT1XAUTH_DONE 2022/07/08 16:38:38.709543 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Method dot1x changing state from 'Running' to 'Authc Success' 2022/07/08 16:38:38.709548 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Context changing state from 'Running' to 'Authc Success' 2022/07/08 16:38:38.709616 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: SVM Apply user profile 2022/07/08 16:38:38.712010 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Activating EPM features with UP 2022/07/08 16:38:38.712160 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Response of epm is SYNC with return code Success 2022/07/08 16:38:38.712207 {wncd_x_R0-0}{1}: [svm] [17028]: (info): [f8e4.e372.6cda] Applied User Profile: : 2022/07/08 16:38:38.712213 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: activation-mode 0 0 [merge] 2022/07/08 16:38:38.712217 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: clid-mac-addr 0 f8 e4 e3 72 6c da 2022/07/08 16:38:38.712219 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: target-scope 0 0 [client] 2022/07/08 16:38:38.712221 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: aaa-unique-id 0 33 (0x21) 2022/07/08 16:38:38.712223 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: client-iif-id 0 4261413601 (0xfe0002e1) 2022/07/08 16:38:38.712225 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: swbidb 0 2684354562 (0xa0000002) 2022/07/08 16:38:38.712227 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile:session-linksec-secured 0 False 2022/07/08 16:38:38.712236 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: vlan-id 0 200 (0xc8) 2022/07/08 16:38:38.712238 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: method 0 0 [dot1x] 2022/07/08 16:38:38.712242 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: clid-mac-addr 0 f8 e4 e3 72 6c da 2022/07/08 16:38:38.712244 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): Applied User Profile: intf-id 0 2684354562 (0xa0000002) 2022/07/08 16:38:38.712289 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link-local bridging not enabled for this client, not checking VLAN validity 2022/07/08 16:38:38.712330 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] User Profile applied successfully - MERGE 2022/07/08 16:38:38.712454 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Raised event AUTHZ_SUCCESS (11) 2022/07/08 16:38:38.712463 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Context changing state from 'Authc Success' to 'Authz Success' 2022/07/08 16:38:38.712529 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_CREATE_SM_SESSION_IN_PROGRESS -> S_CO_MOBILITY_DISCOVERY_IN_PROGRESS 2022/07/08 16:38:38.712563 {wncd_x_R0-0}{1}: [ewlc-infra-evq] [17028]: (note): Authentication Success. Resolved Policy bitmap:0 for client f8e4.e372.6cda 2022/07/08 16:38:38.712569 {wncd_x_R0-0}{1}: [client-auth] [17028]: (info): MAC: f8e4.e372.6cda Client auth-interface state transition: S_AUTHIF_DOT1XAUTH_DONE -> S_AUTHIF_DOT1XAUTH_DONE 2022/07/08 16:38:38.712637 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Wireless session pushed 2022/07/08 16:38:38.712672 {wncd_x_R0-0}{1}: [mm-transition] [17028]: (info): MAC: f8e4.e372.6cda MMIF FSM transition: S_MA_INIT -> S_MA_ANCHORING_ASSOC_RESP_PROCESSED_TR on E_MA_CO_EXP_ANCHOR_REQ_ASSOC_RCVD 2022/07/08 16:38:38.712736 {wncd_x_R0-0}{1}: [mm-client] [17028]: (info): MAC: f8e4.e372.6cda Roam type changed - None -> L3 Requested 2022/07/08 16:38:38.712743 {wncd_x_R0-0}{1}: [mm-client] [17028]: (info): MAC: f8e4.e372.6cda Mobility role changed - Unassoc -> Export Anchor 2022/07/08 16:38:38.712745 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Processed Association Response from Client Orchestrator. 2022/07/08 16:38:38.712826 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda IPv6 Client payload is received in export anchor req 2022/07/08 16:38:38.712852 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: SVM Apply user profile 2022/07/08 16:38:38.712928 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Activating EPM features with UP 2022/07/08 16:38:38.712998 {wncd_x_R0-0}{1}: [svm] [17028]: (info): SVM_INFO: Response of epm is SYNC with return code Success 2022/07/08 16:38:38.713011 {wncd_x_R0-0}{1}: [svm] [17028]: (info): [f8e4.e372.6cda] Applied User Profile: : 2022/07/08 16:38:38.713082 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link-local bridging not enabled for this client, not checking VLAN validity 2022/07/08 16:38:38.713152 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Sending Export Anchor Response. 2022/07/08 16:38:38.713261 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda policy payload: elapsed time: 1799 seconds 2022/07/08 16:38:38.713261 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda policy payload: session timeout: 1800 seconds 2022/07/08 16:38:38.713267 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda policy payload: terminate action not set 2022/07/08 16:38:38.713268 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda setting wlan session timeout: 1800 seconds 2022/07/08 16:38:38.713269 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda policy payload: qos level 5 2022/07/08 16:38:38.713270 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda policy payload: avg data 0, avg rt 0, burst data 0, burst rt 0 2022/07/08 16:38:38.713271 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda setting override bits 0x00000000 2022/07/08 16:38:38.713292 {wncd_x_R0-0}{1}: [sanet-shim-miscellaneous] [17028]: (info): MAC: f8e4.e372.6cda setting Interface name : TEST 2022/07/08 16:38:38.713355 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Sending export_anchor_rsp of XID (63315) to (MobilityD[0]) 2022/07/08 16:38:38.713476 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received export_anchor_rsp, sub type: 0 of XID (63315) from (WNCD[0]) 2022/07/08 16:38:38.713476 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: f8e4.e372.6cda Export Anchor complete. 2022/07/08 16:38:38.713570 {wncd_x_R0-0}{1}: [mm-client] [17028]: (note): MAC: f8e4.e372.6cda Mobility Successful. Roam Type L3 Requested, Sub Roam Type MM_SUB_ROAM_TYPE_NONE, Client IFID: 0xa0000003, Client Role: Export Anchor PoA: 0xa0000002 PoP: 0x0 2022/07/08 16:38:38.713574 {mobilityd_R0-0}{1}: [mm-transition] [18337]: (info): MAC: f8e4.e372.6cda MMFSM transition: S_MC_ANCHOR_WAIT_EXP_ANC_RSP -> S_MC_ANCHOR_EXP_ANC_RSP_RCVD_TR on E_MC_EXP_ANC_RSP_RCVD from WNCD[0] 2022/07/08 16:38:38.713585 {wncd_x_R0-0}{1}: [dot1x] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Posting AUTHZ_SUCCESS on Client 2022/07/08 16:38:38.713615 {wncd_x_R0-0}{1}: [ewlc-infra-evq] [17028]: (note): Authentication Success. Resolved Policy bitmap:0 for client f8e4.e372.6cda 2022/07/08 16:38:38.713620 {wncd_x_R0-0}{1}: [client-auth] [17028]: (info): MAC: f8e4.e372.6cda Client auth-interface state transition: S_AUTHIF_DOT1XAUTH_DONE -> S_AUTHIF_DOT1XAUTH_DONE 2022/07/08 16:38:38.713637 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Export Anchor Response successfully processed. 2022/07/08 16:38:38.713652 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Forwarding Anchor Response to Foreign. 2022/07/08 16:38:38.713660 {mobilityd_R0-0}{1}: [mm-client] [18337]: (info): MAC: f8e4.e372.6cda Forwarding export_anchor_rsp, sub type: 0 of XID (63315) from (WNCD[0]) to (ipv4: 192.168.225.100 ) 2022/07/08 16:38:38.713664 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (debug): MAC: f8e4.e372.6cda Processing mobility response from MMIF. Client ifid: 0xa0000003, roam type: L3 Requested, client role: Export Anchor 2022/07/08 16:38:38.713674 {mobilityd_R0-0}{1}: [mm-pmtu] [18337]: (debug): Peer IP: 192.168.225.100 PMTU size is 1385 and calculated additional header length is 76 2022/07/08 16:38:38.713700 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Sending export_anchor_rsp of XID (63315) to (ipv4: 192.168.225.100 ) 2022/07/08 16:38:38.713841 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Client is ANCHORED. 2022/07/08 16:38:38.713847 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_MOBILITY_DISCOVERY_IN_PROGRESS -> S_CO_DPATH_PLUMB_IN_PROGRESS 2022/07/08 16:38:38.713875 {wncd_x_R0-0}{1}: [dot11] [17028]: (note): MAC: f8e4.e372.6cda Client datapath entry params - ssid:QoS_1X,slot_id:0 bssid ifid: 0x0, radio_ifid: 0x0, wlan_ifid: 0xf0400067 2022/07/08 16:38:38.713915 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link-local bridging not enabled for this client, not checking VLAN validity 2022/07/08 16:38:38.713924 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link Local Bridging not enabled for client 2022/07/08 16:38:38.713926 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda Client QoS dpath create params 2022/07/08 16:38:38.713988 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:0. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:38.713996 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:1. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:38.714015 {wncd_x_R0-0}{1}: [avc-afc] [17028]: (debug): AVC enabled for client f8e4.e372.6cda 2022/07/08 16:38:38.714030 {wncd_x_R0-0}{1}: [dpath_svc] [17028]: (ERR): bssid hdl is null 2022/07/08 16:38:38.714031 {wncd_x_R0-0}{1}: [dpath_svc] [17028]: (ERR): bssid hdl is null 2022/07/08 16:38:38.714332 {wncd_x_R0-0}{1}: [dpath_svc] [17028]: (note): MAC: f8e4.e372.6cda Client datapath entry created for ifid 0xa0000003 2022/07/08 16:38:38.714625 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_DPATH_PLUMB_IN_PROGRESS -> S_CO_IP_LEARN_IN_PROGRESS 2022/07/08 16:38:38.714833 {wncd_x_R0-0}{1}: [client-iplearn] [17028]: (info): MAC: f8e4.e372.6cda IP-learn state transition: S_IPLEARN_INIT -> S_IPLEARN_IN_PROGRESS 2022/07/08 16:38:39.211580 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): RX: ARP from interface mobility_a0000002 on vlan 200 Source MAC: f8e4.e372.6cda Dest MAC: ffff.ffff.ffff ARP REQUEST, ARP sender MAC: f8e4.e372.6cda ARP target MAC: 0000.0000.0000 ARP sender IP: 192.168.200.100, ARP target IP: 192.168.200.100, 2022/07/08 16:38:39.230324 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): RX: ARP from interface mobility_a0000002 on vlan 200 Source MAC: f8e4.e372.6cda Dest MAC: ffff.ffff.ffff ARP REQUEST, ARP sender MAC: f8e4.e372.6cda ARP target MAC: 0000.0000.0000 ARP sender IP: 192.168.200.100, ARP target IP: 192.168.200.1, 2022/07/08 16:38:39.250000 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): RX: ARP from interface mobility_a0000002 on vlan 200 Source MAC: f8e4.e372.6cda Dest MAC: ffff.ffff.ffff ARP REQUEST, ARP sender MAC: f8e4.e372.6cda ARP target MAC: 0000.0000.0000 ARP sender IP: 192.168.200.100, ARP target IP: 192.168.200.1, 2022/07/08 16:38:39.509171 {wncd_x_R0-0}{1}: [auth-mgr-feat_dsensor] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] Skipping DHCP TLVs for further processing. DHCP based classification isn't enabled 2022/07/08 16:38:39.509308 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (info): RX: DHCPv4 from interface mobility_a0000002 on vlan 200 Src MAC: f8e4.e372.6cda Dst MAC: ffff.ffff.ffff src_ip: 0.0.0.0, dst_ip: 255.255.255.255, BOOTPREQUEST, SISF_DHCPREQUEST, giaddr: 0.0.0.0, yiaddr: 0.0.0.0, CMAC: f8e4.e372.6cda 2022/07/08 16:38:39.509437 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (info): TX: DHCPv4 from interface mobility_a0000002 on vlan 200 Src MAC: f8e4.e372.6cda Dst MAC: ffff.ffff.ffff src_ip: 0.0.0.0, dst_ip: 255.255.255.255, BOOTPREQUEST, SISF_DHCPREQUEST, giaddr: 0.0.0.0, yiaddr: 0.0.0.0, CMAC: f8e4.e372.6cda 2022/07/08 16:38:39.513405 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (info): RX: DHCPv4 from interface Gi2 on vlan 200 Src MAC: c800.84bf.a748 Dst MAC: ffff.ffff.ffff src_ip: 192.168.200.1, dst_ip: 255.255.255.255, BOOTPREPLY, SISF_DHCPACK, giaddr: 192.168.200.1, yiaddr: 192.168.200.100, CMAC: f8e4.e372.6cda 2022/07/08 16:38:39.513578 {wncd_x_R0-0}{1}: [capwapac-smgr-sess] [17028]: (ERR): Capwap session is down. session handle id is invalid. 2022/07/08 16:38:39.513584 {wncd_x_R0-0}{1}: [client-iplearn] [17028]: (ERR): MAC: 0000.0000.0000 Failed to send gw nw payload for this AP 2022/07/08 16:38:39.513852 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (info): TX: DHCPv4 from interface Gi2 on vlan 200 Src MAC: c800.84bf.a748 Dst MAC: f8e4.e372.6cda src_ip: 192.168.200.1, dst_ip: 255.255.255.255, BOOTPREPLY, SISF_DHCPACK, giaddr: 192.168.200.1, yiaddr: 192.168.200.100, CMAC: f8e4.e372.6cda 2022/07/08 16:38:39.514109 {wncd_x_R0-0}{1}: [client-iplearn] [17028]: (note): MAC: f8e4.e372.6cda Client IP learn successful. Method: DHCP IP: 192.168.200.100 2022/07/08 16:38:39.514239 {wncd_x_R0-0}{1}: [epm] [17028]: (info): [0000.0000.0000:unknown] HDL = 0x0 vlan 200 fail count 0 dirty_counter 0 is_dirty 0 2022/07/08 16:38:39.514399 {wncd_x_R0-0}{1}: [mm-client] [17028]: (debug): MAC: 0000.0000.0000 Sending ipv4_address_update of XID (0) to (MobilityD[0]) 2022/07/08 16:38:39.514547 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Received ipv4_address_update, sub type: 0 of XID (0) from (WNCD[0]) 2022/07/08 16:38:39.514719 {mobilityd_R0-0}{1}: [mm-client] [18337]: (info): MAC: f8e4.e372.6cda Forwarding ipv4_address_update, sub type: 0 of XID (380787) from (WNCD[0]) to (ipv4: 192.168.225.100 ) 2022/07/08 16:38:39.514756 {mobilityd_R0-0}{1}: [mm-pmtu] [18337]: (debug): Peer IP: 192.168.225.100 PMTU size is 1385 and calculated additional header length is 76 2022/07/08 16:38:39.514778 {mobilityd_R0-0}{1}: [mm-client] [18337]: (debug): MAC: f8e4.e372.6cda Sending ipv4_address_update of XID (380787) to (ipv4: 192.168.225.100 ) 2022/07/08 16:38:39.514785 {wncd_x_R0-0}{1}: [auth-mgr] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] auth mgr attr add/change notification is received for attr addr(8) 2022/07/08 16:38:39.514881 {wncd_x_R0-0}{1}: [auth-mgr-feat_acct] [17028]: (info): [f8e4.e372.6cda:mobility_a0000002] SM Notified attribute Add/Update addr 192.168.200.100 2022/07/08 16:38:39.514931 {wncd_x_R0-0}{1}: [client-iplearn] [17028]: (info): MAC: f8e4.e372.6cda IP-learn state transition: S_IPLEARN_IN_PROGRESS -> S_IPLEARN_COMPLETE 2022/07/08 16:38:39.514976 {wncd_x_R0-0}{1}: [client-orch-sm] [17028]: (debug): MAC: f8e4.e372.6cda Received ip learn response. method: IPLEARN_METHOD_DHCP 2022/07/08 16:38:39.515204 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): [ Applied attribute :bsn-vlan-interface-name 0 "TEST" ] 2022/07/08 16:38:39.515206 {wncd_x_R0-0}{1}: [aaa-attr-inf] [17028]: (info): [ Applied attribute : timeout 0 1800 (0x708) ] 2022/07/08 16:38:39.515228 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda Client QoS run state handler 2022/07/08 16:38:39.515275 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:0. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:39.515302 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:1. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:39.515592 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda Build AAA QoS Params for addMobile: aaa_avgdtus:0, aaa_avgrtdtus:0, aaa_bstdtus:0, aaa_bstrtdtus:0, aaa_avgdtds:0, aaa_avgrtdtds:0, aaa_bstdtds:0, aaa_bstrtdtds:0, aaa_sig:1431655765 2022/07/08 16:38:39.515617 {wncd_x_R0-0}{1}: [rog-proxy-capwap] [17028]: (debug): Managed client RUN state notification: f8e4.e372.6cda 2022/07/08 16:38:39.515631 {wncd_x_R0-0}{1}: [avc-afc] [17028]: (info): Reanchor [client MAC: f8e4.e372.6cda] Client has anchor role 2022/07/08 16:38:39.515635 {wncd_x_R0-0}{1}: [avc-afc] [17028]: (info): Reanchor [client MAC: f8e4.e372.6cda] Guest client detected. Skip it 2022/07/08 16:38:39.515708 {wncd_x_R0-0}{1}: [client-orch-state] [17028]: (note): MAC: f8e4.e372.6cda Client state transition: S_CO_IP_LEARN_IN_PROGRESS -> S_CO_RUN 2022/07/08 16:38:39.515813 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link-local bridging not enabled for this client, not checking VLAN validity 2022/07/08 16:38:39.515836 {wncd_x_R0-0}{1}: [llbridge-main] [17028]: (debug): MAC: f8e4.e372.6cda Link Local Bridging not enabled for client 2022/07/08 16:38:39.515837 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda Client QoS dpath run params 2022/07/08 16:38:39.515871 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:0. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:39.515875 {wncd_x_R0-0}{1}: [ewlc-qos-client] [17028]: (info): MAC: f8e4.e372.6cda No QoS PM Name or QoS Level received from SANet for pm_dir:1. Check client is fastlane, otherwise set pm name to none 2022/07/08 16:38:39.515884 {wncd_x_R0-0}{1}: [avc-afc] [17028]: (debug): AVC enabled for client f8e4.e372.6cda 2022/07/08 16:38:39.515920 {wncd_x_R0-0}{1}: [apmgr-bssid] [17028]: (ERR): Failed to get the wlan_internal_policy record 2022/07/08 16:38:39.515923 {wncd_x_R0-0}{1}: [dpath_svc] [17028]: (ERR): MAC: f8e4.e372.6cda Failed to get zone id of the client- error: 22, Invalid argument 2022/07/08 16:38:39.515923 {wncd_x_R0-0}{1}: [dpath_svc] [17028]: (ERR): Invalid BSSID handle, cannot check central NAT 2022/07/08 16:38:39.556160 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): RX: ARP from interface mobility_a0000002 on vlan 200 Source MAC: f8e4.e372.6cda Dest MAC: ffff.ffff.ffff ARP REQUEST, ARP sender MAC: f8e4.e372.6cda ARP target MAC: 0000.0000.0000 ARP sender IP: 192.168.200.100, ARP target IP: 192.168.200.1, 2022/07/08 16:38:39.556258 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): TX: ARP from interface mobility_a0000002 on vlan 200 Source MAC: f8e4.e372.6cda Dest MAC: ffff.ffff.ffff ARP REQUEST, ARP sender MAC: f8e4.e372.6cda ARP target MAC: 0000.0000.0000 ARP sender IP: 192.168.200.100, ARP target IP: 192.168.200.1, 2022/07/08 16:38:39.557591 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): RX: ARP from interface Gi2 on vlan 200 Source MAC: c800.84bf.a748 Dest MAC: f8e4.e372.6cda ARP REPLY, ARP sender MAC: c800.84bf.a748 ARP target MAC: f8e4.e372.6cda ARP sender IP: 192.168.200.1, ARP target IP: 192.168.200.100, 2022/07/08 16:38:39.557660 {wncd_x_R0-0}{1}: [sisf-packet] [17028]: (debug): TX: ARP from interface Gi2 on vlan 200 Source MAC: c800.84bf.a748 Dest MAC: f8e4.e372.6cda ARP REPLY, ARP sender MAC: c800.84bf.a748 ARP target MAC: f8e4.e372.6cda ARP sender IP: 192.168.200.1, ARP target IP: 192.168.200.100,
You can use the “show platform conditions” CLI command to see what platform conditions has been enabled.
You can use the “clear platform condition all” CLI command to remove platform conditions set earlier. Also “undebug all” to clear all debugging.
C9800-2#clear platform condition all C9800-2#undebug all
If you do client troubleshooting there is a useful CLI command “show wireless stats” available in 9800
You can use the “show wireless stats trace-on-failure” CLI command to see what is the most common client failure reasons. Below shown a sample output
WLC4#show wireless stats trace-on-failure ---------------------------------------------------------- Wireless Trace On Failure Statistics ---------------------------------------------------------- 001. AP radio reset......................................: 0 002. AP reset............................................: 0 003. Client disjoin due to AP radio reset................: 0 004. Client disjoin due to AP reset......................: 0 005. Export client MMIF..................................: 0 006. Export client MM....................................: 0 007. Export client generic...............................: 0 008. Export client message...............................: 0 009. Multicast AP error..................................: 0 010. Multicast client error..............................: 0 011. AP join failure.....................................: 0 012. AP initial configuration failure....................: 0 013. AP configuration update failure.....................: 0 014. AP configuration status failure.....................: 0 015. AP image download failure...........................: 0 016. AP BSSID purge failure..............................: 0 017. Capwap join failure.................................: 0 018. Capwap configuration status failure.................: 0 019. Capwap heartbeat expiry.............................: 0 020. Client association failure..........................: 0 021. Client MAB authentication failure...................: 54 023. Client stage timeout................................: 19707 024. Client datapath nack................................: 0 025. Client mobility clean up............................: 1495 026. DTLS certificate verify failure.....................: 0 027. DTLS handshake failure..............................: 0 028. DTLS no init packet drop............................: 0 029. DTLS cleanup in progress............................: 0 030. DTLS no configuration packet drop...................: 0 031. DTLS no session manager inst........................: 0 032. DTLS invalid hello packet drop......................: 0 033. SANET AUTHZ failure.................................: 38 034. SANET AUTHC failure.................................: 20201 035. MM message build failure............................: 0 036. MM message handle failure...........................: 0 037. MM MA message handle failure........................: 0 038. MM MA build message failure.........................: 0 039. MM MA event handling failure........................: 0 040. MM MA process message failure.......................: 2989 041. MM MC process message failure.......................: 0 042. MM MC message send failure..........................: 0 043. MM message event failure............................: 0 044. MM MA HA event failure..............................: 0 045. MM MC HA event failure..............................: 0 046. LISP agent map request message send failure.........: 0 047. LISP agent negative map reply received..............: 0 048. LISP agent map register message send failure........: 0 049. LISP agent map register reject message received.....: 0 050. QOS BSSID policy install failure....................: 0 051. QOS blacklist client................................: 0 052. Rogue ap failure....................................: 0 053. QOS AP SSO failure..................................: 0 054. QOS client SSO failure..............................: 0
You can use “show wireless stats trace-on-failure | ex :_0” to filter out faiure resasons with stats other than 0
WLC4#show wireless stats trace-on-failure | ex :_0 ---------------------------------------------------------- Wireless Trace On Failure Statistics ---------------------------------------------------------- 021. Client MAB authentication failure...................: 54 023. Client stage timeout................................: 19707 025. Client mobility clean up............................: 1495 033. SANET AUTHZ failure.................................: 38 034. SANET AUTHC failure.................................: 20201 040. MM MA process message failure.......................: 2989
When you get client connectivity issues, always use this method & see what can you find. In our example Foreign WLC doing layer 2 authentications, hence you did not see 802.1X/EAP exchanges on Anchor WLC.
References
1. Cisco Live – Catalyst 9800 Troubleshooting Sessions
2. Understand Wireless Debugs and Log Collection on Catalyst 9800
3. Cisco 9800 WLC KPI Blog – Part 3
Thank you!
You are welcome Diego
Great as always!
Thanks, man 🙂