mbedTLS with dynamic memory [IDFGH-4803]

[bigfede]

Hi Guys,

currently i was tring to implemente a custom HTTPs client to perform a POST. I'm facing problems with mbedTLS with dynamic memory allocation. Let me explain, if I set the MAX_FRAGMENT_LENGTH to 8k IN and 4k OUT with STATIC, the POST is corretly executed. But if I switch to dynamic a crash occurs.
I'have record some logs there, is there any way to solve this problem? The strange thing also is that this problem occurs only with POST, but not with a GET request. I'm using esp_http_client but I have also try others and the problem is still the same.

I attach also the code there. It seems to crash once the fetch_headers occurs.

Code: Select all

 esp_http_client_config_t post_config = {
        .host = (char *)pvParameter,
        .url = iothub_url,
        .client_cert_pem = "",
        .client_key_pem = "",
        .transport_type = HTTP_TRANSPORT_OVER_SSL,
        .timeout_ms = 60000,  //60 minutes
        .method = HTTP_METHOD_POST,
        .event_handler = _http_event_handler,
        .is_async = false,
        .user_data = response_buffer,        // Pass address of local buffer to get response
    };
    esp_http_client_handle_t iothub_client = esp_http_client_init(&post_config);



    // STEP1
    char post_data[512] = "content";
    //esp_http_client_set_url(client, "https://myurl");
    //esp_http_client_set_method(client, HTTP_METHOD_POST);
    esp_http_client_set_header(iothub_client, "Content-Type", "application/json");
    //esp_http_client_set_post_field(client, post_data, strlen(post_data));

    /*Open client https and write headers*/
    if(ESP_OK == esp_http_client_open(iothub_client, strlen(post_data)))
        ESP_LOGW(TAG_LOG, "POST");

    /*Write body*/
    //esp_http_client_perform(client);
    esp_http_client_write(iothub_client, post_data, strlen(post_data));
    ESP_LOGI(TAG_LOG_AZURE, "Post Body: %s", post_data);
    
    /*Fetch response headers*/
    int content_length = esp_http_client_fetch_headers(iothub_client);
    //ESP_LOGI(TAG_LOG, "fetch_headers, content_length = %d", content_length);

    int response_length = esp_http_client_get_content_length(iothub_client);
    //ESP_LOGI(TAG_LOG, "content_length, %d", response_length);

    /*Read data*/
    //esp_http_client_read_response(client, response_buffer, 1024);
    esp_http_client_read(iothub_client, response_buffer, response_length);

Code: Select all

I (27765) mbedtls: ssl_tls.c:8203 => handshake

I (27765) mbedtls: ssl_cli.c:3785 client state: 0

I (27775) mbedtls: ssl_tls.c:2847 => flush output

I (27775) mbedtls: ssl_tls.c:2859 <= flush output

I (27785) mbedtls: ssl_cli.c:3785 client state: 1

I (27785) mbedtls: ssl_tls.c:2847 => flush output

I (27795) mbedtls: ssl_tls.c:2859 <= flush output

I (27795) mbedtls: ssl_cli.c:805 => write client hello

I (27805) mbedtls: ssl_tls.c:3286 => write handshake message

I (27805) mbedtls: ssl_tls.c:3445 => write record

I (27815) mbedtls: ssl_tls.c:2847 => flush output

I (27825) mbedtls: ssl_tls.c:2866 message length: 318, out_left: 318

I (27825) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 318 (-0xfffffec2)

I (27835) mbedtls: ssl_tls.c:2899 <= flush output

I (27845) mbedtls: ssl_tls.c:3578 <= write record

I (27845) mbedtls: ssl_tls.c:3422 <= write handshake message

I (27855) mbedtls: ssl_cli.c:1255 <= write client hello

I (27855) mbedtls: ssl_tls.c:2628 => fetch input

I (27865) mbedtls: ssl_tls.c:2789 in_left: 0, nb_want: 5

I (29815) mbedtls: ssl_tls.c:2813 in_left: 0, nb_want: 5

I (29815) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (29815) mbedtls: ssl_tls.c:2834 <= fetch input

I (29825) mbedtls: ssl_cli.c:3785 client state: 2

I (29825) mbedtls: ssl_tls.c:2847 => flush output

I (29835) mbedtls: ssl_tls.c:2859 <= flush output

I (29835) mbedtls: ssl_cli.c:1684 => parse server hello

