axTLS crashes when malloc fails

[retsifp]

Basic Infos

Hardware

Hardware: ESP-07
Core Version: 2.3.0

Description

I do an update just like in the examples, but sometimes, I get an error and the ESP reboots. Since it's not a permanent error, I think it might be a problem with the HTTPS connection.

By the way, I found another thing:
In Example Sketch httpUpdate.ino, there is the Line //t_httpUpdate_return ret = ESPhttpUpdate.update("https://server/file.bin");, but this won't work since there is no fingerprint given.

Settings in IDE

Module: Generic ESP8266 Module
Flash Size: 1 MB
CPU Frequency: 80 MHz
Flash Mode: DIO
Flash Frequency: ?40Mhz?
Upload Using: OTA
Reset Method: ?ck / nodemcu?

Sketch

#include <Arduino.h>

void setup() {

}

void loop() {
    update("firmware.ino.bin");
}

void update(const String& filename) {
    SPIFFS.end();
    t_httpUpdate_return ret = ESPhttpUpdate.update(String ("https://") + cfg_otaHost + "/" +  filename, getVersion(), cfg_sha1Fingerprint);
    switch(ret) {
    case HTTP_UPDATE_FAILED:
        Serial.printf("Update fehlgeschlagen (%d): %s", ESPhttpUpdate.getLastError(), ESPhttpUpdate.getLastErrorString().c_str());
        break;
    case HTTP_UPDATE_NO_UPDATES:
        Serial.println("Kein Update verfügbar.");
        break;
    case HTTP_UPDATE_OK:
        Serial.println("HTTP_UPDATE_OK");
        break;
    }
    SPIFFS.begin();
}

Debug Messages

Fatal exception 29(StoreProhibitedCause):
epc1=0x4000e1b2, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000004, depc=0x00000000

Exception (29):

epc1=0x4000e1b2 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000004 depc=0x00000000

ctx: cont 

sp: 3fff2340 end: 3fff2a20 offset: 01a0

>>>stack>>>

3fff24e0:  00000414 000010a5 000010a5 4023137f
...

Decoded Stack trace

0x4023137f: bi_int_multiply at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 353
0x40231518: regular_multiply at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 853
0x402317ca: bi_str_import at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 666
0x402107e8: SPIFFSFileImpl::name() const at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/spiffs_api.h line 365
0x40232326: bi_mod_power2 at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1468
0x40232581: ax_hmac_sha1 at /Users/igrokhotkov/e/axtls/e1/crypto/hmac.c line 100
0x402313e4: bi_int_multiply at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 366 (discriminator 1)
0x4023360d: SHA256_Process at /Users/igrokhotkov/e/axtls/e1/crypto/sha256.c line 124
0x4022f718: process_server_hello_done at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 327
:  (inlined by) do_clnt_handshake at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 97
0x4022fb19: send_server_hello at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_svr.c line 324
:  (inlined by) send_server_hello_sequence at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_svr.c line 259
:  (inlined by) do_svr_handshake at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_svr.c line 80
0x4020a7ab: SSLContext::read(unsigned char*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 517
:  (inlined by) WiFiClientSecure::read(unsigned char*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 311
0x4022f510: send_client_hello at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 245
:  (inlined by) do_client_connect at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 153
0x4022f8b8: process_cert_verify at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_svr.c line 480
0x401006f0: cont_run at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/cont.S line 75
0x4022f668: process_server_hello at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 281
:  (inlined by) do_clnt_handshake at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 89
0x4020a58c: ClientContext::read(char*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 517
0x4020ac4d: ax_port_read at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 540
0x40209fb2: ClientContext::_error(signed char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiServer.cpp line 159
:  (inlined by) ClientContext::_s_error(void*, signed char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/include/ClientContext.h line 324
0x4020afa1: WiFiServer::_s_accept(void*, tcp_pcb*, signed char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiServer.cpp line 159
0x4020b998: HTTPClient::sendHeader(char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x4020fb7b: String::concat(char const*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x4020c160: HTTPClient::begin(String) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x4020fd25: operator+(StringSumHelper const&, char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x4021063c: fs::DirImpl::~DirImpl() at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/FSImpl.h line 56
0x4020b847: HTTPClient::connect() at ?? line ?
0x4020c20e: std::unique_ptr   >::operator=(std::unique_ptr   >&&) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
:  (inlined by) HTTPClient::begin(String, String) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 112
0x4020905f: ESP8266HTTPUpdate::handleUpdate(HTTPClient&, String const&, bool) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266httpUpdate/src/ESP8266httpUpdate.cpp line 36
0x4010020c: _umm_free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1287
0x401008e0: __subsf3 at /home/igrokhotkov/xtensa/crosstool-NG/.build/src/gcc-4.8.2/libgcc/config/xtensa/ieee754-sf.S line 412
0x4020f0b3: Stream::readStringUntil(char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/Stream.cpp line 248
0x40209365: ESP8266WiFiGenericClass::hostByName(char const*, IPAddress&) at /home/thomas/.arduino15/packages/esp8266/tools/xtensa-lx106-elf-gcc/1.20.0-26-gb404fb9-2/xtensa-lx106-elf/include/c++/4.8.2/functional line 1954
0x4020fbfe: String::concat(int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x402076ab: Updater::update(String const&) at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/Updater.cpp line 20
0x40207e4b: loop at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/main.cpp line 115
0x4020ebd1: Print::printNumber(unsigned long, unsigned char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/Print.cpp line 188
0x4010020c: _umm_free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1287
0x401008e0: __subsf3 at /home/igrokhotkov/xtensa/crosstool-NG/.build/src/gcc-4.8.2/libgcc/config/xtensa/ieee754-sf.S line 412
0x4020fad0: String::init() at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
:  (inlined by) String::String(double, unsigned char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 110
0x40207c46: setup at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/main.cpp line 80
0x4021083c: SPIFFSFileImpl::write(unsigned char const*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/spiffs_api.h line 291
0x40100970: __mulsf3_aux at /home/igrokhotkov/xtensa/crosstool-NG/.build/src/gcc-4.8.2/libgcc/config/xtensa/ieee754-sf.S line 534

[retsifp]

I just did the same thing without SPIFFS but more debug output:

ssl/tls1.c:545 malloc 6864, left 18072
State:  sending Client Hello (1)
:wr
:sent 77
:ww
:rn 1362
:rd 5, 1362, 0
:rdi 1362, 5
:rd 80, 1362, 5
:rdi 1357, 80
State:  receiving Server Hello (2)
:rd 5, 1362, 85
:rdi 1277, 5
:rch 1362, 1362
:rch 2724, 103
:rd 1272, 1362, 90
:rdi 1272, 1272
:c 1272, 1362, 2827
:rd 1456, 1465, 0
:rdi 1362, 1362
:c 1362, 1362, 1465
:rdi 103, 94
State:  receiving Certificate (11)
crypto/bigint.c:1072 realloc 1028, left 13616
crypto/bigint.c:1072 realloc 2056, left 11456
crypto/bigint.c:1072 realloc 1028, left 7704
crypto/bigint.c:1072 realloc 2056, left 5544
:rd 5, 103, 94
:rdi 9, 5
:rd 4, 103, 99
:rdi 4, 4
:c0 4, 103
State:  receiving Server Hello Done (14)
crypto/bigint.c:1112 malloc 1028, left 3152
crypto/bigint.c:1112 malloc 1024, left 2208
crypto/bigint.c:1112 malloc 1032, left 1128
crypto/bigint.c:1072 realloc 1032 failed, left 1152
crypto/bigint.c:1072 realloc 1032, left 1152
Fatal exception 29(StoreProhibitedCause):
epc1=0x4000e1b2, epc2=0x00000000, epc3=0x00000000, excvaddr=0x00000200, depc=0x00000000

Exception (29):
epc1=0x4000e1b2 epc2=0x00000000 epc3=0x00000000 excvaddr=0x00000200 depc=0x00000000

ctx: cont 
sp: 3fff36b0 end: 3fff3d50 offset: 01a0

Stack decode:

0x4022c913: more_comps at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1072
0x4022caac: alloc at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1106
0x4022cea9: bi_clone at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 263
0x4022d8a1: bi_barrett at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1285
0x4022db15: bi_mod_power at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1414
0x4022c978: trim at /Users/igrokhotkov/e/axtls/e1/crypto/bigint.c line 1197
0x4022eba1: RSA_public at /Users/igrokhotkov/e/axtls/e1/crypto/rsa.c line 242
:  (inlined by) RSA_encrypt at /Users/igrokhotkov/e/axtls/e1/crypto/rsa.c line 276
0x4022acac: send_client_key_xchg at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 352
0x4022b0ad: do_clnt_handshake at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 109
0x40229265: DISPLAY_STATE at /Users/igrokhotkov/e/axtls/e1/ssl/tls1.c line 2047
0x4022aaa4: do_handshake at /Users/igrokhotkov/e/axtls/e1/ssl/tls1.c line 1481
:  (inlined by) basic_read at /Users/igrokhotkov/e/axtls/e1/ssl/tls1.c line 1357
0x4022ae4c: do_client_connect at /Users/igrokhotkov/e/axtls/e1/ssl/tls1_clnt.c line 154
0x401006f0: malloc at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1664
0x4022abfc: ssl_read at /Users/igrokhotkov/e/axtls/e1/ssl/tls1.c line 265
0x4020608c: WiFiClient::_s_connected(void*, void*, signed char) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClient.cpp line 327
0x402067f9: SSLContext::connect(ClientContext*, char const*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 517
:  (inlined by) WiFiClientSecure::_connectSSL(char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 279
0x4020591a: WiFiClient::connect(IPAddress, unsigned short) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClient.cpp line 327
0x40206cc5: WiFiClientSecure::connect(char const*, unsigned short) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266WiFi/src/WiFiClientSecure.cpp line 269
0x40207801: HTTPClient::connect() at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x4020bea8: String::changeBuffer(unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x40208108: HTTPClient::sendRequest(char const*, unsigned char*, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x4020c0a1: String::operator=(char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x4020c9bc: operator new[](unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/abi.cpp line 84
0x4020767f: HTTPClient::collectHeaders(char const**, unsigned int) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x402081b6: HTTPClient::GET() at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266HTTPClient/src/ESP8266HTTPClient.cpp line 197
0x402046ef: ESP8266HTTPUpdate::handleUpdate(HTTPClient&, String const&, bool) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266httpUpdate/src/ESP8266httpUpdate.cpp line 36
0x4010020c: _umm_free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1287
0x401008e0: free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1733
0x402049f5: ESP8266HTTPUpdate::update(String const&, String const&, String const&) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/libraries/ESP8266httpUpdate/src/ESP8266httpUpdate.cpp line 36
0x4020bf7a: String::String(char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x40202d4a: Updater::update(String const&) at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/Updater.cpp line 20
0x402034e3: loop at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/main.cpp line 115
0x4020af15: Print::write(char const*) at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/Print.cpp line 188
0x4010020c: _umm_free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1287
0x401008e0: free at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/umm_malloc/umm_malloc.c line 1733
0x4020be4c: String::~String() at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/WString.cpp line 519
0x402032de: setup at /tmp/buildf5d0cc7b1861a0df8f215d76407bddf1.tmp/sketch/main.cpp line 80
0x4020cbbc: loop_wrapper at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/core_esp8266_main.cpp line 56
0x40100970: cont_norm at /home/thomas/.arduino15/packages/esp8266/hardware/esp8266/2.3.0/cores/esp8266/cont.S line 109

[igrr]

Your log indicates that there is not enough RAM for the connection. It's 18072 bytes before the connection, which is too low for TLS handshake, especially if you aren't using 512 bit keys.
Ideally axTLS should detect out-of-RAM condition and bail out gracefully (i.e. return connection error). I'll look into this and see if this can be done.

[retsifp]

Thanks! So it should be enough as a "workaround" to store e.g. in the RTC that an update is available and then start the update just before I do my normal stuff (constructing objects ...)?
I'm using a 4096 bit key... 😅

[ed7coyne]

Also running in to this issue when trying to have two ssl connections open. How much memory would you expect a TLS handshake to take? We have ~21k available before we try the second connection and appear to be hitting this issue too.

[silbe]

FWIW, I've started modifying axtls to cope gracefully with allocation failures, but it's a lot of work (finished bigint.c yesterday, but only build tested so far) .

[liquidfalcon]

That's brilliant, @silbe - axTLS has been the bane of my existence developing for the ESP8266. The entire library is remarkably poor at checking for allocation failures, making it woefully unstable on these devices. I've spent some time tracking down the most common failures in the axTLS code, and have gotten it to be stable to about ~15 hours between failures sending a ~2K payload over TLS with ~34K of free heap before sending.

Please let me know once you have something working, as I'd love to contribute.

[silbe]

I've pushed my work-in-progress code (bigint.c only so far) to the 20161221-oom-fixes branch in the silbe/axtls-8266 repo. Been running it on several modules for several weeks without encountering any issue that I could trace back to it (after fixing one initial bug), though that doesn't mean too much given how often the modules "crash" for other reasons.
Feel free to use it as a base for further work. I'm not sure when I'll have time to continue working on it.
It's a rather fundamental change in the way axtls works. We should coordinate with the upstream axtls author.