Solved: Need help on dynamic vlan assignment through dot1x - Page 2

Mukund M Deshpande · ‎07-18-2013

Hi,

I have been testing dot1x configuration on a Cisco 2960 Switch with Juniper SBR but unable to get it to work. I have done a very basic configuration on the switch which is as below

aaa new-model

aaa authentication dot1x default group radius

aaa authorization network default group radius

dot1x system-auth-control

interface GigabitEthernet0/1

switchport mode access

dot1x pae authenticator

dot1x port-control auto

dot1x violation-mode protect

spanning-tree portfast

radius-server host 10.253.145.72 auth-port 1812 acct-port 1813 key ******

and i have configured the following attributes on local as well as domain user ID on Radius in the return list.

Tunnel_Medium_Type = 802

Tunnel-Type = VLAN

Tunnel-Private-Group-ID = 143

When i connect a system on to the switchport it asks me for authentication and after entering that it will go into limited or connectivity state. IP address assignment is through DHCP. I enabled debug for radius, dot1x and AAA on the switch and received this as the output.

Mar 1 01:06:32.943: dot1x-ev:dot1x_switch_is_dot1x_forwarding_enabled: Forwarding is disabled on Gi0/1

*Mar 1 01:06:32.943: dot1x-ev:dot1x_switch_addr_remove: Did not locate HA entry for MAC 0000.0000.0000 on interface GigabitEthernet0/1

*Mar 1 01:06:32.943: dot1x-ev:dot1x_vlan_assign_client_deleted for 0000.0000.0000 on interface GigabitEthernet0/1

*Mar 1 01:06:32.943: dot1x_auth Gi0/1: initial state auth_initialize has enter

*Mar 1 01:06:32.943: dot1x-sm:Gi0/1:0000.0000.0000:auth_initialize_enter called

*Mar 1 01:06:32.943: dot1x_auth Gi0/1: during state auth_initialize, got event 0(cfg_auto)

*Mar 1 01:06:32.943: @@@ dot1x_auth Gi0/1: auth_initialize -> auth_disconnected

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_disconnected_enter called

*Mar 1 01:06:32.952: dot1x_auth Gi0/1: idle during state auth_disconnected

*Mar 1 01:06:32.952: @@@ dot1x_auth Gi0/1: auth_disconnected -> auth_restart

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_restart_enter called

*Mar 1 01:06:32.952: dot1x-ev:Sending create new context event to EAP for 0000.0000.0000

*Mar 1 01:06:32.952: dot1x_auth_bend Gi0/1: initial state auth_bend_initialize has enter

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_bend_initialize_enter called

*Mar 1 01:06:32.952: dot1x_auth_bend Gi0/1: initial state auth_bend_initialize has idle

*Mar 1 01:06:32.952: dot1x_auth_bend Gi0/1: during state auth_bend_initialize, got event 16383(idle)

*Mar 1 01:06:32.952: @@@ dot1x_auth_bend Gi0/1: auth_bend_initialize -> auth_bend_idle

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_bend_idle_enter called

*Mar 1 01:06:32.952: dot1x-ev:Created a client entry for the supplicant 0000.0000.0000

*Mar 1 01:06:32.952: dot1x-ev:Created a default authenticator instance on GigabitEthernet0/1

*Mar 1 01:06:32.952: dot1x-sm:Posting !EAP_RESTART on Client=2CD60EC

*Mar 1 01:06:32.952: dot1x_auth Gi0/1: during state auth_restart, got event 6(no_eapRestart)

*Mar 1 01:06:32.952: @@@ dot1x_auth Gi0/1: auth_restart -> auth_connecting

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_connecting_enter called

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_restart_connecting_action called

*Mar 1 01:06:32.952: dot1x-packet:Received an EAP request packet from EAP for mac 0000.0000.0000

*Mar 1 01:06:32.952: dot1x-sm:Posting RX_REQ on Client=2CD60EC

*Mar 1 01:06:32.952: dot1x_auth Gi0/1: during state auth_connecting, got event 11(eapReq_no_reAuthMax)

*Mar 1 01:06:32.952: @@@ dot1x_auth Gi0/1: auth_connecting -> auth_authenticating

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_authenticating_enter called

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_connecting_authenticating_action called

*Mar 1 01:06:32.952: dot1x-sm:Posting AUTH_START on Client=2CD60EC

*Mar 1 01:06:32.952: dot1x_auth_bend Gi0/1: during state auth_bend_idle, got event 4(eapReq_authStart)