I (29845) mbedtls: ssl_tls.c:4419 => read record

I (29845) mbedtls: ssl_tls.c:2628 => fetch input

I (29855) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 5

I (29865) mbedtls: ssl_tls.c:2834 <= fetch input

I (29865) mbedtls: ssl_tls.c:2628 => fetch input

I (29875) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 3820

I (29875) mbedtls: ssl_tls.c:2813 in_left: 5, nb_want: 3820

I (29885) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 1419 (-0xfffffa75)

I (30865) mbedtls: ssl_tls.c:2813 in_left: 1424, nb_want: 3820

I (30865) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 1424 (-0xfffffa70)

I (34865) mbedtls: ssl_tls.c:2813 in_left: 2848, nb_want: 3820

I (34865) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 972 (-0xfffffc34)

I (34865) mbedtls: ssl_tls.c:2834 <= fetch input

I (34875) mbedtls: ssl_tls.c:4493 <= read record

I (34875) mbedtls: ssl_cli.c:2000 server hello, total extension length: 9

I (34885) mbedtls: ssl_cli.c:2200 <= parse server hello

I (34895) mbedtls: ssl_cli.c:3785 client state: 3

I (34895) mbedtls: ssl_tls.c:2847 => flush output

I (34905) mbedtls: ssl_tls.c:2859 <= flush output

I (34905) mbedtls: ssl_tls.c:5763 => parse certificate

I (34915) mbedtls: ssl_tls.c:4419 => read record

I (34915) mbedtls: ssl_tls.c:4493 <= read record

I (34935) mbedtls: ssl_tls.c:5971 <= parse certificate

I (34935) mbedtls: ssl_cli.c:3785 client state: 4

I (34935) mbedtls: ssl_tls.c:2847 => flush output

I (34945) mbedtls: ssl_tls.c:2859 <= flush output

I (34945) mbedtls: ssl_cli.c:2566 => parse server key exchange

I (34955) mbedtls: ssl_tls.c:4419 => read record

I (34955) mbedtls: ssl_tls.c:4493 <= read record

I (34965) mbedtls: ssl_cli.c:2268 ECDH curve: secp256r1

I (34975) mbedtls: ssl_cli.c:2507 Server used SignatureAlgorithm 1

I (34975) mbedtls: ssl_cli.c:2509 Server used HashAlgorithm 4

I (35005) mbedtls: ssl_cli.c:2926 <= parse server key exchange

I (35005) mbedtls: ssl_cli.c:3785 client state: 5

I (35005) mbedtls: ssl_tls.c:2847 => flush output

I (35015) mbedtls: ssl_tls.c:2859 <= flush output

I (35015) mbedtls: ssl_cli.c:2959 => parse certificate request

I (35025) mbedtls: ssl_tls.c:4419 => read record

I (35025) mbedtls: ssl_tls.c:4493 <= read record

I (35035) mbedtls: ssl_cli.c:3115 <= parse certificate request

I (35045) mbedtls: ssl_cli.c:3785 client state: 6

I (35045) mbedtls: ssl_tls.c:2847 => flush output

I (35055) mbedtls: ssl_tls.c:2859 <= flush output

I (35055) mbedtls: ssl_cli.c:3125 => parse server hello done

I (35065) mbedtls: ssl_tls.c:4419 => read record

I (35075) mbedtls: ssl_tls.c:4489 reuse previously read message

I (35075) mbedtls: ssl_tls.c:4493 <= read record

I (35085) mbedtls: ssl_cli.c:3155 <= parse server hello done

I (35085) mbedtls: ssl_cli.c:3785 client state: 7

I (35095) mbedtls: ssl_tls.c:2847 => flush output

I (35095) mbedtls: ssl_tls.c:2859 <= flush output

I (35105) mbedtls: ssl_tls.c:5437 => write certificate

I (35115) mbedtls: ssl_tls.c:5454 <= skip write certificate

I (35115) mbedtls: ssl_cli.c:3785 client state: 8

I (35125) mbedtls: ssl_tls.c:2847 => flush output

I (35125) mbedtls: ssl_tls.c:2859 <= flush output

I (35135) mbedtls: ssl_cli.c:3167 => write client key exchange

I (39375) mbedtls: ssl_tls.c:3286 => write handshake message

I (39375) mbedtls: ssl_tls.c:3445 => write record

I (39375) mbedtls: ssl_tls.c:2847 => flush output

