me-no-dev / ESPAsyncWebServer

Async Web Server for ESP8266 and ESP32
3.71k stars 1.21k forks source link

Crash (heap corruption) when rapidly refreshing the web page #394

Closed me21 closed 4 years ago

me21 commented 6 years ago

I've constructed an example which shows the crashes. Just connect to the ESP32 access point, open its default web page in browser, and hit F5 several times rapidly. You should see a crash like this: CORRUPT HEAP: Bad head at 0x3f801240. Expected 0xabba1234 got 0x3f801334<CR><LF> assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c", line 205, function: multi_heap_free.

I have attached the project which should trigger the bug. I use ESP32-WROVER for this, if it matters.

espasyncwebserverissue.zip

me21 commented 6 years ago

Some stack traces:

stack:
0x40091848: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x40091a4b: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x400dd12f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x40091515: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c:306
0x400868e2: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x40088aa5: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c:42
0x400ffd96: tcp_close_shutdown at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c:835
0x400ffe5e: tcp_close at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c:835
0x4012bb4d: _tcp_close_api(tcpip_api_call*) at AsyncTCP.cpp:?
0x400fca19: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/api/tcpip.c:474
stack:
0x40091848: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x40091a4b: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x400dd12f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x4009156d: multi_heap_realloc at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c:306
0x40086948: heap_caps_realloc at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x400869a6: heap_caps_realloc_default at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x40088ab5: _realloc_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c:47
0x400d9282: String::changeBuffer(unsigned int) at ??:?
0x400d92e5: String::reserve(unsigned int) at ??:?
0x400d9456: String::concat(char const*, unsigned int) at ??:?
0x400d9499: String::concat(char const*) at ??:?
0x400d56b5: AsyncWebServerRequest::_onData(void*, unsigned int) at ??:?
0x400d5945: std::_Function_handler<void (void*, AsyncClient*, void*, unsigned int), AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*, void*, unsigned int)#7}>::_M_invoke(std::_Any_data const&, void*&&, AsyncClient*&&, std::_Any_data const&, unsigned int&&) at WebRequest.cpp:?
0x4012c1a5: AsyncClient::_recv(tcp_pcb*, pbuf*, signed char) at ??:?
0x4012c411: _async_service_task(void*) at AsyncTCP.cpp:?
stack:
0x40091848: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x40091a4b: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x400dd12f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x40091515: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c:306
0x400868e2: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x40088aa5: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c:42
0x400d9252: String::~String() at ??:?
0x400d6a6d: AsyncWebServerResponse::~AsyncWebServerResponse() at ??:?
0x400d6a7e: AsyncWebServerResponse::~AsyncWebServerResponse() at ??:?
0x400d5dc2: AsyncWebServerRequest::~AsyncWebServerRequest() at ??:?
0x400d7d6d: AsyncWebServer::_handleDisconnect(AsyncWebServerRequest*) at ??:?
0x400d36d2: AsyncWebServerRequest::_onDisconnect() at ??:?
0x400d36e1: std::_Function_handler<void (void*, AsyncClient*), AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*)#5}>::_M_invoke(std::_Any_data const&, void*&&, AsyncClient*&&) at WebRequest.cpp:?
0x4012c056: std::function<void (void*, AsyncClient*)>::operator()(void*, AsyncClient*) const at ??:?
0x4012c337: AsyncClient::_error(signed char) at ??:?
0x4012c447: _async_service_task(void*) at AsyncTCP.cpp:?
me21 commented 6 years ago

Firefox 61.0.1 x64 doesn't cause crashes, whereas Chrome 68.0.3440.84 x64 does.

me-no-dev commented 6 years ago

First and last seem to be related to trying to free something that is already freed, though the second one looks similar. Could be related to “Connection: close” header for web sockets

me21 commented 6 years ago

Could you please tell more details? Can I fix it as a user of the library, or it's you who should fix it?

There is no active websocket in the example, by the way, although the browser tries to connect it. I will try to remove it from the webpage code and report back.

me21 commented 6 years ago

No difference after removing websocket code from stored web page.

I've noticed that "Connection: close" is sent with every response, not just web sockets. Is it a problem?

me21 commented 6 years ago

Looks like a duplicate of #324. But I'm not sure.

me-no-dev commented 6 years ago

pull the latest changes for AsyncTCP and the WebServer. I just pushed a probable fix for all of those errors

emptynick commented 6 years ago

Looks a bit better, but still throwing the exception from time to time:

CORRUPT HEAP: Bad head at 0x3ffdf6c8. Expected 0xabba1234 got 0x3ffdf79c
assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning
.c", line 205, function: multi_heap_free
abort() was called at PC 0x400ecb7f on core 0

Backtrace: 0x4009034c:0x3ffb7080 0x4009054f:0x3ffb70a0 0x400ecb7f:0x3ffb70c0 0x40090019:0x3ffb70f0 0x4008534e:0x3ffb7110 0x4
0087515:0x3ffb7130 0x4000bec7:0x3ffb7150 0x4010e99a:0x3ffb7170 0x4010ea62:0x3ffb7190 0x4013ba6d:0x3ffb71b0 0x4010a9a9:0x3ffb
71d0

Decoded

Decoding 11 results
0x400ecb7f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c line 63 (discriminator 8)
0x4009034c: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 649
0x4009054f: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 649
0x400ecb7f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c line 63 (discriminator 8)
0x40090019: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c line 306
0x4008534e: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c line 123
0x4010e99a: tcp_close_shutdown at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c line 225
0x4010ea62: tcp_close at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c line 305
0x4013ba6d: _tcp_close_api(tcpip_api_call*) at AsyncTCP.cpp line ?
0x4010a9a9: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/api/tcpip.c line 474

