Informazioni sulla registrazione di AnyConnect Network Access Manager

Introduzione

In questo documento viene descritto come abilitare la registrazione di AnyConnect Network Access Manager (NAM) e come raccogliere e interpretare i registri. Gli esempi inclusi nel documento descrivono i diversi scenari di autenticazione e i log che riflettono le operazioni eseguite da Network Access Manager per autenticare il client.

Prerequisiti

Requisiti

Nessun requisito specifico previsto per questo documento.

Componenti usati

Il documento può essere consultato per tutte le versioni software o hardware.

Le informazioni discusse in questo documento fanno riferimento a dispositivi usati in uno specifico ambiente di emulazione. Su tutti i dispositivi menzionati nel documento la configurazione è stata ripristinata ai valori predefiniti. Se la rete è operativa, valutare attentamente eventuali conseguenze derivanti dall'uso dei comandi.

Abilita registrazione NAM

Se viene identificato un problema che potrebbe essere correlato al modulo NAM, la prima fase consiste nell'abilitare la funzione di registrazione estesa. Questa operazione deve essere eseguita sull'endpoint del client mentre il modulo NAM è in esecuzione.

Passaggio 1. Aprire la finestra AnyConnect e verificare che sia attiva.

Passaggio 2. Premere questa combinazione di tasti, MAIUSC di sinistra + ALT di sinistra + L. Nessuna risposta.

Passaggio 3. Fare clic con il pulsante destro del mouse sull'icona AnyConnect nella barra delle applicazioni di Windows. Viene visualizzato un menu.

Passaggio 4. Selezionare Log esteso in modo che venga visualizzato un segno di spunta. NAM registra ora i messaggi di debug dettagliati.

Configura acquisizione pacchetti NAM

Quando la registrazione estesa è abilitata, NAM mantiene attivo anche un buffer di acquisizione dei pacchetti. Per impostazione predefinita, il buffer è limitato a circa 1 MB. Se è necessaria l'acquisizione dei pacchetti, può essere utile aumentare le dimensioni del buffer in modo da acquisire più attività. Per estendere il buffer, è necessario modificare manualmente un file di impostazione XML.

Passaggio 1. Sul PC Windows, selezionare:
C:\ProgramData\Cisco\Cisco AnyConnect Secure Mobility Client\Network Access Manager\system\

Passaggio 2. Aprire il file internalConfiguration.xml.

Passaggio 3. Individuare il tag XML <packetCaptureFileSize>1</packetCaptureFileSize> e impostare il valore su 10 per le dimensioni del buffer di 10 MB e così via.

Passaggio 4. Riavviare il PC client per rendere effettiva la modifica.

Raccolta log

La raccolta dei registri NAM viene eseguita tramite DART (Diagnostic And Reporting Tool), un modulo della suite AnyConnect. Nel programma di installazione, selezionare un modulo e utilizzare AnyConnect con l'installazione completa ISO per l'installazione. Il programma di installazione di Cisco Media Services Interface (MSI) è reperibile anche all'interno dell'ISO.

Dopo aver attivato la registrazione estesa ed eseguito un test, eseguire semplicemente DART e passare attraverso la finestra di dialogo, il bundle di log si trova per impostazione predefinita sul desktop di Windows.

Oltre al bundle DART, il log dei messaggi NAM è anche utile per individuare i dati rilevanti nel log NAM. Per trovare il log dei messaggi NAM, selezionare Finestra impostazioni AnyConnect > Network Access Manager > Cronologia messaggi. Il log dei messaggi contiene l'indicatore orario di ogni evento di connessione di rete, che può essere utilizzato per trovare i log relativi all'evento.

Lettura dei log NAM

I registri NAM, soprattutto dopo aver attivato la registrazione estesa, contengono una grande quantità di dati, la maggior parte dei quali sono irrilevanti e possono essere ignorati. In questa sezione vengono elencate le righe di debug per illustrare i passaggi eseguiti da NAM per stabilire una connessione di rete. Quando si analizza un registro, queste frasi chiave possono essere utili per individuare una parte del registro relativa al problema. 

Riepilogo registro di una connessione di rete senza autenticazione 802.1x abilitata

2016 17:20:37.974 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: AccessStateMachine current state = ACCESS_STOPPED, received userEvent = START

