Time to complete 2-way TLS handshake

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

cross mob
lock attach
Attachments are accessible only for community members.
BaRu_3629256
Level 1
Level 1
10 sign-ins 5 replies posted 5 sign-ins

I am looking into speeding up the time it takes for my device to complete a 2-way TLS handshake. A network packet capture is showing that this process takes about 2.5 seconds to complete.

 

My device uses an STM32F412 MCU + CYW4343W Wi-Fi/BLE chip, and application is built using WICED Studio 6.6.1 with ThreadX/NetX Duo.

 

I realize that this is a computationally expensive process, so it might just be the way it is. However, I wasn't sure if there were any WICED build/config flags that might help speed this up.

 

Screenshot of TLS network sniff attached where 192.x.x.x address is the device running code build in WICED.

0 Likes
1 Solution
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

Hi :

   seems the log matches the sniff log.

Actually, here it depends on the speed of the host computation and the TLS flow.

I will recommend a host with a hardware  Accelerator like the below picture to speed up the process if possible:

Zhengbao_Zhang_0-1676538639768.png

 

======= MBEDTLS - DBG - 15590 msec: [mbedtls_ssl_handshake_client_step()] : [3960] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE
======= MBEDTLS - DBG - 16411 msec: [mbedtls_ssl_handshake_client_step()] : [3964] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE DONE : 0
======= MBEDTLS - DBG - 16423 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 9
======= MBEDTLS - DBG - 16433 msec: [mbedtls_ssl_handshake_client_step()] : [3970] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY
======= MBEDTLS - DBG - 17832 msec: [mbedtls_ssl_handshake_client_step()] : [3974] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY DONE : 0
======= MBEDTLS - DBG - 17844 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 10

View solution in original post

0 Likes
10 Replies
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

Hello: 

   Actually, the process should need some time for the computation.  maybe we can capture the logs to see if we can shorten the time,  by the way, the time is consumed in the process of a new connection of wifi, is that right?

0 Likes
BaRu_3629256
Level 1
Level 1
10 sign-ins 5 replies posted 5 sign-ins

Are there any logs that I can capture and pass along that would help? If so, just let me know if you want me to enable any debug/build flags.

0 Likes
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

Hello:

Would you please tell me the application usage?   in the meantime I think you can try to debug more:

 change the TLS version in the wiced_default.h.

  try to use the wiced_time_get_time() method to detail the code position that consumes so much time.

0 Likes

We are connecting to AWS IoT Core. Please let me know if you need more specifics.

We are enforcing TLS v1.2, and that is what is being used. Do you want me to enforce a lower version? Please provide specifics on what you want me to try.

I will add some timestamp debug and report back soon.

0 Likes

Here is the relevant output with timestamps added...

***** aws_iot_connect 1073: 16892 msec *****
[Application/AWS] Opening connection...
[AWS] AWS endpoint: <removed>-ats.iot.us-east-1.amazonaws.com is at <removed>
***** wiced_generic_start_tls_with_ciphers 1333: 17022 msec *****
***** wiced_generic_start_tls_with_ciphers 1367: 19539 msec *****
***** aws_iot_connect 1080: 19645 msec *****

