An receive error occured, FID=NN and ESP32 crashes

[vayllon]

Hi,

Sometimes the ESP32 reboots because this exception.

The error occurs sporadically but before ESP32 crashes it always shows the log:

[HTTPS:E] An receive error occured, FID=NN

Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x400d66d5 PS : 0x00060a30 A0 : 0x800d382d A1 : 0x3ffd4340
A2 : 0x3ffd5aec A3 : 0x3ffd4394 A4 : 0x00007e00 A5 : 0x00000002
A6 : 0x00000001 A7 : 0x000000aa A8 : 0x00007e81 A9 : 0x0000007d
A10 : 0x00000010 A11 : 0x3ffd55e0 A12 : 0x3ffd5690 A13 : 0x00000000
A14 : 0x00000000 A15 : 0x3ffd1d80 SAR : 0x00000008 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000010 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace: 0x400d66d5:0x3ffd4340 0x400d382a:0x3ffd4370 0x400d516a:0x3ffd43d0 0x40088d29:0x3ffd43f0

Rebooting...

I'm using just the HTTPServer and WebSockets (3 Max parameter)

Any idea why it happens or any workaround?

Thanks and congratulations for your project.

Victor.-

[squonk11]

It would be helpful to decode the backtrace addresses to source file lines.

[fhessel]

@squonk11 is right, without being able to know where the addresses in the backtrace point to and without having the binary to check the PC value, it's impossible to say what's happening there.

PlatformIO now supports the monitor_filters filters options, which is a very convenient way to get the additional info. So if you're using PlatformIO, just add the following line to your platformio.ini and use the built-in serial monitor, and you should see which call causes the trouble:

monitor_filters = esp32_exception_decoder

See here for infos on options for monitor_filters and here for a general description of that setting.

[vayllon]

Thanks fhessel, squonk1,

I will try plataformio monitor filters next time, I didn't know that trick.

I did it manually using xtensa-esp32-elf-addr2line probably is the same result.

This is the decoding:

0x400d66d5: httpsserver::WebsocketHandler::send(std::__cxx11::basic_string<char, std::char_traits, std::allocator >, unsigned char) at .platformio/lib/esp32_https_server_ID5887/src/WebsocketHandler.cpp:243

Line 243 is next one:

_con->writeBuffer(data, length);

0x400d382a: WebSocketHandler::sendJSON(ArduinoJson6152_0000010::BasicJsonDocument<ArduinoJson6152_0000010::DefaultAllocator>&) at /home/Projects/HomeBrain/src/common/ESP32/MyWebsocketHandler.cpp:67 (discriminator 1)

This is my code at that point, a wrapper of WebsocketHandler:

void MyWebsocketHandler::sendJSON(DynamicJsonDocument &json) {

std::string msg; 
serializeJson(json, msg);  

// Send it back to every client
for(int i = 0; i < MAX_SOCKET_CLIENTS; i++) {
    if (activeClients[i] != nullptr) {
      activeClients[i]->send(msg, WebsocketHandler::SEND_TYPE_TEXT);
    }
}

}

0x400d516a: taskStatus(void*) at /home/Projects/HomeBrain/src/main.cpp:83

This is the code at main.cpp is a freertos task which periodically invokes sendJSON

0x400d516a: taskStatus(void*) at /home/Projects/HomeBrain/src/main.cpp:83

This is the code at main.cpp is a freertos task which periodically invokes sendJSON:

void taskStatus( void * parameter )
{

while(1) {
  while (WebSocketHandler::is_connected()) {
    robotHandler.get_status(jsonDocumentTx);
    MyWebsocketHandler::sendJSON(jsonDocumentTx);
    delay(3000);
  }
  delay(500);
}

}

0x40088d29: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

[fhessel]

The line WebsocketHandler.cpp:243 doesn't match the call:

    activeClients[i]->send(msg, WebsocketHandler::SEND_TYPE_TEXT);