*Mar 1 01:06:32.952: @@@ dot1x_auth_bend Gi0/1: auth_bend_idle -> auth_bend_request

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_bend_request_enter called

*Mar 1 01:06:32.952: dot1x-packet:dot1x_mgr_send_eapol :EAP code: 0x1 id: 0x2 length: 0x0005 type: 0x1 data:

*Mar 1 01:06:32.952: dot1x-ev:GigabitEthernet0/1:Sending EAPOL packet to group PAE address

*Mar 1 01:06:32.952: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:06:32.952: dot1x-registry:registry:dot1x_ether_macaddr called

*Mar 1 01:06:32.952: dot1x-ev:dot1x_mgr_send_eapol: Sending out EAPOL packet on GigabitEthernet0/1

*Mar 1 01:06:32.952: EAPOL pak dump Tx

*Mar 1 01:06:32.952: EAPOL Version: 0x2 type: 0x0 length: 0x0005

*Mar 1 01:06:32.952: EAP code: 0x1 id: 0x2 length: 0x0005 type: 0x1

*Mar 1 01:06:32.952: dot1x-packet:dot1x_txReq: EAPOL packet sent out for the default authenticator

*Mar 1 01:06:32.952: dot1x-sm:Gi0/1:0000.0000.0000:auth_bend_idle_request_action called

*Mar 1 01:06:33.874: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet0/1, changed state to down

*Mar 1 01:06:51.834: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:06:51.834: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q

*Mar 1 01:06:51.834: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

*Mar 1 01:06:51.834: EAPOL pak dump rx

*Mar 1 01:06:51.834: EAPOL Version: 0x1 type: 0x0 length: 0x000A

*Mar 1 01:06:51.834: dot1x-ev:

dot1x_auth_queue_event: Int Gi0/1 CODE= 2,TYPE= 1,LEN= 10

*Mar 1 01:06:51.834: dot1x-packet:Received an EAPOL frame on interface GigabitEthernet0/1

*Mar 1 01:06:51.834: dot1x-ev:Received pkt saddr =6c62.6d57.4c2e , daddr = 0180.c200.0003,

pae-ether-type = 888e.0100.000a

*Mar 1 01:06:51.834: dot1x-ev:Created a client entry for the supplicant 6c62.6d57.4c2e

*Mar 1 01:06:51.834: dot1x-ev:Found the default authenticator instance on GigabitEthernet0/1

*Mar 1 01:06:51.834: dot1x-registry:EAPOL traffic seen on GigabitEthernet0/1

*Mar 1 01:06:51.834: dot1x-ev:dot1x_auth_process_eapol: EAPOL flag status of the port Gi0/1 is FALSE

*Mar 1 01:06:51.834: dot1x-ev:dot1x_auth_process_eapol: EAPOL flag set for the port Gi0/1

*Mar 1 01:06:51.834: dot1x-packet:Received an EAP packet on interface GigabitEthernet0/1

*Mar 1 01:06:51.834: EAPOL pak dump rx

*Mar 1 01:06:51.834: EAPOL Version: 0x1 type: 0x0 length: 0x000A

*Mar 1 01:06:51.834: dot1x-packet:Received an EAP packet on the GigabitEthernet0/1 from mac 6c62.6d57.4c2e

*Mar 1 01:06:51.834: dot1x-sm:Posting EAPOL_EAP on Client=2CD60EC

*Mar 1 01:06:51.834: dot1x_auth_bend Gi0/1: during state auth_bend_request, got event 6(eapolEap)

*Mar 1 01:06:51.834: @@@ dot1x_auth_bend Gi0/1: auth_bend_request -> auth_bend_response

*Mar 1 01:06:51.834: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_response_enter called

*Mar 1 01:06:51.834: dot1x-ev:dot1x_sendRespToServer: Response sent to the server from 6c62.6d57.4c2e

*Mar 1 01:06:51.834: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_request_response_action called

*Mar 1 01:06:51.834: AAA/BIND(00000007): Bind i/f

*Mar 1 01:06:51.834: AAA/AUTHEN/8021X (00000007): Pick method list 'default'

*Mar 1 01:06:51.834: RADIUS/ENCODE(00000007):Orig. component type = DOT1X

*Mar 1 01:06:51.834: RADIUS(00000007): Config NAS IP: 0.0.0.0

*Mar 1 01:06:51.834: RADIUS/ENCODE: Best Local IP-Address 192.168.109.35 for Radius-Server 10.253.145.72

*Mar 1 01:06:51.834: RADIUS(00000007): Send Access-Request to 10.253.145.72:1812 id 1645/21, len 145