I (39385) mbedtls: ssl_tls.c:2866 message length: 75, out_left: 75

I (39395) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 75 (-0xffffffb5)

I (39395) mbedtls: ssl_tls.c:2899 <= flush output

I (39405) mbedtls: ssl_tls.c:3578 <= write record

I (39405) mbedtls: ssl_tls.c:3422 <= write handshake message

I (39415) mbedtls: ssl_cli.c:3444 <= write client key exchange

I (39425) mbedtls: ssl_cli.c:3785 client state: 9

I (39425) mbedtls: ssl_tls.c:2847 => flush output

I (39435) mbedtls: ssl_tls.c:2859 <= flush output

I (39435) mbedtls: ssl_cli.c:3496 => write certificate verify

I (39445) mbedtls: ssl_tls.c:653 => derive keys

I (39455) mbedtls: ssl_tls.c:1228 => calc verify sha256

I (39455) mbedtls: ssl_tls.c:1234 <= calc verify

I (39465) mbedtls: ssl_tls.c:1139 <= derive keys

I (39465) mbedtls: ssl_cli.c:3525 <= skip write certificate verify

I (39475) mbedtls: ssl_cli.c:3785 client state: 10

I (39485) mbedtls: ssl_tls.c:2847 => flush output

I (39485) mbedtls: ssl_tls.c:2859 <= flush output

I (39495) mbedtls: ssl_tls.c:5987 => write change cipher spec

I (39495) mbedtls: ssl_tls.c:3286 => write handshake message

I (39505) mbedtls: ssl_tls.c:3445 => write record

I (39515) mbedtls: ssl_tls.c:2847 => flush output

I (39515) mbedtls: ssl_tls.c:2866 message length: 6, out_left: 6

I (39525) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 6 (-0xfffffffa)

I (39535) mbedtls: ssl_tls.c:2899 <= flush output

I (39535) mbedtls: ssl_tls.c:3578 <= write record

I (39545) mbedtls: ssl_tls.c:3422 <= write handshake message

I (39545) mbedtls: ssl_tls.c:6001 <= write change cipher spec

I (39555) mbedtls: ssl_cli.c:3785 client state: 11

I (39565) mbedtls: ssl_tls.c:2847 => flush output

I (39565) mbedtls: ssl_tls.c:2859 <= flush output

I (39575) mbedtls: ssl_tls.c:6515 => write finished

I (39575) mbedtls: ssl_tls.c:6331 => calc  finished tls sha256

I (39585) mbedtls: ssl_tls.c:6361 <= calc  finished

I (39585) mbedtls: ssl_tls.c:3286 => write handshake message

I (39595) mbedtls: ssl_tls.c:3445 => write record

I (39605) mbedtls: ssl_tls.c:1446 => encrypt buf

I (39605) mbedtls: ssl_tls.c:1780 <= encrypt buf

I (39615) mbedtls: ssl_tls.c:2847 => flush output

I (39615) mbedtls: ssl_tls.c:2866 message length: 85, out_left: 85

I (39625) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 85 (-0xffffffab)

I (39635) mbedtls: ssl_tls.c:2899 <= flush output

I (39635) mbedtls: ssl_tls.c:3578 <= write record

I (39645) mbedtls: ssl_tls.c:3422 <= write handshake message

I (39655) mbedtls: ssl_tls.c:6624 <= write finished

I (39655) mbedtls: ssl_tls.c:2628 => fetch input

I (39665) mbedtls: ssl_tls.c:2789 in_left: 0, nb_want: 5

I (41115) mbedtls: ssl_tls.c:2813 in_left: 0, nb_want: 5

I (41115) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (41115) mbedtls: ssl_tls.c:2834 <= fetch input

I (41125) mbedtls: ssl_cli.c:3785 client state: 12

I (41125) mbedtls: ssl_tls.c:2847 => flush output

I (41135) mbedtls: ssl_tls.c:2859 <= flush output

I (41135) mbedtls: ssl_tls.c:6010 => parse change cipher spec

I (41145) mbedtls: ssl_tls.c:4419 => read record

I (41145) mbedtls: ssl_tls.c:2628 => fetch input

I (41155) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 5

I (41165) mbedtls: ssl_tls.c:2834 <= fetch input

I (41165) mbedtls: ssl_tls.c:2628 => fetch input

I (41175) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 6

I (41175) mbedtls: ssl_tls.c:2813 in_left: 5, nb_want: 6

