cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
3823
Views
0
Helpful
3
Replies

Troubshoot wired 802.1x with NPS

tim.zhao
Level 1
Level 1

Hi everyone,

 

We have a wired dot1x authentication problem here.

I'm sure the NPS server is ok,because other clients are using it.

We using a switch C2960L running version 15.2(5c)E

 

Here are my conf:

interface GigabitEthernet0/13
description dot1x-fail
switchport access vlan 82
switchport mode access
authentication event server dead action authorize vlan 82
authentication event no-response action authorize vlan 82
authentication event server alive action reinitialize
authentication host-mode multi-auth
authentication port-control auto
authentication violation restrict
dot1x pae authenticator
dot1x timeout quiet-period 5
dot1x timeout tx-period 5
dot1x timeout supp-timeout 5
spanning-tree portfast edge
end

 

Client had authenticated fail

!

#sho authentication sessions interface gigabitEthernet 0/13 detail
Interface: GigabitEthernet0/13
MAC Address: d89e.f322.f1ce
IPv6 Address: Unknown
IPv4 Address: 10.80.82.20
User-Name: host/PC
Status: Authorized
Domain: DATA
Oper host mode: multi-auth
Oper control dir: both
Session timeout: N/A
Restart timeout: N/A
Session Uptime: 84s
Common Session ID: 0000000000000027C930368D
Acct Session ID: Unknown
Handle: 0xB3000015
Current Policy: POLICY_Gi0/13

Local Policies:
Service Template: GUEST_SUPP_VLAN_Gi0/13 (priority 150)
Vlan Group: Vlan: 82

Method status list:
Method State

dot1x Stopped

!

#sho dot1x interface gigabitEthernet 0/13 detail

Dot1x Info for GigabitEthernet0/13
-----------------------------------
PAE = AUTHENTICATOR
QuietPeriod = 5
ServerTimeout = 0
SuppTimeout = 5
ReAuthMax = 2
MaxReq = 2
TxPeriod = 5

Dot1x Authenticator Client List Empty

!

#sho authentication sessions

Interface Identifier Method Domain Status Fg Session ID
Gi0/13 d89e.f322.f1ce N/A DATA Auth 0000000000000027C930368D

I have tried to debug dot1x all. Here are the debug output:

Aug 7 11:28:15: dot1x-ev:[Gi0/13] Interface state changed to UP
Aug 7 11:28:15: dot1x-ev:DOT1X Supplicant not enabled on GigabitEthernet0/13
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] queuing an EAPOL pkt on Auth Q
Aug 7 11:28:15: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x1
Aug 7 11:28:15: dot1x-packet: length: 0x0000
Aug 7 11:28:15: dot1x-ev:[Gi0/13] Dequeued pkt: Int Gi0/13 CODE= 0,TYPE= 0,LEN= 0

Aug 7 11:28:15: dot1x-ev:[Gi0/13] Received pkt saddr =d89e.f322.f1ce , daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000
Aug 7 11:28:15: dot1x-ev:[Gi0/13] Couldn't find the supplicant in the list
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] New client detected, sending session start event for d89e.f322.f1ce
Aug 7 11:28:15: dot1x_auth Gi0/13: initial state auth_initialize has enter
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: initialising
Aug 7 11:28:15: dot1x_auth Gi0/13: during state auth_initialize, got event 0(cfg_auto)
Aug 7 11:28:15: @@@ dot1x_auth Gi0/13: auth_initialize -> auth_disconnected
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: disconnected
Aug 7 11:28:15: dot1x_auth Gi0/13: idle during state auth_disconnected
Aug 7 11:28:15: @@@ dot1x_auth Gi0/13: auth_disconnected -> auth_restart
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: entering restart
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending create new context event to EAP for 0xAA000010 (d89e.f322.f1ce)
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: initial state auth_bend_initialize has enter
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: entering init state
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: initial state auth_bend_initialize has idle
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_initialize, got event 16383(idle)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_initialize -> auth_bend_idle
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering idle state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Created a client entry (0xAA000010)
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Dot1x authentication started for 0xAA000010 (d89e.f322.f1ce)
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting !EAP_RESTART on Client 0xAA000010
Aug 7 11:28:15: dot1x_auth Gi0/13: during state auth_restart, got event 6(no_eapRestart)
Aug 7 11:28:15: @@@ dot1x_auth Gi0/13: auth_restart -> auth_connecting
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:enter connecting state
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: restart connecting
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting RX_REQ on Client 0xAA000010
Aug 7 11:28:15: dot1x_auth Gi0/13: during state auth_connecting, got event 10(eapReq_no_reAuthMax)
Aug 7 11:28:15: @@@ dot1x_auth Gi0/13: auth_connecting -> auth_authenticating
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010: authenticating state entered
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:connecting authenticating action
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting AUTH_START for 0xAA000010
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_idle, got event 4(eapReq_authStart)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_idle -> auth_bend_request
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering request state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:15: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:15: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x0005
Aug 7 11:28:15: dot1x-packet:EAP code: 0x1 id: 0x1 length: 0x0005
Aug 7 11:28:15: dot1x-packet: type: 0x1
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL packet sent to client 0xAA000010
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:idle request action
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] Queuing an EAPOL pkt on Authenticator Q
Aug 7 11:28:15: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x002F
Aug 7 11:28:15: dot1x-ev:[Gi0/13] Dequeued pkt: Int Gi0/13 CODE= 2,TYPE= 1,LEN= 47