*Mar 1 01:06:56.750: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/21

*Mar 1 01:07:01.884: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/21

*Mar 1 01:07:06.951: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/21

*Mar 1 01:07:09.845: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:07:09.845: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q

*Mar 1 01:07:09.845: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

*Mar 1 01:07:09.845: EAPOL pak dump rx

*Mar 1 01:07:09.845: EAPOL Version: 0x1 type: 0x1 length: 0x0000

*Mar 1 01:07:09.845: dot1x-ev:

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

*Mar 1 01:07:09.845: dot1x-packet:Received an EAPOL frame on interface GigabitEthernet0/1

*Mar 1 01:07:09.845: dot1x-ev:Received pkt saddr =6c62.6d57.4c2e , daddr = 0180.c200.0003,

pae-ether-type = 888e.0101.0000

*Mar 1 01:07:09.845: dot1x-ev:dot1x_auth_process_eapol: EAPOL flag status of the port Gi0/1 is TRUE

*Mar 1 01:07:09.845: dot1x-packet:Received an EAPOL-Start packet on interface GigabitEthernet0/1

*Mar 1 01:07:09.845: EAPOL pak dump rx

*Mar 1 01:07:09.845: EAPOL Version: 0x1 type: 0x1 length: 0x0000

*Mar 1 01:07:09.845: dot1x-sm:Posting EAPOL_START on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth Gi0/1: during state auth_authenticating, got event 4(eapolStart)

*Mar 1 01:07:09.845: @@@ dot1x_auth Gi0/1: auth_authenticating -> auth_aborting

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_authenticating_exit called

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_aborting_enter called

*Mar 1 01:07:09.845: dot1x-sm:Posting AUTH_ABORT on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth_bend Gi0/1: during state auth_bend_response, got event 1(authAbort)

*Mar 1 01:07:09.845: @@@ dot1x_auth_bend Gi0/1: auth_bend_response -> auth_bend_initialize

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_response_exit called

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_initialize_enter called

*Mar 1 01:07:09.845: dot1x_auth_bend Gi0/1: idle during state auth_bend_initialize

*Mar 1 01:07:09.845: @@@ dot1x_auth_bend Gi0/1: auth_bend_initialize -> auth_bend_idle

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_idle_enter called

*Mar 1 01:07:09.845: dot1x-sm:Posting !AUTH_ABORT on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth Gi0/1: during state auth_aborting, got event 21(no_eapolLogoff_no_authAbort)

*Mar 1 01:07:09.845: @@@ dot1x_auth Gi0/1: auth_aborting -> auth_restart

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_aborting_exit called

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_restart_enter called

*Mar 1 01:07:09.845: dot1x-ev:Sending create new context event to EAP for 6c62.6d57.4c2e

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_aborting_restart_action called

*Mar 1 01:07:09.845: dot1x-sm:Posting !EAP_RESTART on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth Gi0/1: during state auth_restart, got event 6(no_eapRestart)

*Mar 1 01:07:09.845: @@@ dot1x_auth Gi0/1: auth_restart -> auth_connecting

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_connecting_enter called

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_restart_connecting_action called

*Mar 1 01:07:09.845: dot1x-packet:Received an EAP request packet from EAP for mac 6c62.6d57.4c2e

*Mar 1 01:07:09.845: dot1x-sm:Posting RX_REQ on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth Gi0/1: during state auth_connecting, got event 11(eapReq_no_reAuthMax)

*Mar 1 01:07:09.845: @@@ dot1x_auth Gi0/1: auth_connecting -> auth_authenticating

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_authenticating_enter called

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_connecting_authenticating_action called

*Mar 1 01:07:09.845: dot1x-sm:Posting AUTH_START on Client=2CD60EC

*Mar 1 01:07:09.845: dot1x_auth_bend Gi0/1: during state auth_bend_idle, got event 4(eapReq_authStart)

*Mar 1 01:07:09.845: @@@ dot1x_auth_bend Gi0/1: auth_bend_idle -> auth_bend_request

*Mar 1 01:07:09.845: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_request_enter called

*Mar 1 01:07:09.845: dot1x-packet:dot1x_mgr_send_eapol :EAP code: 0x1 id: 0x2 length: 0x0005 type: 0x1 data:

*Mar 1 01:07:09.845: dot1x-ev:GigabitEthernet0/1:Sending EAPOL packet to group PAE address

*Mar 1 01:07:09.845: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:07:09.853: dot1x-registry:registry:dot1x_ether_macaddr called

