RAM usage for mbedtls

[kolban]

I am trying to utilize mbedtls in an ESP32 application by when I call "mbedtls_ssl_setup" it is throwing an exception:

Code: Select all

E (296405) ssl: error from mbedtls_ssl_setup: -32512 - ffff8100 - SSL - Memory allocation failed

Prior to calling this function I performed a log of the free heap and I had 26K available.

Do we have any indication of how much RAM utilizing mbedtls needs?

Back story: I am working on a leveraging some large and meaty 3rd party libraries in my project and they consume large amounts of RAM. This leaves me about 20K-50K of RAM in which to do the rest of my work. I got stymied trying to use Bluetooth in this environment and now may be stymied using SSL too. It might be useful for us to capture "anticipated" RAM needs for each of our modules so that we can know sooner than later the "cost" of using those components.

[WiFive]

I think 32-35kB with default configuration in menuconfig.

Better get the new module with external ram

[kolban]

Howdy @WiFive,
Oooh ... what is this "external RAM" of which you speak? Is there an option coming to have more RAM that than 512K?

[ESP_Angus]

External RAM module is not quite available yet, but it will be soon.

In the meantime, there's a couple of things you can try:

- The latest esp-idf master (since 189543f317d7f6ac4604856bbcf4c9861afb6bd2) uses less static RAM. So you might find it helps.

- Under menuconfig Components -> mbedTLS you can set "TLS maximum message content length". The default is 16KB, and will allocate double this in RAM (RX & TX buffer) for a 32KB overhead. A 16KB message size is required for TLS specification compliance (unless the server implements the Maximum Fragment Length Negotiation Extension). However, even without this extension, if the server never sends more than a certain length of data in one TLS message, it's safe to shrink this buffer. Try around 4KB-8KB to start with. There are some additional details on the help screen in menuconfig (select the item and press '?').

[WiFive]

Howdy @WiFive,
Oooh ... what is this "external RAM" of which you speak? Is there an option coming to have more RAM that than 512K?

http://esp32.com/viewtopic.php?f=2&t=826

[snahmad75]

This is my detail log. Https crash dump. when I send Https post request to my esp32.
I am tried setting 4k for TLS maximum message content length as well. I have only on board 512 kb ram.
Have any one managed to use Https server without external ram. Kindly reply please. I am stuck.


on start ram usage
Stack free: 2688
Internal Heap free: 339476
Heap free: 266492:339476
on start free heap=266492
D (6297) nvs: nvs_erase_key serial_num

