dot1x log from ex2200 when error message "TLS handshake failure" =~=~=~=~=~=~=~=~=~=~=~= PuTTY log 2018.11.14 15:50:49 =~=~=~=~=~=~=~=~=~=~=~= Nov 14 15:50:56.685160 Task receive function invoked Nov 14 15:50:56.688539 EAPOL packet received on interface ge-0/0/8.0 Nov 14 15:50:56.689175 Creating background job to process EAPOL frame Nov 14 15:50:56.691619 Entering background job to process received EAPOL frames rx_frame_node_count=1 Nov 14 15:50:56.692401 Invoking state machine for frame received on interface ge-0/0/8 Nov 14 15:50:56.693160 Received an EAPOL Frame... Nov 14 15:50:56.697367 Frame is targetted to this machine... Nov 14 15:50:56.699166 EAPOL Frame Received on Port: 78 !!! Nov 14 15:50:56.702634 AuthHandleInEapFrame: Received Port based Eap Frame Nov 14 15:50:56.706370 ASM Called with Event: EAPSTART_RCVD, and State: Authenticated Nov 14 15:50:56.709363 for Port: 78, MAC: 8cfa81 - 906c Nov 14 15:50:56.711163 Id: 19, SessionNode: 381000 Nov 14 15:50:56.715367 ASM CONNECTING : Intf ge-0/0/8.0: ReqId Count 0 Reauth Count 0 Nov 14 15:50:56.718648 ASM moved to state: CONNECTING !! Nov 14 15:50:56.718896 TMR: Transmit Timer Started for port:78, Duration: 30 !! Nov 14 15:50:56.721180 TMR: Timer is started Nov 14 15:50:56.723620 Queuing EAPOL frame to be transmitted out on interface ge-0/0/8 Nov 14 15:50:56.726397 EAP Frame Sent with code: 1 !!! Nov 14 15:50:56.728416 EAP Req Id Frame Sent !!! Nov 14 15:50:56.730467 Processing complete for frame received on interface ge-0/0/8 Nov 14 15:50:56.731165 Deleted background job to process received EAPOL frames Nov 14 15:50:56.737526 Task transmit function invoked Nov 14 15:50:56.738318 EAPOL frame transmitted out on interface (ge-0/0/8.0) Nov 14 15:50:56.741660 State: 3 Reauth: 0 Nov 14 15:50:56.748482 State: 3 Reauth: 0 Nov 14 15:50:56.845297 pnac_cleanup_white_list_entries_on_vmember_del:374:CP_DEBUG: Nov 14 15:50:56.845838 pnac_cleanup_white_list_entries_on_vmember_del:374:CP_DEBUG: Nov 14 15:50:56.846928 pnac_cleanup_white_list_entries_on_vmember_del:374:CP_DEBUG: Nov 14 15:50:56.847687 pnac_cleanup_white_list_entries_on_vmember_del:374:CP_DEBUG: Nov 14 15:50:56.895902 Task receive function invoked Nov 14 15:50:56.897423 EAPOL packet received on interface ge-0/0/8.0 Nov 14 15:50:56.897884 Creating background job to process EAPOL frame Nov 14 15:50:56.898492 Entering background job to process received EAPOL frames rx_frame_node_count=1 Nov 14 15:50:56.898941 Invoking state machine for frame received on interface ge-0/0/8 Nov 14 15:50:56.899669 Received an EAPOL Frame... Nov 14 15:50:56.900261 Frame is targetted to this machine... Nov 14 15:50:56.900472 EAPOL Frame Received on Port: 78 !!! Nov 14 15:50:56.900680 AuthHandleInEapFrame: Received Port based Eap Frame Nov 14 15:50:56.900915 ASM Called with Event: RXRESPID, and State: Connecting Nov 14 15:50:56.902173 for Port: 78, MAC: 8cfa81 - 906c Nov 14 15:50:56.902400 Id: 19, SessionNode: 381000 Nov 14 15:50:56.902593 ASM: Inside PnacAuthAsmRxrespConnecting Nov 14 15:50:56.902806 TMR: Timer is deleted Nov 14 15:50:56.904142 ASM moved to state: AUTHENTICATING !! Nov 14 15:50:56.904379 BSM Called with Event: AUTHSTART, and State: Idle Nov 14 15:50:56.904588 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:56.904788 Id: 19, SessionNode: 381000 Nov 14 15:50:56.905918 TMR: Timer is started Nov 14 15:50:56.908331 BSM moved to state: RESPONSE !! Nov 14 15:50:56.909392 ASIF: Transferring Server-data to Auth Server for the user, anonymous. Nov 14 15:50:56.909642 SessId: 8O2.1x81f5011a000a6e09 strlen: 22 Nov 14 15:50:56.909944 Queuing message to auth client to validate mac address 0:8c:fa:81:90:6c, user anonymous on interface ge-0/0/8.0 Nov 14 15:50:56.910624 ASIF: Radius REQUEST_ID: ce Nov 14 15:50:56.911377 ASIF: Tx of Server-data to Auth Server succeeded Nov 14 15:50:56.912243 Processing complete for frame received on interface ge-0/0/8 Nov 14 15:50:56.912417 Deleted background job to process received EAPOL frames Nov 14 15:50:56.912680 pnac_auth_client_transmit_job created Nov 14 15:50:56.914209 Sending message to authentication client Nov 14 15:50:56.915442 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 1 Nov 14 15:50:56.940617 pnac_auth_client_receive: receive job not found - creating now Nov 14 15:50:56.941496 Received message from authentication client Nov 14 15:50:56.942240 reply: 207910 rply_hdr: 20e000 bytes_remnant :0 len:-1 reply_len:28 Nov 14 15:50:56.942707 hdr_bytes_read 0 Nov 14 15:50:56.943801 len read : 28 reply_len: 3972 reply_code: 8 Nov 14 15:50:56.943986 bytes_remnant 3944 tot_bytes_read 28 Nov 14 15:50:56.945447 bytes_read 3944 Nov 14 15:50:56.945608 Creating background job to process reply from authentication client Nov 14 15:50:56.945752 Received message from authentication client Nov 14 15:50:56.945892 reply: 207910 rply_hdr: 20e000 bytes_remnant :0 len:3972 reply_len:3972 Nov 14 15:50:56.947562 EAGAIN during hdr len read, try again Nov 14 15:50:56.948311 process_auth_reply: Entering background job to process message from authentication client Nov 14 15:50:56.948848 process_auth_reply Reponse from Authentication Client len:3972 for SessID: 9364392189893188029 Nov 14 15:50:56.949461 Received Access-Challenge authentication message Nov 14 15:50:56.949653 Invoking state machine for authentication response for mac 00:8c:fa:81:90:6c on intf ge-0/0/8.0 Nov 14 15:50:56.949821 UAC: authenticatingStateCause (100) Nov 14 15:50:56.949970 ASIF: Handing over Server frame to Authenticator Nov 14 15:50:56.951393 AUTH: Handling Server Frame Nov 14 15:50:56.951631 SessNode got from SessIdtbl for Id 20 is : 381000, Port: 78 Nov 14 15:50:56.951829 Code = 1, Id = 20, Len = 74 Nov 14 15:50:56.952483 BSM Called with Event: AREQ_RCVD, and State: Response Nov 14 15:50:56.953578 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:56.954499 Id: 19, SessionNode: 381000 Nov 14 15:50:56.956880 TMR: Timer is deleted Nov 14 15:50:56.959610 Queuing EAPOL frame to be transmitted out on interface ge-0/0/8 Nov 14 15:50:56.964170 EAP Req Frame Sent !!! Nov 14 15:50:56.970562 TMR: Timer is started Nov 14 15:50:56.975293 BSM moved to state: REQUEST !! Nov 14 15:50:56.978641 ASIF: Handing over Server frame to Authenticator 78. Nov 14 15:50:56.981318 PnacAsIfRecvFromServer : Rad Attr Statelen = 15 Nov 14 15:50:56.983727 ASIF: Received No Key from Server Nov 14 15:50:56.990324 Processing authentication response complete Nov 14 15:50:56.990502 Deleted background job to process replies from authentication client Nov 14 15:50:56.990769 Task transmit function invoked Nov 14 15:50:56.995958 EAPOL frame transmitted out on interface (ge-0/0/8.0) Nov 14 15:50:57.403311 Task receive function invoked Nov 14 15:50:57.404608 EAPOL packet received on interface ge-0/0/8.0 Nov 14 15:50:57.405212 Creating background job to process EAPOL frame Nov 14 15:50:57.405754 Entering background job to process received EAPOL frames rx_frame_node_count=1 Nov 14 15:50:57.407295 Invoking state machine for frame received on interface ge-0/0/8 Nov 14 15:50:57.407732 Received an EAPOL Frame... Nov 14 15:50:57.408886 Frame is targetted to this machine... Nov 14 15:50:57.409762 EAPOL Frame Received on Port: 78 !!! Nov 14 15:50:57.410908 AuthHandleInEapFrame: Received Port based Eap Frame Nov 14 15:50:57.411799 BSM Called with Event: RXRESP, and State: Request Nov 14 15:50:57.412944 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:57.413803 Id: 20, SessionNode: 381000 Nov 14 15:50:57.415104 TMR: Timer is deleted Nov 14 15:50:57.415935 TMR: Timer is started Nov 14 15:50:57.417786 BSM moved to state: RESPONSE !! Nov 14 15:50:57.418686 ASIF: Transferring Server-data to Auth Server for the user, anonymous. Nov 14 15:50:57.419873 SessId: 8O2.1x81f5011a000a6e09 strlen: 22 Nov 14 15:50:57.420542 Queuing message to auth client to validate mac address 0:8c:fa:81:90:6c, user anonymous on interface ge-0/0/8.0 Nov 14 15:50:57.421945 ASIF: Radius REQUEST_ID: cf Nov 14 15:50:57.422446 ASIF: Tx of Server-data to Auth Server succeeded Nov 14 15:50:57.424335 Processing complete for frame received on interface ge-0/0/8 Nov 14 15:50:57.424790 Deleted background job to process received EAPOL frames Nov 14 15:50:57.425687 pnac_auth_client_transmit_job created Nov 14 15:50:57.427897 Sending message to authentication client Nov 14 15:50:57.431948 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 1 Nov 14 15:50:57.469629 pnac_auth_client_receive: receive job not found - creating now Nov 14 15:50:57.470387 Received message from authentication client Nov 14 15:50:57.470562 reply: 207910 rply_hdr: 20e000 bytes_remnant :0 len:-1 reply_len:3972 Nov 14 15:50:57.470736 hdr_bytes_read 0 Nov 14 15:50:57.470879 len read : 28 reply_len: 3972 reply_code: 8 Nov 14 15:50:57.473972 bytes_remnant 3944 tot_bytes_read 28 Nov 14 15:50:57.479627 bytes_read 3944 Nov 14 15:50:57.479791 Creating background job to process reply from authentication client Nov 14 15:50:57.479939 Received message from authentication client Nov 14 15:50:57.484148 reply: 2078ac rply_hdr: 20e000 bytes_remnant :0 len:3972 reply_len:3972 Nov 14 15:50:57.485594 EAGAIN during hdr len read, try again Nov 14 15:50:57.488148 process_auth_reply: Entering background job to process message from authentication client Nov 14 15:50:57.489900 process_auth_reply Reponse from Authentication Client len:3972 for SessID: 9364392189893188029 Nov 14 15:50:57.493380 Received Access-Challenge authentication message Nov 14 15:50:57.498175 Invoking state machine for authentication response for mac 00:8c:fa:81:90:6c on intf ge-0/0/8.0 Nov 14 15:50:57.501413 UAC: authenticatingStateCause (100) Nov 14 15:50:57.502386 ASIF: Handing over Server frame to Authenticator Nov 14 15:50:57.505797 AUTH: Handling Server Frame Nov 14 15:50:57.507369 SessNode got from SessIdtbl for Id 21 is : 381000, Port: 78 Nov 14 15:50:57.510120 Code = 1, Id = 21, Len = 147 Nov 14 15:50:57.512166 BSM Called with Event: AREQ_RCVD, and State: Response Nov 14 15:50:57.515358 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:57.519359 Id: 20, SessionNode: 381000 Nov 14 15:50:57.522241 TMR: Timer is deleted Nov 14 15:50:57.528180 Queuing EAPOL frame to be transmitted out on interface ge-0/0/8 Nov 14 15:50:57.530909 EAP Req Frame Sent !!! Nov 14 15:50:57.532710 TMR: Timer is started Nov 14 15:50:57.533466 BSM moved to state: REQUEST !! Nov 14 15:50:57.533751 ASIF: Handing over Server frame to Authenticator 78. Nov 14 15:50:57.533977 PnacAsIfRecvFromServer : Rad Attr Statelen = 15 Nov 14 15:50:57.534831 ASIF: Received No Key from Server Nov 14 15:50:57.535932 Processing authentication response complete Nov 14 15:50:57.537390 Deleted background job to process replies from authentication client Nov 14 15:50:57.537678 Task transmit function invoked Nov 14 15:50:57.539382 EAPOL frame transmitted out on interface (ge-0/0/8.0) Nov 14 15:50:57.539894 UAC: processing add message for (00:8c:fa:81:90:6c) from uacd Nov 14 15:50:57.542202 UAC: Process EAP success for the mac (00:8c:fa:81:90:6c) Nov 14 15:50:57.542672 UAC: Auth add message received from uacd. mac (00:8c:fa:81:90:6c) will be authenticated Nov 14 15:50:57.544160 UAC: Handle vlan membership during auth reply Nov 14 15:50:57.544426 UAC: mac address (00:8c:fa:81:90:6c) is learnt Nov 14 15:50:57.544652 ASIF: Handing over Server frame to Authenticator Nov 14 15:50:57.544881 AUTH: Handling Server Frame Nov 14 15:50:57.546788 SessNode got from SessIdtbl for Id 18 is : 381000, Port: 78 Nov 14 15:50:57.549623 Code = 3, Id = 18, Len = 1024 Nov 14 15:50:57.549841 AuthHandleInServerFrame : Intf: ge-0/0/8.0 Timeout 86280 for Nov 14 15:50:57.551974 BSM Called with Event: ASUCCESS_RCVD, and State: Request Nov 14 15:50:57.553363 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:57.554150 Id: 21, SessionNode: 381000 Nov 14 15:50:57.554368 BSM: No Operations to perform Nov 14 15:50:57.554575 ASIF: Handing over Server frame to Authenticator 78. Nov 14 15:50:57.554787 PnacAsIfRecvFromServer : Rad Attr Statelen = 0 Nov 14 15:50:57.554923 ASIF: Received No Key from Server Nov 14 15:50:57.556771 ACCTG State no change Nov 14 15:50:57.557679 Task receive function invoked Nov 14 15:50:57.559622 EAPOL packet received on interface ge-0/0/8.0 Nov 14 15:50:57.559815 Creating background job to process EAPOL frame Nov 14 15:50:57.560374 Entering background job to process received EAPOL frames rx_frame_node_count=1 Nov 14 15:50:57.560539 Invoking state machine for frame received on interface ge-0/0/8 Nov 14 15:50:57.560677 Received an EAPOL Frame... Nov 14 15:50:57.560885 Frame is targetted to this machine... Nov 14 15:50:57.561496 EAPOL Frame Received on Port: 78 !!! Nov 14 15:50:57.561715 AuthHandleInEapFrame: Received Port based Eap Frame Nov 14 15:50:57.561944 BSM Called with Event: RXRESP, and State: Request Nov 14 15:50:57.562277 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:57.562484 Id: 21, SessionNode: 381000 Nov 14 15:50:57.562781 TMR: Timer is deleted Nov 14 15:50:57.563745 TMR: Timer is started Nov 14 15:50:57.564027 BSM moved to state: RESPONSE !! Nov 14 15:50:57.570302 ASIF: Transferring Server-data to Auth Server for the user, anonymous. Nov 14 15:50:57.572138 SessId: 8O2.1x81f5011a000a6e09 strlen: 22 Nov 14 15:50:57.574876 Queuing message to auth client to validate mac address 0:8c:fa:81:90:6c, user anonymous on interface ge-0/0/8.0 Nov 14 15:50:57.577346 ASIF: Radius REQUEST_ID: d0 Nov 14 15:50:57.578117 ASIF: Tx of Server-data to Auth Server succeeded Nov 14 15:50:57.581640 Processing complete for frame received on interface ge-0/0/8 Nov 14 15:50:57.584745 Deleted background job to process received EAPOL frames Nov 14 15:50:57.586875 pnac_auth_client_transmit_job created Nov 14 15:50:57.652827 Sending message to authentication client Nov 14 15:50:57.660174 pnac_auth_client_transmit_job: pnac_auth_client_transmit_job is deleted. num packets: 1 Nov 14 15:50:57.688831 pnac_auth_client_receive: receive job not found - creating now Nov 14 15:50:57.690893 Received message from authentication client Nov 14 15:50:57.726151 reply: 2078ac rply_hdr: 20e000 bytes_remnant :0 len:-1 reply_len:3972 Nov 14 15:50:57.731816 hdr_bytes_read 0 Nov 14 15:50:57.733545 len read : 28 reply_len: 3972 reply_code: 8 Nov 14 15:50:57.735541 bytes_remnant 3944 tot_bytes_read 28 Nov 14 15:50:57.736178 bytes_read 3944 Nov 14 15:50:57.737344 Creating background job to process reply from authentication client Nov 14 15:50:57.740716 Received message from authentication client Nov 14 15:50:57.742934 reply: 207898 rply_hdr: 20e000 bytes_remnant :0 len:3972 reply_len:3972 Nov 14 15:50:57.757132 EAGAIN during hdr len read, try again Nov 14 15:50:57.758554 process_auth_reply: Entering background job to process message from authentication client Nov 14 15:50:57.759847 process_auth_reply Reponse from Authentication Client len:3972 for SessID: 9364392189893188029 Nov 14 15:50:57.761958 Received Access-Challenge authentication message Nov 14 15:50:57.771145 Invoking state machine for authentication response for mac 00:8c:fa:81:90:6c on intf ge-0/0/8.0 Nov 14 15:50:57.771628 UAC: authenticatingStateCause (100) Nov 14 15:50:57.772417 ASIF: Handing over Server frame to Authenticator Nov 14 15:50:57.774443 AUTH: Handling Server Frame Nov 14 15:50:57.775312 SessNode got from SessIdtbl for Id 22 is : 381000, Port: 78 Nov 14 15:50:57.776472 Code = 1, Id = 22, Len = 74 Nov 14 15:50:57.777363 BSM Called with Event: AREQ_RCVD, and State: Response Nov 14 15:50:57.778509 for Port: 78, MAC: 8cfa81-906c Nov 14 15:50:57.780349 Id: 21, SessionNode: 381000 Nov 14 15:50:57.781325 TMR: Timer is deleted Nov 14 15:50:57.782563 Queuing EAPOL frame to be transmitted out on interface ge-0/0/8 Nov 14 15:50:57.783589 EAP Req Frame Sent !!! Nov 14 15:50:57.784742 TMR: Timer is started Nov 14 15:50:57.785629 BSM moved to state: REQUEST !! Nov 14 15:50:57.786787 ASIF: Handing over Server frame to Authenticator 78. Nov 14 15:50:57.787684 PnacAsIfRecvFromServer : Rad Attr Statelen = 15 Nov 14 15:50:57.788479 ASIF: Received No Key from Server Nov 14 15:50:57.796769 Processing authentication response complete Nov 14 15:50:57.797577 Deleted background job to process replies from authentication client Nov 14 15:50:57.800299 Task transmit function invoked Nov 14 15:50:57.802122 EAPOL frame transmitted out on interface (ge-0/0/8.0)
... View more