root@Test-802.1x-Switch> show log dot1x | grep "Sep 15 15:11" Sep 15 15:11:07.144737 Task receive function invoked Sep 15 15:11:07.146343 EAPOL packet received on interface ge-0/0/11.0 Sep 15 15:11:07.146577 Creating background job to process EAPOL frame Sep 15 15:11:07.147077 Entering background job to process received EAPOL frames rx_frame_node_count=1 Sep 15 15:11:07.147273 pnac_bd_tag_lookup 149 0 6 Sep 15 15:11:07.147444 Invoking state machine for frame received on interface ge-0/0/11 Sep 15 15:11:07.147598 Received an EAPOL Frame... Sep 15 15:11:07.147821 Frame is targetted to this machine... Sep 15 15:11:07.148444 EAPOL Frame Received on Port: 83 !!! Sep 15 15:11:07.148686 pnac_ng_is_native_ifbd_marked_for_deletion:202 native vlan of port 83 NOT-MARKED for deletion Sep 15 15:11:07.148889 AuthHandleInEapFrame: Received Port based Eap Frame Sep 15 15:11:07.149205 ASM Called with Event: RXRESPID, and State: Connecting Sep 15 15:11:07.149439 for Port: 83, MAC: e04c68 - 381 Sep 15 15:11:07.149658 Id: 1, SessionNode: 3c7000 Sep 15 15:11:07.149866 ASM: Inside PnacAuthAsmRxrespConnecting Sep 15 15:11:07.150699 ASM moved to state: AUTHENTICATING !! Sep 15 15:11:07.150975 BSM Called with Event: AUTHSTART, and State: Idle Sep 15 15:11:07.151211 for Port: 83, MAC: e04c68-381 Sep 15 15:11:07.151431 Id: 1, SessionNode: 3c7000 Sep 15 15:11:07.151687 TMR: Timer is started Sep 15 15:11:07.152263 BSM moved to state: RESPONSE !! Sep 15 15:11:07.152534 ASIF: Transferring Server-data to Auth Server for the user, TMHA\z-dchidgey. Sep 15 15:11:07.152781 SessId: 8O2.1x81d1837a0001d764 strlen: 22 Sep 15 15:11:07.153179 Queuing message to auth client to validate mac address 0:e0:4c:68:3:81, user TMHA\z-dchidgey on interface ge-0/0/11.0 Sep 15 15:11:07.153508 ASIF: Radius REQUEST_ID: bc Sep 15 15:11:07.153682 ASIF: Tx of Server-data to Auth Server succeeded Sep 15 15:11:07.154316 Processing complete for frame received on interface ge-0/0/11 Sep 15 15:11:07.154512 Deleted background job to process received EAPOL frames Sep 15 15:11:07.154796 pnac_auth_client_transmit_job created Sep 15 15:11:07.157111 Sending message to authentication client Sep 15 15:11:07.158377 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 1 Sep 15 15:11:07.158882 l2d query for mac 00:e0:4c:68:03:81 vlan id 6 Sep 15 15:11:07.159161 Mac address 00:e0:4c:68:03:81 on interface ge-0/0/11.0 NOT found in Static list Sep 15 15:11:07.159344 pnac_ng_is_native_ifbd_marked_for_deletion:202 native vlan of port 83 NOT-MARKED for deletion Sep 15 15:11:09.520751 ASM Called with Event: QUIETWHILE_EXPIRED, and State: Held Sep 15 15:11:09.521419 for Port: 84, MAC: 64167f4a - c517 Sep 15 15:11:09.521633 Id: 1, SessionNode: 4e0000 Sep 15 15:11:09.521906 Trying to delete the session for MAC: -64167f4a-c517- on Port: 84 ... Sep 15 15:11:09.522132 Trying to delete the Session Node : 4e0000 ... Sep 15 15:11:09.522480 PnacAuthDeleteSession: MAC: 64:16:7f:4a:c5:17 authenticatedStateCause: 1 AuthenticatorState: 7 SessionID: 9354402448150050030 Sep 15 15:11:09.522653 Send Radius Accounting STOP Sep 15 15:11:09.523232 [(64:16:7f:4a:c5:17) 8O2.1x81d18377000734ee] previously ACCTG was not Started[0]. New req rcvd: STOP Sep 15 15:11:09.523413 ACCTG State no change Sep 15 15:11:09.523589 Queuing session cleanup message message to auth client Sep 15 15:11:09.524334 pnac_client_delete_session: MAC: 64:16:7f:4a:c5:17 authenticatedStateCause: 1 AuthenticatorState: 7 SessionID: 9354402448150050030 Sep 15 15:11:09.524519 Send Radius Accounting STOP Sep 15 15:11:09.524722 [(64:16:7f:4a:c5:17) 8O2.1x81d18377000734ee] previously ACCTG was not Started[0]. New req rcvd: STOP Sep 15 15:11:09.525364 ACCTG State no change Sep 15 15:11:09.525564 Queuing session cleanup message message to auth client Sep 15 15:11:09.525868 Deleting AuthSession node with Mac: 64167f4a-c517 to the session DB, port 84 Sep 15 15:11:09.526127 Deleted AuthSessionInProgress node with Mac: 64167f4a-c517 from session DB !!! Sep 15 15:11:09.526355 Deleted AuthSessionInProgress node with Mac: 64167f4a-c517 from port 84 session DB !!! Sep 15 15:11:09.527443 Session Deleted for MAC: -64167f4a-c517- on Port: 84 ... Sep 15 15:11:09.527694 Deleted Session Node : 4e0000 ... Sep 15 15:11:09.528086 QuietWhile Timer Expired and Session deleted !!! Sep 15 15:11:09.528477 pnac_auth_client_transmit_job created Sep 15 15:11:09.531651 Sending message to authentication client Sep 15 15:11:09.533205 Sending message to authentication client Sep 15 15:11:09.534472 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 2 Sep 15 15:11:09.534815 pnac_auth_client_receive: receive job not found - creating now Sep 15 15:11:09.536238 Received message from authentication client Sep 15 15:11:09.536426 reply: 32db7c rply_hdr: 338004 bytes_remnant :0 len:-1 reply_len:28 Sep 15 15:11:09.536625 hdr_bytes_read 0 Sep 15 15:11:09.536791 len read : 28 reply_len: 28 reply_code: 1 Sep 15 15:11:09.537352 bytes_remnant 0 tot_bytes_read 28 Sep 15 15:11:09.537513 Creating background job to process reply from authentication client Sep 15 15:11:09.537686 Received message from authentication client Sep 15 15:11:09.537901 reply: 32dc6c rply_hdr: 338004 bytes_remnant :0 len:28 reply_len:28 Sep 15 15:11:09.538115 hdr_bytes_read 0 Sep 15 15:11:09.538285 len read : 28 reply_len: 28 reply_code: 1 Sep 15 15:11:09.538465 bytes_remnant 0 tot_bytes_read 28 Sep 15 15:11:09.538623 Received message from authentication client Sep 15 15:11:09.538791 reply: 32db54 rply_hdr: 338004 bytes_remnant :0 len:28 reply_len:28 Sep 15 15:11:09.539347 EAGAIN during hdr len read, try again Sep 15 15:11:09.539812 process_auth_reply: Entering background job to process message from authentication client Sep 15 15:11:09.541367 process_auth_reply Reponse from Authentication Client len:28 for SessID: 9354402448150050030 Sep 15 15:11:09.541646 Error retrieving session node 9354402448150050030 rqst_id 0 Sep 15 15:11:09.541814 Error response from authentication client. Message not processed further Sep 15 15:11:09.542119 Error retrieving session node 9354402448150050030 Sep 15 15:11:09.542297 ASIF: Handing over Server frame to Authenticator Sep 15 15:11:09.542521 AUTH: Handling Server Frame Sep 15 15:11:09.542750 Port Info is NULL for portnum:0 Sep 15 15:11:09.543273 ASIF: Authenticator handling of Server frame failed Sep 15 15:11:09.543625 process_auth_reply Reponse from Authentication Client len:28 for SessID: 9354402448150050030 Sep 15 15:11:09.543941 Error retrieving session node 9354402448150050030 rqst_id 0 Sep 15 15:11:09.544121 Error response from authentication client. Message not processed further Sep 15 15:11:09.544359 Error retrieving session node 9354402448150050030 Sep 15 15:11:09.544538 ASIF: Handing over Server frame to Authenticator Sep 15 15:11:09.544764 AUTH: Handling Server Frame Sep 15 15:11:09.545400 Port Info is NULL for portnum:0 Sep 15 15:11:09.545555 ASIF: Authenticator handling of Server frame failed Sep 15 15:11:09.545807 Deleted background job to process replies from authentication client Sep 15 15:11:19.177407 pnac_auth_client_receive: receive job not found - creating now Sep 15 15:11:19.178371 Received message from authentication client Sep 15 15:11:19.179316 reply: 32db54 rply_hdr: 338004 bytes_remnant :0 len:-1 reply_len:28 Sep 15 15:11:19.180060 hdr_bytes_read 0 Sep 15 15:11:19.180241 len read : 28 reply_len: 28 reply_code: 3 Sep 15 15:11:19.180418 bytes_remnant 0 tot_bytes_read 28 Sep 15 15:11:19.180622 Creating background job to process reply from authentication client Sep 15 15:11:19.180798 Received message from authentication client Sep 15 15:11:19.180974 reply: 32db54 rply_hdr: 338004 bytes_remnant :0 len:28 reply_len:28 Sep 15 15:11:19.181149 EAGAIN during hdr len read, try again Sep 15 15:11:19.181479 process_auth_reply: Entering background job to process message from authentication client Sep 15 15:11:19.182134 process_auth_reply Reponse from Authentication Client len:28 for SessID: 9354402461034600292 Sep 15 15:11:19.182315 Authentication client could not contact RADIUS servers Sep 15 15:11:19.182489 pnac_apply_server_fail_action portnum:83 Sep 15 15:11:19.182715 Server Fail 0 Sep 15 15:11:19.182869 Server Fail Deny/Default Sep 15 15:11:19.183084 Invoking state machine for authentication response for mac 00:e0:4c:68:03:81 on intf ge-0/0/11.0 Sep 15 15:11:19.183295 auth_vid :0, queried_vid :6 arg.vlan_id 6 Sep 15 15:11:19.183885 pnac_process_auth_reply_result: server reject vlan not configured Sep 15 15:11:19.184063 authenticatedStateCause :1 Sep 15 15:11:19.184346 pnac_client_delete_session: MAC: 00:e0:4c:68:03:81 authenticatedStateCause: 1 AuthenticatorState: 4 SessionID: 9354402461034600292 Sep 15 15:11:19.184563 Send Radius Accounting STOP Sep 15 15:11:19.184789 [(00:e0:4c:68:03:81) 8O2.1x81d1837a0001d764] previously ACCTG was not Started[0]. New req rcvd: STOP Sep 15 15:11:19.184956 ACCTG State no change Sep 15 15:11:19.185133 Queuing session cleanup message message to auth client Sep 15 15:11:19.185454 ASIF: Handing over Server frame to Authenticator Sep 15 15:11:19.186041 AUTH: Handling Server Frame Sep 15 15:11:19.186278 SessNode got from SessIdtbl for Id 0 is : 3c7000, Port: 83 Sep 15 15:11:19.186591 Code = 4, Id = 0, Len = 1024 Sep 15 15:11:19.186850 BSM Called with Event: AFAIL_RCVD, and State: Response Sep 15 15:11:19.187086 for Port: 83, MAC: e04c68-381 Sep 15 15:11:19.187305 Id: 1, SessionNode: 3c7000 Sep 15 15:11:19.188135 TMR: Timer is deleted Sep 15 15:11:19.188463 Queuing EAPOL frame to be transmitted out on interface ge-0/0/11 Sep 15 15:11:19.190037 EAP Frame Sent with code: 4 !!! Sep 15 15:11:19.190275 BSM moved to state: FAIL !! Sep 15 15:11:19.190556 BSM moved to state: IDLE !! Sep 15 15:11:19.190808 ASM Called with Event: BKEND_AUTHFAIL, and State: Authenticating Sep 15 15:11:19.191047 for Port: 83, MAC: e04c68 - 381 Sep 15 15:11:19.191267 Id: 0, SessionNode: 3c7000 Sep 15 15:11:19.191903 PnacAuthAsmMakeHeld Session 00:e0:4c:68:03:81 Authentication mode: Mac-Radius Sep 15 15:11:19.192180 TMR: Quiet While Timer Started for port:83, Duration: 60 !! Sep 15 15:11:19.192428 TMR: Timer is started Sep 15 15:11:19.192816 ASM moved to state: HELD !! Sep 15 15:11:19.193060 ASIF: Handing over Server frame to Authenticator 83. Sep 15 15:11:19.193294 PnacAsIfRecvFromServer : Rad Attr Statelen = 0 Sep 15 15:11:19.193448 ASIF: Received No Key from Server Sep 15 15:11:19.194077 Processing authentication response complete Sep 15 15:11:19.194271 Deleted background job to process replies from authentication client Sep 15 15:11:19.194611 pnac_auth_client_transmit_job created Sep 15 15:11:19.194825 Task transmit function invoked Sep 15 15:11:19.196638 EAPOL frame transmitted out on interface (ge-0/0/11.0) Sep 15 15:11:19.200449 Sending message to authentication client Sep 15 15:11:19.201886 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 1 Sep 15 15:11:19.203930 pnac_auth_client_receive: receive job not found - creating now Sep 15 15:11:19.204253 Received message from authentication client Sep 15 15:11:19.204434 reply: 32db54 rply_hdr: 338004 bytes_remnant :0 len:-1 reply_len:28 Sep 15 15:11:19.205592 hdr_bytes_read 0 Sep 15 15:11:19.205774 len read : 28 reply_len: 28 reply_code: 1 Sep 15 15:11:19.205954 bytes_remnant 0 tot_bytes_read 28 Sep 15 15:11:19.206106 Creating background job to process reply from authentication client Sep 15 15:11:19.206275 Received message from authentication client Sep 15 15:11:19.206445 reply: 32dc6c rply_hdr: 338004 bytes_remnant :0 len:28 reply_len:28 Sep 15 15:11:19.206974 EAGAIN during hdr len read, try again Sep 15 15:11:19.207324 process_auth_reply: Entering background job to process message from authentication client Sep 15 15:11:19.207704 process_auth_reply Reponse from Authentication Client len:28 for SessID: 9354402461034600292 Sep 15 15:11:19.207909 Error response from authentication client. Message not processed further Sep 15 15:11:19.208091 ASIF: Handing over Server frame to Authenticator Sep 15 15:11:19.208313 AUTH: Handling Server Frame Sep 15 15:11:19.209712 SessNode got from SessIdtbl for Id 0 is : 3c7000, Port: 83 Sep 15 15:11:19.209956 Code = 4, Id = 0, Len = 1024 Sep 15 15:11:19.210182 BSM Called with Event: AFAIL_RCVD, and State: Idle Sep 15 15:11:19.210412 for Port: 83, MAC: e04c68-381 Sep 15 15:11:19.211803 Id: 1, SessionNode: 3c7000 Sep 15 15:11:19.212015 BSM: No Operations to perform Sep 15 15:11:19.212244 ASIF: Handing over Server frame to Authenticator 83. Sep 15 15:11:19.212470 PnacAsIfRecvFromServer : Rad Attr Statelen = 0 Sep 15 15:11:19.213015 ASIF: Received No Key from Server Sep 15 15:11:19.213269 Deleted background job to process replies from authentication client Sep 15 15:11:20.761084 l2d query for mac 00:e0:4c:68:03:81 vlan id 6 Sep 15 15:11:20.761384 Mac address 00:e0:4c:68:03:81 on interface ge-0/0/11.0 NOT found in Static list Sep 15 15:11:20.762173 pnac_ng_is_native_ifbd_marked_for_deletion:202 native vlan of port 83 NOT-MARKED for deletion Sep 15 15:11:29.569942 l2d query for mac 00:e0:4c:68:03:81 vlan id 6 Sep 15 15:11:29.570745 Mac address 00:e0:4c:68:03:81 on interface ge-0/0/11.0 NOT found in Static list Sep 15 15:11:29.570942 pnac_ng_is_native_ifbd_marked_for_deletion:202 native vlan of port 83 NOT-MARKED for deletion Sep 15 15:11:38.175778 l2d query for mac 00:e0:4c:68:03:81 vlan id 6 Sep 15 15:11:38.176450 Mac address 00:e0:4c:68:03:81 on interface ge-0/0/11.0 NOT found in Static list Sep 15 15:11:38.176663 pnac_ng_is_native_ifbd_marked_for_deletion:202 native vlan of port 83 NOT-MARKED for deletion