*Mar 1 01:07:09.853: dot1x-ev:dot1x_mgr_send_eapol: Sending out EAPOL packet on GigabitEthernet0/1

*Mar 1 01:07:09.853: EAPOL pak dump Tx

*Mar 1 01:07:09.853: EAPOL Version: 0x2 type: 0x0 length: 0x0005

*Mar 1 01:07:09.853: EAP code: 0x1 id: 0x2 length: 0x0005 type: 0x1

*Mar 1 01:07:09.853: dot1x-packet:dot1x_txReq: EAPOL packet sent to client (6c62.6d57.4c2e)

*Mar 1 01:07:09.853: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_idle_request_action called

*Mar 1 01:07:11.455: RADIUS: No response from (10.253.145.72:1812,1813) for id 1645/21

*Mar 1 01:07:11.455: RADIUS/DECODE: parse response no app start; FAIL

*Mar 1 01:07:11.455: RADIUS/DECODE: parse response; FAIL

*Mar 1 01:07:28.358: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:07:28.358: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q

*Mar 1 01:07:28.358: dot1x-ev:Enqueued the eapol packet to the global authenticator queue

*Mar 1 01:07:28.358: EAPOL pak dump rx

*Mar 1 01:07:28.358: EAPOL Version: 0x1 type: 0x0 length: 0x0018

*Mar 1 01:07:28.358: dot1x-ev:dot1x_auth_queue_event: Int Gi0/1 CODE= 2,TYPE= 1,LEN= 24

*Mar 1 01:07:28.358: dot1x-packet:Received an EAPOL frame on interface GigabitEthernet0/1

*Mar 1 01:07:28.358: dot1x-ev:Received pkt saddr =6c62.6d57.4c2e , daddr = 0180.c200.0003, pae-ether-type = 888e.0100.0018

*Mar 1 01:07:28.358: dot1x-ev:dot1x_auth_process_eapol: EAPOL flag status of the port Gi0/1 is TRUE

*Mar 1 01:07:28.358: dot1x-packet:Received an EAP packet on interface GigabitEthernet0/1

*Mar 1 01:07:28.358: EAPOL pak dump rx

*Mar 1 01:07:28.358: EAPOL Version: 0x1 type: 0x0 length: 0x0018

*Mar 1 01:07:28.358: dot1x-packet:Received an EAP packet on the GigabitEthernet0/1 from mac 6c62.6d57.4c2e

*Mar 1 01:07:28.358: dot1x-sm:Posting EAPOL_EAP on Client=2CD60EC

*Mar 1 01:07:28.358: dot1x_auth_bend Gi0/1: during state auth_bend_request, got event 6(eapolEap)

*Mar 1 01:07:28.358: @@@ dot1x_auth_bend Gi0/1: auth_bend_request -> auth_bend_response

*Mar 1 01:07:28.358: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_response_enter called

*Mar 1 01:07:28.358: dot1x-ev:dot1x_sendRespToServer: Response sent to the server from 6c62.6d57.4c2e

*Mar 1 01:07:28.358: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_request_response_action called

*Mar 1 01:07:28.358: AAA/BIND(00000008): Bind i/f

*Mar 1 01:07:28.358: AAA/AUTHEN/8021X (00000008): Pick method list 'default'

*Mar 1 01:07:28.367: RADIUS/ENCODE(00000008):Orig. component type = DOT1X

*Mar 1 01:07:28.367: RADIUS(00000008): Config NAS IP: 0.0.0.0

*Mar 1 01:07:28.367: RADIUS/ENCODE: Best Local IP-Address 192.168.109.35 for Radius-Server 10.253.145.72

*Mar 1 01:07:28.367: RADIUS(00000008): Send Access-Request to 10.253.145.72:1812 id 1645/22, len 173

*Mar 1 01:07:33.333: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/22

*Mar 1 01:07:38.140: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/22

*Mar 1 01:07:43.206: RADIUS: Retransmit to (10.253.145.72:1812,1813) for id 1645/22

*Mar 1 01:07:48.072: RADIUS: No response from (10.253.145.72:1812,1813) for id 1645/22

*Mar 1 01:07:48.072: RADIUS/DECODE: parse response no app start; FAIL

*Mar 1 01:07:48.072: RADIUS/DECODE: parse response; FAIL

*Mar 1 01:07:48.072: dot1x-ev:Authorization data for client 6c62.6d57.4c2e has been reset on GigabitEthernet0/1

