Tip / Sign in to post questions, reply, level up, and achieve exciting badges. Know more

ModusToolbox™ General Forum Discussions

cedric_roomz
Level 4
Level 4
50 replies posted 50 sign-ins 25 replies posted

Hi,

I have successfully implemented enterprise security with mschapv2 and freeradius following https://infineon.github.io/enterprise-security/api_reference_manual/html/index.html

Is it possible to skip the check of the radius server CA?  I have not found any obvious way.

 

Best regards,

Cédric

0 Likes
4 Replies
cedric_roomz
Level 4
Level 4
50 replies posted 50 sign-ins 25 replies posted

And additionally, is there some specific configuration to support  EAP-TLS?

Currently it fails at handshake state 12

2022-12-21 17:21:39,815 INFO COM5: b'[F4] : [L4] : 1115 00:00:31.832 TLS handshake state: 12\r\n'
2022-12-21 17:21:39,816 INFO COM5: b'[F4] : [L4] : 1116 00:00:31.837 Push outgoing packet to queue\r\n'
2022-12-21 17:21:39,817 INFO COM5: b'[F4] : [L5] : 1117 00:00:31.843 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2239: ssl->f_send() returned 37 (-0xffffffdb)\r\n'
2022-12-21 17:21:39,817 INFO COM5: b'[F4] : [L5] : 1118 00:00:31.854 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2267: <= flush output\r\n'
2022-12-21 17:21:39,818 INFO COM5: b'[F4] : [L5] : 1119 00:00:31.864 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2981: <= write record\r\n'
2022-12-21 17:21:39,819 INFO COM5: b'[F4] : [L5] : 1120 00:00:31.873 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2787: <= write handshake message\r\n'
2022-12-21 17:21:39,819 INFO COM5: b'[F4] : [L5] : 1121 00:00:31.883 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3484: <= write finished\r\n'
2022-12-21 17:21:39,820 INFO COM5: b'[F4] : [L5] : 1122 00:00:31.893 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_cli.c:4416: client state: 12\r\n'
2022-12-21 17:21:39,820 INFO COM5: b'[F4] : [L5] : 1123 00:00:31.902 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2215: => flush output\r\n'
2022-12-21 17:21:39,820 INFO COM5: b'[F4] : [L5] : 1124 00:00:31.838 \r\n'
2022-12-21 17:21:39,820 INFO COM5: b'Process EAPOL packet\r\n'
2022-12-21 17:21:39,821 INFO COM5: b'[F4] : [L5] : 1125 00:00:31.916 Supplicant event packet to send\r\n'
2022-12-21 17:21:40,132 INFO COM5: b'[F4] : [L5] : 1126 00:00:31.922 Outgoing eap tls packet_length = [1048]\r\n'
2022-12-21 17:21:40,134 INFO COM5: b'[F4] : [L5] : 1127 00:00:31.913 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2227: <= flush output\r\n'
2022-12-21 17:21:40,135 INFO COM5: b'[F4] : [L5] : 1128 00:00:31.937 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_cli.c:4520: mbedtls_ssl_parse_change_cipher_spec\r\n'
2022-12-21 17:21:40,136 INFO COM5: b'[F4] : [L5] : 1129 00:00:31.949 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:5082: => parse change cipher spec\r\n'
2022-12-21 17:21:40,137 INFO COM5: b'[F4] : [L5] : 1130 00:00:31.959 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:4013: => read record\r\n'
2022-12-21 17:21:40,137 INFO COM5: b'[F4] : [L5] : 1131 00:00:31.968 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2003: => fetch input\r\n'
2022-12-21 17:21:40,138 INFO COM5: b'[F4] : [L4] : 1132 00:00:31.928 \r\n'
2022-12-21 17:21:40,138 INFO COM5: b'[supplicant_process_event()] : L1050 : Returning succesfully from supplicant_process_event\r\n'
2022-12-21 17:21:40,139 INFO COM5: b'[F4] : [L4] : 1133 00:00:31.988 [supplicant_thread_main()] : L1074 : In processing loop...\r\n'
2022-12-21 17:21:40,140 INFO COM5: b'[F4] : [L5] : 1134 00:00:31.996 Calculate the wait time\r\n'
2022-12-21 17:21:40,141 INFO COM5: b'[F4] : [L5] : 1135 00:00:32.001 Waiting for EAPOL packet\r\n'
2022-12-21 17:21:40,141 INFO COM5: b'[F4] : [L5] : 1136 00:00:32.006 \r\n'
2022-12-21 17:21:40,141 INFO COM5: b'Process EAPOL packet\r\n'
2022-12-21 17:21:40,142 INFO COM5: b'[F4] : [L4] : 1137 00:00:32.010 [supplicant_process_event()] : L868 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2022-12-21 17:21:40,143 INFO COM5: b'[F4] : [L5] : 1138 00:00:32.020 [supplicant_process_event()] : L931 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [13]\r\n'
2022-12-21 17:21:40,143 INFO COM5: b'[F4] : [L5] : 1139 00:00:32.032 EAP packet received with EAP ID = [157], len = 6 \r\n'
2022-12-21 17:21:40,144 INFO COM5: b'[F4] : [L5] : 1140 00:00:32.039 [supplicant_process_event()] : L978 : Received a Zero length EAP request\r\n'
2022-12-21 17:21:40,145 INFO COM5: b'[F4] : [L5] : 1141 00:00:32.048 [supplicant_process_event()] : L983 : Calling supplicant_send_eap_tls_fragment()\r\n'
2022-12-21 17:21:40,145 INFO COM5: b'[F4] : [L5] : 1142 00:00:32.058 Outgoing eap tls packet_length = [625]\r\n'
2022-12-21 17:21:40,146 INFO COM5: b'[F4] : [L5] : 1143 00:00:31.977 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2156: in_left: 0, nb_want: 5\r\n'
2022-12-21 17:21:40,147 INFO COM5: b'[F4] : [L5] : 1144 00:00:32.074 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2180: in_left: 0, nb_want: 5\r\n'
2022-12-21 17:21:40,148 INFO COM5: b'[F4] : [L5] : 1145 00:00:32.084 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2182: ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)\r\n'
2022-12-21 17:21:40,149 INFO COM5: b'[F4] : [L5] : 1146 00:00:32.096 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2202: <= fetch input\r\n'
2022-12-21 17:21:40,149 INFO COM5: b'[F4] : [L5] : 1147 00:00:32.105 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:3694: unknown record type 55\r\n'
2022-12-21 17:21:40,150 INFO COM5: b'[F4] : [L5] : 1148 00:00:32.115 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:4046: ssl_get_next_record() returned -29184 (-0x7200)\r\n'
2022-12-21 17:21:40,151 INFO COM5: b'[F4] : [L5] : 1149 00:00:32.128 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:5086: mbedtls_ssl_read_record() returned -29184 (-0x7200)\r\n'
2022-12-21 17:21:40,152 INFO COM5: b'[F4] : [L5] : 1150 00:00:32.140 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:5815: <= handshake\r\n'
2022-12-21 17:21:40,152 WARNING COM5: b'[F4] : [L1] : 1151 00:00:32.149 failed oups\r\n'
2022-12-21 17:21:40,152 INFO COM5: b'! mbedtls_ssl_handshake returned -0x7200\r\n'

 

 