I (41185) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 1 (-0xffffffff)

I (41195) mbedtls: ssl_tls.c:2834 <= fetch input

I (41195) mbedtls: ssl_tls.c:4493 <= read record

I (41205) mbedtls: ssl_tls.c:6074 <= parse change cipher spec

I (41205) mbedtls: ssl_tls.c:2628 => fetch input

I (41215) mbedtls: ssl_tls.c:2789 in_left: 0, nb_want: 5

I (41225) mbedtls: ssl_tls.c:2813 in_left: 0, nb_want: 5

I (41225) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (41235) mbedtls: ssl_tls.c:2834 <= fetch input

I (41245) mbedtls: ssl_cli.c:3785 client state: 13

I (41245) mbedtls: ssl_tls.c:2847 => flush output

I (41255) mbedtls: ssl_tls.c:2859 <= flush output

I (41255) mbedtls: ssl_tls.c:6641 => parse finished

I (41265) mbedtls: ssl_tls.c:6331 => calc  finished tls sha256

I (41275) mbedtls: ssl_tls.c:6361 <= calc  finished

I (41275) mbedtls: ssl_tls.c:4419 => read record

I (41285) mbedtls: ssl_tls.c:2628 => fetch input

I (41285) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 5

I (41295) mbedtls: ssl_tls.c:2834 <= fetch input

I (41295) mbedtls: ssl_tls.c:2628 => fetch input

I (41305) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 85

I (41315) mbedtls: ssl_tls.c:2813 in_left: 5, nb_want: 85

I (41315) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 80 (-0xffffffb0)

I (41325) mbedtls: ssl_tls.c:2834 <= fetch input

I (41335) mbedtls: ssl_tls.c:1943 => decrypt buf

I (41335) mbedtls: ssl_tls.c:2468 <= decrypt buf

I (41345) mbedtls: ssl_tls.c:4493 <= read record

I (41345) mbedtls: ssl_tls.c:6709 <= parse finished

I (41355) mbedtls: ssl_cli.c:3785 client state: 14

I (41355) mbedtls: ssl_tls.c:2847 => flush output

I (41365) mbedtls: ssl_tls.c:2859 <= flush output

I (41365) mbedtls: ssl_cli.c:3896 handshake: done

I (41375) mbedtls: ssl_cli.c:3785 client state: 15

I (41385) mbedtls: ssl_tls.c:2847 => flush output

I (41385) mbedtls: ssl_tls.c:2859 <= flush output

I (41395) mbedtls: ssl_tls.c:8213 <= handshake

I (41395) 32|LOG_AZURE_TASK: HTTP_EVENT_ON_CONNECTED
I (41405) mbedtls: ssl_tls.c:8805 => write

I (41405) mbedtls: ssl_tls.c:3445 => write record

I (41415) mbedtls: ssl_tls.c:1446 => encrypt buf

I (41415) mbedtls: ssl_tls.c:1780 <= encrypt buf

I (41425) mbedtls: ssl_tls.c:2847 => flush output

I (41425) mbedtls: ssl_tls.c:2866 message length: 293, out_left: 293

I (41435) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 293 (-0xfffffedb)

I (41445) mbedtls: ssl_tls.c:2899 <= flush output

I (41455) mbedtls: ssl_tls.c:3578 <= write record

I (41455) mbedtls: ssl_tls.c:8833 <= write

I (41465) 36|LOG_AZURE_TASK: HTTP_EVENT_HEADER_SENT
W (41465) 146|LOG_AZURE_TASK: POST
I (41475) mbedtls: ssl_tls.c:8805 => write

I (41475) mbedtls: ssl_tls.c:3445 => write record

I (41485) mbedtls: ssl_tls.c:1446 => encrypt buf

I (41485) mbedtls: ssl_tls.c:1780 <= encrypt buf

I (41495) mbedtls: ssl_tls.c:2847 => flush output

I (41495) mbedtls: ssl_tls.c:2866 message length: 85, out_left: 85

I (41505) mbedtls: ssl_tls.c:2871 ssl->f_send() returned 85 (-0xffffffab)

I (41515) mbedtls: ssl_tls.c:2899 <= flush output

I (41515) mbedtls: ssl_tls.c:3578 <= write record

I (41525) mbedtls: ssl_tls.c:8833 <= write