*Mar 1 01:07:48.072: dot1x-ev:Received an EAP Fail on GigabitEthernet0/1 for mac 6c62.6d57.4c2e

*Mar 1 01:07:48.072: dot1x-ev:No reply attributes received from AAA for 6c62.6d57.4c2e

*Mar 1 01:07:48.072: dot1x-sm:Posting EAP_FAIL on Client=2CD60EC

*Mar 1 01:07:48.072: dot1x_auth_bend Gi0/1: during state auth_bend_response, got event 10(eapFail)

*Mar 1 01:07:48.072: @@@ dot1x_auth_bend Gi0/1: auth_bend_response -> auth_bend_fail

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_response_exit called

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_fail_enter called

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_response_fail_action called

*Mar 1 01:07:48.072: dot1x_auth_bend Gi0/1: idle during state auth_bend_fail

*Mar 1 01:07:48.072: @@@ dot1x_auth_bend Gi0/1: auth_bend_fail -> auth_bend_idle

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_bend_idle_enter called

*Mar 1 01:07:48.072: dot1x-sm:Posting AUTH_FAIL on Client=2CD60EC

*Mar 1 01:07:48.072: dot1x_auth Gi0/1: during state auth_authenticating, got event 16(authFail)

*Mar 1 01:07:48.072: @@@ dot1x_auth Gi0/1: auth_authenticating -> auth_authc_result

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_authenticating_exit called

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_authc_result_enter called

*Mar 1 01:07:48.072: dot1x-ev:dot1x_critical_applicable: Critical auth not applicable. Feature is not enabled on port GigabitEthernet0/1.

*Mar 1 01:07:48.072: dot1x-sm:Posting AUTHC_FAIL on Client=2CD60EC

*Mar 1 01:07:48.072: dot1x_auth Gi0/1: during state auth_authc_result, got event 24(authcFail)

*Mar 1 01:07:48.072: @@@ dot1x_auth Gi0/1: auth_authc_result -> auth_held

*Mar 1 01:07:48.072: dot1x-ev:dot1x_critical_applicable: Critical auth not applicable. Feature is not enabled on port GigabitEthernet0/1.

*Mar 1 01:07:48.072: dot1x-sm:Gi0/1:6c62.6d57.4c2e:auth_held_enter called

*Mar 1 01:07:48.072: dot1x-ev:dot1x_switch_authz_fail: Called for GigabitEthernet0/1 and 6c62.6d57.4c2e

*Mar 1 01:07:48.072: dot1x-ev:dot1x_switch_port_unauthorized: Unauthorizing interface GigabitEthernet0/1

*Mar 1 01:07:48.072: dot1x-ev:dot1x_switch_is_dot1x_forwarding_enabled: Forwarding is disabled on Gi0/1

*Mar 1 01:07:48.072: dot1x-ev:dot1x_switch_addr_remove: Did not locate HA entry for MAC 6c62.6d57.4c2e on interface GigabitEthernet0/1

*Mar 1 01:07:48.072: dot1x-ev:dot1x_vlan_assign_authz_fail on interface GigabitEthernet0/1

*Mar 1 01:07:48.072: dot1x-packet:dot1x_mgr_send_eapol :EAP code: 0x4 id: 0x2 length: 0x0004 type: 0x0 data:

*Mar 1 01:07:48.072: dot1x-ev:GigabitEthernet0/1:Sending EAPOL packet to group PAE address

*Mar 1 01:07:48.072: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on GigabitEthernet0/1.

*Mar 1 01:07:48.072: dot1x-registry:registry:dot1x_ether_macaddr called

*Mar 1 01:07:48.072: dot1x-ev:dot1x_mgr_send_eapol: Sending out EAPOL packet on GigabitEthernet0/1

*Mar 1 01:07:48.072: EAPOL pak dump Tx

*Mar 1 01:07:48.072: EAPOL Version: 0x2 type: 0x0 length: 0x0004

*Mar 1 01:07:48.072: EAP code: 0x4 id: 0x2 length: 0x0004

*Mar 1 01:07:48.072: dot1x-packet:dot1x_txReq: EAPOL packet sent to client (6c62.6d57.4c2e)

*Mar 1 01:08:16.878: dot1x-registry:dot1x_switch_port_physical_linkchange invoked on interface Gi0/1

*Mar 1 01:08:16.878: dot1x-ev:

dot1x_switch_sb_vp_errdisable_set: setting Gi0/1 domain 1 to errdisabled

*Mar 1 01:08:16.878: dot1x-ev:

dot1x_switch_sb_vp_errdisable_set: setting Gi0/1 domain 2 to errdisabled

*Mar 1 01:08:16.878: dot1x-ev:dot1x_mgr_if_state_change: GigabitEthernet0/1 has changed to DOWN

*Mar 1 01:08:16.878: dot1x-ev:Cleared all authenticator instances on GigabitEthernet0/1

*Mar 1 01:08:16.878: dot1x-ev:dot1x_switch_port_unauthorized: Unauthorizing interface GigabitEthernet0/1

*Mar 1 01:08:16.878: dot1x-ev:dot1x_switch_is_dot1x_forwarding_enabled: Forwarding is disabled on Gi0/1

*Mar 1 01:08:16.878: dot1x-ev:dot1x_switch_addr_remove: Did not locate HA entry for MAC 6c62.6d57.4c2e on interface GigabitEthernet0/1

*Mar 1 01:08:16.878: dot1x-ev:dot1x_vlan_assign_client_deleted for 6c62.6d57.4c2e on interface GigabitEthernet0/1

*Mar 1 01:08:16.878: dot1x-ev:dot1x_vlan_assign_client_deleted: Ignoring client 6c62.6d57.4c2e on GigabitEthernet0/1, domain is data

*Mar 1 01:08:18.883: %LINK-3-UPDOWN: Interface GigabitEthernet0/1, changed state to down

Please suggest as i'm unable to understand where am i possibly going wrong.

Mukund M Deshpande · ‎08-01-2013

Hi Paul,

I have checked this through the debug logs on the radius server. I have also done the packet capture on the radius but i only see the attributes in the radius debug logs and not in the packet capture.

The switch IOS is

cat4500e-lanbase-mz.122-53.SG1 and this image supports dot1x vlan assignment.

Would also need your views on this.

Thanks...

Peter Paluch · ‎08-01-2013

Sagar,

If the 3 attributes are not put into the Access-Accept message sent from the RADIUS to the switch then definitely, that is the reason why the automatic VLAN assignment is not working. The RADIUS server, or its configuration, is to be blamed here.

However, as I have not worked with the Juniper RADIUS server before, I do not know what to do with it to force it to send the attributes. Once again, have you actually tried to define both the attributes and their values numerically, not by names?

If you have a support contract with Juniper, or if you can access its support forums (I believe they have a similar forum to this one), can you ask there about this issue?

In the meanwhile, do you have an option of testing a different RADIUS server? Personally I suggest FreeRADIUS although setting it up for the first time is not entirely simple.

Once again - we need to see those 3 attributes in an Access-Accept message, and that is the responsibility of the RADIUS server. A switch can not do anything about it. Until those 3 attributes are not seen in the packets as they are captured on the RADIUS server, this is a problem of the RADIUS server.

Best regards,

Peter

Mukund M Deshpande · ‎08-02-2013

Hi Peter,

I'm now able to receive all the 3 attributes on the switch after creating a accept filter on the Juniper Radius.

But the vlan is not getting assigned to the desginated port even though all the integer values are as mentioned by you

and it also keeps on asking me for constant reauthentication.

Please suggest.

007763: Aug 2 11:30:56.260: @@@ dot1x_auth_bend Gi2/3: auth_bend_request -> auth_bend_response

007764: Aug 2 11:30:56.260: dot1x-sm(Gi2/3): 0x58000007:auth_bend_response_enter called

007765: Aug 2 11:30:56.260: dot1x-ev(Gi2/3): dot1x_sendRespToServer: Response sent to the server from 0x58000007 (047d.7b35.a381)

007766: Aug 2 11:30:56.260: dot1x-sm(Gi2/3): 0x58000007:auth_bend_request_response_action called

007767: Aug 2 11:30:56.260: RADIUS/ENCODE(00000011):Orig. component type = DOT1X

007768: Aug 2 11:30:56.260: RADIUS(00000011): Config NAS IP: 0.0.0.0

007769: Aug 2 11:30:56.260: RADIUS/ENCODE(00000011): acct_session_id: 17

007785: Aug 2 11:30:56.260: RADIUS: NAS-Port-Type [61] 6 Ethernet [15]

007786: Aug 2 11:30:56.260: RADIUS: NAS-Port [5] 6 50203

007787: Aug 2 11:30:56.260: RADIUS: NAS-Port-Id [87] 20 "GigabitEthernet2/3"

007788: Aug 2 11:30:56.260: RADIUS: State [24] 18

007789: Aug 2 11:30:56.260: RADIUS: 53 42 52 2D 43 48 20 33 37 30 38 39 7C 31 31 00 [ SBR-CH 37089|11]