Spiegazione: indica che l'utente ha selezionato una rete dal modulo NAM e NAM ha ricevuto un userEvent di START.

538: TESTPC: May 16 2016 17:20:37.974 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: AccessStateMachine new state = ACCESS_STARTED
539: TESTPC: May 16 2016 17:20:37.974 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: NetworkStateMachine current state USER_T_DISCONNECTED, received access event ACCESS_STARTED

Spiegazione: sia la macchina a stati di accesso che la macchina a stati di rete sono state avviate.

545: TESTPC: May 16 2016 17:20:37.974 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Ipv4 {EFDAF0F0-CF25-4D88-B125-E748CD539DFF}: received Cancel event [state: COMPLETE]

Spiegazione: L'istanza IPv4 è stata annullata per reimpostare gli stati.

547: TESTPC: May 16 2016 17:20:37.974 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: starting makeMatches...
549: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-6-INFO_MSG: %[tid=1412]: matching adapter {484E4FEF-392C-436F-97F0-CD7206CD7D48} and network test123 ...

Spiegazione: La scheda con ID 484E4FEF-392C-436F-97F0-CD7206CD7D48 è stata selezionata per la connessione a test123 di rete, che è il nome della connessione di rete configurata in NAM.

551: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: AccessStateMachine new state = ACCESS_ATTACHED
557: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: AccessStateMachine current state = ACCESS_ATTACHED, received userEvent = CONNECT

Spiegazione: NAM ha inserito correttamente la scheda per questa rete. NAM tenta ora di associare (connettersi) a questa rete (che è wireless):

561: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM current: state(STATE_DISCONNECTED_LINK_DOWN), event(EVENT_CONNECT)
562: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM state change: STATE_DISCONNECTED_LINK_DOWN -> STATE_ASSOCIATING
567: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Starting wifi connection, trying ssid test123 ...
568: TESTPC: May 16 2016 17:20:37.989 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Connection Association Started(openNoEncryption)

Spiegazione: openNoEncryption indica che la rete è configurata come aperta. Sul controller LAN wireless viene usato il MAC Authentication Bypass (MAB) per l'autenticazione.

234: TESTPC: May 16 2016 17:20:38.020 +0600: %NAMSSO-7-DEBUG_MSG: %[tid=1912]: waiting for cs...

Nota esplicativa: La tecnologia cs può essere rilevata molto nei log di NAM. Si tratta di registri irrilevanti che devono essere ignorati.

575: TESTPC: May 16 2016 17:20:38.020 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: NetworkStateMachine new state USER_T_DISCONNECTED 236: TESTPC: May 16 2016 17:20:38.020 +0600: %NAMSSO-7-DEBUG_MSG: %[tid=1912]: Tx CP Msg: <?xml version="1.0" encoding="UTF-8"?><SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" xmlns:ssc="http://www.cisco.com/ssc" encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"> <SOAP-ENV:Body> <networkStateEvent> <sequenceNumber>16</sequenceNumber> <groupName>Local networks</groupName> <networkName>test123</networkName> <networkState>Associating</networkState> <adapterName>Intel(R) Centrino(R) Ultimate-N 6300 AGN</adapterName> <serverVerifiedName></serverVerifiedName> </networkStateEvent> </SOAP-ENV:Body></SOAP-ENV:Envelope>
 

Spiegazione: Si tratta di messaggi SOAP (Simple Object Access Protocol) utilizzati per indicare all'interfaccia utente di AnyConnect di visualizzare il messaggio di stato della connessione, in questo caso l'associazione. Tutti i messaggi di errore visualizzati nella finestra NAM si trovano in uno dei messaggi SOAP nel registro che può essere utilizzato per individuare facilmente il problema.

582: TESTPC: May 16 2016 17:20:38.020 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: {484E4FEF-392C-436F-97F0-CD7206CD7D48} - Received STATE_AUTHENTICATED
583: TESTPC: May 16 2016 17:20:38.020 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM current: state(STATE_ASSOCIATING), event(EVENT_AUTH_SUCCESS)

Spiegazione: NAM riceve un evento AUTH_SUCCESS che è fuorviante in quanto al momento non è presente alcuna autenticazione. Questo evento viene generato semplicemente perché ci si connette a una rete aperta e pertanto, per impostazione predefinita, l'autenticazione ha esito positivo.