I'm using freeradius.

 

0 Likes
Charles_Lai
Moderator
Moderator
Moderator
250 replies posted 100 solutions authored 100 replies posted

Hi,

You are right.  cy_enterprise_security_parameters_t doesn't accept a NULL CA config. By the way, enterprise_security/radius always requires CA certification, So it's not valid to skip CA check normally.

You can't skip the CA check but you can provide the correct CA certificate to continue the process. You can generate your own CA certificate / find your FreeRadius server CA and paste it onto the following .h file:
\mtb_shared\wifi-cert\release-v4.0.0\include\wifi_cert_enterprise_certificate.h
It's where all the certificates are stored. You can even export the CA certificate from it and apply it to your FreeRadius Server.

Best regards

0 Likes
cedric_roomz
Level 4
Level 4
50 replies posted 50 sign-ins 25 replies posted

Hi, thanks for your reply!

It does work when we use the proper certificate, however in some contexts it's much easier to avoid checking the server authenticity (and we understand the security risk implied). 

 

we progressed with our tests but still have some issues.

- It works ok with mschapv2 (username/password) with the proper CA cert

- When using a  user certificate instead of mschapv2, it fails at  TLS handshake state: 12.

- When activating MBEDTLS_DEBUG_C and adding mbedtls_debug_set_threshold(1) to get mbedtls debug output, the mschapv2 connection also fails at TLS handshake 12

 