007790: Aug 2 11:30:56.260: RADIUS: NAS-IP-Address [4] 6 192.168.109.17

007791: Aug 2 11:31:00.876: RADIUS: Received from id 1645/104 10.253.145.72:1812, Access-Accept, len 370

007792: Aug 2 11:31:00.876: RADIUS: authenticator 45 04 06 51 A8 57 14 47 - 66 40 B5 61 B8 D6 50 6C

007793: Aug 2 11:31:00.876: RADIUS: Class [25] 142

007794: Aug 2 11:31:00.876: RADIUS: 53 42 52 32 43 4C DA E5 D3 DA BF B6 B3 E1 CE 80 11 80 79 01 80 04 81 99 8C 86 80 02 80 0C 81 B0 DB CE D7 83 85 DA AE B2 99 AD F0 12 80 0E 81 DA E5 D3 DA BF B6 B3 E1 CE 80 85 8A CB 94 14 80 4A 81 FF C6 EE DB E7 A0 86 FB DB B3 E6 E4 81 EB 91 E6 EA F0 E9 E1 D4 CD 99 CF DA BF E5 B7 AF DB D0 84 BB FC F4 90 BA 90 96 C4 F1 F3 E7 FF F4 99 D8 F1 FC E1 A9 E6 F8 C0 D5 EC 8E C1 AA A5 CB CC B3 F6 B6 D2 B5 CF AA CC DB A3 F7 86 C0 [ SBR2CLyJ]

007795: Aug 2 11:31:00.876: RADIUS: Tunnel-Type [64] 6 00:VLAN [13]

007796: Aug 2 11:31:00.876: RADIUS: Tunnel-Private-Group[81] 7 00:"143 "

007797: Aug 2 11:31:00.876: RADIUS: Tunnel-Medium-Type [65] 6 00:ALL_802 [6]

007798: Aug 2 11:31:00.876: RADIUS: Class [25] 73

007799: Aug 2 11:31:00.880: RADIUS: 53 42 52 32 43 4C DA E5 D3 DA BF B6 B3 E1 CE 80 11 80 34 01 80 02 81 9B 80 02 80 18 81 AE 97 89 94 F2 D1 8A D2 A7 90 A9 C5 E3 85 DC F5 B8 98 AD D2 F3 91 CA EF 12 80 0E 81 DA E5 D3 DA BF B6 B3 E1 CE 80 85 8A CB 94 [ SBR2CL4]

007800: Aug 2 11:31:00.880: RADIUS: Vendor, Microsoft [26] 58

007801: Aug 2 11:31:00.880: RADIUS: MS-MPPE-Recv-Key [17] 52 *

007802: Aug 2 11:31:00.880: RADIUS: Vendor, Microsoft [26] 58

007803: Aug 2 11:31:00.880: RADIUS: MS-MPPE-Send-Key [16] 52 *

007804: Aug 2 11:31:00.956: RADIUS(00000011): Received from id 1645/104

007805: Aug 2 11:31:00.968: dot1x-ev(Gi2/3): Received an EAP Fail

007806: Aug 2 11:31:00.980: dot1x-sm(Gi2/3): Posting EAP_FAIL for 0x58000007

007807: Aug 2 11:31:00.980: dot1x_auth_bend Gi2/3: during state auth_bend_response, got event 10(eapFail)

007808: Aug 2 11:31:00.980: @@@ dot1x_auth_bend Gi2/3: auth_bend_response -> auth_bend_fail

007809: Aug 2 11:31:00.980: dot1x-sm(Gi2/3): 0x58000007:auth_bend_response_exit called

007810: Aug 2 11:31:00.980: dot1x-sm(Gi2/3): 0x58000007:auth_bend_fail_enter called

007811: Aug 2 11:31:00.980: dot1x-sm(Gi2/3): 0x58000007:auth_bend_response_fail_action called

007812: Aug 2 11:31:00.980: dot1x_auth_bend Gi2/3: idle during state auth_bend_fail

007813: Aug 2 11:31:00.980: @@@ dot1x_auth_bend Gi2/3: auth_bend_fail -> auth_bend_idle

007814: Aug 2 11:31:00.980: dot1x-sm(Gi2/3): 0x58000007:auth_bend_idle_enter called

007815: Aug 2 11:31:01.000: dot1x-sm(Gi2/3): Posting AUTH_FAIL on Client 0x58000007