595: TESTPC: May 16 2016 17:20:38.738 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network test123: AccessStateMachine current state = ACCESS_ASSOCIATING, received adapterState = associated

Spiegazione: associazione a SSID (Service Set Identifier) riuscita. Tempo necessario per gestire l'autenticazione.

603: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-6-INFO_MSG: %[tid=1412][mac=1,6,3c:a9:f4:33:ab:50]: Authentication not required.
604: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM current: state(STATE_ASSOCIATED), event(EVENT_AUTH_SUCCESS)
605: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM state change: STATE_ASSOCIATED -> STATE_AUTHENTICATED

Spiegazione: Trattandosi di una rete aperta, per impostazione predefinita viene autenticata. A questo punto, NAM è connesso alla rete e ora avvia il processo DHCP:

610: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: {484E4FEF-392C-436F-97F0-CD7206CD7D48} creating a new DHCP work
612: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-6-INFO_MSG: %[tid=1412][mac=1,6,3c:a9:f4:33:ab:50]: {484E4FEF-392C-436F-97F0-CD7206CD7D48}: DHCP: Sending DHCP request
613: TESTPC: May 16 2016 17:20:38.754 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: queueing DHCP work
642: TESTPC: May 16 2016 17:20:40.830 +0600: %NAM-7-DEBUG_MSG: %[tid=1448]: Ipv4 {484E4FEF-392C-436F-97F0-CD7206CD7D48}: connectivity test[03]: IP:10.201.230.196(255.255.255.224) GW:10.201.230.193 [Success]
643: TESTPC: May 16 2016 17:20:40.830 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Ipv4 {484E4FEF-392C-436F-97F0-CD7206CD7D48}: received Success event [state: WAIT_FOR_CONNECTIVITY]
645: TESTPC: May 16 2016 17:20:40.845 +0600: %NAM-6-INFO_MSG: %[tid=1412][mac=1,6,3c:a9:f4:33:ab:50]: {484E4FEF-392C-436F-97F0-CD7206CD7D48}: IP Address Received: 10.201.230.196
646: TESTPC: May 16 2016 17:20:40.845 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Ipv4 Connectivity Result: SUCCESS

Spiegazione: NAM ha acquisito un indirizzo IP.

648: TESTPC: May 16 2016 17:20:40.845 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM current: state(STATE_AUTHENTICATED), event(EVENT_IP_CONNECTIVITY)
649: TESTPC: May 16 2016 17:20:40.845 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: ACE: adapter SM state change: STATE_AUTHENTICATED -> STATE_CONNECTED

Spiegazione: Dopo aver ricevuto un indirizzo IP, NAM invierà una richiesta ARP (Address Resolution Protocol) al gateway (Get-Connectivity). Dopo aver ricevuto la risposta ARP, il client è connesso.

Riepilogo registro di una connessione di rete che utilizza 802.1x e PEAP su rete cablata

1286: TESTPC: May 16 2016 17:55:17.138 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network WiredPEAP: AccessStateMachine new state = ACCESS_STARTED
 

Spiegazione: NAM ha avviato la connessione alla rete WiredPEAP.

1300: TESTPC: May 16 2016 17:55:17.138 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Binding adapter Intel(R) 82579LM Gigabit Network Connection and user auth for network WiredPEAP
1303: TESTPC: May 16 2016 17:55:17.138 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network WiredPEAP: AccessStateMachine new state = ACCESS_ATTACHED
 

Spiegazione: il NAM corrisponde a una scheda a questa rete.

1309: TESTPC: May 16 2016 17:55:17.138 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Network WiredPEAP: AccessStateMachine current state = ACCESS_ATTACHED, received userEvent = CONNECT
1342: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: STATE (4) S_enterStateAux called with state = CONNECTING (dot1x_sm.c 142)
 

Spiegazione: NAM ha avviato la connessione a questa rete cablata.

1351: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: 8021X (4) Sent start frame (dot1x_sm.c 117)
 

Spiegazione: Il client invia EAPOL_START.

1388: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: PORT (3) net: RECV (status: UP, AUTO) (portMsg.c 658)
1389: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: 8021X (4) recvd EAP IDENTITY frame (dot1x_util.c 264)
1397: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) EAP State: EAP_STATE_IDENTITY (eap_auth_client.c 940)
 

Spiegazione: il client riceve la richiesta di identità dallo switch e ora cerca una credenziale da restituire.

