Cisco Support Community
cancel
Showing results for 
Search instead for 
Did you mean: 
Announcements

Welcome to Cisco Support Community. We would love to have your feedback.

For an introduction to the new site, click here. And see here for current known issues.

New Member

802.1x port authentication failing after getting a access-accept packet

Hi all,

Im not 100% sure what the hell is going on here.

Any idea's or help will be appreciated.

Heres the topology.

1 x windows 2012 NPS

1x 3750X

1x Windows 7 x64

data flow

<laptop> - - [gi 1/0/13]<3750X>[gi 1/0/48]- -[gi 5/39]<6513>[po 1] - - [po 4]<6509><5/1> - - <VMWARE>[NPS Server]

The switch that is doing the authentication is the 3750X. Here is the IOS version.

Switch Ports Model              SW Version            SW Image

------ ----- -----              ----------            ----------

*    1 54    WS-C3750X-48       15.2(1)E              C3750E-UNIVERSALK9-M

A wireshark trace on the NPS server shows that the packets are arriving and being sent back

Wireshark on a mirror of the trunk port connecting the 6513. It also shows packets being sent and arriving. access-accept packets are being recieved.

As you can see in the debug output, the switch is getting a access-accept, then it is stating a AAA failure.

here is a debug output as you plug in the laptop.

Oct 24 10:53:44.653: dot1x-ev:[Gi1/0/13] Interface state changed to DOWN

Oct 24 10:53:44.653: dot1x-ev:[Gi1/0/13] No DOT1X subblock found for port down

Oct 24 10:53:45.643: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/13, changed state to down

Oct 24 10:53:46.641: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/13, changed state to down

Oct 24 10:53:47.538: dot1x-ev:[Gi1/0/13] Interface state changed to UP

Oct 24 10:53:47.564: dot1x-packet:[6431.500e.9b00, Gi1/0/13] queuing an EAPOL pkt on Auth Q

Oct 24 10:53:47.572: dot1x-ev:DOT1X Supplicant not enabled on GigabitEthernet1/0/13

Oct 24 10:53:47.572: dot1x-packet:EAPOL pak rx - Ver: 0x1  type: 0x1

Oct 24 10:53:47.572: dot1x-packet: length: 0x0000

Oct 24 10:53:47.572: dot1x-ev:[Gi1/0/13] Dequeued pkt: Int Gi1/0/13 CODE= 0,TYPE= 0,LEN= 0

Oct 24 10:53:47.572: dot1x-ev:[Gi1/0/13] Received pkt saddr =6431.500e.9b00 , daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000

Oct 24 10:53:47.572: dot1x-ev:[Gi1/0/13] Couldn't find the supplicant in the list

Oct 24 10:53:47.572: dot1x-ev:[6431.500e.9b00, Gi1/0/13] New client detected, sending session start event for 6431.500e.9b00

Oct 24 10:53:47.572: AAA/BIND(00000047): Bind i/f

Oct 24 10:53:47.580: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Sending create new context event to EAP for 0x15000045 (6431.500e.9b00)

Oct 24 10:53:47.580: EAP-EVENT: Received context create from LL (Dot1x-Authenticator) (0x15000045)

Oct 24 10:53:47.580: EAP-AUTH-EVENT: Received AAA ID 0x00000047 from LL

Oct 24 10:53:47.580: EAP-AUTH-AAA-EVENT: Assigning AAA ID 0x00000047

Oct 24 10:53:47.580: EAP-AUTH-AAA-EVENT: CTS not enabled on interface Gi1/0/13

Oct 24 10:53:47.580: EAP-AUTH-EVENT: Received Session ID "C0A846660000004700DF6030" from LL

Oct 24 10:53:47.580: EAP-AUTH-EVENT: Setting authentication mode: Passthrough

Oct 24 10:53:47.580:     eap_authen : initial state eap_auth_initialize has enter

Oct 24 10:53:47.580: EAP-EVENT: Allocated new EAP context (handle = 0xE8000047)

Oct 24 10:53:47.580: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Created a client entry (0x15000045)

Oct 24 10:53:47.580: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Dot1x authentication started for 0x15000045 (6431.500e.9b00)

Oct 24 10:53:47.580: %AUTHMGR-5-START: Starting 'dot1x' for client (6431.500e.9b00) on Interface Gi1/0/13 AuditSessionID C0A846660000004700DF6030

Oct 24 10:53:47.580: EAP-EVENT: Received EAP event 'EAP_AUTHENTICATOR_START' on handle 0xE8000047