One thing I noticed: After it crashed once I cant get it to crash again. Am I seeing things?

me-no-dev commented 6 years ago

it's just really hard to crash it. I know why it happens but I don't have a final fix yet... if you use the server normally, all is fine. Crashes when you refresh your browser while it's loading (that causes premature closing of connections and opening new ones)

bbasil2012 commented 6 years ago

It seems that it works better than before. Uptime is more than 1 hour

bbasil2012 commented 6 years ago

3 hours of uptime and crash: CORRUPT HEAP: Bad head at 0x3ffe1c70. Expected 0xabba1234 got 0x3ffe1ccc assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/./multi_heap_poisoning.c", line 199, function: multi_heap_free abort() was called at PC 0x400e8e53 on core 1

Backtrace: 0x4008888c:0x3ffd9e70 0x4008898b:0x3ffd9e90 0x400e8e53:0x3ffd9eb0 0x400885b5:0x3ffd9ee0 0x40084306:0x3ffd9f00 0x40084889:0x3ffd9f20 0x4000bec7:0x3ffd9f40 0x40105ff1:0x3ffd9f60 0x401060b3:0x3ffd9f80 0x400de7cd:0x3ffd9fa0 0x40102675:0x3ffd9fc0

Rebooting...

me-no-dev commented 6 years ago

please decode any backtrace that you post ;)

I am still hunting causes for bad heap... I am getting to the point where they make no sense... I am checking everything for accessing already freed resources (that is usually what causes the above) but i am starting to fail. There are a few fixes to both AsyncTCP and the WebServer, make sure you have them all :)

emptynick commented 6 years ago

Dont know if its helpful for you that we post more and more exceptions, but here you go:

Guru Meditation Error: Core  1 panic'ed (StoreProhibited). Exception was unhandled.
Core 1 register dump:
PC      : 0x4016326f  PS      : 0x00060830  A0      : 0x8013b821  A1      : 0x3ffde670
A2      : 0x02a40742  A3      : 0x00000000  A4      : 0x00060820  A5      : 0x3ffde710
A6      : 0x3ffe0c98  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x3ffde680
A10     : 0x3ffd4fc8  A11     : 0x3ffdfa54  A12     : 0x4c400000  A13     : 0x00000000

A14     : 0x00000000  A15     : 0x00000001  SAR     : 0x0000000a  EXCCAUSE: 0x0000001d
EXCVADDR: 0x02a40772  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff

Backtrace: 0x4016326f:0x3ffde670 0x4013b81e:0x3ffde690 0x4013bb1c:0x3ffde6d0 0x4013bb8f:0x3ffde700

Decoded

0x4016326f: tcp_arg at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c line 1652
0x4016326f: tcp_arg at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c line 1652
0x4013b81e: AsyncClient::_close() at ?? line ?
0x4013bb1c: AsyncClient::_poll(tcp_pcb*) at ?? line ?
0x4013bb8f: _async_service_task(void*) at AsyncTCP.cpp line ?
me21 commented 6 years ago

Is it possible that the heap is already silently corrupted earlier and the backtrace doesn't show the root cause? Also, is it possible that ESP32 memory manager is not thread safe? Then you cannot fix it at library level :(

me-no-dev commented 6 years ago

I went back and fourth and covered everything that I can come up with. Given that exceptions happen even when running normal web server code (no web sockets or service events) and given that the server runs in a single thread... I am totally out of ideas. I double checked, triple checked... nothing if freed twice or accessed after free, so why the corruption...? Poked @igrr for ideas (no response yet)... no idea where to go next... I have traced JTAGed and done everything i can come up so far to try and figure out what chain of events might cause this... nothing. BTW when I use the server normally (no crazy reloads or else) everything is fine. I can see how there can be some issues with the web sockets and I will patch those down the line, but the web server itself... i see nothing

me-no-dev commented 6 years ago

BTW I could not crash the server for pages that run from flash (progmem and not spiffs)

me21 commented 6 years ago

Thanks, that's an interesting idea! I will check and report back. Maybe it's SPIFFS who corrupts the heap, and web server is just poor victim.

bbasil2012 commented 6 years ago

I communicate with the server rendered as chrome app. This chorme-app communicate with the server only through rest-api SPIFS is used only at startup to read configuration files. Thus, the server does not serve any files located on the SPIFS via http But it is still crashes ...

me-no-dev commented 6 years ago

@bbasil2012 this with the latest tcp and server libs?

bbasil2012 commented 6 years ago

@me-no-dev Yes

me21 commented 6 years ago

I've found the following paragraph at https://arduino-esp8266.readthedocs.io/en/latest/faq/a02-my-esp-crashes.html

Asynchronous Callbacks Asynchronous CBs, such as for the Ticker or ESPAsync* libs, have looser restrictions than ISRs, but some restrictions still apply. It is not possible to execute delay() or yield() from an asynchronous callback. Timing is not as tight as an ISR, but it should remain below a few milliseconds. This is a guideline. The hard timing requirements depend on the WiFi configuration and amount of traffic. In general, the CPU must not be hogged by the user code, as the longer it is away from servicing the WiFi stack, the more likely that memory corruption can happen.

Wait, so the memory corruption can happen by simply staying too long in the asynchronous callback??

Or this applies to ESP8266 only, and not to ESP32?

HenrikSte commented 6 years ago

Folks,

(I am totally new to github - bear with me, willing to learn)

I am getting a similar (same?) issue with an almost unmodified example code. I do not need to run the refresh at high speed, once every 3 seconds is enough to get it to eventually crash.

