- Tue Mar 24, 2020 8:06 am
#86179
Memory (heap) out after +100 TLS request with custom x509 root certificate
What to do to produce the error:
1 - Use ESP-IDF Example https_mbedtls
2 - Get root certificate of your server (self signed in my case) by using OpenSSL command: openssl s_client -showcerts -servername *.mydomain.com -connect MyServerIP:443 </dev/null 2>/dev/null|openssl x509 -outform PEM >/home/me/Desktop/server_root_cert.pem
3 - In menuconfig add custom certificate to the custom bundle CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE_PATH="/home/me/Desktop/server_root_cert.pem"
4 - Build the firmware and flash..
It's will work great, but on every request mbedTLS allocate around ~2000 bytes on handshake stage, so after around ~120 requests we get a out of memory warning.
Note: I get free heap size by using ESP_LOGW(TAG, "Free Heap: %d", esp_get_free_heap_size());
Monitor log
If you see the heap size, we lose ~2000 bytes on every requests.
The example work fine without custom certificate, this problem is only when adding custom x509 root certificate by menuconfig
Thank you,
What to do to produce the error:
1 - Use ESP-IDF Example https_mbedtls
2 - Get root certificate of your server (self signed in my case) by using OpenSSL command: openssl s_client -showcerts -servername *.mydomain.com -connect MyServerIP:443 </dev/null 2>/dev/null|openssl x509 -outform PEM >/home/me/Desktop/server_root_cert.pem
3 - In menuconfig add custom certificate to the custom bundle CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE_PATH="/home/me/Desktop/server_root_cert.pem"
4 - Build the firmware and flash..
It's will work great, but on every request mbedTLS allocate around ~2000 bytes on handshake stage, so after around ~120 requests we get a out of memory warning.
Note: I get free heap size by using ESP_LOGW(TAG, "Free Heap: %d", esp_get_free_heap_size());
Monitor log
Code: Select all
--- idf_monitor on /dev/ttyUSB1 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun 8 2016 00:22:57
rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7224
load:0x40078000,len:13092
load:0x40080400,len:3936
0x40080400: _init at ??:?
entry 0x40080688
I (28) boot: ESP-IDF v4.2-dev-701-g0ae960f2f-dirty 2nd stage bootloader
I (29) boot: compile time 15:53:08
I (30) boot: chip revision: 1
I (33) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (40) boot.esp32: SPI Speed : 40MHz
I (45) boot.esp32: SPI Mode : DIO
I (50) boot.esp32: SPI Flash Size : 2MB
I (54) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (63) boot: ## Label Usage Type ST Offset Length
I (70) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (78) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (85) boot: 2 factory factory app 00 00 00010000 00100000
I (93) boot: End of partition table
I (97) boot_comm: chip revision: 1, min. application chip revision: 0
I (104) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2e1c4 (188868) map
I (185) esp_image: segment 1: paddr=0x0003e1ec vaddr=0x3ffb0000 size=0x01e2c ( 7724) load
I (189) esp_image: segment 2: paddr=0x00040020 vaddr=0x400d0020 size=0x85194 (545172) map
0x400d0020: _stext at ??:?
I (399) esp_image: segment 3: paddr=0x000c51bc vaddr=0x3ffb1e2c size=0x01b18 ( 6936) load
I (402) esp_image: segment 4: paddr=0x000c6cdc vaddr=0x40080000 size=0x00404 ( 1028) load
0x40080000: _WindowOverflow4 at /home/me/Desktop/MY_FIRMWARE/SDK/ESP_IDF/components/freertos/xtensa/xtensa_vectors.S:1817
I (406) esp_image: segment 5: paddr=0x000c70e8 vaddr=0x40080404 size=0x14be4 ( 84964) load
I (463) boot: Loaded app from partition at offset 0x10000
I (463) boot: Disabling RNG early entropy source...
I (464) cpu_start: Pro cpu up.
I (467) cpu_start: Application information:
I (472) cpu_start: Project name: https-mbedtls
I (478) cpu_start: App version: 1
I (482) cpu_start: Compile time: Mar 23 2020 15:52:59
I (488) cpu_start: ELF file SHA256: 3e4cef9cc8901077...
I (494) cpu_start: ESP-IDF: v4.2-dev-701-g0ae960f2f-dirty
I (501) cpu_start: Starting app cpu, entry point is 0x40081280
0x40081280: call_start_cpu1 at /home/me/Desktop/MY_FIRMWARE/SDK/ESP_IDF/components/esp32/cpu_start.c:273
I (0) cpu_start: App cpu up.
I (511) heap_init: Initializing. RAM available for dynamic allocation:
I (518) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (524) heap_init: At 3FFB9530 len 00026AD0 (154 KiB): DRAM
I (531) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (537) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (543) heap_init: At 40094FE8 len 0000B018 (44 KiB): IRAM
I (550) cpu_start: Pro cpu start user code
I (568) spi_flash: detected chip: generic
I (569) spi_flash: flash io: dio
W (569) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (579) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (685) wifi:wifi driver task: 3ffc0e0c, prio:23, stack:3584, core=0
I (685) system_api: Base MAC address is not set
I (685) system_api: read default base MAC address from EFUSE
I (705) wifi:wifi firmware version: d76a2dd
I (705) wifi:config NVS flash: enabled
I (705) wifi:config nano formating: disabled
I (705) wifi:Init dynamic tx buffer num: 32
I (715) wifi:Init data frame dynamic rx buffer num: 32
I (715) wifi:Init management frame dynamic rx buffer num: 32
I (725) wifi:Init management short buffer num: 32
I (725) wifi:Init static rx buffer size: 1600
I (735) wifi:Init static rx buffer num: 10
I (735) wifi:Init dynamic rx buffer num: 32
I (745) example_connect: Connecting to my_wireless...
I (835) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (835) wifi:mode : sta (c4:4f:33:3e:c1:c5)
I (845) example_connect: Waiting for IP
I (965) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (965) wifi:state: init -> auth (b0)
I (965) wifi:state: auth -> assoc (0)
I (975) wifi:state: assoc -> run (10)
I (1005) wifi:connected with my_wireless, aid = 23, channel 1, BW20, bssid = b4:fb:e4:e5:41:c0
I (1005) wifi:security type: 3, phy: bgn, rssi: -65
I (1005) wifi:pm start, type: 1
I (1045) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (1675) esp_netif_handlers: sta ip: 192.168.165.191, mask: 255.255.255.0, gw: 192.168.165.1
I (1675) example_connect: Got IP event!
I (2675) example_connect: Got IPv6 event!
I (2675) example_connect: Connected to my_wireless
I (2675) example_connect: IPv4 address: 192.168.165.191
I (2675) example_connect: IPv6 address: fe80:0000:0000:0000:c64f:33ff:fe3e:xxxx
I (2685) example: Seeding the random number generator
I (2695) example: Attaching the certificate bundle...
I (2695) example: Setting hostname for TLS session...
I (2705) example: Setting up the SSL/TLS structure...
W (2715) example: Free Heap: 206168 <<----------------------------------------
I (2715) example: Connecting to 192.168.168.XX:443...
I (2735) example: Connected.
I (2735) example: Performing the SSL/TLS handshake...
I (2845) esp-x509-crt-bundle: Certificate validated
I (3795) example: Verifying peer X.509 certificate...
I (3795) example: Certificate verified.
I (3795) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (3805) example: Writing HTTP request...
I (3815) example: 103 bytes written
I (3815) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:04:51 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (3855) example: Completed 1 requests
I (3855) example: 10...
...
I (13855) example: 0...
I (14855) example: Starting again!
W (14855) example: Free Heap: 204212 <<----------------------------------------
I (14855) example: Connecting to 192.168.168.XX:443...
I (14865) example: Connected.
I (14865) example: Performing the SSL/TLS handshake...
I (14985) esp-x509-crt-bundle: Certificate validated
I (15935) example: Verifying peer X.509 certificate...
I (15935) example: Certificate verified.
I (15935) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (15945) example: Writing HTTP request...
I (15955) example: 103 bytes written
I (15955) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:05:03 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (15995) example: Completed 2 requests
I (15995) example: 10...
...
I (25995) example: 0...
I (26995) example: Starting again!
W (26995) example: Free Heap: 202984 <<----------------------------------------
I (26995) example: Connecting to 192.168.168.XX:443...
I (27005) example: Connected.
I (27005) example: Performing the SSL/TLS handshake...
I (27135) esp-x509-crt-bundle: Certificate validated
I (28115) example: Verifying peer X.509 certificate...
I (28125) example: Certificate verified.
I (28125) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (28125) example: Writing HTTP request...
I (28135) example: 103 bytes written
I (28135) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:05:15 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (28195) example: Completed 3 requests
I (28195) example: 10...
...
I (38195) example: 0...
I (39195) example: Starting again!
W (39195) example: Free Heap: 201760 <<----------------------------------------
I (39195) example: Connecting to 192.168.168.XX:443...
I (39205) example: Connected.
I (39205) example: Performing the SSL/TLS handshake...
I (39325) esp-x509-crt-bundle: Certificate validated
I (40315) example: Verifying peer X.509 certificate...
I (40315) example: Certificate verified.
I (40315) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (40325) example: Writing HTTP request...
I (40325) example: 103 bytes written
I (40335) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:05:27 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (40365) example: Completed 4 requests
I (40365) example: 10...
...
I (50375) example: 0...
I (51375) example: Starting again!
W (51375) example: Free Heap: 200532 <<----------------------------------------
I (51375) example: Connecting to 192.168.168.XX:443...
I (51385) example: Connected.
I (51385) example: Performing the SSL/TLS handshake...
I (51525) esp-x509-crt-bundle: Certificate validated
I (52545) example: Verifying peer X.509 certificate...
I (52545) example: Certificate verified.
I (52545) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (52545) example: Writing HTTP request...
I (52555) example: 103 bytes written
I (52555) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:05:39 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (52595) example: Completed 5 requests
I (52595) example: 10...
...
I (62595) example: 0...
I (63595) example: Starting again!
W (63595) example: Free Heap: 199308 <<----------------------------------------
I (63595) example: Connecting to 192.168.168.XX:443...
I (63605) example: Connected.
I (63605) example: Performing the SSL/TLS handshake...
I (63715) esp-x509-crt-bundle: Certificate validated
I (64705) example: Verifying peer X.509 certificate...
I (64705) example: Certificate verified.
I (64705) example: Cipher suite is TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
I (64705) example: Writing HTTP request...
I (64715) example: 103 bytes written
I (64715) example: Reading HTTP response...
HTTP/1.1 200 OK
Date: Tue, 24 Mar 2020 12:05:52 GMT
Server: Apache/2.4.37 (centos) OpenSSL/1.1.1c mod_fcgid/2.3.9
Last-Modified: Thu, 12 Mar 2020 18:08:25 GMT
ETag: "15-xxxx"
Accept-Ranges: bytes
Content-Length: 21
Connection: close
Content-Type: text/html; charset=UTF-8
<html>...</html>
I (64755) example: Completed 6 requests
I (64755) example: ...If you see the heap size, we lose ~2000 bytes on every requests.
Code: Select all
W (2715) example: Free Heap: 206168
W (14855) example: Free Heap: 204212
W (26995) example: Free Heap: 202984
W (39195) example: Free Heap: 201760
W (51375) example: Free Heap: 200532
W (63595) example: Free Heap: 199308The example work fine without custom certificate, this problem is only when adding custom x509 root certificate by menuconfig
Code: Select all
#
# Certificate Bundle
#
CONFIG_MBEDTLS_CERTIFICATE_BUNDLE=y
CONFIG_MBEDTLS_CERTIFICATE_BUNDLE_DEFAULT_FULL=y
# CONFIG_MBEDTLS_CERTIFICATE_BUNDLE_DEFAULT_CMN is not set
# CONFIG_MBEDTLS_CERTIFICATE_BUNDLE_DEFAULT_NONE is not set
CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE=y
CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE_PATH="/home/me/Desktop/server_root_cert.pem"
# end of Certificate BundleThank you,
Last edited by saif_iot on Thu Mar 26, 2020 5:13 pm, edited 1 time in total.
