Slow Https Post Request

[aeropagz]

I am using the esp-idf Http Client on my ESP32 to call REST-Api Endpoints.

One simple HTTS login Post call with body like:

Code: Select all

{
"username": "test",
"password": "test"
}

takes 2 seconds to perform...

Is it always that slow? It takes a whole second just for TLS handshake (See log). Do you have similiar experiences?

Is there any ways to improve that speed?



code:

Code: Select all

esp_http_client_config_t config = {
        .url = API_URL "users/login",
        .method = HTTP_METHOD_POST,
        .user_data = local_response_buffer,
        .crt_bundle_attach = esp_crt_bundle_attach,
        .event_handler = _http_event_handler};

    cJSON *root = cJSON_CreateObject();
    cJSON *name = cJSON_CreateString(creds->username);
    cJSON *password = cJSON_CreateString(creds->password);
    cJSON_AddItemToObject(root, "username", name);
    cJSON_AddItemToObject(root, "password", password);
    char *json_string = cJSON_Print(root);

    ESP_LOGI(TAG, "Token: %s", json_string); // FROM HERE

    esp_http_client_handle_t client = esp_http_client_init(&config);

    esp_http_client_set_header(client, "Content-Type", "application/json");
    esp_http_client_set_post_field(client, json_string, strlen(json_string));

    esp_err_t err = esp_http_client_perform(client);
    if (err == ESP_OK && (esp_http_client_get_status_code(client) == 200))
    {   
        ESP_LOGI(TAG, "TEST"); // TO HERE IT TAKES 2.5 secs

Code: Select all

Verbose Logs

I (227622) KICKER_CLUB: Token: {
        "username":     "****",
        "password":     "****"
}
D (227632) HTTP_CLIENT: set post file length = 56
D (227632) HTTP_CLIENT: Begin connect to: https://********.de:443
D (227642) esp-tls: ******.de: strlen 26
W (227662) wifi:<ba-add>idx:0 (ifx:0, b8:27:eb:f1:6d:9c), tid:0, ssn:2, winSize:64
D (227692) esp-tls: [sock=58] Resolved IPv4 address: *******
D (227692) esp-tls: [sock=58] Connecting to server. HOST: ****
D (227722) esp-tls-mbedtls: Use certificate bundle
D (227722) esp-tls: handshake in progress...
D (227832) esp-x509-crt-bundle: 127 certificates in bundle
I (227862) esp-x509-crt-bundle: Certificate validated
D (228762) HTTP_HANDLER: HTTP_EVENT_ON_CONNECTED
D (228762) HTTP_CLIENT: Write header[4]: POST /api/users/login HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: ****
Content-Type: application/json
Content-Length: 56


D (228782) HTTP_HANDLER: HTTP_EVENT_HEADER_SENT
D (229362) HTTP_CLIENT: on_message_begin
D (229362) HTTP_CLIENT: HEADER=Date:Sat, 16 Apr 2022 16:07:28 GMT
D (229362) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Date, value=Sat, 16 Apr 2022 16:07:28 GMT
D (229362) HTTP_CLIENT: HEADER=Content-Type:application/json
D (229372) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Content-Type, value=application/json
D (229382) HTTP_CLIENT: HEADER=Transfer-Encoding:chunked
D (229382) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Transfer-Encoding, value=chunked
D (229392) HTTP_CLIENT: HEADER=Connection:keep-alive
D (229402) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Connection, value=keep-alive
D (229402) HTTP_CLIENT: HEADER=Server:nginx/1.15.1
D (229412) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Server, value=nginx/1.15.1
D (229422) HTTP_CLIENT: HEADER=Vary:Origin
D (229422) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Vary, value=Origin
D (229432) HTTP_CLIENT: HEADER=Vary:Access-Control-Request-Method
D (229432) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Vary, value=Access-Control-Request-Method
D (229442) HTTP_CLIENT: HEADER=Vary:Access-Control-Request-Headers
D (229452) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Vary, value=Access-Control-Request-Headers
D (229462) HTTP_CLIENT: HEADER=X-Content-Type-Options:nosniff
D (229462) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=X-Content-Type-Options, value=nosniff
D (229472) HTTP_CLIENT: HEADER=X-XSS-Protection:1; mode=block
D (229482) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=X-XSS-Protection, value=1; mode=block
D (229482) HTTP_CLIENT: HEADER=Cache-Control:no-cache, no-store, max-age=0, must-revalidate
D (229492) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Cache-Control, value=no-cache, no-store, max-age=0, must-revalidate
D (229502) HTTP_CLIENT: HEADER=Pragma:no-cache
D (229512) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Pragma, value=no-cache
D (229512) HTTP_CLIENT: HEADER=Expires:0
D (229522) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=Expires, value=0
D (229522) HTTP_CLIENT: HEADER=X-Frame-Options:DENY
D (229532) HTTP_HANDLER: HTTP_EVENT_ON_HEADER, key=X-Frame-Options, value=DENY
D (229542) HTTP_CLIENT: http_on_headers_complete, status=200, offset=431, nread=431
D (229542) HTTP_CLIENT: http_on_chunk_header, chunk_length
D (229552) HTTP_CLIENT: http_on_body 76
D (229552) HTTP_HANDLER: HTTP_EVENT_ON_DATA, len=76
D (229562) HTTP_CLIENT: content_length = -1
D (229562) HTTP_CLIENT: data_process=76, content_length=-1
D (229572) TRANSPORT_BASE: remain data in cache, need to read again
D (229572) HTTP_CLIENT: http_on_body 327
D (229582) HTTP_HANDLER: HTTP_EVENT_ON_DATA, len=327
D (229582) HTTP_CLIENT: http_on_chunk_complete
D (229592) HTTP_CLIENT: data_process=403, content_length=-1
D (229602) HTTP_CLIENT: http_on_chunk_header, chunk_length
D (229602) HTTP_CLIENT: http_on_chunk_complete
D (229602) HTTP_CLIENT: http_on_message_complete, parser=3ffb21ec
D (229612) HTTP_HANDLER: HTTP_EVENT_ON_FINISH
D (229612) HTTP_HANDLER: ***
I (229652) KICKER_CLUB: TEST

[c32958]

I recommend you enable TLS session resumption. It will take the 1-2 second TLS negotiation to ~100-150ms on repeat connections.

Here's how I implemented it (this is running in IDF v4.4.1):

Code: Select all

    void *serializedSession=malloc(2048);
    if (nvs_get_blob(main_flash_handle,"tls_session",serializedSession,&session_size)==ESP_OK) {
        if (!mbedtls_ssl_session_load(&mbedtlsSslSession,serializedSession,session_size))
            cfg.client_session=(void *)&mbedtlsSslSession;
    }

    z=0;
    tls=NULL;
    while (1) {
        ESP_LOGW(TAG,"tls conn start");
        tls = esp_tls_conn_http_new(url, &cfg);
        if (tls != NULL) {
            esp_tls_client_session_t *session;
            ESP_LOGW(TAG, "Connection established...");
            session=esp_tls_get_client_session(tls);
            void *sbuf=malloc(2048);
            size_t sbuf_len;
            if (!mbedtls_ssl_session_save(&session->saved_session,sbuf,2048,&sbuf_len)) {
                nvs_set_blob(main_flash_handle,"tls_session",sbuf,sbuf_len);
                nvs_commit(main_flash_handle);
            }
            free(sbuf);
            break;
        } else {
            ESP_LOGW(TAG, "Connection failed for %s...",url);
            z++;
            if (z > 5) goto exit;
        }
    }
    
    if (serializedSession)
        free(serializedSession);

With this and a bevy of other optimizations, I can wake, connect to wifi, do an https/REST update to the cloud, and go to sleep in about 1.2 seconds on average. I extended the session lifetime on my cloud nginx instance to several days so it only had to do a full SSL negotiation once a week (the default lifetime was 5 minutes).

I believe this is about as good as it can get--some uploads are as fast as 500ms (wake to sleep)--quite impressive when you consider all that has to happen. Unfortunately, there is too much variability in wifi association time, dhcp, dns, occasional lost packets, etc, to rely on 500ms every time -- 1 to 1.2 seconds average is likely the best you rely on in anything other than ideal conditions.

-Chris

[Jonathan2892]

Hi Chris,
Thank you for you code! I think I understand what you are doing in you code, but as far as I understand you are not using the esp_http_client at all, right?
Or do you pass the tls-client to the http-client, so the http-client knows which connection to use?

http-client has some nice methods to set headers and post-field etc. But I think with the tls-client I have to build the url by my own, right?

Best
Jonathan