Oct 24 10:53:47.580:     eap_authen : during state eap_auth_initialize, got event 25(eapStartTmo)

Oct 24 10:53:47.580: @@@ eap_authen : eap_auth_initialize -> eap_auth_select_action

Oct 24 10:53:47.580:     eap_authen : during state eap_auth_select_action, got event 20(eapDecisionPropose)

Oct 24 10:53:47.580: @@@ eap_authen : eap_auth_select_action -> eap_auth_propose_method

Oct 24 10:53:47.580:     eap_authen : idle during state eap_auth_propose_method

Oct 24 10:53:47.580: @@@ eap_authen : eap_auth_propose_method -> eap_auth_method_request

Oct 24 10:53:47.580:     eap_authen : idle during state eap_auth_method_request

Oct 24 10:53:47.580: @@@ eap_authen : eap_auth_method_request -> eap_auth_tx_packet

Oct 24 10:53:47.580: EAP-AUTH-EVENT: Current method = Identity

Oct 24 10:53:47.580: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_CUSTOMIZE_ID_REQUEST' on handle 0xE8000047

Oct 24 10:53:47.580:     eap_authen : idle during state eap_auth_tx_packet

Oct 24 10:53:47.580: @@@ eap_authen : eap_auth_tx_packet -> eap_auth_idle

Oct 24 10:53:47.589: EAP-AUTH-TX-PAK: Code:REQUEST  ID:0x1   Length:0x0005  Type:IDENTITY

Oct 24 10:53:47.589: EAP-EVENT: Started 'Authenticator ReqId Retransmit' timer (30s) for EAP sesion handle 0xE8000047

Oct 24 10:53:47.589: EAP-EVENT: Started EAP tick timer

Oct 24 10:53:47.589: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_TX_PACKET' on handle 0xE8000047

Oct 24 10:53:47.597: dot1x-ev:[Gi1/0/13] Sending EAPOL packet to group PAE address

Oct 24 10:53:47.597: dot1x-ev:[Gi1/0/13] Sending out EAPOL packet

Oct 24 10:53:47.597: dot1x-packet:EAPOL pak Tx - Ver: 0x3  type: 0x0

Oct 24 10:53:47.597: dot1x-packet: length: 0x0005

Oct 24 10:53:47.597: dot1x-packet:EAP code: 0x1  id: 0x1  length: 0x0005

Oct 24 10:53:47.597: dot1x-packet: type: 0x1

Oct 24 10:53:47.597: dot1x-packet:[6431.500e.9b00, Gi1/0/13] EAPOL packet sent to client 0x15000045

Oct 24 10:53:47.606: dot1x-packet:[6431.500e.9b00, Gi1/0/13] Queuing an EAPOL pkt on Authenticator Q

Oct 24 10:53:47.606: dot1x-packet:EAPOL pak rx - Ver: 0x1  type: 0x0

Oct 24 10:53:47.606: dot1x-packet: length: 0x001F

Oct 24 10:53:47.606: dot1x-ev:[Gi1/0/13] Dequeued pkt: Int Gi1/0/13 CODE= 2,TYPE= 1,LEN= 31

Oct 24 10:53:47.606: dot1x-ev:[Gi1/0/13] Received pkt saddr =6431.500e.9b00 , daddr = 0180.c200.0003, pae-ether-type = 888e.0100.001f

Oct 24 10:53:47.606: dot1x-packet:EAPOL pak rx - Ver: 0x1  type: 0x0

Oct 24 10:53:47.606: dot1x-packet: length: 0x001F

Oct 24 10:53:47.606: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Response sent to the server from 0x15000045

Oct 24 10:53:47.606: EAP-EVENT: Received LL (Dot1x-Authenticator) event 'EAP_RX_PACKET' on handle 0xE8000047

Oct 24 10:53:47.606: EAP-AUTH-RX-PAK: Code:RESPONSE  ID:0x1   Length:0x001F  Type:IDENTITY

Oct 24 10:53:47.606:     Payload:  47454E4552414C5C72616E64792E636F ...

Oct 24 10:53:47.606:     eap_authen : during state eap_auth_idle, got event 1(eapRxPacket)

Oct 24 10:53:47.606: @@@ eap_authen : eap_auth_idle -> eap_auth_received

Oct 24 10:53:47.606: EAP-AUTH-EVENT: EAP Response received by context 0xE8000047

Oct 24 10:53:47.606: EAP-AUTH-EVENT: EAP Response type = Identity

Oct 24 10:53:47.606: EAP-EVENT: Stopping 'Authenticator ReqId Retransmit' timer for EAP sesion handle 0xE8000047

Oct 24 10:53:47.606:     eap_authen : during state eap_auth_received, got event 10(eapMethodData)

Oct 24 10:53:47.606: @@@ eap_authen : eap_auth_received -> eap_auth_method_response

Oct 24 10:53:47.606: EAP-AUTH-EVENT: Received peer identity: GENERAL\randy.coburn.admin

Oct 24 10:53:47.606: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_IDENTITY' on handle 0xE8000047

Oct 24 10:53:47.606:     eap_authen : during state eap_auth_method_response, got event 13(eapMethodEnd)

Oct 24 10:53:47.606: @@@ eap_authen : eap_auth_method_response -> eap_auth_select_action

Oct 24 10:53:47.606:     eap_authen : during state eap_auth_select_action, got event 19(eapDecisionPass)

Oct 24 10:53:47.606: @@@ eap_authen : eap_auth_select_action -> eap_auth_passthru_init

Oct 24 10:53:47.606:     eap_authen : during state eap_auth_passthru_init, got event 22(eapPthruIdentity)

Oct 24 10:53:47.614: @@@ eap_authen : eap_auth_passthru_init -> eap_auth_aaa_req

Oct 24 10:53:47.614: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_GET_PEER_MAC_ADDRESS' on handle 0xE8000047

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: Adding Audit-Session-ID "C0A846660000004700DF6030" to RADIUS Req

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: Added Audit-Session-ID

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: Adding IDB "0x070B90F8" to RADIUS Req

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: Added IDB

Oct 24 10:53:47.614: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_CUSTOMIZE_AAA_REQUEST' on handle 0xE8000047

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: eap_auth_aaa_authen_request_shim aaa_service 19, eap aaa_list handle 0, mlist handle 0

Oct 24 10:53:47.614: AAA/AUTHEN/8021X (00000000): Pick method list 'default'

Oct 24 10:53:47.614: EAP-AUTH-AAA-EVENT: Request sent successfully

Oct 24 10:53:47.614:     eap_authen : during state eap_auth_aaa_req, got event 24(eapAAAReqOk)

Oct 24 10:53:47.614: @@@ eap_authen : eap_auth_aaa_req -> eap_auth_aaa_idle

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000):Orig. component type = Invalid

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute hwidb

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute aaa-authen-type

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute aaa-authen-service

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute clid-mac-addr

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute target-scope

Oct 24 10:53:47.614: RADIUS/ENCODE(00000000): Unsupported AAA attribute aaa-unique-id

Oct 24 10:53:47.614: RADIUS(00000000): Config NAS IP: 0.0.0.0

Oct 24 10:53:47.614: RADIUS(00000000): sending

Oct 24 10:53:47.614: RADIUS/ENCODE: Best Local IP-Address 192.168.70.102 for Radius-Server 192.168.19.121

Oct 24 10:53:47.614: RADIUS(00000000): Send Access-Request to 192.168.19.121:1645 id 1645/21, len 288

Oct 24 10:53:47.614: RADIUS:  authenticator F1 BA E5 31 71 54 BF 1A - A2 B1 5E 1A 63 72 1E 72

Oct 24 10:53:47.614: RADIUS:  User-Name           [1]   28  "GENERAL\randy.coburn.admin"

Oct 24 10:53:47.614: RADIUS:  Service-Type        [6]   6   Framed                    [2]

Oct 24 10:53:47.614: RADIUS:  Vendor, Cisco       [26]  27

Oct 24 10:53:47.614: RADIUS:   Cisco AVpair       [1]   21  "service-type=Framed"

Oct 24 10:53:47.614: RADIUS:  Framed-MTU          [12]  6   1500

Oct 24 10:53:47.614: RADIUS:  Called-Station-Id   [30]  19  "AC-F2-C5-75-7D-0D"

Oct 24 10:53:47.614: RADIUS:  Calling-Station-Id  [31]  19  "64-31-50-0E-9B-00"

Oct 24 10:53:47.614: RADIUS:  EAP-Message         [79]  33

Oct 24 10:53:47.614: RADIUS:   02 01 00 1F 01 47 45 4E 45 52 41 4C 5C 72 61 6E 64 79 2E 63 6F  [GENERAL\randy.co]

Oct 24 10:53:47.622: RADIUS:   62 75 72 6E 2E 61 64 6D 69 6E        [ burn.admin]

Oct 24 10:53:47.622: RADIUS:  Message-Authenticato[80]  18

Oct 24 10:53:47.622: RADIUS:   EE 52 4D ED B9 06 F3 CE 63 AC 9D 73 24 1B A7 ED             [ RMcs$]

Oct 24 10:53:47.622: RADIUS:  EAP-Key-Name        [102] 2   *

Oct 24 10:53:47.622: RADIUS:  Vendor, Cisco       [26]  49

Oct 24 10:53:47.622: RADIUS:   Cisco AVpair       [1]   43  "audit-session-id=C0A846660000004700DF6030"

Oct 24 10:53:47.622: RADIUS:  Vendor, Cisco       [26]  20

Oct 24 10:53:47.622: RADIUS:   Cisco AVpair       [1]   14  "method=dot1x"

Oct 24 10:53:47.622: RADIUS:  NAS-IP-Address      [4]   6   192.168.70.102

Oct 24 10:53:47.622: RADIUS:  NAS-Port            [5]   6   60000

Oct 24 10:53:47.622: RADIUS:  NAS-Port-Id         [87]  23  "GigabitEthernet1/0/13"

Oct 24 10:53:47.622: RADIUS:  NAS-Port-Type       [61]  6   Ethernet                  [15]

Oct 24 10:53:47.622: RADIUS(00000000): Sending a IPv4 Radius Packet

Oct 24 10:53:47.622: RADIUS(00000000): Started 10 sec timeout

Oct 24 10:53:47.622: RADIUS: Received from id 1645/21 192.168.19.121:1645, Access-Accept, len 66

Oct 24 10:53:47.622: RADIUS:  authenticator 92 F6 07 AF C1 AB 0B 4C - 1D 9E A0 D1 01 36 27 26

Oct 24 10:53:47.622: RADIUS:  Class               [25]  46

Oct 24 10:53:47.622: RADIUS:   76 E3 06 66 00 00 01 37 00 01 02 00 C0 A8 13 79 00 00 00 00 00 00 00 00 00 00 00 00 01 CE CF F8 1F 7B 75 41 00 00 00 00 00 00 00 50          [ vf7y{uAP]

Oct 24 10:53:47.622: RADIUS(00000000): Received from id 1645/21

Oct 24 10:53:47.622: EAP-EVENT: eap_aaa_reply

Oct 24 10:53:47.622: EAP-AUTH-AAA-EVENT: Reply received session_label 72000033

Oct 24 10:53:47.622: EAP-EVENT: Received AAA event 'EAP_AAA_FAIL' on handle 0xE8000047

Oct 24 10:53:47.622:     eap_authen : during state eap_auth_aaa_idle, got event 8(eapAAAFail)

Oct 24 10:53:47.622: @@@ eap_authen : eap_auth_aaa_idle -> eap_auth_failure

Oct 24 10:53:47.631: EAP-EVENT: Received get canned status from lower layer (0xE8000047)

Oct 24 10:53:47.631: EAP-AUTH-TX-PAK: Code:FAILURE  ID:0x1   Length:0x0004

Oct 24 10:53:47.631: EAP-AUTH-EVENT: FAIL for EAP method ID: 1, name: , on handle 0xE8000047

Oct 24 10:53:47.631: EAP-EVENT: Sending LL (Dot1x-Authenticator) event 'EAP_FAIL' on handle 0xE8000047

Oct 24 10:53:47.631: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Received an EAP Fail

Oct 24 10:53:47.639: %DOT1X-5-FAIL: Authentication failed for client (6431.500e.9b00) on Interface Gi1/0/13 AuditSessionID C0A846660000004700DF6030

Oct 24 10:53:47.639: dot1x-packet:[6431.500e.9b00, Gi1/0/13] Added username in dot1x

Oct 24 10:53:47.639: dot1x-packet:[6431.500e.9b00, Gi1/0/13] Dot1x did not receive any key data

Oct 24 10:53:47.639: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Processing client delete for hdl 0x15000045 sent by Auth Mgr

Oct 24 10:53:47.639: dot1x-ev:[6431.500e.9b00, Gi1/0/13] 6431.500e.9b00: sending canned failure due to method termination

Oct 24 10:53:47.639: EAP-EVENT: Received get canned status from lower layer (0xE8000047)

Oct 24 10:53:47.639: dot1x-ev:[Gi1/0/13] Sending EAPOL packet to group PAE address

Oct 24 10:53:47.639: dot1x-ev:[Gi1/0/13] Sending out EAPOL packet

Oct 24 10:53:47.639: dot1x-packet:EAPOL pak Tx - Ver: 0x3  type: 0x0

Oct 24 10:53:47.639: dot1x-packet: length: 0x0004

Oct 24 10:53:47.639: dot1x-packet:EAP code: 0x4  id: 0x1  length: 0x0004

Oct 24 10:53:47.639: dot1x-packet:[6431.500e.9b00, Gi1/0/13] EAPOL canned status packet sent to client 0x15000045

Oct 24 10:53:47.639: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Deleting client 0x15000045 (6431.500e.9b00)

Oct 24 10:53:47.639: %AUTHMGR-7-STOPPING: Stopping 'dot1x' for client 6431.500e.9b00 on Interface Gi1/0/13 AuditSessionID C0A846660000004700DF6030

Oct 24 10:53:47.639: %AUTHMGR-5-FAIL: Authorization failed or unapplied for client (6431.500e.9b00) on Interface Gi1/0/13 AuditSessionID C0A846660000004700DF6030

Oct 24 10:53:47.648: dot1x-ev:[6431.500e.9b00, Gi1/0/13] Delete auth client (0x15000045) message

Oct 24 10:53:47.648: EAP-EVENT: Received free context (0xE8000047) from LL (Dot1x-Authenticator)

Oct 24 10:53:47.648: dot1x-ev:Auth client ctx destroyed

Oct 24 10:53:47.648: EAP-EVENT: Received LL (Dot1x-Authenticator) event 'EAP_DELETE' on handle 0xE8000047

Oct 24 10:53:47.648: EAP-AUTH-EVENT: Freed EAP auth context

Oct 24 10:53:47.648: EAP-EVENT: Freed EAP context

Oct 24 10:53:48.621: EAP-EVENT: Stopped EAP tick timer

Oct 24 10:53:49.485: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/13, changed state to up

Oct 24 10:53:50.491: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/13, changed state to up

Oct 24 10:53:53.528: dot1x-ev:[Gi1/0/13] Interface state changed to DOWN

Oct 24 10:53:53.528: dot1x-ev:[Gi1/0/13] No DOT1X subblock found for port down

Oct 24 10:53:54.518: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet1/0/13, changed state to down

Oct 24 10:53:55.524: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/13, changed state to down

3 REPLIES
Cisco Employee

802.1x port authentication failing after getting a access-accept

Please provide little more information about switch/NPS configuration.

Show run | in aaa

Show run Interface GigabitEthernet1/0/13

Show auth session Interface GigabitEthernet1/0/13

Show mac address-table Interface GigabitEthernet1/0/13

Screen shot of NPS policy being defined for 802.1x

~BR
Jatin Katyal

**Do rate helpful posts**

~BR Jatin Katyal **Do rate helpful posts**
New Member

Re: 802.1x port authentication failing after getting a access-ac

Hi Jatin,

See below the data that you have requested.

show run bits.

aaa new-model

aaa authentication dot1x default group radius

aaa session-id common

clock timezone BST 0 0

clock summer-time UTC recurring last Sun Mar 1:00 last Sun Oct 2:00

dot1x system-auth-control

interface GigabitEthernet1/0/13

switchport access vlan 80

switchport mode access

authentication port-control auto

dot1x pae authenticator

spanning-tree portfast

interface GigabitEthernet1/0/48

switchport trunk encapsulation dot1q

switchport trunk native vlan 70

switchport mode trunk

radius server NPS1

address ipv4 192.168.19.121 auth-port 1645 acct-port 1646

timeout 10

key thesecret

ip default-gateway 192.168.70.1

SW1-randy#show auth sessions interface gig 1/0/13

Interface    MAC Address    Method       Domain          Status    Fg Session ID

----------------------------------------------------------------------

Gi1/0/13     803f.5d09.189e N/A          UNKNOWN      Unauth         C0A846660000002F00251DBC

SW1-randy#Show mac address-table Interface GigabitEthernet1/0/13

          Mac Address Table

-------------------------------------------

Vlan    Mac Address       Type        Ports

----    -----------       --------    -----

  80    803f.5d09.189e    DYNAMIC     Drop

SW1-randy#ping 192.168.19.121

Type escape sequence to abort.

Sending 5, 100-byte ICMP Echos to 192.168.19.121, timeout is 2 seconds:

!!!!!

Success rate is 100 percent (5/5), round-trip min/avg/max = 1/2/8 ms

Here is a wireshark of the accept packet.

Message was edited by: randy coburn Added wireshark trace

New Member

Re: 802.1x port authentication failing after getting a access-ac

Hi All,

I managed to figure out the problem but not the solution.

It ended up being the Certificate servers.

I re-built the servers and reissued the certificated and it started working.

Not sure what the issue was with the last ones though.

3746
Views
0
Helpful
3
Replies
CreatePlease to create content