I (41525) 151|LOG_AZURE_TASK: Post Body: {"blobName":"test9.log"}
I (42615) mbedtls: ssl_tls.c:2628 => fetch input

I (42615) mbedtls: ssl_tls.c:2789 in_left: 0, nb_want: 5

I (42615) mbedtls: ssl_tls.c:2813 in_left: 0, nb_want: 5

I (42615) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (42625) mbedtls: ssl_tls.c:2834 <= fetch input

I (42635) mbedtls: ssl_tls.c:8389 => read

I (42635) mbedtls: ssl_tls.c:4419 => read record

I (42645) mbedtls: ssl_tls.c:2628 => fetch input

I (42645) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 5

I (42655) mbedtls: ssl_tls.c:2834 <= fetch input

I (42655) mbedtls: ssl_tls.c:2628 => fetch input

I (42665) mbedtls: ssl_tls.c:2789 in_left: 5, nb_want: 69

I (42675) mbedtls: ssl_tls.c:2813 in_left: 5, nb_want: 69

I (42675) mbedtls: ssl_tls.c:2814 ssl->f_recv(_timeout)() returned 64 (-0xffffffc0)

I (42685) mbedtls: ssl_tls.c:2834 <= fetch input

I (42695) mbedtls: ssl_tls.c:1943 => decrypt buf

I (42695) mbedtls: ssl_tls.c:2468 <= decrypt buf

I (42705) mbedtls: ssl_tls.c:4493 <= read record

W (42705) mbedtls: ssl_tls.c:8476 received handshake message

I (42715) mbedtls: ssl_tls.c:5358 => send alert message

I (42725) mbedtls: ssl_tls.c:3445 => write record

I (42725) mbedtls: ssl_tls.c:1446 => encrypt buf

Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4000c2e4  PS      : 0x00060230  A0      : 0x801083fd  A1      : 0x3ffdc4d0  
A2      : 0x00000000  A3      : 0x3ffe8d84  A4      : 0x00000010  A5      : 0x00000000  
A6      : 0x1f8d8194  A7      : 0xe0852eec  A8      : 0x00000000  A9      : 0x3ffdc450  
A10     : 0x00000000  A11     : 0x607faa5d  A12     : 0x607faa5d  A13     : 0x3ffbfeac  
A14     : 0x00000000  A15     : 0x3ffddcec  SAR     : 0x00000010  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  

Backtrace:0x4000c2e1:0x3ffdc4d0 0x401083fa:0x3ffdc4e0 0x40109514:0x3ffdc580 0x4010afff:0x3ffdc5b0 0x4010b570:0x3ffdc5d0 0x400ff815:0x3ffdc5f0 0x40123590:0x3ffdc610 0x4013b967:0x3ffdc630 0x401002e0:0x3ffdc650 0x400dca9d:0x3ffdc670

[ESP_Angus]

Hi bigfede,

Sorry noone got back to you about this earlier. I've edited the post title with our internal tracking ID.

Which ESP-IDF version are you using? (The program should log this during startup if unsure.)

Also, are you able to decode the backtrace when it crashes? Running the program in the "idf.py monitor" tool should do this automatically.

Thanks.

[bigfede]

Hi,
I'm using ESP-IDF v4.2-dev-1206-g741960d5c-dirty and unfortunatly I am no able to go back and understand when the code crashes.
Is there something I can try?

[ESP_YJM]

Could you please try this patch to confirm your issue whether has been fixed.

[bigfede]

for sure, i'll let you know if the crash occurs again

[bigfede]

Could you please try this patch to confirm your issue whether has been fixed.

Can you please provide the SHA commit of mbedtls?

[ESP_YJM]

Could you please try this patch to confirm your issue whether has been fixed.

Can you please provide the SHA commit of mbedtls?

My mbedtls commit id is after bf513b6f, only change the mbedtls/port/dynamic directory.

[ESP_YJM]

Hi bigfede
Is there any update for this patch.Please spare no effort to tell me what help I can provide.

[bigfede]

Hi, sorry for my late reply. At the moment the hardware is faulty and I'm waiting for new to arrive. This week I'll try this patch. Just for reminder which version of ESP-IDF are you using? Since I've tried to apply the patch but it doesn't. Maybe I was in the wrong directory.

[ESP_YJM]

I am using ESP-IDF master branch whose commit id is 1067b28707e527f177752741e3aa08b5dc64a4d7. You can follow this commit and apply the patch, or merge the patch manually.