Friday, October 12, 2018

Brocade/Ruckus ICX 802.1x Wired 15Sec Delay AAA_Accept Msg

Anyobody an idea where this 15 sec delay could origin from (18:51:41 - 18:51:56)

- radius accept msg leaves the radius server 14 seconds earlier

- no problem or 15 sec delay with non ICX Switches

Debug: Oct 11 18:51:41 [T:748473649] [EVENTS] (1/1/7) dot1x_add_new_mac_session: new MAC session - original_vlanid 0 - mac session b8ae.ed75.95f9 vlan 10 index 32768

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7: [b8aeed75:95f9] is INITIALIZE

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is INITIALIZE

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAPOL Pkt at DISCONNECTED State of Auth PA ESM with EAP Code: 0x04 (Failure), EAP Id: 0

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is DISCONNECTED

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAPOL Pkt at CONNECTING State of Auth PAE SM with EAP Code: 0x01 (Request), EAP Id: 1, EAP Type: 0x01 (Identity)

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is CONNECTING

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is IDLE

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAPOL Pkt at CONNECTING State of Auth PAE SM with EAP Code: 0x01 (Request), EAP Id: 1, EAP Type: 0x01 (Identity)

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is CONNECTING

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7 Rx EAPOL_START

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAPOL Pkt at CONNECTING State of Auth PAE SM with EAP Code: 0x01 (Request), EAP Id: 1, EAP Type: 0x01 (Identity)

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is CONNECTING

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: port 1/1/7 Rx EAPOL Pkt with EAP Code: 0x02 (Response), EAP Id: 1, EAP Type: 0x01 (Indentity)

Debug: Oct 11 18:51:41 [T:748473650] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:41 [T:748473650] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is AUTHENTICATING

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) : 802.1X: port 1/1/7 Rx EAPOL Pkt with EAP Code: 0x02 (Response), EAP Id: 1, EAP Type: 0x01 (Indentity)

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) 802.1X: Port 1/1/7 UP

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) Port is up

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) : 802.1X: Rx AAA_INTERACTIVE for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) : 802.1X Pass-through from auth server: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 2, len: 6, type : 13

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAP-Packet (EAP Req) received from RADIUS Server to Supplicant at REQUEST State of Backend Auth SM with EAP Id: 2

Debug: Oct 11 18:51:41 [T:748473651] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 30 seconds in the REQUEST state of backend state machine

Debug: Oct 11 18:51:41 [T:748473651] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is REQUEST

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X Pass-through: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 2, len: 184, type : 13

Debug: Oct 11 18:51:41 [T:748473652] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X: Rx AAA_INTERACTIVE for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X Pass-through from auth server: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 3, len: 1024, type : 13

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAP-Packet (EAP Req) received from RADIUS Server to Supplicant at REQUEST State of Backend Auth SM with EAP Id: 3

Debug: Oct 11 18:51:41 [T:748473652] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 30 seconds in the REQUEST state of backend state machine

Debug: Oct 11 18:51:41 [T:748473652] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is REQUEST

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X Pass-through: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 3, len: 6, type: 13

Debug: Oct 11 18:51:41 [T:748473653] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: Rx AAA_INTERACTIVE for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X Pass-through from auth server: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 4, len: 249, type : 13

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAP-Packet (EAP Req) received from RADIUS Server to Supplicant at REQUEST State of Backend Auth SM with EAP Id: 4

Debug: Oct 11 18:51:41 [T:748473653] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 30 seconds in the REQUEST state of backend state machine

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is REQUEST

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X Pass-through: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 4, len: 1492, type : 13

Debug: Oct 11 18:51:41 [T:748473653] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: Rx AAA_INTERACTIVE for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X Pass-through from auth server: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 5, len: 6, type : 13

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAP-Packet (EAP Req) received from RADIUS Server to Supplicant at REQUEST State of Backend Auth SM with EAP Id: 5

Debug: Oct 11 18:51:41 [T:748473653] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 30 seconds in the REQUEST state of backend state machine

Debug: Oct 11 18:51:41 [T:748473653] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is REQUEST

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X Pass-through: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 5, len: 56, type : 13

Debug: Oct 11 18:51:41 [T:748473654] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X: Rx AAA_INTERACTIVE for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X Pass-through from auth server: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 6, len: 69, type : 13

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] Tx EAP-Packet (EAP Req) received from RADIUS Server to Supplicant at REQUEST State of Backend Auth SM with EAP Id: 6

Debug: Oct 11 18:51:41 [T:748473654] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 30 seconds in the REQUEST state of backend state machine

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is REQUEST

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X Pass-through: port 1/1/7 Rx EAPOL Pkt with EAP Code: 13,Id: 6, len: 6, type: 13

Debug: Oct 11 18:51:41 [T:748473654] [TIMER] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] sets aWhile timer to 0 seconds in the RESPONSE state of backend state machine

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) GRIDIRON DEBUG: Sending packet to AAA

Debug: Oct 11 18:51:41 [T:748473654] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is RESPONSE

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) : 802.1X: Rx AAA_ACCEPT for port 1/1/7:b8ae.ed75.95f9 from authentication server

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) : 802.1X: port 1/1/7:[b8aeed75,95f9] is passed the info of Tunnel-Type=13; Tunnel_Medium_Type=6Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) ; Tunnel_Private_Group_ID=10

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) txCannedSuccessDelayed: Enter a4161cc6/1

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) txCannedSuccessDelayed: a4161cc6/1 setting timer

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is SUCCESS

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) : 802.1X: authenticator state for port 1/1/7:[b8aeed75,95f9] is AUTHENTICATED

Debug: Oct 11 18:51:56 [T:748473804] [EVENTS] (1/1/7) : 802.1X: backend state for port 1/1/7:[b8aeed75,95f9] is IDLE



No comments:

Post a Comment