I suppose both failures have the same cause, and I suspect either a memory issue (stack?) or some weird timing /synchronization issue.

Wireshark shows the exact same interaction with both OK (mschapv2 without debug) and NOK (mschapv2 with mbedtls debug) up to the point where the radius server waits for a reply.

 

Do you have any pointer or recommendation as to what could cause this kind of issue? Or what could help point to its cause?

 

Here is where it fails (mschapv2 with mbedtls debug), and in the file attached the whole debug output:

 

2023-01-05 15:08:27,269 INFO COM5: b'[F4] : [L4] : 0372 00:00:08.736 TLS handshake state: 11\r\n'
2023-01-05 15:08:27,270 INFO COM5: b'[F4] : [L5] : 0373 00:00:08.741 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2267: <= flush output\r\n'
2023-01-05 15:08:27,271 INFO COM5: b'[F4] : [L5] : 0374 00:00:08.751 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2981: <= write record\r\n'
2023-01-05 15:08:27,271 INFO COM5: b'[F4] : [L5] : 0375 00:00:08.760 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2787: <= write handshake message\r\n'
2023-01-05 15:08:27,272 INFO COM5: b'[F4] : [L5] : 0376 00:00:08.770 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:5073: <= write change cipher spec\r\n'
2023-01-05 15:08:27,273 INFO COM5: b'[F4] : [L5] : 0377 00:00:08.781 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_cli.c:4416: client state: 11\r\n'
2023-01-05 15:08:27,273 INFO COM5: b'[F4] : [L5] : 0378 00:00:08.790 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2215: => flush output\r\n'
2023-01-05 15:08:27,274 INFO COM5: b'[F4] : [L5] : 0379 00:00:08.799 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2227: <= flush output\r\n'
2023-01-05 15:08:27,274 INFO COM5: b'[F4] : [L5] : 0380 00:00:08.809 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3375: => write finished\r\n'
2023-01-05 15:08:27,275 INFO COM5: b'[F4] : [L5] : 0381 00:00:08.818 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3247: => calc  finished tls sha384\r\n'
2023-01-05 15:08:27,276 INFO COM5: b'[F4] : [L5] : 0382 00:00:08.834 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3279: <= calc  finished\r\n'
2023-01-05 15:08:27,277 INFO COM5: b'[F4] : [L5] : 0383 00:00:08.843 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3420: switching to new transform spec for outbound data\r\n'
2023-01-05 15:08:27,277 INFO COM5: b'[F4] : [L5] : 0384 00:00:08.856 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2651: => write handshake message\r\n'
2023-01-05 15:08:27,278 INFO COM5: b'[F4] : [L5] : 0385 00:00:08.866 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2810: => write record\r\n'
2023-01-05 15:08:27,278 INFO COM5: b'[F4] : [L5] : 0386 00:00:08.875 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:0597: => encrypt buf\r\n'
2023-01-05 15:08:27,279 INFO COM5: b'[F4] : [L5] : 0387 00:00:08.885 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:0845: before encrypt: msglen = 16, including 0 bytes of padding\r\n'
2023-01-05 15:08:27,280 INFO COM5: b'[F4] : [L5] : 0388 00:00:08.898 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:1042: <= encrypt buf\r\n'
2023-01-05 15:08:27,281 INFO COM5: b'[F4] : [L5] : 0389 00:00:08.907 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2925: output record: msgtype = 22, version = [3:3], msglen = 40\r\n'
2023-01-05 15:08:27,282 INFO COM5: b'[F4] : [L5] : 0390 00:00:08.920 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2215: => flush output\r\n'
2023-01-05 15:08:27,282 INFO COM5: b'[F4] : [L5] : 0391 00:00:08.929 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2233: message length: 45, out_left: 45\r\n'
2023-01-05 15:08:27,283 INFO COM5: b'[F4] : [L4] : 0392 00:00:08.940 TLS handshake state: 12\r\n'
2023-01-05 15:08:27,595 INFO COM5: b'[F4] : [L5] : 0393 00:00:08.945 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2267: <= flush output\r\n'
2023-01-05 15:08:27,595 INFO COM5: b'[F4] : [L5] : 0394 00:00:08.954 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2981: <= write record\r\n'
2023-01-05 15:08:27,596 INFO COM5: b'[F4] : [L5] : 0395 00:00:08.964 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2787: <= write handshake message\r\n'
2023-01-05 15:08:27,597 INFO COM5: b'[F4] : [L5] : 0396 00:00:08.974 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:3484: <= write finished\r\n'
2023-01-05 15:08:27,597 INFO COM5: b'[F4] : [L5] : 0397 00:00:08.984 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_cli.c:4416: client state: 12\r\n'
2023-01-05 15:08:27,598 INFO COM5: b'[F4] : [L5] : 0398 00:00:08.993 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2215: => flush output\r\n'
2023-01-05 15:08:27,599 INFO COM5: b'[F4] : [L5] : 0399 00:00:09.002 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2227: <= flush output\r\n'
2023-01-05 15:08:27,599 INFO COM5: b'[F4] : [L5] : 0400 00:00:09.012 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_cli.c:4520: mbedtls_ssl_parse_change_cipher_spec\r\n'
2023-01-05 15:08:27,600 INFO COM5: b'[F4] : [L5] : 0401 00:00:09.023 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:5082: => parse change cipher spec\r\n'
2023-01-05 15:08:27,601 INFO COM5: b'[F4] : [L5] : 0402 00:00:09.033 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:4013: => read record\r\n'
2023-01-05 15:08:27,601 INFO COM5: b'[F4] : [L5] : 0403 00:00:09.043 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2003: => fetch input\r\n'
2023-01-05 15:08:27,602 INFO COM5: b'[F4] : [L5] : 0404 00:00:09.052 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2156: in_left: 0, nb_want: 5\r\n'
2023-01-05 15:08:27,602 INFO COM5: b'[F4] : [L5] : 0405 00:00:08.905 \r\n'
2023-01-05 15:08:27,602 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-05 15:08:27,603 INFO COM5: b'[F4] : [L4] : 0406 00:00:09.067 [supplicant_process_event()] : L868 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-05 15:08:27,604 INFO COM5: b'[F4] : [L5] : 0407 00:00:09.076 [supplicant_process_event()] : L931 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-05 15:08:27,604 INFO COM5: b'[F4] : [L5] : 0408 00:00:09.088 EAP packet received with EAP ID = [111], len = 1003 \r\n'
2023-01-05 15:08:27,605 INFO COM5: b'[F4] : [L5] : 0409 00:00:09.095 [supplicant_process_event()] : L961 : Move the packet start to the start of TLS data\r\n'
2023-01-05 15:08:27,605 INFO COM5: b'[F4] : [L5] : 0410 00:00:09.105 [supplicant_process_event()] : L970 : Send the TLS packet to TLS Agent\r\n'
2023-01-05 15:08:27,606 INFO COM5: b'[F4] : [L4] : 0411 00:00:09.114 \r\n'
2023-01-05 15:08:27,606 INFO COM5: b'[supplicant_process_event()] : L1050 : Returning succesfully from supplicant_process_event\r\n'
2023-01-05 15:08:27,607 INFO COM5: b'[F4] : [L4] : 0412 00:00:09.125 [supplicant_thread_main()] : L1074 : In processing loop...\r\n'
2023-01-05 15:08:27,607 INFO COM5: b'[F4] : [L5] : 0413 00:00:09.133 Calculate the wait time\r\n'
2023-01-05 15:08:27,608 INFO COM5: b'[F4] : [L5] : 0414 00:00:09.137 Waiting for EAPOL packet\r\n'
2023-01-05 15:08:27,608 INFO COM5: b'[F4] : [L5] : 0415 00:00:09.142 \r\n'
2023-01-05 15:08:27,608 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-05 15:08:27,609 INFO COM5: b'[F4] : [L5] : 0416 00:00:09.147 Supplicant event packet to send\r\n'
2023-01-05 15:08:27,609 INFO COM5: b'[F4] : [L5] : 0417 00:00:09.153 Outgoing eap tls packet_length = [154]\r\n'
2023-01-05 15:08:27,610 INFO COM5: b'[F4] : [L5] : 0418 00:00:09.115 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2180: in_left: 0, nb_want: 5\r\n'
2023-01-05 15:08:27,610 INFO COM5: b'[F4] : [L5] : 0419 00:00:09.169 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:2202: <= fetch input\r\n'
2023-01-05 15:08:27,611 INFO COM5: b'[F4] : [L5] : 0420 00:00:09.178 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:3694: unknown record type 116\r\n'
2023-01-05 15:08:27,612 INFO COM5: b'[F4] : [L5] : 0421 00:00:09.188 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:4046: ssl_get_next_record() returned -29184 (-0x7200)\r\n'
2023-01-05 15:08:27,613 INFO COM5: b'[F4] : [L5] : 0422 00:00:09.200 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_msg.c:5086: mbedtls_ssl_read_record() returned -29184 (-0x7200)\r\n'
2023-01-05 15:08:27,613 INFO COM5: b'[F4] : [L5] : 0423 00:00:09.213 ../mtb_shared/mbedtls/mbedtls-2.25.0/library/ssl_tls.c:5815: <= handshake\r\n'

 