D (6301) CPPNVS: >> set: key: serial_num, u32: value=456
D (6306) nvs: nvs_set serial_num 4 456
D (6310) CPPNVS: << set
D (6312) nvs: nvs_get serial_num 4
serial num=456
I (6317) sd_card: Using SPI peripheral
D (6321) sdspi_host: sdspi_host_init_slot: SPI2 miso=2 mosi=15 sck=14 cs=13 cd
=-1 wp=-1, dma_ch=1
D (6330) spi: SPI1 use gpio matrix.
V (6334) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (6340) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting f
lags 0x80E
D (6348) intr_alloc: Connected src 30 to int 12 (cpu 0)
D (6354) spi_master: SPI1: New device added to CS0, effective clock: 400kHz
I (6361) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pul
ldown: 0| Intr:0
D (6370) sdmmc_cmd: sdmmc_card_init
V (6374) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 d
atalen=0 timeout=1000
V (6383) sdspi_host: sdspi_host_start_command: slot=1, CMD0, arg=0x00000000 fl
ags=0x4, data=0x0, data_size=0 crc=0x4a
V (6394) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0xffffffff
V (6399) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 s
tate=0
V (6427) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 d
atalen=0 timeout=1000
V (6427) sdspi_host: sdspi_host_start_command: slot=1, CMD0, arg=0x00000000 fl
ags=0x4, data=0x0, data_size=0 crc=0x4a
V (6436) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0xffffffff
V (6441) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 s
tate=0
V (6469) sdmmc_cmd: sending cmd slot=1 op=8 arg=1aa flags=1c30 data=0x0 blklen
=0 datalen=0 timeout=1000
V (6469) sdspi_host: sdspi_host_start_command: slot=1, CMD8, arg=0x000001aa fl
ags=0x20, data=0x0, data_size=0 crc=0x43
V (6478) sdspi_transaction: r1 = 0x00 hw_cmd.r[0]=0x00000000
V (6483) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 s
tate=0
D (6491) sdmmc_cmd: sdmmc_send_cmd_send_if_cond: received=0x0 expected=0xaa
E (6498) sdmmc_cmd: sdmmc_card_init: send_if_cond (1) returned 0x108
D (6505) vfs_fat_sdmmc: sdmmc_card_init failed 0x(108)
V (6511) intr_alloc: esp_intr_free: Disabling int, killing handler
E (6517) sd_card: Failed to initialize the card (264). Make sure SD card lines
have pull-up resistors in place.
D (6528) WiFi: >> setWifiEventHandler: 0x1073473328
D (6532) WiFi: << setWifiEventHandler
D (6536) WiFi: >> connectAP
D (6540) nvs: nvs_open_from_partition misc 1
D (6544) nvs: nvs_get_str_or_blob log
I (6547) wifi: wifi firmware version: ebd3e5d
I (6551) wifi: config NVS flash: enabled
I (6555) wifi: config nano formating: disabled
I (6559) system_api: Base MAC address is not set, read default base MAC addres
s from BLK0 of EFUSE
I (6569) system_api: Base MAC address is not set, read default base MAC addres
s from BLK0 of EFUSE
D (6578) nvs: nvs_open_from_partition nvs.net80211 1
D (6583) nvs: nvs_get opmode 1
D (6587) nvs: nvs_get_str_or_blob sta.ssid
D (6591) nvs: nvs_get_str_or_blob sta.mac
D (6595) nvs: nvs_get sta.authmode 1
D (6598) nvs: nvs_get_str_or_blob sta.pswd
D (6603) nvs: nvs_get_str_or_blob sta.pmk
D (6607) nvs: nvs_get sta.chan 1
D (6610) nvs: nvs_get auto.conn 1
D (6613) nvs: nvs_get bssid.set 1
D (6617) nvs: nvs_get_str_or_blob sta.bssid
D (6621) nvs: nvs_get sta.phym 1
D (6624) nvs: nvs_get sta.phybw 1
D (6628) nvs: nvs_get_str_or_blob sta.apsw
D (6632) nvs: nvs_get_str_or_blob sta.apinfo
D (6637) nvs: nvs_get sta.scan_method 1
D (6640) nvs: nvs_get sta.sort_method 1
D (6644) nvs: nvs_get sta.minrssi 1
D (6648) nvs: nvs_get sta.minauth 1
D (6651) nvs: nvs_get_str_or_blob ap.ssid
D (6655) nvs: nvs_get_str_or_blob ap.mac
D (6659) nvs: nvs_get_str_or_blob ap.passwd
D (6663) nvs: nvs_get_str_or_blob ap.pmk
D (6667) nvs: nvs_get ap.chan 1
D (6671) nvs: nvs_get ap.authmode 1
D (6674) nvs: nvs_get ap.hidden 1
D (6678) nvs: nvs_get ap.max.conn 1
D (6681) nvs: nvs_get bcn.interval 2
D (6685) nvs: nvs_get ap.phym 1
D (6688) nvs: nvs_get ap.phybw 1
D (6691) nvs: nvs_get ap.sndchan 1
D (6695) nvs: nvs_set_blob sta.mac 6
D (6699) nvs: nvs_set_blob ap.mac 6
I (6703) wifi: Init dynamic tx buffer num: 32
I (6706) wifi: Init data frame dynamic rx buffer num: 32
I (6711) wifi: Init management frame dynamic rx buffer num: 32
I (6717) wifi: wifi driver task: 3ffc235c, prio:23, stack:4096
I (6722) wifi: Init static rx buffer num: 10
I (6726) wifi: Init dynamic rx buffer num: 32
I (6730) wifi: wifi power manager task: 0x3ffc6fac prio: 21 stack: 2560
D (6737) RTC_MODULE: Wi-Fi takes adc2 lock.
D (6741) phy_init: loading PHY init data from application binary
D (6747) nvs: nvs_open_from_partition phy 0
D (6751) nvs: nvs_get cal_version 4
V (6755) phy_init: phy_get_rf_cal_version: 383

