Comprendre la journalisation AnyConnect Network Access Manager

Introduction

Ce document décrit comment activer la journalisation d'AnyConnect Network Access Manager (NAM) ainsi que comment collecter et interpréter les journaux. Les exemples inclus dans le document décrivent différents scénarios d'authentification et les journaux qui reflètent les étapes suivies par Network Access Manager pour authentifier le client.

Conditions préalables

Exigences

Aucune exigence spécifique n'est associée à ce document.

Composants utilisés

Ce document n'est pas limité à des versions de matériel et de logiciel spécifiques.

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.

Activer la journalisation NAM

Si un problème lié au module NAM est identifié, la première étape consiste à activer la fonctionnalité de journalisation étendue. Cette opération doit être effectuée sur le terminal client pendant l'exécution du module NAM.

Étape 1. Ouvrez la fenêtre AnyConnect et assurez-vous qu’elle est active.

Étape 2. Appuyez sur cette combinaison de touches, Maj gauche + Alt gauche + L. Il n'y a pas de réponse.

Étape 3. Cliquez avec le bouton droit sur l’icône AnyConnect dans la barre d’état système Windows. Un menu s'affiche.

Étape 4. Sélectionnez Journalisation étendue pour qu'une coche s'affiche. NAM consigne maintenant les messages de débogage détaillés.

Configuration de la capture de paquets NAM

Lorsque la consignation étendue est activée, le NAM maintient également un tampon de capture de paquets. La mémoire tampon est limitée par défaut à environ 1 Mo. Si la capture de paquets est nécessaire, il peut être avantageux d'augmenter la taille de la mémoire tampon afin de capturer davantage d'activités. Pour étendre la mémoire tampon, un fichier de paramètres XML doit être modifié manuellement.

Étape 1. Sur le PC Windows, accédez à :
C:\ProgramData\Cisco\Cisco AnyConnect Secure Mobility Client\Network Access Manager\system\

Étape 2. Ouvrez le fichier internalConfiguration.xml.

Étape 3. Localisez la balise XML <packetCaptureFileSize>1</packetCaptureFileSize> et réglez la valeur sur 10 pour une taille de mémoire tampon de 10 Mo, etc.

Étape 4. Redémarrez le PC client pour que la modification prenne effet.

Collecte des journaux

La collecte des journaux NAM s’effectue via l’outil DART (Diagnostic And Reporting Tool), qui est un module de la suite AnyConnect. Dans le programme d'installation, sélectionnez un module et utilisez AnyConnect full installation ISO pour l'installer. Le programme d'installation de Cisco Media Services Interface (MSI) se trouve également à l'intérieur de l'ISO.

Après avoir activé la consignation étendue et effectué un test, exécutez simplement DART et accédez à la boîte de dialogue, le groupe de journaux est situé par défaut sur le Bureau Windows.

En plus de l'ensemble DART, le journal des messages NAM est également utile pour localiser les données pertinentes dans le journal NAM. Afin de trouver le journal des messages NAM, naviguez vers la fenêtre des paramètres AnyConnect > Network Access Manager > Message History. Le journal des messages contient l'horodatage de chaque événement de connexion réseau, qui peut être utilisé pour rechercher les journaux pertinents pour l'événement.

Lecture des journaux NAM

Les journaux NAM, en particulier après l'activation de la consignation étendue, contiennent une grande quantité de données, dont la plupart ne sont pas pertinentes et peuvent être ignorées. Cette section répertorie les lignes de débogage pour illustrer chaque étape que le NAM effectue pour établir une connexion réseau. Lorsque vous parcourez un journal, ces phrases clés peuvent être utiles pour localiser une partie du journal correspondant au problème. 

Résumé du journal d'une connexion réseau sans authentification 802.1x activée

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

Explication : cela indique que l'utilisateur a sélectionné un réseau dans le module NAM et que NAM a reçu un userEvent de 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

Explication : L'ordinateur à état d'accès et l'ordinateur à état de réseau ont été démarrés.

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]

Explication : l'instance IPv4 a été annulée afin de réinitialiser les états.

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 ...

Explication : l'adaptateur portant l'ID 484E4FEF-392C-436F-97F0-CD7206CD7D48 a été sélectionné pour se connecter au réseau test123, qui est le nom de la connexion réseau configurée dans 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

Explication : NAM a correctement connecté la carte pour ce réseau. Maintenant, NAM tente de s'associer (se connecter) à ce réseau (qui se trouve être sans fil) :

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)

Explication : openNoEncryption indique que le réseau est configuré comme ouvert. Sur le contrôleur LAN sans fil, il utilise le contournement d'authentification MAC (MAB) pour l'authentification.

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

