alloc(16749 bytes) failed occasionally occurs when you upgrade using http (IDFGH-11730)

[SeanYang-7]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v5.1.1

Espressif SoC revision.

ESP32 C3

Operating System used.

Windows

How did you build your project?

Command line with Make

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-C3-13

Power Supply used.

USB

What is the expected behavior?

Read the firmware normally using http.

What is the actual behavior?

E (1185926) Dynamic Impl: alloc(16749 bytes) failed
E (1185926) esp-tls-mbedtls: read error :-0x7F00:
E (1185926) transport_base: esp_tls_conn_read error, errno=Success
E (1185933) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
I (1185941) native_esp_ota: current_dl_len:1657394,progress_tmp:90
E (1185966) Dynamic Impl: alloc(41913 bytes) failed
E (1185967) esp-tls-mbedtls: read error :-0x7F00:
E (1185967) transport_base: esp_tls_conn_read error, errno=Success
E (1185973) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
E (1185980) native_esp_ota: Error: SSL data read error -1

Steps to reproduce.

1. Step
2. Step
3. Step
   ...

Debug Logs.

Free heap space: 46400 byte
I (1185477) native_esp_ota: current_dl_len:1646592,progress_tmp:90
I (1185541) native_esp_ota: current_dl_len:1647616,progress_tmp:90
I (1185565) native_esp_ota: current_dl_len:1648640,progress_tmp:90
I (1185588) native_esp_ota: current_dl_len:1649664,progress_tmp:90
I (1185655) native_esp_ota: current_dl_len:1650688,progress_tmp:90
I (1185717) native_esp_ota: current_dl_len:1651712,progress_tmp:90
I (1185741) native_esp_ota: current_dl_len:1652736,progress_tmp:90
I (1185764) native_esp_ota: current_dl_len:1653760,progress_tmp:90
I (1185823) native_esp_ota: current_dl_len:1654784,progress_tmp:90
I (1185881) native_esp_ota: current_dl_len:1655808,progress_tmp:90
I (1185905) native_esp_ota: current_dl_len:1656832,progress_tmp:90
E (1185926) Dynamic Impl: alloc(16749 bytes) failed
E (1185926) esp-tls-mbedtls: read error :-0x7F00:
E (1185926) transport_base: esp_tls_conn_read error, errno=Success
E (1185933) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
I (1185941) native_esp_ota: current_dl_len:1657394,progress_tmp:90
E (1185966) Dynamic Impl: alloc(41913 bytes) failed
E (1185967) esp-tls-mbedtls: read error :-0x7F00:
E (1185967) transport_base: esp_tls_conn_read error, errno=Success
E (1185973) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
E (1185980) native_esp_ota: Error: SSL data read error -1

More Information.

Occasionally triggering this error,

[torkleyy]

Can you add a log printing the max free block size, please?

[SeanYang-7]

你能添加一个日志打印最大可用块大小吗？

Free heap space: 46400 byte

[SeanYang-7]

Can you add a log printing the max free block size, please?

Ask how much heap memory is needed to avoid this problem

[hmalpani]

Hello @LHYYSY
Can you share the sample application and the sdkconfig file which can be used to reproduce this issue?

Thanks!

[SeanYang-7]

Hello @LHYYSY Can you share the sample application and the sdkconfig file which can be used to reproduce this issue?

Thanks!

Take a look. thank you very much
sdkconfig.txt

[hmalpani]

Hello @LHYYSY
Can you also share the application code which can be used to reproduce this issue?

[SeanYang-7]

Hello @LHYYSY Can you also share the application code which can be used to reproduce this issue?

I'm using routines to reproduce the problem, and I can't reproduce the problem,but I have both mqtt and http running at the same time, does it matter?

[hmalpani]

Hello @LHYYSY

Can you please log the largest free block in heap, you can use this API: https://github.com/espressif/esp-idf/blob/master/components/heap/heap_caps.c#L570

[SeanYang-7]

Hello @LHYYSY

Can you please log the largest free block in heap, you can use this API: https://github.com/espressif/esp-idf/blob/master/components/heap/heap_caps.c#L570

I used a task during the ota upgrade process to print "printf(" Free heap space: %ld byte free block %d\n", esp_get_free_heap_size(),heap_caps_get_largest_free_block(MALLOC_CAP_32BIT));”
Log:
Free heap space: 66852 byte free block 19456
I (92017) native_esp_ota: current_dl_len:1286144,progress_tmp:80
I (92080) native_esp_ota: current_dl_len:1287168,progress_tmp:80
I (92104) native_esp_ota: current_dl_len:1288192,progress_tmp:80
I (92127) native_esp_ota: current_dl_len:1289216,progress_tmp:80
I (92187) native_esp_ota: current_dl_len:1290240,progress_tmp:80
I (92248) native_esp_ota: current_dl_len:1291264,progress_tmp:80
I (92272) native_esp_ota: current_dl_len:1292288,progress_tmp:80
I (92295) native_esp_ota: current_dl_len:1293312,progress_tmp:80
I (92358) native_esp_ota: current_dl_len:1294336,progress_tmp:80
I (92422) native_esp_ota: current_dl_len:1295360,progress_tmp:80
I (92446) native_esp_ota: current_dl_len:1296384,progress_tmp:80
I (92469) native_esp_ota: current_dl_len:1297408,progress_tmp:80
E (92490) Dynamic Impl: alloc(16749 bytes) failed
E (92490) esp-tls-mbedtls: read error :-0x7F00:
E (92490) transport_base: esp_tls_conn_read error, errno=Success
E (92496) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
I (92505) native_esp_ota: current_dl_len:1298131,progress_tmp:80
E (92529) Dynamic Impl: alloc(51491 bytes) failed
E (92530) esp-tls-mbedtls: read error :-0x7F00:
E (92530) transport_base: esp_tls_conn_read error, errno=Success
E (92536) HTTP_CLIENT: transport_read: error - -1 | ESP_FAIL
E (92542) native_esp_ota: Error: SSL data read error -1

[hmalpani]

Hello @LHYYSY

Can you update the code code to print the largest free block size such a way that we can get it just before the crash occurs. Also it will be helpful if you can share some application which can be used to reproduce this issue.

[rockys-spindance]

@SeanYang-7

Did you ever get a resolution for this issue? I see it was closed without being answered here.

We are seeing the same thing. In our case, the mbedtls rx buffer allocation fails because the largest free block in the heap is not large enough. Here's a log snippet

I (61013) Dynamic Impl: >>>>-------------------------- Before mbedtls_calloc in esp_mbedtls_add_rx_buffer Free heap: 44636. Min ever: 15960 largest free block: 16384
E (61013) Dynamic Impl: esp_mbedtls_add_rx_buffer alloc(16749 bytes) failed

So it's not a mystery for us why that allocation fails. What is a mystery is why we keep hitting this same error even if we free up other memory and increase our starting heap size.

Any insight you can share?

[chegewara]

@rockys-spindance the logs are clear
largest free block: 16384
and
alloc(16749 bytes) failed