msg is of type std::string, so that should be a call to WebsocketHandler::send(std::string, uint8_t), but line 243 is part of WebsocketHandler::send(uint8_t*, uint16_t, uint8_t).

Line 243 is next one:
_con->writeBuffer(data, length);

Did you check that in your local file at .platformio/lib/esp32_https_server_ID5887/src/WebsocketHandler.cpp:243 or in the repo?

From your code snippets, I wouldn't expect the execution to reach line 243 at all, or at least not from the call in sendJSON. Could you check that again? And could you also check the current version/commit you're on? I just don't want to base the analysis on false assumptions about that.

Also, if you'd switch to PlatformIO, enabling the DEBUG logs could help with that:

build_flags = -DHTTPS_LOGLEVEL=5

[vayllon]

I reinstalled the library from platformio's libraries (just in case)

"version": "1.0.0" in manifest file.

This time I tried with platformio monitoring.

I recompiled and upload the code into the device.

After some minutes sending JSON via websockets (and refreshing once in a while the web page), I obtained two different exceptions:

[HTTPS:I] Request: GET / (FID=58)
[HTTPS:D] Header: Host = 192.168.1.128 (FID=58)
[HTTPS:D] Header: Connection = keep-alive (FID=58)
[HTTPS:D] Header: Cache-Control = max-age=0 (FID=58)
[HTTPS:D] Header: Authorization = Basic dmljdG9yOjY2NzY= (FID=58)
[HTTPS:D] Header: Upgrade-Insecure-Requests = 1 (FID=58)
[HTTPS:D] Header: User-Agent = Mozilla/5.0 (Linux; Android 7.1.1; SM-J510FN) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.106 Mobile Safari/537.36 (FID=58)
[HTTPS:D] Header: Accept = text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,/;q=0.8,application/signed-exchange;v=b3;q=0.9 (FID=58)
[HTTPS:D] Header: Accept-Encoding = gzip, deflate (FID=58)
[HTTPS:D] Header: Accept-Language = es-ES,es;q=0.9,en;q=0.8 (FID=58)
[HTTPS:D] Headers finished, FID=58
[HTTPS:D] Resolving resource...
[HTTPS:D] Testing route /*
[HTTPS:D] (INIT) inputIdx: 0, pathIdx: 0, pathEnd: 1, path: /, url: /
[HTTPS:D] (LOOP) inputIdx: 0, pathIdx: 0, pathEnd: 1, path: /, url: /[HTTPS:D]
[HTTPS:D] >> Websocket.send(): length=176(STTC) inputIdx: 1, pathIdx: 2, pathEnd: 1, path: /*, url: /

Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.
Core 1 register dump:
PC : 0x400d6a4e PS : 0x00060230 A0 : 0x800d38e5 A1 : 0x3ffd42e0
A2 : 0x3ffd6104 A3 : 0x3ffd4334 A4 : 0xc000e67e A5 : 0x3ffc1ca4
A6 : 0x3f401f78 A7 : 0x00000002 A8 : 0x00007e81 A9 : 0x0000007d
A10 : 0x343a3132 A11 : 0x71924600 A12 : 0x00000002 A13 : 0x3ffc2098
A14 : 0x3ffd427c A15 : 0x3ffd427c SAR : 0x00000004 EXCCAUSE: 0x0000001c
EXCVADDR: 0xc000e69a LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace: 0x400d6a4e:0x3ffd42e0 0x400d38e2:0x3ffd4310 0x400d5222:0x3ffd4370 0x40088d29:0x3ffd4390
#0 0x400d6a4e:0x3ffd42e0 in httpsserver::WebsocketHandler::send(std::__cxx11::basic_string<char, std::char_traits, std::allocator >, unsigned char) at /home/user1/.platformio/lib/esp32_https_server_ID5887/src/WebsocketHandler.cpp:244
#1 0x400d38e2:0x3ffd4310 in MyWebsocketHandler::sendJSON(ArduinoJson6152_0000010::BasicJsonDocument<ArduinoJson6152_0000010::DefaultAllocator>&) at src/common/ESP32/MyWebsocketHandler.cpp:67 (discriminator 1)
#2 0x400d5222:0x3ffd4370 in taskStatus(void*) at src/main.cpp:83
#3 0x40088d29:0x3ffd4390 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

The other one:

[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] >> Websocket.send(): length=176
[HTTPS:D] << Websocket.send()
[HTTPS:D] Data on Socket FID=57
[HTTPS:E] An receive error occured, FID=57
[HTTPS:I] Connection closed. Socket FID=57
[HTTPS:D] Free headers
[HTTPS:D] Free WS Handler

Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled.
Core 1 register dump:
PC : 0x40196a2f PS : 0x00060830 A0 : 0x800d8e65 A1 : 0x3ffb1d60
A2 : 0x00000000 A3 : 0x00000000 A4 : 0x000001ff A5 : 0x00000001
A6 : 0x00060420 A7 : 0x00000000 A8 : 0x800d7946 A9 : 0x3ffb1d40
A10 : 0x00000000 A11 : 0x400d7428 A12 : 0x3ffc1ca4 A13 : 0x3ffbd450
A14 : 0x00000000 A15 : 0x3ffb0060 SAR : 0x00000004 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000008 LBEG : 0x400014fd LEND : 0x4000150d LCOUNT : 0xffffffff

Backtrace: 0x40196a2f:0x3ffb1d60 0x400d8e62:0x3ffb1d80 0x400d5e0a:0x3ffb1f60 0x400d510e:0x3ffb1f90 0x400dd715:0x3ffb1fb0 0x40088d29:0x3ffb1fd0

#0 0x40196a2f:0x3ffb1d60 in httpsserver::WebsocketHandler::closed() at /home/user1/.platformio/lib/esp32_https_server_ID5887/src/WebsocketHandler.cpp:251
#1 0x400d8e62:0x3ffb1d80 in httpsserver::HTTPConnection::loop() at /home/user1/.platformio/lib/esp32_https_server_ID5887/src/HTTPConnection.cpp:591
#2 0x400d5e0a:0x3ffb1f60 in httpsserver::HTTPServer::loop() at /home/user1/.platformio/lib/esp32_https_server_ID5887/src/HTTPServer.cpp:122
#3 0x400d510e:0x3ffb1f90 in loop() at src/main.cpp:67
#4 0x400dd715:0x3ffb1fb0 in loopTask(void*) at /home/user1/.platformio/packages/framework-arduinoespressif32/cores/esp32/main.cpp:19
#5 0x40088d29:0x3ffb1fd0 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

First one is at WebsocketHandler.cpp:244, one line after the first error I sent.

I clicked in the link the monitoring tool provides and it took me to the debugging line after the writeBuffer.

_con->writeBuffer(data, length);
HTTPS_LOGD("<< Websocket.send()");

[fhessel]

At least the second one sounds somewhat familiar, can you try #89 and see if it helps? I didn't get to reviewing that in detail, but the situation seems similar. With PIO, the easiest way to test it is to create a lib folder in your project, and within that, do a git clone of this repo and checking out the PR branach.

(And you may want to change the password you're using on the ESP32, I missed to warn you that an auth header would be logged, too. Sorry for that)

[vayllon]

Yeah...bligeti's code works!

Now, trace shows the receive error but does not crash.

[HTTPS:E] An receive error occured, FID=55
[HTTPS:I] Connection closed. Socket FID=55
[HTTPS:I] New connection. Socket FID=56
[HTTPS:I] New connection. Socket FID=58
[HTTPS:I] Request: GET / (FID=56)
[HTTPS:I] Connection closed. Socket FID=56
[HTTPS:I] New connection. Socket FID=59

Thanks!