1406: TESTPC: May 16 2016 17:55:17.154 +0600: %NAM-7-DEBUG_MSG: %[tid=1464]: EAP-CB: credential requested: sync=8, session-id=1, handle=00AE1FFC, type=AC_CRED_SESSION_START
1426: TESTPC: May 16 2016 17:55:17.169 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: EAP: processing credential request: sync=8, session-id=1, eap-handle=00AE1FFC, eap-level=0, auth-level=0, protected=0, type=CRED_REQ_SESSION_START
1458: TESTPC: May 16 2016 17:55:17.169 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Trying fast reauthentication for unprotected identity anonymous
1464: TESTPC: May 16 2016 17:55:17.169 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: EAP: credential request completed, response sent: sync=9
 

Spiegazione: Per impostazione predefinita, Anyconnect invia l'anonimato come identità non protetta (identità esterna), quindi in questo caso prova con l'anonimo e verifica se il server funziona correttamente. Il fatto che l'identità sia anonima rispetto all'host/anonima indica che si tratta di un'autenticazione utente, piuttosto che di un'autenticazione automatica.

1492: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: 8021X (4) recvd EAP TLS frame (dot1x_util.c 293)
 

Spiegazione: il server RADIUS invia un frame EAP-TLS (Extensible Authentication Protocol-Transport Layer Security) senza alcun contenuto. Il suo scopo è negoziare il protocollo EAP-TLS con il client.

1516: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-6-INFO_MSG: %[tid=1412]: EAP: EAP suggested by server: eapTls
1517: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-6-INFO_MSG: %[tid=1412]: EAP: EAP requested by client: eapPeap
1518: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: EAP: EAP methods sent: sync=10
1519: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: EAP: credential request 10: state transition: PENDING -> RESPONDED
 

Spiegazione: NAM riconosce la richiesta del server di utilizzare EAP-TLS ma il client è configurato per utilizzare PEAP (Protected Extensible Authentication Protocol). È per questo motivo che NAM rinvia una controproposta per PEAP.

1520: TESTPC: May 16 2016 17:55:17.185 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: Authentication state transition: AUTH_STATE_UNPROTECTED_IDENTITY_SENT_FOR_FAST_REAUTHENTICATION -> AUTH_STATE_UNPROTECTED_IDENTITY_ACCEPTED
 

Spiegazione: il server RADIUS accetta l'identità esterna/non protetta.

1551: TESTPC: May 16 2016 17:55:17.200 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: 8021X (4) recvd EAP PEAP frame (dot1x_util.c 305)
1563: TESTPC: May 16 2016 17:55:17.200 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) EAP-PEAP: SSL handshake start (eap_auth_tls_p.c 409)
 

Spiegazione: la parte Protected di PEAP (per stabilire un tunnel sicuro per lo scambio delle credenziali interne) viene avviata dopo che il client riceve una conferma dal server RADIUS per continuare a utilizzare PEAP.

1565: TESTPC: May 16 2016 17:55:17.200 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) SSL STATE: SSLv3 write client hello A (eap_auth_tls_p.c 394)
1566: TESTPC: May 16 2016 17:55:17.200 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) SSL STATE: SSLv3 read server hello A (eap_auth_tls_p.c 394)
 

Spiegazione: il NAM invia un hello client incapsulato nel messaggio EAP e attende il saluto del server. Poiché il server contiene un certificato ISE, il completamento del trasferimento richiede del tempo.

1622: TESTPC: May 16 2016 17:55:17.216 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: 8021X (4) recvd EAP PEAP frame (dot1x_util.c 305)
1632: TESTPC: May 16 2016 17:55:17.216 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) SSL STATE: SSLv3 read server hello A (eap_auth_tls_p.c 394)
1633: TESTPC: May 16 2016 17:55:17.216 +0600: %NAM-6-INFO_MSG: %[tid=1468][comp=SAE]: CERT (0) looking up: "/CN=ISE20-1.kurmai.com" (lookup.c 100)
1634: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-6-INFO_MSG: %[tid=1468][comp=SAE]: CERT (0) Certificate not found: "/CN=ISE20-1.kurmai.com" (lookup.c 133)
1646: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) SSL_ERROR_WANT_X509_LOOKUP (eap_auth_tls_p.c 193)
 