The relevant timestamps are in bold. These reside in wiced_generic_start_tls_with_ciphers() around the do { while(); after the 4. Handshake comment.

The first (1333) is before the do while, and the second (1367) is after the do while. Please advise if you need more timestamps added, and where if needed.

0 Likes
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

Hello:

   we can enable the debug for the mbedtls module.

Actually,  STM32F412 will spend more time than the high-performance chip.

   /* Added for debug purpose */
#define MBEDTLS_DEBUG( X ) //printf(" ======= MBEDTLS - DBG : "); printf X
/* WICED_MBEDTLS End */

I think we can find the exact position where it costs the time.

Zhengbao_Zhang_0-1676293943717.png

from the pic the process spends most of the time on:

certificate

client key exchange

certificate verify

That really needs a lot of computation.

0 Likes

Here is the output from MBEDTLS_DEBUG with time stamps added...

***** aws_iot_connect 1073: 14943 msec *****
[Application/AWS] Opening connection...
[AWS] AWS endpoint: <removed>-ats.iot.us-east-1.amazonaws.com is at <removed>
***** wiced_generic_start_tls_with_ciphers 1333: 15076 msec *****
======= MBEDTLS - DBG - 15082 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 0
======= MBEDTLS - DBG - 15092 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 1
======= MBEDTLS - DBG - 15102 msec: [mbedtls_ssl_handshake_client_step()] : [3876] : Write MBEDTLS_SSL_CLIENT_HELLO
======= MBEDTLS - DBG - 15115 msec: [mbedtls_ssl_handshake_client_step()] : [3880] : Write MBEDTLS_SSL_CLIENT_HELLO DONE : 0
======= MBEDTLS - DBG - 15126 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 2
======= MBEDTLS - DBG - 15136 msec: [mbedtls_ssl_handshake_client_step()] : [3893] : Parse MBEDTLS_SSL_SERVER_HELLO
======= MBEDTLS - DBG - 15161 msec: [mbedtls_ssl_handshake_client_step()] : [3897] : Parse MBEDTLS_SSL_SERVER_HELLO DONE : 0
======= MBEDTLS - DBG - 15173 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 3
======= MBEDTLS - DBG - 15183 msec: [mbedtls_ssl_handshake_client_step()] : [3903] : Parse MBEDTLS_SSL_SERVER_CERTIFICATE
======= MBEDTLS - DBG - 15239 msec: Total defragmentation buffer length [5000] and received bytes [2920], PKT length : 1460
======= MBEDTLS - DBG - 15251 msec: Total defragmentation buffer length [5000] and received bytes [4380], PKT length : 1460
======= MBEDTLS - DBG - 15285 msec: Total defragmentation buffer length [5000] and received bytes [5000], PKT length : 1004
======= MBEDTLS - DBG - 15391 msec: [mbedtls_ssl_handshake_client_step()] : [3907] : Parse MBEDTLS_SSL_SERVER_CERTIFICATE DONE : 0
======= MBEDTLS - DBG - 15403 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 4
======= MBEDTLS - DBG - 15412 msec: [mbedtls_ssl_handshake_client_step()] : [3913] : Parse MBEDTLS_SSL_SERVER_KEY_EXCHANGE
======= MBEDTLS - DBG - 15466 msec: [mbedtls_ssl_handshake_client_step()] : [3917] : Parse MBEDTLS_SSL_SERVER_KEY_EXCHANGE DONE : 0
======= MBEDTLS - DBG - 15478 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 5
======= MBEDTLS - DBG - 15488 msec: [mbedtls_ssl_handshake_client_step()] : [3923] : Parse MBEDTLS_SSL_CERTIFICATE_REQUEST
======= MBEDTLS - DBG - 15500 msec: [mbedtls_ssl_handshake_client_step()] : [3927] : Parse MBEDTLS_SSL_CERTIFICATE_REQUEST DONE : 0
======= MBEDTLS - DBG - 15511 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 6
======= MBEDTLS - DBG - 15521 msec: [mbedtls_ssl_handshake_client_step()] : [3933] : Parse MBEDTLS_SSL_SERVER_HELLO_DONE
======= MBEDTLS - DBG - 15533 msec: [mbedtls_ssl_handshake_client_step()] : [3937] : Parse MBEDTLS_SSL_SERVER_HELLO_DONE DONE : 0
======= MBEDTLS - DBG - 15544 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 7
======= MBEDTLS - DBG - 15554 msec: [mbedtls_ssl_handshake_client_step()] : [3950] : Write MBEDTLS_SSL_CLIENT_CERTIFICATE
======= MBEDTLS - DBG - 15569 msec: [mbedtls_ssl_handshake_client_step()] : [3954] : Write MBEDTLS_SSL_CLIENT_CERTIFICATE DONE : 0
======= MBEDTLS - DBG - 15580 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 8
======= MBEDTLS - DBG - 15590 msec: [mbedtls_ssl_handshake_client_step()] : [3960] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE
======= MBEDTLS - DBG - 16411 msec: [mbedtls_ssl_handshake_client_step()] : [3964] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE DONE : 0
======= MBEDTLS - DBG - 16423 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 9
======= MBEDTLS - DBG - 16433 msec: [mbedtls_ssl_handshake_client_step()] : [3970] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY
======= MBEDTLS - DBG - 17832 msec: [mbedtls_ssl_handshake_client_step()] : [3974] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY DONE : 0
======= MBEDTLS - DBG - 17844 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 10
======= MBEDTLS - DBG - 17854 msec: [mbedtls_ssl_handshake_client_step()] : [3980] : Write MBEDTLS_SSL_CLIENT_CHANGE_CIPHER_SPEC
======= MBEDTLS - DBG - 17866 msec: [mbedtls_ssl_handshake_client_step()] : [3984] : Write MBEDTLS_SSL_CLIENT_CHANGE_CIPHER_SPEC DONE : 0
======= MBEDTLS - DBG - 17879 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 11
======= MBEDTLS - DBG - 17888 msec: [mbedtls_ssl_handshake_client_step()] : [3990] : Write MBEDTLS_SSL_CLIENT_FINISHED
======= MBEDTLS - DBG - 17900 msec: [mbedtls_ssl_handshake_client_step()] : [3994] : Write MBEDTLS_SSL_CLIENT_FINISHED DONE : 0
======= MBEDTLS - DBG - 17912 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 12
======= MBEDTLS - DBG - 17922 msec: [mbedtls_ssl_handshake_client_step()] : [4012] : Parse MBEDTLS_SSL_SERVER_CHANGE_CIPHER_SPEC
======= MBEDTLS - DBG - 17946 msec: [mbedtls_ssl_handshake_client_step()] : [4016] : Parse MBEDTLS_SSL_SERVER_CHANGE_CIPHER_SPEC DONE : 0
======= MBEDTLS - DBG - 17958 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 13
======= MBEDTLS - DBG - 17968 msec: [mbedtls_ssl_handshake_client_step()] : [4022] : Parse MBEDTLS_SSL_SERVER_FINISHED
======= MBEDTLS - DBG - 17980 msec: [mbedtls_ssl_handshake_client_step()] : [4026] : Parse MBEDTLS_SSL_SERVER_FINISHED DONE : 0
======= MBEDTLS - DBG - 17992 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 14
======= MBEDTLS - DBG - 18002 msec: [mbedtls_ssl_handshake_client_step()] : [4033] : TLS handshake success
======= MBEDTLS - DBG - 18012 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 15
***** wiced_generic_start_tls_with_ciphers 1367: 18022 msec *****
***** aws_iot_connect 1080: 18128 msec *****

0 Likes
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

Hi :

   seems the log matches the sniff log.

Actually, here it depends on the speed of the host computation and the TLS flow.

I will recommend a host with a hardware  Accelerator like the below picture to speed up the process if possible:

Zhengbao_Zhang_0-1676538639768.png

 

======= MBEDTLS - DBG - 15590 msec: [mbedtls_ssl_handshake_client_step()] : [3960] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE
======= MBEDTLS - DBG - 16411 msec: [mbedtls_ssl_handshake_client_step()] : [3964] : Write MBEDTLS_SSL_CLIENT_KEY_EXCHANGE DONE : 0
======= MBEDTLS - DBG - 16423 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 9
======= MBEDTLS - DBG - 16433 msec: [mbedtls_ssl_handshake_client_step()] : [3970] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY
======= MBEDTLS - DBG - 17832 msec: [mbedtls_ssl_handshake_client_step()] : [3974] : Write MBEDTLS_SSL_CERTIFICATE_VERIFY DONE : 0
======= MBEDTLS - DBG - 17844 msec: [mbedtls_ssl_handshake_client_step()] : [3840] : TLS Handshake state : 10

0 Likes

So that I am clear on your response, I believe you are saying that there is nothing that can be done in WICED (firmware) to speed up this process with my current hardware (STM32F412 MCU). If I want to speed up this process, I would need to use an MCU that supports crypto hardware acceleration for my specific application. Does this summarize your response?

0 Likes
Zhengbao_Zhang
Moderator
Moderator
Moderator
250 sign-ins First comment on KBA 10 questions asked

sure, thanks for the reply and understanding, the TLS authenticate stage is decided by the mbedTLS flow and host ability, we can't offload it from the firmware side.

0 Likes