Thanks,

Cédric

0 Likes
cedric_roomz
Level 4
Level 4
50 replies posted 50 sign-ins 25 replies posted

Hi,

After some digging, we found that the eap packet is received twice when we add debug in mbedtls.

In the following debug output you can search for lines : "EAP packet received with EAP ID = ["

You'll see that the eap id 190 is received twiced.

I suppose there is some issue in the lower layers where when a message is not acked rapidly enough, it gets resent and reprocessed as if new.

To fix it, I've just added a check in supplicant_process_event

+ if (last_eap_id != eap_tls_packet->eap.id)
+ {
+ last_eap_id = (unsigned int)eap_tls_packet->eap.id;
supplicant_send_eap_tls_packet( workspace, &tls_agent_message, SUPPLICANT_NEVER_TIMEOUT );
+ }

 

 

2023-01-12 10:07:25,264 INFO COM5: b'[F4] : [L5] : 0138 00:00:15.110 EAP packet received with EAP ID = [186], len = 1014 \r\n'
2023-01-12 10:07:25,265 INFO COM5: b'[F4] : [L5] : 0139 00:00:15.118 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:25,266 INFO COM5: b'[F4] : [L5] : 0140 00:00:15.128 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:25,266 INFO COM5: b'[F4] : [L4] : 0141 00:00:15.136 Count in queue: 0\r\n'
2023-01-12 10:07:25,266 INFO COM5: b'[F4] : [L4] : 0142 00:00:15.141 \r\n'
2023-01-12 10:07:25,267 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:25,267 INFO COM5: b'[F4] : [L4] : 0143 00:00:15.151 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:25,268 INFO COM5: b'[F4] : [L5] : 0144 00:00:15.159 Calculate the wait time\r\n'
2023-01-12 10:07:25,268 INFO COM5: b'[F4] : [L5] : 0145 00:00:15.164 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:25,489 INFO COM5: b'[F4] : [L4] : 0146 00:00:15.265 Count in queue after: 0\r\n'
2023-01-12 10:07:25,490 INFO COM5: b'[F4] : [L5] : 0147 00:00:15.269 Received 1004 \r\n'
2023-01-12 10:07:25,491 INFO COM5: b'[F4] : [L5] : 0148 00:00:15.273 remaining bytes 1004 \r\n'
2023-01-12 10:07:25,491 INFO COM5: b'[F4] : [L5] : 0149 00:00:15.278 remaining bytes 999 \r\n'
2023-01-12 10:07:25,492 INFO COM5: b'[F4] : [L5] : 0150 00:00:15.283 remaining bytes 942 \r\n'
2023-01-12 10:07:25,492 INFO COM5: b'[F4] : [L5] : 0151 00:00:15.288 remaining bytes 937 \r\n'
2023-01-12 10:07:25,493 INFO COM5: b'[F4] : [L5] : 0152 00:00:15.293 No remaining bytes \r\n'
2023-01-12 10:07:25,493 INFO COM5: b'[F4] : [L4] : 0153 00:00:15.297 Get queue\r\n'
2023-01-12 10:07:25,494 INFO COM5: b'[F4] : [L4] : 0154 00:00:15.301 Count in queue before: 0\r\n'
2023-01-12 10:07:25,494 INFO COM5: b'[F4] : [L5] : 0155 00:00:15.298 \r\n'
2023-01-12 10:07:25,494 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-12 10:07:25,495 INFO COM5: b'[F4] : [L4] : 0156 00:00:15.310 [supplicant_process_event()] : L883 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-12 10:07:25,496 INFO COM5: b'[F4] : [L5] : 0157 00:00:15.320 [supplicant_process_event()] : L946 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-12 10:07:25,496 INFO COM5: b'[F4] : [L5] : 0158 00:00:15.332 Sending zero length EAP-TLS packet\r\n'
2023-01-12 10:07:25,497 INFO COM5: b'[F4] : [L5] : 0159 00:00:15.337 EAP packet received with EAP ID = [187], len = 1010 \r\n'
2023-01-12 10:07:25,498 INFO COM5: b'[F4] : [L5] : 0160 00:00:15.345 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:25,498 INFO COM5: b'[F4] : [L5] : 0161 00:00:15.355 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:25,499 INFO COM5: b'[F4] : [L4] : 0162 00:00:15.364 Count in queue: 0\r\n'
2023-01-12 10:07:25,499 INFO COM5: b'[F4] : [L4] : 0163 00:00:15.368 \r\n'
2023-01-12 10:07:25,500 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:25,501 INFO COM5: b'[F4] : [L4] : 0164 00:00:15.379 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:25,501 INFO COM5: b'[F4] : [L5] : 0165 00:00:15.386 Calculate the wait time\r\n'
2023-01-12 10:07:25,502 INFO COM5: b'[F4] : [L5] : 0166 00:00:15.391 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:25,585 INFO COM5: b'[F4] : [L5] : 0167 00:00:15.499 \r\n'
2023-01-12 10:07:25,686 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-12 10:07:25,687 INFO COM5: b'[F4] : [L4] : 0168 00:00:15.503 [supplicant_process_event()] : L883 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-12 10:07:25,687 INFO COM5: b'[F4] : [L5] : 0169 00:00:15.513 [supplicant_process_event()] : L946 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-12 10:07:25,688 INFO COM5: b'[F4] : [L5] : 0170 00:00:15.525 Sending zero length EAP-TLS packet\r\n'
2023-01-12 10:07:25,688 INFO COM5: b'[F4] : [L5] : 0171 00:00:15.531 EAP packet received with EAP ID = [188], len = 1010 \r\n'
2023-01-12 10:07:25,689 INFO COM5: b'[F4] : [L5] : 0172 00:00:15.538 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:25,690 INFO COM5: b'[F4] : [L5] : 0173 00:00:15.548 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:25,690 INFO COM5: b'[F4] : [L4] : 0174 00:00:15.557 Count in queue: 1\r\n'
2023-01-12 10:07:25,691 INFO COM5: b'[F4] : [L4] : 0175 00:00:15.561 \r\n'
2023-01-12 10:07:25,691 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:25,692 INFO COM5: b'[F4] : [L4] : 0176 00:00:15.572 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:25,692 INFO COM5: b'[F4] : [L5] : 0177 00:00:15.579 Calculate the wait time\r\n'
2023-01-12 10:07:25,692 INFO COM5: b'[F4] : [L5] : 0178 00:00:15.584 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:25,905 INFO COM5: b'[F4] : [L5] : 0179 00:00:15.686 \r\n'
2023-01-12 10:07:25,907 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-12 10:07:25,909 INFO COM5: b'[F4] : [L4] : 0180 00:00:15.691 [supplicant_process_event()] : L883 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-12 10:07:25,911 INFO COM5: b'[F4] : [L5] : 0181 00:00:15.700 [supplicant_process_event()] : L946 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-12 10:07:25,912 INFO COM5: b'[F4] : [L5] : 0182 00:00:15.713 Sending zero length EAP-TLS packet\r\n'
2023-01-12 10:07:25,913 INFO COM5: b'[F4] : [L4] : 0183 00:00:15.705 Count in queue after: 1\r\n'
2023-01-12 10:07:25,913 INFO COM5: b'[F4] : [L5] : 0184 00:00:15.723 Received 1004 \r\n'
2023-01-12 10:07:25,914 INFO COM5: b'[F4] : [L5] : 0185 00:00:15.719 EAP packet received with EAP ID = [189], len = 1010 \r\n'
2023-01-12 10:07:25,916 INFO COM5: b'[F4] : [L5] : 0186 00:00:15.735 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:25,917 INFO COM5: b'[F4] : [L5] : 0187 00:00:15.745 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:25,918 INFO COM5: b'[F4] : [L4] : 0188 00:00:15.754 Count in queue: 1\r\n'
2023-01-12 10:07:25,918 INFO COM5: b'[F4] : [L4] : 0189 00:00:15.758 \r\n'
2023-01-12 10:07:25,919 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:25,920 INFO COM5: b'[F4] : [L4] : 0190 00:00:15.769 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:25,921 INFO COM5: b'[F4] : [L5] : 0191 00:00:15.776 Calculate the wait time\r\n'
2023-01-12 10:07:25,921 INFO COM5: b'[F4] : [L5] : 0192 00:00:15.781 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:25,922 INFO COM5: b'[F4] : [L5] : 0193 00:00:15.729 remaining bytes 1004 \r\n'
2023-01-12 10:07:25,922 INFO COM5: b'[F4] : [L5] : 0194 00:00:15.791 No remaining bytes \r\n'
2023-01-12 10:07:25,922 INFO COM5: b'[F4] : [L4] : 0195 00:00:15.795 Get queue\r\n'
2023-01-12 10:07:25,923 INFO COM5: b'[F4] : [L4] : 0196 00:00:15.799 Count in queue before: 2\r\n'
2023-01-12 10:07:26,097 INFO COM5: b'[F4] : [L5] : 0197 00:00:15.910 \r\n'
2023-01-12 10:07:26,098 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-12 10:07:26,100 INFO COM5: b'[F4] : [L4] : 0198 00:00:15.915 [supplicant_process_event()] : L883 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-12 10:07:26,102 INFO COM5: b'[F4] : [L5] : 0199 00:00:15.924 [supplicant_process_event()] : L946 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-12 10:07:26,103 INFO COM5: b'[F4] : [L5] : 0200 00:00:15.936 EAP packet received with EAP ID = [190], len = 1003 \r\n'
2023-01-12 10:07:26,104 INFO COM5: b'[F4] : [L5] : 0201 00:00:15.944 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:26,105 INFO COM5: b'[F4] : [L5] : 0202 00:00:15.954 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:26,105 INFO COM5: b'[F4] : [L4] : 0203 00:00:15.963 Count in queue: 2\r\n'
2023-01-12 10:07:26,105 INFO COM5: b'[F4] : [L4] : 0204 00:00:15.967 \r\n'
2023-01-12 10:07:26,106 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:26,106 INFO COM5: b'[F4] : [L4] : 0205 00:00:15.978 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:26,107 INFO COM5: b'[F4] : [L5] : 0206 00:00:15.985 Calculate the wait time\r\n'
2023-01-12 10:07:26,107 INFO COM5: b'[F4] : [L5] : 0207 00:00:15.990 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:26,340 INFO COM5: b'[F4] : [L4] : 0208 00:00:16.204 Count in queue after: 2\r\n'
2023-01-12 10:07:26,341 INFO COM5: b'[F4] : [L5] : 0209 00:00:16.208 Received 1004 \r\n'
2023-01-12 10:07:26,342 INFO COM5: b'[F4] : [L5] : 0210 00:00:16.212 remaining bytes 1004 \r\n'
2023-01-12 10:07:26,343 INFO COM5: b'[F4] : [L5] : 0211 00:00:16.217 No remaining bytes \r\n'
2023-01-12 10:07:26,343 INFO COM5: b'[F4] : [L4] : 0212 00:00:16.222 Get queue\r\n'
2023-01-12 10:07:26,344 INFO COM5: b'[F4] : [L4] : 0213 00:00:16.225 Count in queue before: 2\r\n'
2023-01-12 10:07:26,772 INFO COM5: b'[F4] : [L4] : 0214 00:00:16.630 Count in queue after: 1\r\n'
2023-01-12 10:07:26,772 INFO COM5: b'[F4] : [L5] : 0215 00:00:16.634 Received 1004 \r\n'
2023-01-12 10:07:26,773 INFO COM5: b'[F4] : [L5] : 0216 00:00:16.638 remaining bytes 1004 \r\n'
2023-01-12 10:07:26,773 INFO COM5: b'[F4] : [L5] : 0217 00:00:16.643 No remaining bytes \r\n'
2023-01-12 10:07:26,773 INFO COM5: b'[F4] : [L4] : 0218 00:00:16.648 Get queue\r\n'
2023-01-12 10:07:26,774 INFO COM5: b'[F4] : [L4] : 0219 00:00:16.651 Count in queue before: 1\r\n'
2023-01-12 10:07:27,189 INFO COM5: b'[F4] : [L4] : 0220 00:00:17.056 Count in queue after: 0\r\n'
2023-01-12 10:07:27,190 INFO COM5: b'[F4] : [L5] : 0221 00:00:17.060 Received 997 \r\n'
2023-01-12 10:07:27,191 INFO COM5: b'[F4] : [L5] : 0222 00:00:17.064 remaining bytes 997 \r\n'
2023-01-12 10:07:27,298 INFO COM5: b'[F4] : [L5] : 0223 00:00:17.168 remaining bytes 347 \r\n'
2023-01-12 10:07:27,299 INFO COM5: b'[F4] : [L5] : 0224 00:00:17.172 remaining bytes 342 \r\n'
2023-01-12 10:07:27,385 INFO COM5: b'[F4] : [L5] : 0225 00:00:17.255 remaining bytes 9 \r\n'
2023-01-12 10:07:27,387 INFO COM5: b'[F4] : [L5] : 0226 00:00:17.259 remaining bytes 4 \r\n'
2023-01-12 10:07:28,494 INFO COM5: b'[F4] : [L5] : 0227 00:00:18.208 \r\n'
2023-01-12 10:07:28,495 INFO COM5: b'Process EAPOL packet\r\n'
2023-01-12 10:07:28,497 INFO COM5: b'[F4] : [L4] : 0228 00:00:18.218 [supplicant_process_event()] : L883 : SUPPLICANT_EVENT_EAPOL_PACKET_RECEIVED\r\n'
2023-01-12 10:07:28,499 INFO COM5: b'[F4] : [L5] : 0229 00:00:18.234 [supplicant_process_event()] : L946 : Should be a EAPOL packet for TLS/PEAP/Other. workspace->eap_type = [25]\r\n'
2023-01-12 10:07:28,501 INFO COM5: b'[F4] : [L5] : 0230 00:00:18.254 EAP packet received with EAP ID = [190], len = 1003 \r\n'
2023-01-12 10:07:28,502 INFO COM5: b'[F4] : [L5] : 0231 00:00:18.266 [supplicant_process_event()] : L976 : Move the packet start to the start of TLS data\r\n'
2023-01-12 10:07:28,504 INFO COM5: b'[F4] : [L5] : 0232 00:00:18.284 [supplicant_process_event()] : L985 : Send the TLS packet to TLS Agent\r\n'
2023-01-12 10:07:28,505 INFO COM5: b'[F4] : [L4] : 0233 00:00:18.298 Count in queue: 0\r\n'
2023-01-12 10:07:28,505 INFO COM5: b'[F4] : [L4] : 0234 00:00:18.306 \r\n'
2023-01-12 10:07:28,506 INFO COM5: b'[supplicant_process_event()] : L1065 : Returning succesfully from supplicant_process_event\r\n'
2023-01-12 10:07:28,507 INFO COM5: b'[F4] : [L4] : 0235 00:00:18.324 [supplicant_thread_main()] : L1089 : In processing loop...\r\n'
2023-01-12 10:07:28,507 INFO COM5: b'[F4] : [L5] : 0236 00:00:18.336 Calculate the wait time\r\n'
2023-01-12 10:07:28,508 INFO COM5: b'[F4] : [L5] : 0237 00:00:18.346 Waiting for EAPOL packet\r\n'
2023-01-12 10:07:28,687 INFO COM5: b'[F4] : [L4] : 0238 00:00:18.540 TLS handshake state: 9\r\n'
2023-01-12 10:07:28,863 INFO COM5: b'[F4] : [L4] : 0239 00:00:18.574 TLS handshake state: 11\r\n'
2023-01-12 10:07:28,864 INFO COM5: b'[F4] : [L4] : 0240 00:00:18.584 TLS handshake state: 12\r\n'

  

0 Likes