Spiegazione: NAM ha estratto il nome soggetto del server ISE dal certificato del server. Il certificato server non è installato nell'archivio di attendibilità, pertanto non è disponibile.

1649: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (5) EAP_EVENT_CRED_REQUEST queued (eapCredProcess.c 496)
1650: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-7-DEBUG_MSG: %[tid=1464][comp=SAE]: EAP (5) EAP: CRED_REQUEST (eapMessage.c 355)
1662: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Getting credentials from logon.
1685: TESTPC: May 16 2016 17:55:17.232 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: ...resumed
 

Spiegazione: NAM cerca l'identità interna/protetta da inviare al server RADIUS dopo aver stabilito il tunnel. In questo caso, l'opzione "Usa automaticamente nome di accesso e password di Windows" è stata abilitata sulla scheda cablata, pertanto NAM utilizza le credenziali di accesso di Windows anziché richiederle all'utente.

1700: TESTPC: May 16 2016 17:55:17.247 +0600: %NAM-7-DEBUG_MSG: %[tid=1464][comp=SAE]: EAP (0) SSL STATE: SSLv3 write client key exchange A (eap_auth_tls_p.c 394)
1701: TESTPC: May 16 2016 17:55:17.247 +0600: %NAM-7-DEBUG_MSG: %[tid=1464][comp=SAE]: EAP (0) SSL STATE: SSLv3 write change cipher spec A (eap_auth_tls_p.c 394)
1750: TESTPC: May 16 2016 17:55:17.278 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) SSL STATE: SSL negotiation finished successfully (eap_auth_tls_p.c 394)
1751: TESTPC: May 16 2016 17:55:17.278 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) EAP-PEAP: SSL handshake done (eap_auth_tls_p.c 425)
1752: TESTPC: May 16 2016 17:55:17.278 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) EAP-PEAP: New session. (eap_auth_tls_p.c 433)
1753: TESTPC: May 16 2016 17:55:17.278 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: EAP (0) EAP-PEAP: session cipher AES256-SHA. (eap_auth_tls_p.c 441)
 

Spiegazione: NAM ha inviato la chiave client e la specifica di cifratura al server e ha ricevuto conferma. Negoziazione SSL completata. È stato stabilito un tunnel.

1810: TESTPC: May 16 2016 17:55:17.294 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Protected identity/(Username) sent.
1814: TESTPC: May 16 2016 17:55:17.294 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: Authentication state transition: AUTH_STATE_UNPROTECTED_IDENTITY_ACCEPTED -> AUTH_STATE_PROTECTED_IDENTITY_SENT
1883: TESTPC: May 16 2016 17:55:17.310 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: Authentication state transition: AUTH_STATE_PROTECTED_IDENTITY_SENT -> AUTH_STATE_PROTECTED_IDENTITY_ACCEPTED
 

Spiegazione: l'identità protetta viene inviata al server, che accetta l'identità. Il server ora richiede la password.

1902: TESTPC: May 16 2016 17:55:17.310 +0600: %NAM-7-DEBUG_MSG: %[tid=1464][comp=SAE]: EAP (5) deferred password request (eapRequest.c 147)
1918: TESTPC: May 16 2016 17:55:17.310 +0600: %NAM-6-INFO_MSG: %[tid=1412]: Protected password sent.
1921: TESTPC: May 16 2016 17:55:17.325 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: Authentication state transition: AUTH_STATE_PROTECTED_IDENTITY_ACCEPTED -> AUTH_STATE_CREDENTIAL_SENT
 

Spiegazione: NAM riceve la richiesta della password e invia la password al server.

2076: TESTPC: May 16 2016 17:55:17.856 +0600: %NAM-7-DEBUG_MSG: %[tid=1412]: Auth[WiredPEAP:user-auth]: Authentication state transition: AUTH_STATE_CREDENTIAL_SENT -> AUTH_STATE_SUCCESS
2077: TESTPC: May 16 2016 17:55:17.856 +0600: %NAM-7-DEBUG_MSG: %[tid=1468][comp=SAE]: STATE (4) S_enterStateAux called with state = AUTHENTICATED (dot1x_sm.c 142)
 

Spiegazione: Il server riceve la password, la verifica e invia EAP-Success. A questo punto l'autenticazione ha esito positivo e il client procede non appena riceve l'indirizzo IP da DHCP.