Tags

, ,

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.

9800-Troble-0

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.

9800-Troble-3

In 9800 GUI, You can go to “Troubleshooting > Radioactive Trace” & add the MAC address of the client to the list as shown below.

9800-Troble-1

Once you do that you need to start conditional debugging by clicking the “Start” button.

9800-Troble-2

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.

9800-Troble-4

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.

9800-Troble-41

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.

9800-Troble-42

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.

9800-Troble-5

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.

9800-Troble-7

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.

9800-Troble-8

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.

9800-Troble-6

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.

9800-Troble-9

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

9800-Troble-10

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