Explication : cs est beaucoup visible dans les journaux NAM. Ces journaux ne sont pas pertinents et doivent être ignorés.

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>
 

Explication : il s'agit de messages SOAP (Simple Object Access Protocol) utilisés pour indiquer à l'interface graphique d'AnyConnect d'afficher le message d'état de la connexion, tel que Associating dans ce cas. Tous les messages d'erreur affichés dans la fenêtre NAM peuvent être trouvés dans l'un des messages SOAP du journal qui peut être utilisé pour localiser facilement le problème.

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)

Explication : NAM reçoit un événement AUTH_SUCCESS, ce qui induit en erreur parce qu'il n'y a pas d'authentification qui s'est produite actuellement. Vous obtenez cet événement simplement parce que vous vous connectez à un réseau ouvert, de sorte que par défaut l'authentification est réussie.

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

Explication : L'association à l'identificateur SSID (Service Set Identifier) a réussi, le temps de gestion de l'authentification est écoulé.

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

Explication : Comme il s'agit d'un réseau ouvert, il est authentifié par défaut. À ce stade, NAM est connecté au réseau et lance maintenant le processus 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

Explication : NAM a réussi à acquérir une adresse 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

Explication : une fois qu'une adresse IP est reçue, NAM envoie une requête ARP (Address Resolution Protocol) à la passerelle (Get-Connectivity). Une fois la réponse ARP reçue, le client est connecté.

Résumé du journal d'une connexion réseau utilisant 802.1x et PEAP sur un réseau câblé

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

Explication : NAM a commencé à se connecter au réseau 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
 

Explication : NAM a associé une carte à ce réseau.

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)
 

Explication : NAM a commencé à se connecter à ce réseau câblé.

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)
 

Explication : le client envoie 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)
 

Explication : le client reçoit une demande d'identité de la part du commutateur, il recherche à présent un justificatif d'identité à renvoyer.

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
 

Explication : Par défaut, Anyconnect envoie l'identité anonyme comme identité non protégée (identité externe), donc ici il essaie l'identité anonyme et voir si le serveur est d'accord avec elle. Le fait que l'identité soit anonyme par opposition à host/anonymous indique qu'il s'agit d'une authentification d'utilisateur, plutôt que d'une authentification de machine.

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)
 

Explication : Le serveur RADIUS envoie une trame EAP-TLS (Extensible Authentication Protocol-Transport Layer Security) sans contenu. Son objectif est de négocier le protocole EAP-TLS avec le 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
 

Explication : NAM reconnaît la demande du serveur d'utiliser EAP-TLS, mais le client est configuré pour utiliser le protocole PEAP (Protected Extensible Authentication Protocol). C'est la raison pour laquelle NAM renvoie une contre-offre pour 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
 

Explication : le serveur RADIUS accepte l'identité externe/non protégée.

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)
 

Explication : La partie Protected du PEAP (pour établir un tunnel sécurisé pour échanger des informations d'identification internes) démarre, après que le client a reçu une confirmation du serveur RADIUS pour continuer à utiliser le 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)
 

Explication : NAM envoie un message Hello client encapsulé dans EAP et attend que le message Hello du serveur arrive. Le Hello du serveur contient un certificat ISE. Le transfert prend donc un certain temps.

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)
 

Explication : NAM a extrait le nom du sujet du serveur ISE du certificat du serveur. Comme aucun certificat de serveur n'est installé dans le magasin d'approbation, vous ne le trouvez pas à cet emplacement.

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
 

Explication : NAM recherche l'identité interne/protégée à envoyer au serveur RADIUS après l'établissement du tunnel. Dans ce cas, l'option "Utiliser automatiquement mon nom d'ouverture de session et mon mot de passe Windows" a été activée sur l'adaptateur câblé, de sorte que NAM utilise les informations d'identification d'ouverture de session Windows au lieu de demander à l'utilisateur de les saisir.

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)
 

Explication : NAM a envoyé la clé client et les spécifications de chiffrement au serveur et a reçu la confirmation. La négociation SSL a réussi et un tunnel a été établi.

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
 

Explication : L'identité protégée est envoyée au serveur, qui accepte l'identité. Le serveur demande maintenant un mot de passe.

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
 

Explication : NAM reçoit une demande de mot de passe et envoie le mot de passe au serveur.

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)
 

Explication : le serveur reçoit le mot de passe, le vérifie et envoie EAP-Success. L'authentification est réussie à ce stade, et le client poursuit en obtenant l'adresse IP du serveur DHCP.