007816: Aug 2 11:31:01.000: dot1x_auth Gi2/3: during state auth_authenticating, got event 15(authFail)

007817: Aug 2 11:31:01.000: @@@ dot1x_auth Gi2/3: auth_authenticating -> auth_authc_result

007818: Aug 2 11:31:01.000: dot1x-sm(Gi2/3): 0x58000007:auth_authenticating_exit called

007819: Aug 2 11:31:01.000: dot1x-sm(Gi2/3): 0x58000007:auth_authc_result_enter called

007820: Aug 2 17:01:01: %DOT1X-5-FAIL: Authentication failed for client (047d.7b35.a381) on Interface Gi2/3

007831: Aug 2 11:31:01.004: dot1x-ev(Gi2/3): Sending EAPOL packet to group PAE address

007832: Aug 2 11:31:01.004: dot1x-ev(Gi2/3): Role determination not required

007833: Aug 2 11:31:01.004: dot1x-registry:registry:dot1x_ether_macaddr called

007834: Aug 2 11:31:01.004: dot1x-ev(Gi2/3): Sending out EAPOL packet

007835: Aug 2 11:31:01.004: EAPOL pak dump Tx

007836: Aug 2 11:31:01.004: EAPOL Version: 0x2 type: 0x0 length: 0x0004

007837: Aug 2 11:31:01.004: EAP code: 0x4 id: 0xD length: 0x0004

007838: Aug 2 11:31:01.004: dot1x-packet(Gi2/3): EAPOL packet sent to client 0x58000007 (047d.7b35.a381)

007839: Aug 2 11:31:04.776: dot1x-ev(Gi2/3): Interface state changed to DOWN

007840: Aug 2 11:31:04.776: dot1x-ev(Gi2/3): Deleting client 0x58000007 (047d.7b35.a381)

007841: Aug 2 11:31:04.776: dot1x-ev:Delete auth client (0x58000007) message

007842: Aug 2 11:31:04.776: dot1x-ev:Auth client ctx destroyed

Peter Paluch · ‎08-02-2013

Hello Sagar,

We're getting closer.

There appears to be a very subtle typo in the Tunnel-Private-Group-ID attribute: notice that its value is "143". This could be the cause of the problem - combining a whitespace character with the VLAN ID that the switch cannot understand. Please double-check the configuration of the RADIUS server and make sure that the value stored in the Tunnel-Private-Group-ID does not contain any whitespace.

Please keep me informed!

Best regards,

Peter

Mukund M Deshpande · ‎08-05-2013

Hi Peter,

Thanks you for your response.!!!

I have checked and and could not find any typo error in the attribute options. Is there a possibilty of a bug in the IOS..?

Peter Paluch · ‎08-09-2013

Hello Sagar,

I apologize for getting back to you after such a long delay.

Can you try capturing the RADIUS communication on the RADIUS server using Wireshark, store it in a file and post it here? It would be most helpful if I could see and analyze the messages in detail.

Thank you - and once again, please accept my apologies.

Best regards,

Peter

Mukund M Deshpande · ‎08-17-2013

Hi Peter,

I apologise for the late response... I would not be able to share the capture due to security policies of the organisation.... Would not be able to upload here... Can try sending it to you through mail if you can share your mail id...

Peter Paluch · ‎08-18-2013

Hi Sagar,

I also apologize for my late reply here. My e-mail is Peter.Paluch@fri.uniza.sk - it is also publicly shown on my CSC profile.You are welcome to send the capture there.

Best regards,

Peter

Mukund M Deshpande · ‎08-28-2013

Hi Peter,

The implementation is now working successfully as tested yesterday. There was a setting difference which had to be done on the Client (Laptop) i.e. i changed the authentication method from Microsoft PEAP to Cisco PEAP and it all started working fine. Please could you help me to understand why this difference. Microsoft PEAP uses MSCHAP V2 and Cisco PEAP uses OTP. Is there some compatibility issue with Microsoft PEAP with respect to the Cisco switches or is this an IOS limitation.

As of now i can say that if i use Cisco PEAP it works as expected. Thanks al lot for all your help and support till now.

I appreciate all the help you could provide in resolving this issue...!!!!

Mukund M Deshpande · ‎09-10-2013

Hi Peter,

Hope you are doing well... I had sent you the packet captures last week for both MS-CHAPv2 and Cisco PEAP.

Have you recevied the attachments.... Desperately waiting for your analysis on this...

Thanks once again for all the help...

Peter Paluch · ‎09-10-2013

Hi,

I've just sent you an e-mail.

Best regards,

Peter