D (6759) nvs: nvs_get_str_or_blob cal_mac
D (6764) nvs: nvs_get_str_or_blob cal_data
D (6769) nvs: nvs_close 4
V (6770) phy_init: register_chipv7_phy, init_data=0x3f433544, cal_data=0x3ffc7
1e0, mode=0
I (6830) phy: phy_version: 383.0, 79a622c, Jan 30 2018, 15:38:06, 0, 0
I (6832) wifi: mode : sta (30:ae:a4:3a:d4:a4)
D (6833) event: SYSTEM_EVENT_STA_START
V (6834) event: enter default callback
V (6838) tcpip_adapter: check: local, if=0 fn=0x400e377c

V (6844) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (6849) tcpip_adapter: check: remote, if=0 fn=0x400e377c

V (6855) event: exit default callback
D (6859) WiFiEventHandler: >> getEventHandler()
D (6863) WiFiEventHandler: << getEventHandler: 0x401127d0
D (6869) WiFiEventHandler: >> eventHandler called: ctx=0x3ffbe730, event=0x3ff
bfa70
staStart
V (6878) tcpip_adapter: check: local, if=0 fn=0x400e4290

V (6883) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (6889) tcpip_adapter: check: remote, if=0 fn=0x400e4290

tcpip_adapter_set_hostname with err=0
D (6898) FreeRTOS: Semaphore taking: name: ConnectFinished (0x3ffbe818), owner
: <N/A> for connectAP
D (6907) FreeRTOS: Semaphore taken: name: ConnectFinished (0x3ffbe818), owner
: connectAP
D (6915) WiFi: esp_wifi_connect
V (6920) FreeRTOS: Semaphore taking: name: ConnectFinished (0x3ffbe818), owner
: connectAP for connectAP
I (7644) wifi: n:6 2, o:1 0, ap:255 255, sta:6 2, prof:1
I (8301) wifi: state: init -> auth (b0)
I (8307) wifi: state: auth -> assoc (0)
I (8314) wifi: state: assoc -> run (10)
I (8384) wifi: connected with TP-LINK_3DE348, channel 6
D (8385) event: SYSTEM_EVENT_STA_CONNECTED, ssid:TP-LINK_3DE348, ssid_len:14,
bssid:e8:94:f6:3d:e3:48, channel:6, authmode:3
V (8390) event: enter default callback
V (8394) tcpip_adapter: check: local, if=0 fn=0x400e39c0

V (8399) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (8405) tcpip_adapter: check: remote, if=0 fn=0x400e39c0

V (8411) tcpip_adapter: check: local, if=0 fn=0x400e4004

D (8416) tcpip_adapter: dhcp client init ip/mask/gw to all-0
D (8422) tcpip_adapter: if0 start ip lost tmr: enter
D (8427) tcpip_adapter: if0 start ip lost tmr: no need start because netif=0x3
ffc7674 interval=30 ip=0
D (8438) tcpip_adapter: dhcp client start successfully
V (8441) tcpip_adapter: call api in lwip: ret=0x0, give sem
V (8447) tcpip_adapter: check: remote, if=0 fn=0x400e4004