//
// A simple server implementation showing how to:
//  * serve static messages
//  * read GET and POST parameters
//  * handle missing pages / 404s
//

#include <FreeRTOS.h>
#include <AsyncTCP.h>
//#include <Hash.h>
#include <ESPAsyncWebServer.h>
AsyncWebServer server(80);

const char* ssid = "MSIDEMO";
const char* password = "msitest123";

const char* PARAM_MESSAGE = "message";

void notFound(AsyncWebServerRequest *request) {
    request->send(404, "text/plain", "Not found");
}

void setup() {

    Serial.begin(115200);
    WiFi.mode(WIFI_STA);

    IPAddress _ip,_gw,_sn;
    _ip.fromString("192.168.150.252");
    _gw.fromString("10.0.1.1");
    _sn.fromString("255.255.255.0"); 

    Serial.println(F("Connecting as wifi client..."));

  // check if we've got static_ip settings, if we do, use those.
    WiFi.config(_ip, _gw, _sn);
    WiFi.begin(ssid, password);
    if (WiFi.waitForConnectResult() != WL_CONNECTED) {
        Serial.printf("WiFi Failed!\n");
        return;
    }

    Serial.print("IP Address: ");
    Serial.println(WiFi.localIP());
    Serial.print("Hostname: ");
    Serial.println(WiFi.getHostname());

    server.on("/", HTTP_GET, [](AsyncWebServerRequest *request){
        request->send(200, "text/plain", "Hello, world");
    });

    // Send a GET request to <IP>/get?message=<message>
    server.on("/get", HTTP_GET, [] (AsyncWebServerRequest *request) {
        String message;
        if (request->hasParam(PARAM_MESSAGE)) {
            message = request->getParam(PARAM_MESSAGE)->value();
        } else {
            message = "No message sent";
        }
        request->send(200, "text/plain", "Hello, GET: " + message);
    });

    // Send a POST request to <IP>/post with a form field message set to <message>
    server.on("/post", HTTP_POST, [](AsyncWebServerRequest *request){
        String message;
        if (request->hasParam(PARAM_MESSAGE, true)) {
            message = request->getParam(PARAM_MESSAGE, true)->value();
        } else {
            message = "No message sent";
        }
        request->send(200, "text/plain", "Hello, POST: " + message);
    });

    server.on("/GetNextMessage", HTTP_GET, [](AsyncWebServerRequest *request){
      if (request)
      {
        Serial.print("GetNextMessage");
        String response;
        //toggleLED();
        response = "<NoMessage/>";
        request->send(200, "text/plain", response);
      }
      else
      {
        Serial.println("request is NULL");
      }
      Serial.println(".");

    });

    server.onNotFound(notFound);

    server.begin();
}

void loop() {
}

Some of my exceptions:

Exception Cause: Not found

0x4013a1e7: AsyncServer::_accept(tcp_pcb*, signed char) at ??:?
0x4000c349: ?? ??:0
0x4000c36b: ?? ??:0
0x4013a1e7: AsyncServer::_accept(tcp_pcb*, signed char) at ??:?
0x4013a2b0: AsyncServer::_s_accept(void*, tcp_pcb*, signed char) at ??:?
0x40109cf9: tcp_process at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp_in.c:792 (discriminator 1)
0x4010a7ed: tcp_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp_in.c:357
0x4010f38e: ip4_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/ipv4/ip4.c:711
0x40115df6: ethernet_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/netif/ethernet.c:176
0x40103bf9: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/api/tcpip.c:474

(this one is rare, the other are the ususal ones)

Exception Cause: Not found

0x400da19f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x4008f6f4: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x4008f8f7: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x400da19f: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x4008f3c1: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c:306
0x40084782: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x40086949: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c:42
0x4000bec7: ?? ??:0
0x400f3bde: tcp_close_shutdown at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c:835
0x400f3ca6: tcp_close at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c:835
0x4011f7c9: _tcp_close_api(tcpip_api_call*) at AsyncTCP.cpp:?
0x400f0875: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/api/tcpip.c:474
Exception Cause: Not found

0x4011fdc7: AsyncServer::_accept(tcp_pcb*, signed char) at ??:?
0x4000c349: ?? ??:0
0x4000c36b: ?? ??:0
0x4011fdc7: AsyncServer::_accept(tcp_pcb*, signed char) at ??:?
0x4011fe90: AsyncServer::_s_accept(void*, tcp_pcb*, signed char) at ??:?
0x400f5975: tcp_process at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp_in.c:792 (discriminator 1)
0x400f6469: tcp_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp_in.c:357
0x400fafde: ip4_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/ipv4/ip4.c:711
0x40100e02: ethernet_input at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/netif/ethernet.c:176
0x400f089d: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/api/tcpip.c:474
0x400da29b: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x4008f6f4: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x4008f8f7: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c:649
0x400da29b: __assert_func at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdlib/../../../.././newlib/libc/stdlib/assert.c:63 (discriminator 8)
0x4008eb03: get_next_block at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap.c:377
 (inlined by) assert_valid_block at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap.c:164
0x4008ee53: multi_heap_free_impl at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap.c:377
0x4008f3ca: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c:306
0x40084782: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c:123
0x40086949: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c:42
0x4000bec7: ?? ??:0
0x401200f3: _async_service_task(void*) at AsyncTCP.cpp:?
HenrikSte commented 6 years ago

One additional note: sometimes I get a different behavior. Not sure if that has the same cause...

E (23754) wifi: lmac.c lmacProcessTxRtsError 1637

Task watchdog got triggered. The following tasks did not reset the watchdog in time:
 - IDLE (CPU 0)
Tasks currently running:
CPU 0: wifi
CPU 1: loopTask
Task watchdog got triggered. The following tasks did not reset the watchdog in time:
 - IDLE (CPU 0)
Tasks currently running:
CPU 0: wifi
CPU 1: loopTask
Task watchdog got triggered. The following tasks did not reset the watchdog in time:
 - IDLE (CPU 0)
Tasks currently running:
CPU 0: wifi
CPU 1: loopTask

[ repeating forever]
acris5 commented 6 years ago

Also got many errors while serving page with many resources from SPIFFS and rapidly refreshing ajax:

Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.

CORRUPT HEAP: Bad head at 0x3ffbfdbc. Expected 0xabba1234 got 0x3ffbfef8
assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c", line 205, function: multi_heap_free
abort() was called at PC 0x400e3e8f on core 1

Backtrace: 0x4008f7d8:0x3ffb6900 0x4008f9db:0x3ffb6920 0x400e3e8f:0x3ffb6940 0x4008f4a5:0x3ffb6970 0x40084866:0x3ffb6990 0x40086a2d:0x3ffb69b0 0x4000bec7:0x3ffb69d0 0x40109bea:0x3ffb69f0 0x40109cb2:0x3ffb6a10 0x40150825:0x3ffb6a30 0x40105cf1:0x3ffb6a50

tcp_close_shutdown + 306 in section .flash.text
(gdb) info symbol 0x40109cb2
tcp_close + 26 in section .flash.text
(gdb) info symbol 0x40150825
_tcp_close_api(tcpip_api_call*) + 5 in section .flash.text
(gdb) info symbol 0x4015082
No symbol matches 0x4015082.
(gdb) info symbol 0x40105cf1
tcpip_thread + 81 in section .flash.text

Most of errors gone when uncommented: #define DEBUGF(...) Serial.printf(__VA_ARGS__)

but still have problem uploading multipart data with HTTP_POST request (only get first three parts of data than fails)

server.on("/update.cgi", HTTP_POST, [](AsyncWebServerRequest *request) {},
        [](AsyncWebServerRequest *request, const String filename, size_t index, uint8_t *data, size_t len, bool final){}, 
        HTTPExecutePostUpdate);
UPDATE: len, index ,total
1436 0 79788
UPDATE: len, index ,total
1436 1436 79788
UPDATE: len, index ,total
1436 2872 79788

assertion "new_rcv_ann_wnd <= 0xffff" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/core/tcp.c", line 630, function: tcp_update_rcv_ann_wnd
abort() was called at PC 0x400e064b on core 1

Backtrace: 0x4008f7d8:0x3ffb6980 0x4008f9db:0x3ffb69a0 0x400e064b:0x3ffb69c0 0x40104546:0x3ffb69f0 0x401045ce:0x3ffb6a10 0x4014a6f5:0x3ffb6a30 0x40101c95:0x3ffb6a50
Rebooting...

(gdb) info symbol 0x40104546
tcp_update_rcv_ann_wnd + 90 in section .flash.text
(gdb) info symbol 0x401045ce
tcp_recved + 122 in section .flash.text
(gdb) info symbol 0x4014a6f5
_tcp_recved_api(tcpip_api_call*) + 13 in section .flash.text
(gdb) info symbol 0x40101c95
tcpip_thread + 81 in section .flash.text

problem was because of sending 200 for every chunk of data. Seems that works only if send 200 on end of data.

davidgevorgian commented 5 years ago

Simple bin upload. "Update.write"- upload only three parts, then crash...

Part of code

server.on("/update", HTTP_POST, [](AsyncWebServerRequest request){ request->send(200, "text/plain","DONE..."); },[](AsyncWebServerRequest request, String filename, size_t index, uint8_t *data, size_t len, bool final)

Update.write(data, len)

DEBUG LOG

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:1 load:0x3fff0018,len:4 load:0x3fff001c,len:1496 load:0x40078000,len:8596 load:0x40080400,len:6980 entry 0x400806f4 Update Start: ver0.1a.ino.esp32.bin Start write: 1271 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c abort() was called at PC 0x400e05a9 on core 1

Backtrace: 0x4008f9c4:0x3ffc9b80 0x4008fb99:0x3ffc9ba0 0x400e05a9:0x3ffc9bc0 0x400819fb:0x3ffc9be0 0x400d8605:0x3ffc9c00 0x400d817c:0x3ffc9c20 0x400d8361:0x3ffc9c40 0x400d1d25:0x3ffc9c60 0x4014d0c3:0x3ffc9c90 0x4014cfea:0x3ffc9ce0 0x400d481a:0x3ffc9d10 0x400d5bae:0x3ffc9d70 0x400d5d79:0x3ffc9dc0 0x400d3739:0x3ffc9de0 0x400d3782:0x3ffc9e20 0x400d3a22:0x3ffc9e40 0x4008ba0d:0x3ffc9e70

Exception Decoder Decoding stack results 0x4008f9c4: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x4008fb99: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x400e05a9: is_safe_write_address at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 118 0x400819fb: spi_flash_erase_sector at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 196 0x400d8605: EspClass::flashEraseSector(unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\cores\esp32\Esp.cpp line 243 0x400d817c: UpdateClass::_writeBuffer() at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 185 0x400d8361: UpdateClass::write(unsigned char, unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 290 0x400d1d25: std::_Function_handler >::_M_invoke(const std::_Any_data &, , const String &, , , , ) at D:\DAVID_FILES\Desktop\Arduino_Projects\AQUARIUM\ESP32\HTTP_Async\ver0.1a/ver0.1a.ino line 70 0x4014d0c3: AsyncCallbackWebHandler::handleUpload(AsyncWebServerRequest, String const&, unsigned int, unsigned char, unsigned int, bool) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x4014cfea: AsyncWebServerRequest::_handleUploadByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 370 0x400d481a: AsyncWebServerRequest::_parseMultipartPostByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 402 0x400d5bae: AsyncWebServerRequest::_onData(void, unsigned int) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 137 0x400d5d79: std::_Function_handler >::_M_invoke(const std::_Any_data &, , , , ) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 75 0x400d3739: AsyncClient::_recv(tcp_pcb, pbuf, signed char) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x400d3782: AsyncClient::_s_recv(void, tcp_pcb, pbuf, signed char) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 977 0x400d3a22: _async_service_task(void) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 148 0x4008ba0d: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 141

NOTE: I found. And problem solved by SPIFFS.format().

ms4905 commented 5 years ago

Simple bin upload. "Update.write"- upload only three parts, then crash...

Part of code

server.on("/update", HTTP_POST, [](AsyncWebServerRequest request){ request->send(200, "text/plain","DONE..."); },[](AsyncWebServerRequest request, String filename, size_t index, uint8_t *data, size_t len, bool final)

Update.write(data, len)

DEBUG LOG

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:1 load:0x3fff0018,len:4 load:0x3fff001c,len:1496 load:0x40078000,len:8596 load:0x40080400,len:6980 entry 0x400806f4 Update Start: ver0.1a.ino.esp32.bin Start write: 1271 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c abort() was called at PC 0x400e05a9 on core 1

Backtrace: 0x4008f9c4:0x3ffc9b80 0x4008fb99:0x3ffc9ba0 0x400e05a9:0x3ffc9bc0 0x400819fb:0x3ffc9be0 0x400d8605:0x3ffc9c00 0x400d817c:0x3ffc9c20 0x400d8361:0x3ffc9c40 0x400d1d25:0x3ffc9c60 0x4014d0c3:0x3ffc9c90 0x4014cfea:0x3ffc9ce0 0x400d481a:0x3ffc9d10 0x400d5bae:0x3ffc9d70 0x400d5d79:0x3ffc9dc0 0x400d3739:0x3ffc9de0 0x400d3782:0x3ffc9e20 0x400d3a22:0x3ffc9e40 0x4008ba0d:0x3ffc9e70

Exception Decoder Decoding stack results 0x4008f9c4: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x4008fb99: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x400e05a9: is_safe_write_address at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 118 0x400819fb: spi_flash_erase_sector at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 196 0x400d8605: EspClass::flashEraseSector(unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\cores\esp32\Esp.cpp line 243 0x400d817c: UpdateClass::_writeBuffer() at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 185 0x400d8361: UpdateClass::write(unsigned char, unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 290 0x400d1d25: std::_Function_handler >::_M_invoke(const std::_Any_data &, , const String &, , , , ) at D:\DAVID_FILES\Desktop\Arduino_Projects\AQUARIUM\ESP32\HTTP_Async\ver0.1a/ver0.1a.ino line 70 0x4014d0c3: AsyncCallbackWebHandler::handleUpload(AsyncWebServerRequest, String const&, unsigned int, unsigned char, unsigned int, bool) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x4014cfea: AsyncWebServerRequest::_handleUploadByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 370 0x400d481a: AsyncWebServerRequest::_parseMultipartPostByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 402 0x400d5bae: AsyncWebServerRequest::_onData(void, unsigned int) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 137 0x400d5d79: std::_Function_handler >::_M_invoke(const std::_Any_data &, , , , ) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 75 0x400d3739: AsyncClient::_recv(tcp_pcb, pbuf, signed char) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x400d3782: AsyncClient::_s_recv(void, tcp_pcb, pbuf, signed char) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 977 0x400d3a22: _async_service_task(void) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 148 0x4008ba0d: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 141

NOTE: I found. And problem solved by SPIFFS.format().

But where did you put the SPIFFS.format() ? I tried it but it seems to crash anyway.

davidgevorgian commented 5 years ago

Simple bin upload. "Update.write"- upload only three parts, then crash... Part of code server.on("/update", HTTP_POST, [](AsyncWebServerRequest request){ request->send(200, "text/plain","DONE..."); },[](AsyncWebServerRequest request, String filename, size_t index, uint8_t data, size_t len, bool final) Update.write(data, len) DEBUG LOG 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:1 load:0x3fff0018,len:4 load:0x3fff001c,len:1496 load:0x40078000,len:8596 load:0x40080400,len:6980 entry 0x400806f4 Update Start: ver0.1a.ino.esp32.bin Start write: 1271 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c Start write: 1436 bytes Pack addr: 0x3ffca91c abort() was called at PC 0x400e05a9 on core 1 Backtrace: 0x4008f9c4:0x3ffc9b80 0x4008fb99:0x3ffc9ba0 0x400e05a9:0x3ffc9bc0 0x400819fb:0x3ffc9be0 0x400d8605:0x3ffc9c00 0x400d817c:0x3ffc9c20 0x400d8361:0x3ffc9c40 0x400d1d25:0x3ffc9c60 0x4014d0c3:0x3ffc9c90 0x4014cfea:0x3ffc9ce0 0x400d481a:0x3ffc9d10 0x400d5bae:0x3ffc9d70 0x400d5d79:0x3ffc9dc0 0x400d3739:0x3ffc9de0 0x400d3782:0x3ffc9e20 0x400d3a22:0x3ffc9e40 0x4008ba0d:0x3ffc9e70 Exception Decoder Decoding stack results 0x4008f9c4: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x4008fb99: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x400e05a9: is_safe_write_address at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 118 0x400819fb: spi_flash_erase_sector at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/spi_flash/flash_ops.c line 196 0x400d8605: EspClass::flashEraseSector(unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\cores\esp32\Esp.cpp line 243 0x400d817c: UpdateClass::_writeBuffer() at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 185 0x400d8361: UpdateClass::write(unsigned char, unsigned int) at C:\Users\David\Documents\Arduino\hardware\espressif\esp32\libraries\Update\src\Updater.cpp line 290 0x400d1d25: std::_Function_handler >::_M_invoke(const std::_Any_data &, , const String &, , , , ) at D:\DAVID_FILES\Desktop\Arduino_Projects\AQUARIUM\ESP32\HTTP_Async\ver0.1a/ver0.1a.ino line 70 0x4014d0c3: AsyncCallbackWebHandler::handleUpload(AsyncWebServerRequest, String const&, unsigned int, unsigned char, unsigned int, bool) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x4014cfea: AsyncWebServerRequest::_handleUploadByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 370 0x400d481a: AsyncWebServerRequest::_parseMultipartPostByte(unsigned char, bool) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 402 0x400d5bae: AsyncWebServerRequest::_onData(void, unsigned int) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 137 0x400d5d79: std::_Function_handler >::_M_invoke(const std::_Any_data &, , , , ) at C:\Users\David\Documents\Arduino\libraries\ESPAsyncWebServer\src\WebRequest.cpp line 75 0x400d3739: AsyncClient::_recv(tcp_pcb, pbuf, signed char) at c:\users\david\documents\arduino\hardware\espressif\esp32\tools\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\5.2.0/functional line 2271 0x400d3782: AsyncClient::_s_recv(void, tcp_pcb, pbuf, signed char) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 977 0x400d3a22: _async_service_task(void*) at C:\Users\David\Documents\Arduino\libraries\AsyncTCP\src\AsyncTCP.cpp line 148 0x4008ba0d: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 141 NOTE: I found. And problem solved by SPIFFS.format().

But where did you put the SPIFFS.format() ? I tried it but it seems to crash anyway.

Here, https://github.com/davidgevorgian/ESP8266UpdatePack/tree/master/ESP32

spyder0069 commented 5 years ago

Thanks, that's an interesting idea! I will check and report back. Maybe it's SPIFFS who corrupts the heap, and web server is just poor victim.

@me21 did you find a resolution for this error? I am having a similar failure that I am trying to track down. From my main page if I click a link that directs to a new page and I return back and try it again several times I crash and reboot with:

`CORRUPT HEAP: Bad head at 0x3ffb8768. Expected 0xabba1234 got 0x3ffb8940 assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c", line 214, function: multi_heap_free abort() was called at PC 0x400fd93f on core 0

Backtrace: 0x4008d540:0x3ffbb360 0x4008d771:0x3ffbb380 0x400fd93f:0x3ffbb3a0 0x4008d19d:0x3ffbb3d0 0x400858f2:0x3ffbb3f0 0x40086f1d:0x3ffbb410 0x4000bec7:0x3ffbb430 0x40136503:0x3ffbb450 0x40136563:0x3ffbb470 0x401365ab:0x3ffbb490 0x40138cca:0x3ffbb4b0 0x40138d32:0x3ffbb4d0 0x400edcd9:0x3ffbb4f0 0x40134edc:0x3ffbb510 0x40089491:0x3ffbb540

Decoding stack results 0x4008d540: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x4008d771: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x400fd93f: __assert_func at ../../../.././newlib/libc/stdlib/assert.c line 63 0x4008d19d: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c line 214 0x400858f2: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c line 268 0x40086f1d: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c line 42 0x40136503: mem_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/mem.c line 151 0x40136563: do_memp_free_pool at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/memp.c line 432 0x401365ab: memp_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/memp.c line 489 0x40138cca: tcp_close_shutdown at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 311 0x40138d32: tcp_close at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 409 0x400edcd9: _tcp_close_api(tcpip_api_call_data*) at C:\arduino\SKETCHBOOK\libraries\AsyncTCP\src\AsyncTCP.cpp line 348 0x40134edc: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/api/tcpip.c line 124 0x40089491: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143`

spyder0069 commented 5 years ago

It appears my issue may be solved. I'll try my best to explain what was happening. My program had a main page that ran a function using xmlhttprequest to dynamically load data to it on a 1 second loop. This calls another page that gets the info in the background and posts it to the page you are viewing. This main page had links to redirect to other pages. If I would switch to one of these other pages and back several times eventually I would cause the error. What I think was happening was I was hitting the link to redirect at the same time that the function was calling for new data and it was switching to the new page but also I was getting the response from background page and that fouled things up. What seems to have fixed it is creating a flag and if its not set then my function sends the response to the main page with the new data. If any of my redirect pages load up they immediately set the flag so that the response from the background page will not be run.

Ximite commented 5 years ago

Thanks, that's an interesting idea! I will check and report back. Maybe it's SPIFFS who corrupts the heap, and web server is just poor victim.

@me21 did you find a resolution for this error? I am having a similar failure that I am trying to track down. From my main page if I click a link that directs to a new page and I return back and try it again several times I crash and reboot with:

Have the same error here.

CORRUPT HEAP: Bad head at 0x3ffdd37c. Expected 0xabba1234 got 0x3ffdd558 assertion "head != NULL" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c", line 214, function: multi_heap_free abort() was called at PC 0x401058bf on core 0

Backtrace: 0x400913b8:0x3ffd1a90 0x400915e9:0x3ffd1ab0 0x401058bf:0x3ffd1ad0 0x4009102d:0x3ffd1b00 0x40084a6e:0x3ffd1b20 0x4008adf5:0x3ffd1b40 0x4000bec7:0x3ffd1b60 0x4014529f:0x3ffd1b80 0x401452ff:0x3ffd1ba0 0x40145347:0x3ffd1bc0 0x40147a66:0x3ffd1be0 0x40147ace:0x3ffd1c00 0x400ea76d:0x3ffd1c20 0x401436b4:0x3ffd1c40 0x4008d355:0x3ffd1c70

Decoding stack results 0x400913b8: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x400915e9: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x401058bf: __assert_func at ../../../.././newlib/libc/stdlib/assert.c line 63 0x4009102d: multi_heap_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/multi_heap_poisoning.c line 214 0x40084a6e: heap_caps_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/heap/heap_caps.c line 268 0x4008adf5: _free_r at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/newlib/syscalls.c line 42 0x4014529f: mem_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/mem.c line 151 0x401452ff: do_memp_free_pool at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/memp.c line 432 0x40145347: memp_free at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/memp.c line 489 0x40147a66: tcp_close_shutdown at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 311 0x40147ace: tcp_close at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 409 0x400ea76d: _tcp_close_api(tcpip_api_call_data*) at D:\Documents\Arduino\libraries\AsyncTCP-master\src\AsyncTCP.cpp line 348 0x401436b4: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/api/tcpip.c line 124 0x4008d355: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143

me-no-dev commented 5 years ago

AsyncTCP has been updated. Please give it a shot.

spyder0069 commented 5 years ago

AsyncTCP has been updated. Please give it a shot.

The new version seems like its more robust but I can still make it fail only its a different error now:

assertion "new_rcv_ann_wnd <= 0xffff" failed: file "/Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c", line 779, function: tcp_update_rcv_ann_wnd abort() was called at PC 0x40106fb7 on core 0

Backtrace: 0x4008d540:0x3ffcaaa0 0x4008d771:0x3ffcaac0 0x40106fb7:0x3ffcaae0 0x40147f2a:0x3ffcab10 0x40147fb9:0x3ffcab30 0x400f6281:0x3ffcab50 0x401449bc:0x3ffcab70 0x40089491:0x3ffcaba0

Rebooting... The decode looks like:

Decoding stack results 0x4008d540: invoke_abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 155 0x4008d771: abort at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/panic.c line 170 0x40106fb7: _fopen_r at ../../../.././newlib/libc/stdio/fopen.c line 138 0x40147f2a: tcp_seg_copy at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 1442 0x40147fb9: tcp_poll at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 1897 0x400f6281: AsyncClient::AsyncClient(tcp_pcb*) at c:\users\user\appdata\local\arduino15\packages\esp32\tools\xtensa-esp32-elf-gcc\1.22.0-80-g6c4433a-5.2.0\xtensa-esp32-elf\include\c++\5.2.0/functional line 1825 0x401449bc: tcpip_callback_with_block at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/api/tcpip.c line 264 0x40089491: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143

I just create a webpage that opens the main page in 20 separate frames. Then hit the refresh rapidly. I know its not typical to have 20 connections come in at once but I've seen things hitting my router before and if I open this up to the outside world I don't want a way that the outside can cause a reboot. I have had it reboot before with just one connection and it running two pages (one refreshing the other) so I think its more of a timing thing.

This page doesn't seem to want to show my html source even with the CODE tags

Thank you for looking into this! I really appreciate your efforts! :^)

me-no-dev commented 5 years ago

in this case you are exhausting the available resources on the chip :) there always will be some limitations. This is after all just a micro-controller with a few K of memory. Maybe the only proper option would be to add memory check before accepting a client and just reject if memory is less than X KB. How about that?

spyder0069 commented 5 years ago

in this case you are exhausting the available resources on the chip :) there always will be some limitations. This is after all just a micro-controller with a few K of memory. Maybe the only proper option would be to add memory check before accepting a client and just reject if memory is less than X KB. How about that?

That sounds great! Anything to keep it from causing the crash/reboot. On occasion when forcing the error the server will stop responding but the rest of my project is still running. I'm assuming its just the problem presenting itself a little differently.

me-no-dev commented 5 years ago

can you send me the source of that web page of yours so I can run it here? do you run it from SPIFFS?

spyder0069 commented 5 years ago

can you send me the source of that web page of yours so I can run it here? do you run it from SPIFFS?

Attached is the file (rename to html) that I run from my desktop. The IP is the address of the esp32 on my internal network. Just change that to yours to recreate. I don't think the page that my esp is running is the issue. It currently does load a image from spiffs on that page but the html created in my arduino code. I was having crashes before i had figured out how to work with spiffs which was just a couple days ago. :^)

crash.txt

spyder0069 commented 5 years ago

I just pulled those images from that html page and was still able to recreate the crash.

me-no-dev commented 5 years ago

I think that this happens outside of Async. When the server hangs, there are no pending packets inside. All that have been received have been dispatched. I do not see HEAP issue either, so not something that can be caught. Overall, quite an edge case :)

spyder0069 commented 5 years ago

I think that this happens outside of Async. When the server hangs, there are no pending packets inside. All that have been received have been dispatched. I do not see HEAP issue either, so not something that can be caught. Overall, quite an edge case :)

Previously I would receive a crash switching from one page that was being dynamically refreshed to another. To get around it I had to set a flag to not try and send the dynamic data before the 301 redirect. I could cause the crash by going back and forth between these pages and eventually it would crash. I pulled my work around out and with the new tcp all seems well. Great job! How can I donate some beer money to you? :^)

spyder0069 commented 5 years ago

I spoke too soon. I had just had a crash switching pages. This was a click from my dynamic page to a standard html page. This time I received:

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

The decode was: 0x40152360: tcp_output at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp_out.c line 1027 0x4014d437: tcp_recved at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/core/tcp.c line 828 0x400fa3dd: _tcp_recved_api(tcpip_api_call_data*) at C:\FIRMWARE\arduino\SKETCHBOOK\libraries\AsyncTCP\src\AsyncTCP.cpp line 383 0x40149e20: tcpip_thread at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/lwip/lwip/src/api/tcpip.c line 124 0x40089491: vPortTaskWrapper at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 143

Funny i couldn't make it crash earlier but just in general use it popped up. Let me know what you think. Thanks!

Overall it seems very stable. I just need to figure out why every now and then it bites me.

atanisoft commented 5 years ago

@spyder0069 that looks memory related. Most likely out of heap space. I haven't been able to reproduce any heap issues under normal usage on my project now

spyder0069 commented 5 years ago

@spyder0069 that looks memory related. Most likely out of heap space. I haven't been able to reproduce any heap issues under normal usage on my project now

When my pages are running I show: freeheep=205588 min: 106040

I've got this sending heep via serial debugger for every page load now and I will monitor it.

atanisoft commented 5 years ago

That is total heap, it doesn't mean that the heap is not fragmented. It is entirely possible that the largest block of free heap was smaller than requested. It is also possible that PSRAM is being used by the TCP stack (if you are using WROVER and configure it that way) and it is running low.

For reference, my project heap shows around 135-145k at runtime. It never drops below 100k even when under heavy load (90%+ core utilization)

spyder0069 commented 5 years ago

This is on a wroom32.

Not sure if I am doing this right but I added block=heap_caps_get_largest_free_block(8); Serial.printf("block= %d", block );

Currently after switching back and forth pages many times I get: freeheep=195032 min: 131124 block= 113792

The webpages are built from strings but I did a .reserve in my code for those.

atanisoft commented 5 years ago

Hmm, that looks right I think. It would appear that heap is a bit fragmented but still can supply a very large block. So unless you are reserving/sending or receiving over 50kb at one time it shouldn't be a problem.

@me-no-dev any ideas?

barbiani commented 5 years ago

How about using http://www.gii.upv.es/tlsf/ ?

On Sun, Jun 23, 2019, 22:14 Mike Dunston notifications@github.com wrote:

Hmm, that looks right I think. It would appear that heap is a bit fragmented but still can supply a very large block. So unless you are reserving/sending or receiving over 50kb at one time it shouldn't be a problem.

@me-no-dev https://github.com/me-no-dev any ideas?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/me-no-dev/ESPAsyncWebServer/issues/394?email_source=notifications&email_token=ABYLTJBAF5YUOFRS2NP2KN3P4ANXTA5CNFSM4FN6JDBKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYLLZXA#issuecomment-504806620, or mute the thread https://github.com/notifications/unsubscribe-auth/ABYLTJFNKNCAFEMI4UWPXA3P4ANXTANCNFSM4FN6JDBA .

spyder0069 commented 5 years ago

The larger webpage is about 4k. I have only had the problem when switching from my dynamic page to another and thought it had to do with the code running in the browser telling it to refresh the data from the other page at the same time I happen to click to go to a different page. Like its expecting the response from the other one but then the main page is no longer there to receive it. I don't fully understand how async server works and since the refresh is basically running in a timer through the browser that might be still active before the redirect finishes? I am not sure. I do know that when had set flags to disable the background refresh if I was redirecting that worked to get by the crash previously but has some downsides to deal with (like if more than one client is viewing that page). Here is a stripped down version of what I am doing with the web side of my project. Again, i can click back and forth between the pages many times and its fine then out of the blue at some point I would get the timing right to crash it.
async_test.txt

atanisoft commented 5 years ago

How about using http://www.gii.upv.es/tlsf/ ?

@barbiani the allocator is coming from esp-idf and is a custom built tool as the esp32 has a number of config options for the variations. In general it does work very well but there are a few corner cases which occasionally have issues. Often times a small adjustment to the approach being taken will resolve those and as an added bonus often better code.

The larger webpage is about 4k.

Is that a dynamic page or static page? If dynamic that is a pretty big chunk that will be split for transmission likely. My largest page is roughly 9kb compressed and served from an in memory blob (compiled into the code). Everything that is dynamic is under 1kb typically.

The webpages are built from strings but I did a .reserve in my code for those.

Are those using a std::string or String (Arduino object)? String was pretty bad prior to 1.0.3-rc1 about fragmenting memory when concatenating String objects. A few fixes went in to help with that though.

spyder0069 commented 5 years ago

I just double checked and currently the string that is being sent as the dynamic data is 1070 characters long. So you have the initial main page with the script which is pretty short and then this dynamic data being sent in the background every second.

I am on 1.0.3-rc1. I am declaring a variable as String in arduino. I am concatenating the data to build the webpage into the string. I am reserving the size for the string using statuspagebodytemp.reserve(5000);

This was so that the webpages didn't fragment the memory and I left extra space intentionally for additional development. I don't think it has to do with the strings causing a problem. I think its either the redirect deal or maybe I am not suppose to close the connection after each 200? response->addHeader("Connection", "close");

I am new to both the esp (coming from years of pic micro projects) and this type of web programming so I am learning via school of hard knocks.

atanisoft commented 5 years ago

You don't need to close the connection via header, that is added automatically IIRC. Reserving space is not a bad approach and should avoid most fragmenting issues, which should be better on 1.0.3-rc1.