Aug 7 11:28:15: dot1x-ev:[Gi0/13] Received pkt saddr =d89e.f322.f1ce , daddr = 0180.c200.0003, pae-ether-type = 888e.0100.002f
Aug 7 11:28:15: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x002F
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAPOL_EAP for 0xAA000010
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_request, got event 6(eapolEap)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_request -> auth_bend_response
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering response state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Response sent to the server from 0xAA000010
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:request response action
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAP_REQ for 0xAA000010
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_response, got event 7(eapReq)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_response -> auth_bend_request
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:exiting response state
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering request state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:15: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:15: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x0006
Aug 7 11:28:15: dot1x-packet:EAP code: 0x1 id: 0x2 length: 0x0006
Aug 7 11:28:15: dot1x-packet: type: 0xD
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL packet sent to client 0xAA000010
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:response request action
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] Queuing an EAPOL pkt on Authenticator Q
Aug 7 11:28:15: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x006D
Aug 7 11:28:15: dot1x-ev:[Gi0/13] Dequeued pkt: Int Gi0/13 CODE= 2,TYPE= 13,LEN= 109

Aug 7 11:28:15: dot1x-ev:[Gi0/13] Received pkt saddr =d89e.f322.f1ce , daddr = 0180.c200.0003, pae-ether-type = 888e.0100.006d
Aug 7 11:28:15: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x006D
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAPOL_EAP for 0xAA000010
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_request, got event 6(eapolEap)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_request -> auth_bend_response
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering response state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Response sent to the server from 0xAA000010
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:request response action
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAP_REQ for 0xAA000010
Aug 7 11:28:15: dot1x_auth_bend Gi0/13: during state auth_bend_response, got event 7(eapReq)
Aug 7 11:28:15: @@@ dot1x_auth_bend Gi0/13: auth_bend_response -> auth_bend_request
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:exiting response state
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering request state
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:15: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:15: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:15: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:15: dot1x-packet: length: 0x05EE
Aug 7 11:28:15: dot1x-packet:EAP code: 0x1 id: 0x3 length: 0x05EE
Aug 7 11:28:15: dot1x-packet: type: 0xD
Aug 7 11:28:15: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL packet sent to client 0xAA000010
Aug 7 11:28:15: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:response request action
Aug 7 11:28:17: %LINK-3-UPDOWN: Interface GigabitEthernet0/13, changed state to up
Aug 7 11:28:18: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/13, changed state to up
Aug 7 11:28:20: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAP_REQ for 0xAA000010
Aug 7 11:28:20: dot1x_auth_bend Gi0/13: during state auth_bend_request, got event 7(eapReq)
Aug 7 11:28:20: @@@ dot1x_auth_bend Gi0/13: auth_bend_request -> auth_bend_request
Aug 7 11:28:20: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:request request action
Aug 7 11:28:20: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering request state
Aug 7 11:28:20: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:20: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:20: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:20: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:20: dot1x-packet: length: 0x05EE
Aug 7 11:28:20: dot1x-packet:EAP code: 0x1 id: 0x3 length: 0x05EE
Aug 7 11:28:20: dot1x-packet: type: 0xD
Aug 7 11:28:20: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL packet sent to client 0xAA000010
Aug 7 11:28:25: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAP_REQ for 0xAA000010
Aug 7 11:28:25: dot1x_auth_bend Gi0/13: during state auth_bend_request, got event 7(eapReq)
Aug 7 11:28:25: @@@ dot1x_auth_bend Gi0/13: auth_bend_request -> auth_bend_request
Aug 7 11:28:25: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:request request action
Aug 7 11:28:25: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering request state
Aug 7 11:28:25: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:25: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:25: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:25: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:25: dot1x-packet: length: 0x05EE
Aug 7 11:28:25: dot1x-packet:EAP code: 0x1 id: 0x3 length: 0x05EE
Aug 7 11:28:25: dot1x-packet: type: 0xD
Aug 7 11:28:25: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL packet sent to client 0xAA000010
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Received an EAP Timeout
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting EAP_TIMEOUT for 0xAA000010
Aug 7 11:28:30: dot1x_auth_bend Gi0/13: during state auth_bend_request, got event 12(eapTimeout)
Aug 7 11:28:30: @@@ dot1x_auth_bend Gi0/13: auth_bend_request -> auth_bend_timeout
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering timeout state
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:request timeout action
Aug 7 11:28:30: dot1x_auth_bend Gi0/13: idle during state auth_bend_timeout
Aug 7 11:28:30: @@@ dot1x_auth_bend Gi0/13: auth_bend_timeout -> auth_bend_idle
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering idle state
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] Posting AUTH_TIMEOUT on Client 0xAA000010
Aug 7 11:28:30: dot1x_auth Gi0/13: during state auth_authenticating, got event 14(authTimeout)
Aug 7 11:28:30: @@@ dot1x_auth Gi0/13: auth_authenticating -> auth_authc_result
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:exiting authenticating state
Aug 7 11:28:30: dot1x-sm:[d89e.f322.f1ce, Gi0/13] 0xAA000010:entering authc result state
Aug 7 11:28:30: %DOT1X-5-FAIL: Authentication failed for client (d89e.f322.f1ce) on Interface Gi0/13 AuditSessionID 0000000000000023C9218FF3
Aug 7 11:28:30: dot1x-packet:[d89e.f322.f1ce, Gi0/13] Added username in dot1x
Aug 7 11:28:30: dot1x-packet:[d89e.f322.f1ce, Gi0/13] Dot1x did not receive any key data
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Processing client delete for hdl 0xAA000010 sent by Auth Mgr
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] d89e.f322.f1ce: sending canned failure due to method termination
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending EAPOL packet
Aug 7 11:28:30: dot1x-registry:registry:dot1x_ether_macaddr called
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Sending out EAPOL packet to MAC d89e.f322.f1ce
Aug 7 11:28:30: dot1x-packet:EAPOL pak Tx - Ver: 0x3 type: 0x0
Aug 7 11:28:30: dot1x-packet: length: 0x0004
Aug 7 11:28:30: dot1x-packet:EAP code: 0x4 id: 0x3 length: 0x0004
Aug 7 11:28:30: dot1x-packet:[d89e.f322.f1ce, Gi0/13] EAPOL canned status packet sent to client 0xAA000010
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Deleting client 0xAA000010 (d89e.f322.f1ce)
Aug 7 11:28:30: dot1x-ev:[d89e.f322.f1ce, Gi0/13] Delete auth client (0xAA000010) message
Aug 7 11:28:30: dot1x-ev:Auth client ctx destroyed

 

Any idea's or help will be appreciated.

Thank you

Regards,

Tim

 

3 Replies 3

howon
Cisco Employee
Cisco Employee

In general it is much easier to see the overall issue on the policy server. Can you validate what NPS is sending back to the switch? I suggest stripping the policy down to bare minimum and send back ACCESS-ACCEPT only and start adding additional attributes once successful.

MarioLieb
Level 1
Level 1

Hi Guys

 

any idea ? We have the same issue. One i have allready figured out is. There seems to be a problem with how fast the port comes up. For test proposals we remove the spanning-tree portfast edge. After we did that the authentication works fine. Any idea what the spanning- tree portfast makes with dot1x ???? Very strange ….

 

 

We are witnessing exactly the same. After removing spanning-tree portfast edge dot1x works fine. With portfast configuration authentication fails after "Dot1x did not receive any key data". I don't have any explanation for this behavior.

Did you find anything out about the reason for this?

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: