PEAP-GTC instead of PEAP-MSCHAPv2, but how?

Heiko Kelling · ‎11-22-2011

We use the following constellation: Supplicant -> Cisco Switches -> Cisco ACS -> Open LDAP.

Originally, PEAP-MSCHAPv2 should be used, but it doesn´t work with Open LDAP.

Now we have to accept another authentication method, for example PEAP-GTC or TTLS...

We have already tried the Aruba and the SecureW2 GTC-Plugin for Windows 7, but the authentication is not succesfully.

If we use the Aruba Plugin a Pop-up with Username and Password is shown.

After fill it out, the ACS debug shows:

Steps

11001 Received RADIUS Access-Request

11017 RADIUS created a new session

Evaluating Service Selection Policy

15004 Matched rule

15012 Selected Access Service - Default Network Access

11507 Extracted EAP-Response/Identity

12300 Prepared EAP-Request proposing PEAP with challenge

12625 Valid EAP-Key-Name attribute received.

11006 Returned RADIUS Access-Challenge

11001 Received RADIUS Access-Request

11018 RADIUS is re-using an existing session

12302 Extracted EAP-Response containing PEAP challenge-response and accepting PEAP as negotiated

12318 Successfully negotiated PEAP version 0

12800 Extracted first TLS record; TLS handshake started.

12805 Extracted TLS ClientHello message.

12806 Prepared TLS ServerHello message.

12807 Prepared TLS Certificate message.

12810 Prepared TLS ServerDone message.

12305 Prepared EAP-Request with another PEAP challenge

11006 Returned RADIUS Access-Challenge

11001 Received RADIUS Access-Request

11018 RADIUS is re-using an existing session

12304 Extracted EAP-Response containing PEAP challenge-response

12318 Successfully negotiated PEAP version 0

12812 Extracted TLS ClientKeyExchange message.

12804 Extracted TLS Finished message.

12801 Prepared TLS ChangeCipherSpec message.

12802 Prepared TLS Finished message.

12816 TLS handshake succeeded.

12310 PEAP full handshake finished successfully

12305 Prepared EAP-Request with another PEAP challenge

11006 Returned RADIUS Access-Challenge

11001 Received RADIUS Access-Request

11018 RADIUS is re-using an existing session

12304 Extracted EAP-Response containing PEAP challenge-response

12313 PEAP inner method started

11521 Prepared EAP-Request/Identity for inner EAP method

12305 Prepared EAP-Request with another PEAP challenge

11006 Returned RADIUS Access-Challenge

11001 Received RADIUS Access-Request

11018 RADIUS is re-using an existing session

12304 Extracted EAP-Response containing PEAP challenge-response

11522 Extracted EAP-Response/Identity for inner EAP method

12606 Prepared EAP-Request for inner method proposing EAP-GTC with challenge.

12611 Prepared EAP-Request for inner method with another EAP-GTC challenge.

Evaluating Identity Policy

15006 Matched Default Rule

15013 Selected Identity Store -

12606 Prepared EAP-Request for inner method proposing EAP-GTC with challenge.

12305 Prepared EAP-Request with another PEAP challenge

11006 Returned RADIUS Access-Challenge

and the Radius status is: 5411 EAP session timed out

Does anyone have any experiences with this problem?

We need the authentication for LAN and not for WLAN! Is PEAP-GTC possible in LAN?

Tarik Admani · ‎11-22-2011

It doesnt matter if you are wired or wireless the peap-gtc is between the supplicant and the radius server. It seems as if the ACS is sending the challenge back to the client and we need to see why the client isnt responding. We need to get some radius level debugs on the switch and run a packet capture on the client's end.

Also what version of ACS are you on, I can tell it is 5.x but what version and patch level.

Thanks,

Tarik Admani

Heiko Kelling · ‎11-22-2011

First thanks for the quick response.

It´s ACS version 5.2.

A RADIUS debug is hard to get now, because the devices are located at the customer.

The ACS debug shows imho, that the TLS tunnel was built succesfully, but then EAP-GTC not runs.

11522 Extracted EAP-Response/Identity for inner EAP method

12606 Prepared EAP-Request for inner method proposing EAP-GTC with challenge.

12611 Prepared EAP-Request for inner method with another EAP-GTC challenge.

I watched the radius debug live on a switch. There were to see a lot of RADIUS-Requests and Challenges. They are in the ACS debug, too:

11006 Returned RADIUS Access-Challenge

11001 Received RADIUS Access-Request

Heiko Kelling · ‎11-22-2011

I have an additional note: We use no certificate for the PEAP-GTC Test. Only Username and Password. Could it be a problem?

Nicolas Darchis · ‎11-22-2011

The clients don't need to have a user/password.Moreover the PEAP phase seems to be done so the server cert went through. All what is left is the credentials exchange in the inner GTC, so I don't see certs having a relation.

Your client is not responding and only advanced debugs may reveal why

Heiko Kelling · ‎12-13-2011

ST116-H5.2.09#

Dec 13 10:28:56.989: dot1x-ev(Gi1/0/1): Interface state changed to UP

Dec 13 10:28:56.989: dot1x_auth Gi1/0/1: initial state auth_initialize has enter

Dec 13 10:28:56.989: dot1x-sm(Gi1/0/1): 0xE6000015:auth_initialize_enter called

Dec 13 10:28:56.989: dot1x_auth Gi1/0/1: during state auth_initialize, got event 0(cfg_auto)

Dec 13 10:28:56.989: @@@ dot1x_auth Gi1/0/1: auth_initialize -> auth_disconnected

Dec 13 10:28:56.989: dot1x-sm(Gi1/0/1): 0xE6000015:auth_disconnected_enter called

Dec 13 10:28:56.989: dot1x_auth Gi1/0/1: idle during state auth_disconnected

Dec 13 10:28:56.989: @@@ dot1x_auth Gi1/0/1: auth_disconnected -> auth_restart

Dec 13 10:28:56.989: dot1x-sm(Gi1/0/1): 0xE6000015:auth_restart_enter called

Dec 13 10:28:56.989: dot1x-ev(Gi1/0/1): Sending create new context event to EAP for 0xE6000015 (0000.0000.0000)

Dec 13 10:28:56.989: dot1x_auth_bend Gi1/0/1: initial state auth_bend_initialize has enter

Dec 13 10:28:56.989: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_initialize_enter called

Dec 13 10:28:56.989: dot1x_auth_bend Gi1/0/1: initial state auth_bend_initialize has idle

Dec 13 10:28:56.989: dot1x_auth_bend Gi1/0/1: during state auth_bend_initialize, got event 16383(idle)

Dec 13 10:28:56.989: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_initialize -> auth_bend_idle

Dec 13 10:28:56.989: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_idle_enter called

Dec 13 10:28:56.989: dot1x-ev(Gi1/0/1): Created a client entry (0xE6000015)

Dec 13 10:28:56.989: dot1x-ev(Gi1/0/1): Dot1x authentication started for 0xE6000015 (0000.0000.0000)

Dec 13 10:28:56.989: dot1x-ev:DOT1X Supplicant not enabled on GigabitEthernet1/0/1

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): Posting !EAP_RESTART on Client 0xE6000015

Dec 13 10:28:56.994: dot1x_auth Gi1/0/1: during state auth_restart, got event 6(no_eapRestart)

Dec 13 10:28:56.994: @@@ dot1x_auth Gi1/0/1: auth_restart -> auth_connecting

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_connecting_enter called

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_restart_connecting_action called

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): Posting RX_REQ on Client 0xE6000015

Dec 13 10:28:56.994: dot1x_auth Gi1/0/1: during state auth_connecting, got event 10(eapReq_no_reAuthMax)

Dec 13 10:28:56.994: @@@ dot1x_auth Gi1/0/1: auth_connecting -> auth_authenticating

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_authenticating_enter called

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_connecting_authenticating_action called

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): Posting AUTH_START for 0xE6000015

Dec 13 10:28:56.994: dot1x_auth_bend Gi1/0/1: during state auth_bend_idle, got event 4(eapReq_authStart)

Dec 13 10:28:56.994: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_idle -> auth_bend_request

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_request_enter called

Dec 13 10:28:56.994: dot1x-ev(Gi1/0/1): Sending EAPOL packet to group PAE address

Dec 13 10:28:56.994: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:28:56.994: dot1x-registry:registry:dot1x_ether_macaddr called

Dec 13 10:28:56.994: dot1x-ev(Gi1/0/1): Sending out EAPOL packet

Dec 13 10:28:56.994: EAPOL pak dump Tx

Dec 13 10:28:56.994: EAPOL Version: 0x3 type: 0x0 length: 0x0005

Dec 13 10:28:56.994: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1

Dec 13 10:28:56.994: dot1x-packet(Gi1/0/1): EAPOL packet sent to client 0xE6000015 (0000.0000.0000)

Dec 13 10:28:56.994: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_idle_request_action called

Dec 13 10:28:57.608: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:28:57.608: dot1x-packet(Gi1/0/1): queuing an EAPOL pkt on Auth Q

Dec 13 10:28:57.608: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

Dec 13 10:28:57.608: EAPOL pak dump rx

Dec 13 10:28:57.608: EAPOL Version: 0x1 type: 0x1 length: 0x0000

Dec 13 10:28:57.608: dot1x-ev:

dot1x_auth_queue_event: Int Gi1/0/1 CODE= 0,TYPE= 0,LEN= 0

Dec 13 10:28:57.608: dot1x-packet(Gi1/0/1): Received an EAPOL frame

Dec 13 10:28:57.608: dot1x-ev(Gi1/0/1): Received pkt saddr =8c73.6eaf.8499 , daddr = 0180.c200.0003,

pae-ether-type = 888e.0101.0000

Dec 13 10:28:57.608: dot1x-ev(Gi1/0/1): Couldn't find the supplicant in the list

Dec 13 10:28:57.608: dot1x-ev(Gi1/0/1): New client detected, notifying AuthMgr

Dec 13 10:28:57.608: dot1x-ev(Gi1/0/1): Sending event (0) to Auth Mgr for 8c73.6eaf.8499

Dec 13 10:28:57.608: dot1x-packet(Gi1/0/1): Received an EAPOL-Start packet

Dec 13 10:28:57.608: EAPOL pak dump rx

Dec 13 10:28:57.608: EAPOL Version: 0x1 type: 0x1 length: 0x0000

Dec 13 10:28:57.608: dot1x-sm(Gi1/0/1): Posting EAPOL_START on Client 0xE6000015

Dec 13 10:28:57.608: dot1x_auth Gi1/0/1: during state auth_authenticating, got event 4(eapolStart)

Dec 13 10:28:57.608: @@@ dot1x_auth Gi1/0/1: auth_authenticating -> auth_aborting

Dec 13 10:28:57.608: dot1x-sm(Gi1/0/1): 0xE6000015:auth_authenticating_exit called

Dec 13 10:28:57.608: dot1x-sm(Gi1/0/1): 0xE6000015:auth_aborting_enter called

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): 802.1x method gets the go ahead from Auth Mgr for 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:28:57.613: %AUTHMGR-5-START: Starting 'dot1x' for client (8c73.6eaf.8499) on Interface Gi1/0/1 AuditSessionID C0A8FF74000000130049E839

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): Posting AUTH_ABORT for 0xE6000015

Dec 13 10:28:57.613: dot1x_auth_bend Gi1/0/1: during state auth_bend_request, got event 1(authAbort)

Dec 13 10:28:57.613: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_request -> auth_bend_initialize

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_initialize_enter called

Dec 13 10:28:57.613: dot1x_auth_bend Gi1/0/1: idle during state auth_bend_initialize

Dec 13 10:28:57.613: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_initialize -> auth_bend_idle

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_idle_enter called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): Posting !AUTH_ABORT on Client 0xE6000015

Dec 13 10:28:57.613: dot1x_auth Gi1/0/1: during state auth_aborting, got event 20(no_eapolLogoff_no_authAbort)

Dec 13 10:28:57.613: @@@ dot1x_auth Gi1/0/1: auth_aborting -> auth_restart

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_aborting_exit called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_restart_enter called

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): Resetting the client 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): Sending create new context event to EAP for 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_aborting_restart_action called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): Posting !EAP_RESTART on Client 0xE6000015

Dec 13 10:28:57.613: dot1x_auth Gi1/0/1: during state auth_restart, got event 6(no_eapRestart)

Dec 13 10:28:57.613: @@@ dot1x_auth Gi1/0/1: auth_restart -> auth_connecting

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_connecting_enter called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_restart_connecting_action called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): Posting RX_REQ on Client 0xE6000015

Dec 13 10:28:57.613: dot1x_auth Gi1/0/1: during state auth_connecting, got event 10(eapReq_no_reAuthMax)

Dec 13 10:28:57.613: @@@ dot1x_auth Gi1/0/1: auth_connecting -> auth_authenticating

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_authenticating_enter called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_connecting_authenticating_action called

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): Posting AUTH_START for 0xE6000015

Dec 13 10:28:57.613: dot1x_auth_bend Gi1/0/1: during state auth_bend_idle, got event 4(eapReq_authStart)

Dec 13 10:28:57.613: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_idle -> auth_bend_request

Dec 13 10:28:57.613: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_request_enter called

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): Sending EAPOL packet to group PAE address

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:28:57.613: dot1x-registry:registry:dot1x_ether_macaddr called

Dec 13 10:28:57.613: dot1x-ev(Gi1/0/1): Sending out EAPOL packet

Dec 13 10:28:57.618: EAPOL pak dump Tx

Dec 13 10:28:57.618: EAPOL Version: 0x3 type: 0x0 length: 0x0005

Dec 13 10:28:57.618: EAP code: 0x1 id: 0x1 length: 0x0005 type: 0x1

Dec 13 10:28:57.618: dot1x-packet(Gi1/0/1): EAPOL packet sent to client 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:28:57.618: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_idle_request_action called

Dec 13 10:28:58.986: %LINK-3-UPDOWN: Interface GigabitEthernet1/0/1, changed state to up

Dec 13 10:29:05.131: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:29:05.131: dot1x-packet(Gi1/0/1): Queuing an EAPOL pkt on Authenticator Q

Dec 13 10:29:05.131: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

Dec 13 10:29:05.131: EAPOL pak dump rx

Dec 13 10:29:05.131: EAPOL Version: 0x1 type: 0x0 length: 0x0009

Dec 13 10:29:05.131: dot1x-ev:

dot1x_auth_queue_event: Int Gi1/0/1 CODE= 2,TYPE= 1,LEN= 9

Dec 13 10:29:05.131: dot1x-packet(Gi1/0/1): Received an EAPOL frame

Dec 13 10:29:05.131: dot1x-ev(Gi1/0/1): Received pkt saddr =8c73.6eaf.8499 , daddr = 0180.c200.0003,

pae-ether-type = 888e.0100.0009

Dec 13 10:29:05.131: dot1x-packet(Gi1/0/1): Received an EAP packet

Dec 13 10:29:05.131: EAPOL pak dump rx

Dec 13 10:29:05.131: EAPOL Version: 0x1 type: 0x0 length: 0x0009

Dec 13 10:29:05.131: dot1x-packet(Gi1/0/1): Received an EAP packet from 8c73.6eaf.8499

Dec 13 10:29:05.131: dot1x-sm(Gi1/0/1): Posting EAPOL_EAP for 0xE6000015

Dec 13 10:29:05.131: dot1x_auth_bend Gi1/0/1: during state auth_bend_request, got event 6(eapolEap)

Dec 13 10:29:05.131: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_request -> auth_bend_response

Dec 13 10:29:05.131: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_enter called

Dec 13 10:29:05.131: dot1x-ev(Gi1/0/1): dot1x_sendRespToServer: Response sent to the server from 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:29:05.131: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_request_response_action called

Dec 13 10:29:05.137: RADIUS/ENCODE(00000016):Orig. component type = DOT1X

Dec 13 10:29:05.137: RADIUS: AAA Unsupported Attr: audit-session-id [607] 24

Dec 13 10:29:05.137: RADIUS: 43 30 41 38 46 46 37 34 30 30 30 30 30 30 31 33 [C0A8FF7400000013]

Dec 13 10:29:05.137: RADIUS: 30 30 34 39 45 38 [ 0049E8]

Dec 13 10:29:05.137: RADIUS: AAA Unsupported Attr: interface [171] 20

Dec 13 10:29:05.137: RADIUS: 47 69 67 61 62 69 74 45 74 68 65 72 6E 65 74 31 [GigabitEthernet1]

Dec 13 10:29:05.137: RADIUS: 2F 30 [ /0]

Dec 13 10:29:05.137: RADIUS(00000016): Config NAS IP: 0.0.0.0

Dec 13 10:29:05.137: RADIUS/ENCODE(00000016): acct_session_id: 22

Dec 13 10:29:05.137: RADIUS(00000016): sending

Dec 13 10:29:05.137: RADIUS/ENCODE: Best Local IP-Address 192.168.255.116 for Radius-Server 192.168.255.245

Dec 13 10:29:05.137: RADIUS(00000016): Send Access-Request to 192.168.255.245:1812 id 1645/28, len 147

Dec 13 10:29:05.137: RADIUS: authenticator 89 45 9F 8F 85 DC 1C 00 - E0 A1 DF BF BC EB 0D C6

Dec 13 10:29:05.137: RADIUS: User-Name [1] 6 "Test"

Dec 13 10:29:05.137: RADIUS: Service-Type [6] 6 Framed [2]

Dec 13 10:29:05.137: RADIUS: Framed-MTU [12] 6 1500

Dec 13 10:29:05.137: RADIUS: Called-Station-Id [30] 19 "44-E4-D9-36-88-01"

Dec 13 10:29:05.137: RADIUS: Calling-Station-Id [31] 19 "8C-73-6E-AF-84-99"

Dec 13 10:29:05.137: RADIUS: EAP-Message [79] 11

Dec 13 10:29:05.137: RADIUS: 02 01 00 09 01 54 65 73 74 [ Test]

Dec 13 10:29:05.137: RADIUS: Message-Authenticato[80] 18

Dec 13 10:29:05.137: RADIUS: 81 BA A0 BC FA ED F3 92 27 6E DB 52 23 94 57 8B [ 'nR#W]

Dec 13 10:29:05.137: RADIUS: EAP-Key-Name [102] 2 *

Dec 13 10:29:05.137: RADIUS: NAS-Port-Type [61] 6 Ethernet [15]

Dec 13 10:29:05.142: RADIUS: NAS-Port [5] 6 50101

Dec 13 10:29:05.142: RADIUS: NAS-Port-Id [87] 22 "GigabitEthernet1/0/1"

Dec 13 10:29:05.142: RADIUS: NAS-IP-Address [4] 6 192.168.255.116

Dec 13 10:29:05.142: RADIUS(00000016): Started 5 sec timeout

Dec 13 10:29:05.147: RADIUS: Received from id 1645/28 192.168.255.245:1812, Access-Challenge, len 78

Dec 13 10:29:05.147: RADIUS: authenticator E0 1D 24 4C EC DC A5 05 - 61 01 45 18 CB 79 45 D5

Dec 13 10:29:05.147: RADIUS: State [24] 32

Dec 13 10:29:05.147: RADIUS: 32 37 53 65 73 73 69 6F 6E 49 44 3D 41 43 53 31 [27SessionID=ACS1]

Dec 13 10:29:05.147: RADIUS: 2F 31 30 37 36 30 30 32 38 37 2F 39 39 3B [ /107600287/99;]

Dec 13 10:29:05.147: RADIUS: EAP-Message [79] 8

Dec 13 10:29:05.152: RADIUS: 01 A8 00 06 19 21 [ !]

Dec 13 10:29:05.152: RADIUS: Message-Authenticato[80] 18

Dec 13 10:29:05.152: RADIUS: D2 44 40 D6 3A A8 C5 37 F9 60 1B F4 CB 56 F3 DC [ D@:7`V]

Dec 13 10:29:05.152: RADIUS(00000016): Received from id 1645/28

Dec 13 10:29:05.152: RADIUS/DECODE: EAP-Message fragments, 6, total 6 bytes

Dec 13 10:29:05.152: dot1x-sm(Gi1/0/1): Posting EAP_REQ for 0xE6000015

Dec 13 10:29:05.152: dot1x_auth_bend Gi1/0/1: during state auth_bend_response, got event 7(eapReq)

Dec 13 10:29:05.152: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_response -> auth_bend_request

Dec 13 10:29:05.152: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_exit called

Dec 13 10:29:05.152: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_request_enter called

Dec 13 10:29:05.152: dot1x-ev(Gi1/0/1): Sending EAPOL packet to group PAE address

Dec 13 10:29:05.152: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:29:05.152: dot1x-registry:registry:dot1x_ether_macaddr called

Dec 13 10:29:05.152: dot1x-ev(Gi1/0/1): Sending out EAPOL packet

Dec 13 10:29:05.152: EAPOL pak dump Tx

Dec 13 10:29:05.152: EAPOL Version: 0x3 type: 0x0 length: 0x0006

Dec 13 10:29:05.152: EAP code: 0x1 id: 0xA8 length: 0x0006 type: 0x19

Dec 13 10:29:05.152: dot1x-packet(Gi1/0/1): EAPOL packet sent to client 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:29:05.152: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_request_action called

Dec 13 10:29:05.158: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:29:05.158: dot1x-packet(Gi1/0/1): Queuing an EAPOL pkt on Authenticator Q

Dec 13 10:29:05.158: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

Dec 13 10:29:05.158: EAPOL pak dump rx

Dec 13 10:29:05.158: EAPOL Version: 0x1 type: 0x0 length: 0x0006

Dec 13 10:29:05.158: dot1x-ev:

dot1x_auth_queue_event: Int Gi1/0/1 CODE= 2,TYPE= 3,LEN= 6

Dec 13 10:29:05.158: dot1x-packet(Gi1/0/1): Received an EAPOL frame

Dec 13 10:29:05.158: dot1x-ev(Gi1/0/1): Received pkt saddr =8c73.6eaf.8499 , daddr = 0180.c200.0003,

pae-ether-type = 888e.0100.0006

Dec 13 10:29:05.158: dot1x-packet(Gi1/0/1): Received an EAP packet

Dec 13 10:29:05.158: EAPOL pak dump rx

Dec 13 10:29:05.163: EAPOL Version: 0x1 type: 0x0 length: 0x0006

Dec 13 10:29:05.163: dot1x-packet(Gi1/0/1): Received an EAP packet from 8c73.6eaf.8499

Dec 13 10:29:05.168: dot1x-sm(Gi1/0/1): Posting EAPOL_EAP for 0xE6000015

Dec 13 10:29:05.168: dot1x_auth_bend Gi1/0/1: during state auth_bend_request, got event 6(eapolEap)

Dec 13 10:29:05.168: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_request -> auth_bend_response

Dec 13 10:29:05.168: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_enter called

Dec 13 10:29:05.168: dot1x-ev(Gi1/0/1): dot1x_sendRespToServer: Response sent to the server from 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:29:05.168: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_request_response_action called

Dec 13 10:29:05.173: RADIUS/ENCODE(00000016):Orig. component type = DOT1X

Dec 13 10:29:05.173: RADIUS: AAA Unsupported Attr: audit-session-id [607] 24

Dec 13 10:29:05.173: RADIUS: 43 30 41 38 46 46 37 34 30 30 30 30 30 30 31 33 [C0A8FF7400000013]

Dec 13 10:29:05.173: RADIUS: 30 30 34 39 45 38 [ 0049E8]

Dec 13 10:29:05.173: RADIUS: AAA Unsupported Attr: interface [171] 20

Dec 13 10:29:05.173: RADIUS: 47 69 67 61 62 69 74 45 74 68 65 72 6E 65 74 31 [GigabitEthernet1]

Dec 13 10:29:05.173: RADIUS: 2F 30 [ /0]

Dec 13 10:29:05.173: RADIUS(00000016): Config NAS IP: 0.0.0.0

Dec 13 10:29:05.173: RADIUS/ENCODE(00000016): acct_session_id: 22

Dec 13 10:29:05.173: RADIUS(00000016): sending

Dec 13 10:29:05.173: RADIUS/ENCODE: Best Local IP-Address 192.168.255.116 for Radius-Server 192.168.255.245

Dec 13 10:29:05.173: RADIUS(00000016): Send Access-Request to 192.168.255.245:1812 id 1645/29, len 176

Dec 13 10:29:05.173: RADIUS: authenticator B0 2E 5B CB 38 B0 4F 6B - D1 8F 71 38 F8 19 79 A4

Dec 13 10:29:05.173: RADIUS: User-Name [1] 6 "Test"

Dec 13 10:29:05.173: RADIUS: Service-Type [6] 6 Framed [2]

Dec 13 10:29:05.173: RADIUS: Framed-MTU [12] 6 1500

Dec 13 10:29:05.173: RADIUS: Called-Station-Id [30] 19 "44-E4-D9-36-88-01"

Dec 13 10:29:05.173: RADIUS: Calling-Station-Id [31] 19 "8C-73-6E-AF-84-99"

Dec 13 10:29:05.173: RADIUS: EAP-Message [79] 8

Dec 13 10:29:05.173: RADIUS: 02 A8 00 06 03 06

Dec 13 10:29:05.173: RADIUS: Message-Authenticato[80] 18

Dec 13 10:29:05.173: RADIUS: 90 CD 45 B8 78 9A 38 AD 7B B8 93 96 63 E6 EC F0 [ Ex8{c]

Dec 13 10:29:05.173: RADIUS: EAP-Key-Name [102] 2 *

Dec 13 10:29:05.173: RADIUS: NAS-Port-Type [61] 6 Ethernet [15]

Dec 13 10:29:05.173: RADIUS: NAS-Port [5] 6 50101

Dec 13 10:29:05.173: RADIUS: NAS-Port-Id [87] 22 "GigabitEthernet1/0/1"

Dec 13 10:29:05.173: RADIUS: State [24] 32

Dec 13 10:29:05.178: RADIUS: 32 37 53 65 73 73 69 6F 6E 49 44 3D 41 43 53 31 [27SessionID=ACS1]

Dec 13 10:29:05.178: RADIUS: 2F 31 30 37 36 30 30 32 38 37 2F 39 39 3B [ /107600287/99;]

Dec 13 10:29:05.178: RADIUS: NAS-IP-Address [4] 6 192.168.255.116

Dec 13 10:29:05.178: RADIUS(00000016): Started 5 sec timeout

Dec 13 10:29:05.178: RADIUS: Received from id 1645/29 192.168.255.245:1812, Access-Reject, len 44

Dec 13 10:29:05.178: RADIUS: authenticator 75 A6 2E 0F 27 A5 58 D7 - F2 E2 A5 E8 DA E7 1E 47

Dec 13 10:29:05.178: RADIUS: EAP-Message [79] 6

Dec 13 10:29:05.178: RADIUS: 04 A8 00 04

Dec 13 10:29:05.178: RADIUS: Message-Authenticato[80] 18

Dec 13 10:29:05.178: RADIUS: CD FA 29 F6 15 37 ED E1 7B 6D BF 17 F7 C7 23 24 [ )7{m#$]

Dec 13 10:29:05.178: RADIUS(00000016): Received from id 1645/29

Dec 13 10:29:05.178: RADIUS/DECODE: EAP-Message fragments, 4, total 4 bytes

Dec 13 10:29:05.178: dot1x-ev(Gi1/0/1): Received an EAP Fail

Dec 13 10:29:05.178: dot1x-sm(Gi1/0/1): Posting EAP_FAIL for 0xE6000015

Dec 13 10:29:05.178: dot1x_auth_bend Gi1/0/1: during state auth_bend_response, got event 10(eapFail)

Dec 13 10:29:05.178: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_response -> auth_bend_fail

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_exit called

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_fail_enter called

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_response_fail_action called

Dec 13 10:29:05.184: dot1x_auth_bend Gi1/0/1: idle during state auth_bend_fail

Dec 13 10:29:05.184: @@@ dot1x_auth_bend Gi1/0/1: auth_bend_fail -> auth_bend_idle

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_bend_idle_enter called

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): Posting AUTH_FAIL on Client 0xE6000015

Dec 13 10:29:05.184: dot1x_auth Gi1/0/1: during state auth_authenticating, got event 15(authFail)

Dec 13 10:29:05.184: @@@ dot1x_auth Gi1/0/1: auth_authenticating -> auth_authc_result

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_authenticating_exit called

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_authc_result_enter called

Dec 13 10:29:05.184: %DOT1X-5-FAIL: Authentication failed for client (8c73.6eaf.8499) on Interface Gi1/0/1 AuditSessionID

Dec 13 10:29:05.184: dot1x-ev(Gi1/0/1): Sending event (2) to Auth Mgr for 8c73.6eaf.8499

Dec 13 10:29:05.184: %AUTHMGR-7-RESULT: Authentication result 'fail' from 'dot1x' for client (8c73.6eaf.8499) on Interface Gi1/0/1 AuditSessionID C0A8FF74000000130049E839

Dec 13 10:29:05.184: %AUTHMGR-5-FAIL: Authorization failed for client (8c73.6eaf.8499) on Interface Gi1/0/1 AuditSessionID C0A8FF74000000130049E839

Dec 13 10:29:05.184: dot1x-redundancy: State for client 8c73.6eaf.8499 successfully retrieved

Dec 13 10:29:05.184: dot1x-ev(Gi1/0/1): Received Authz fail for the client 0xE6000015 (8c73.6eaf.8499)

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): Posting_AUTHZ_FAIL on Client 0xE6000015

Dec 13 10:29:05.184: dot1x_auth Gi1/0/1: during state auth_authc_result, got event 22(authzFail)

Dec 13 10:29:05.184: @@@ dot1x_auth Gi1/0/1: auth_authc_result -> auth_held

Dec 13 10:29:05.184: dot1x-sm(Gi1/0/1): 0xE6000015:auth_held_enter called

Dec 13 10:29:05.184: dot1x-ev(Gi1/0/1): Sending EAPOL packet to group PAE address

Dec 13 10:29:05.184: dot1x-ev(Gi1/0/1): Role determination not required

Dec 13 10:29:05.184: dot1x-registry:registry:dot1x_ether_macaddr called

Dec 13 10:29:05.184: dot1x-ev(Gi1/0/1): Sending out EAPOL packet

Dec 13 10:29:05.184: EAPOL pak dump Tx

Dec 13 10:29:05.184: EAPOL Version: 0x3 type: 0x0 length: 0x0004

Dec 13 10:29:05.184: EAP code: 0x4 id: 0xA8 length: 0x0004

Dec 13 10:29:05.184: dot1x-packet(Gi1/0/1): EAPOL packet sent to client 0xE6000015 (8c73.6eaf.8499)