V (8453) event: exit default callback
D (8456) WiFiEventHandler: >> getEventHandler()
D (8461) WiFiEventHandler: << getEventHandler: 0x401127d0
D (8466) WiFiEventHandler: >> eventHandler called: ctx=0x3ffbe730, event=0x3ff
bfa70
staConnected
D (9385) tcpip_adapter: if0 dhcpc cb
D (9385) tcpip_adapter: if0 ip changed=1
D (9385) event: SYSTEM_EVENT_STA_GOT_IP, ip:192.168.2.103, mask:255.255.255.0,
gw:192.168.2.254
V (9390) event: enter default callback
I (9394) event: sta ip: 192.168.2.103, mask: 255.255.255.0, gw: 192.168.2.254
V (9402) event: exit default callback
D (9406) WiFiEventHandler: >> getEventHandler()
D (9410) WiFiEventHandler: << getEventHandler: 0x401127d0
D (9416) WiFiEventHandler: >> eventHandler called: ctx=0x3ffbe730, event=0x3ff
bfa70
staGotIp
V (9424) FreeRTOS: Semaphore giving: name: ConnectFinished (0x3ffbe818), owner
: connectAP
D (9433) Task: >> runTask: taskName=Task
Info_getMainInfo
Enter UDPSender::open
Exit UDPSender::open
Enter TCPSocket::open(port=50152)
Exit TCPSocket::open
Enter TCPSocket::run
esp32_builder started
esp32_builder setup
after build free heap=122356
D (9455) Task: >> runTask: taskName=Task
D (9455) Task: >> runTask: taskName=Task
D (9457) Task: << runTask: taskName=Task
ApplicationTask::run builder=0x3FFC8D78
D (9465) http: Testing http ...
D (9476) HttpServer: >> start: port: 80, useSSL: 1
V (9480) FreeRTOS: Semaphore taking: name: ServerStarted (0x3ffdc4f4), owner:
<N/A> for start
V (9488) FreeRTOS: Semaphore taken: name: ServerStarted (0x3ffdc4f4), owner:
start
D (9496) HttpServer: << start
D (9498) Task: >> runTask: taskName=HttpServerTask
D (9500) Task: << runTask: taskName=Task
D (9505) Socket: >> setSSL: Yes
V (9519) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (9519) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting f
lags 0xE
D (9525) intr_alloc: Connected src 51 to int 12 (cpu 0)
D (9977) Socket: >> listen: port: 80, isDatagram: 0
D (9977) Socket: >> createSocket: isDatagram: 0
D (9980) Socket: << createSocket: sockFd: 4099
D (9980) Socket: >> setReuseAddress: 1
D (9985) Socket: << setReuseAddress
D (9987) Socket: >> bind: port=80, address=0x0
D (9994) Socket: << bind
D (9997) Socket: << listen
D (9997) HttpServerTask: Listening on port 80
D (10003) HttpServerTask: Waiting for new peer client
D (10008) Socket: >> accept: Accepting on 0.0.0.0 [80]; sockFd: 4099, using SS
L: 1
I (11315) wifi: pm start, type:0

ApplicationTask::run free heap=85664
tcpip_adapter_get_hostname(hostname=testing
ApplicationTask::run free heap=85664
tcpip_adapter_get_hostname(hostname=testing
D (34734) Socket: - accept: Received new client!: sockFd: 4100
D (34735) Socket: >> setSSL: Yes
D (35189) Socket: >> sslHandshake: sock: 4100
D (35193) Socket: - Reset complete
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6557: => han
dshake
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:4016: server
state: 0
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2416: => flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2428: <= flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:4016: server
state: 1
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2416: => flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2428: <= flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1190: => par
se client hello
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2208: => fet
ch input
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2366: in_lef
t: 0, nb_want: 5
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2390: in_lef
t: 0, nb_want: 5
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2391: ssl->f
_recv(_timeout)() returned 5 (-0xfffffffb)
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2403: <= fet
ch input
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1222: dumpin
g 'record header' (5 bytes)
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1222: 0000:
47 45 54 20 2f GET /
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c client
hello v3, message type: 71
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1238: bad cl
ient hello message
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6567: <= han
dshake
D (35339) Socket: mbedtls_ssl_handshake returned -30976


D (35345) Socket: DEBUG DEBUG
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6743: => rea
d
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6557: => han
dshake
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:4016: server
state: 1
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2416: => flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2428: <= flu
sh output
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1190: => par
se client hello
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2208: => fet
ch input
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2366: in_lef
t: 5, nb_want: 5
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:2403: <= fet
ch input
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1222: dumpin
g 'record header' (5 bytes)
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1222: 0000:
47 45 54 20 2f GET /
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c client
hello v3, message type: 71
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_srv.c:1238: bad cl
ient hello message
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6567: <= han
dshake
C:/Work/LibDev/esp32/esp-idf/components/mbedtls/library/ssl_tls.c:6788: mbedtl
s_ssl_handshake() returned -30976 (-0x7900)
D (35475) Socket: rc=-30976, MBEDTLS_ERR_SSL_WANT_READ=-26880
D (35481) Socket: << accept: sockFd: 4100
D (35487) HttpServerTask: HttpServer that was listening on port 80 has receive
d a new client connection; sockFd=4100
D (35495) HttpParser: >> parse: socket: fd: 4100
Guru Meditation Error: Core 0 panic'ed (InstrFetchProhibited)
. Exception was unhandled.
Core 0 register dump:
PC : 0x3ffb8610 PS : 0x00060d30 A0 : 0x801632b0 A1 : 0x
3ffe62b0
A2 : 0x3ffe7a90 A3 : 0x00000002 A4 : 0x3f4284f4 A5 : 0x
00001a57
A6 : 0x3ffb8610 A7 : 0x0000000a A8 : 0x80163671 A9 : 0x
3ffe6270
A10 : 0x3ffb8610 A11 : 0x00000002 A12 : 0x3f4284f4 A13 : 0x
00001a57
A14 : 0x3ffe62bc A15 : 0x00000014 SAR : 0x00000004 EXCCAUSE: 0x
00000014
EXCVADDR: 0x3ffb8610 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0x
ffffffff

Backtrace: 0x3ffb8610:0x3ffe62b0 0x401632ad:0x3ffe6500 0x40112f71:0x3ffe6520 0
x40113795:0x3ffe6550 0x40116699:0x3ffe65c0 0x40114222:0x3ffe6940 0x4010f605:0x
3ffe7150 0x40112bdc:0x3ffe82e0

[BuddyCasino]

I once worked around this issue by using BearSSL (see https://github.com/MrBuddyCasino/ESP32_Alexa/). You get ownership of the buffer, and thus don't have to copy. Its not trivial though, and I can't give any assistance.
Another option to safe memory is to not use a threading model, but an event reactor. This is IMHO much more sensible anyway on a MCU. I did a half-assed version of this myself, and I think MongooseOS follows that pattern as well. The ESP32 has really a lot of RAM, all those hacks shouldn't be necessary.

Simple fix: if you have control over the server side, def. try lowering buffer sizes via the "max fragment length" extension first.

[snahmad75]

Where to set this?
Simple fix: if you have control over the server side, def. try lowering buffer sizes via the "max fragment length" extension first.

[BuddyCasino]

That depends on the server you use, of course - nginx, apache, whatever. But OpenSSL only recently added support for that extension, so its possible that yours doesn't support it yet.

[snahmad75]

I was using port=80 instead 443 for https.

Now handshake successfully.

size_t Socket::receive(uint8_t* data, size_t length, bool exact) cause crash on http post data receive. Any suggestion.
see logs below.

s_ssl_read_record_layer() returned -29312 (-0x7280)
D (29204) Socket: rc=0, MBEDTLS_ERR_SSL_WANT_READ=-26880
D (29210) Socket: << accept: sockFd: 4100
D (29216) HttpServerTask: HttpServer that was listening on port 443 has receiv
ed a new client connection; sockFd=4100
D (29224) HttpParser: >> parse: socket: fd: 4100
Guru Meditation Error: Core 0 panic'ed (InstrFetchProhibited)