Crash when refreshing embedded website multiple times

[tonilopezmr]

⚠️ This could be related to this issue, not sure: #1731

Bug description
While preparing the Shelly 1PM PR support When open espurna website and refresh multiple times it crashes and restarts the device, it's an error in this line:

espurna/code/espurna/ws.ino

Line 389 in 746ad70

client->text(buffer);

, It's a JSON parser error.

Steps to reproduce

1. Open espurna embedded website
2. Press If you are in mac CMD+R or if you are in windows CRL+R, twice or more very fast.
3. Espurna device crash

Device information

• Shelly 1PM (I need to test in more different devices)
  It has enabled HJL01 / BL0937 and NTC support, these variables could create a JSON parse error.

• Arduino Core version:
• CPU chip ID: 0xE67907
• CPU frequency: 80 MHz
• SDK version: 1.5.3(aec24ac9)
• Core version: 2.3.0
• Core revision: 9826c6d
• ESPURNA 1.13.6-dev
• Flash mode
• Device brand, model and version

Tools used

• Desktop MAC
• Chrome Version 75.0.3770.100 (Official Build) (64-bit)

Additional context

Stack trace

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

ctx: sys 
sp: 3ffffb80 end: 3fffffb0 offset: 01a0

>>>stack>>>
3ffffd20:  3fff861c 3fffa6f4 3fff09ac 4020d711  
3ffffd30:  00000b3f 00000b3f 00000b3f 00000000  
3ffffd40:  00000003 3fff7934 3fff09ac 40216a7d  
3ffffd50:  00000000 00000000 00000000 3fff60f4  
3ffffd60:  00000003 3fff60f4 3fff8470 40216b0b  
3ffffd70:  3ffe9558 00000000 3fffa884 00002000  
3ffffd80:  3fff6cbc 00000003 000000c0 000000a8  
3ffffd90:  00000001 00000080 3ffffdd0 00000000  
3ffffda0:  3fff7934 00000001 3fff09ac 402189db  
3ffffdb0:  3fff3b2c 00000980 00000980 4010020c  
3ffffdc0:  00000001 3fff7934 3ffffe10 4010068c  
3ffffdd0:  3ffea6f8 8001a8c0 3ffffe10 4022de94  
3ffffde0:  3fff2524 00000c53 00000c53 4010020c  
3ffffdf0:  00000001 00000000 3ffffe40 3fff8d84  
3ffffe00:  00000001 3fff7934 00000000 4022e7b2  
3ffffe10:  3fff7914 3ffe8611 40222330 4022f255  
3ffffe20:  00000000 00000000 3fff7934 40220a35  
3ffffe30:  3fff2524 00000000 3fff7934 4022131e  
3ffffe40:  3fff7934 3ffe8611 40220788 40221e84  
3ffffe50:  3fff77fc 00000004 3fff8f54 401004d8  
3ffffe60:  3fff2524 00000c39 00000c39 3fff2b10  
3ffffe70:  00000101 00000004 3fff8f54 40221355  
3ffffe80:  3fff8d84 011e3555 00002200 40107660  
3ffffe90:  3fff8edc 3fff2b1c 3fff8d84 4022f2b4  
3ffffea0:  3fff8d84 00000101 3fff77fc 4022248d  
3ffffeb0:  00000001 3fff2d08 3fff77fc 4021b1f4  
3ffffec0:  3fff762c 3fff2b18 3fff2b14 4021b214  
3ffffed0:  3fff762c 3fff2b18 3fff2b14 402495a5  
3ffffee0:  00000000 8401a8c0 00000010 00000000  
3ffffef0:  00000010 00000000 3fff13fc 40107650  
3fffff00:  40240000 00000000 0000007d 3fff2d00  
3fffff10:  3ffed96a 3fff2d08 3fff73a4 40247af1  
3fffff20:  3fff2a0c 3fff6cbc 3fff6cbc 3fff0160  
3fffff30:  00000000 3fff73a4 0000001c 3fff6cbc  
3fffff40:  3ffed95c 00000000 3fff73a4 40246ee9  
3fffff50:  8001a8c0 00000064 00000000 00000031  
3fffff60:  00000002 0000001a 402366e7 3ffeeba0  
3fffff70:  3ffed934 3fffdcc0 3ffeb1b0 3ffeb1b0  
3fffff80:  4023665a 3ffeeba0 00000000 3fff6d04  
3fffff90:  3fffdc80 00000000 3fff73a4 4023eb5b  
3fffffa0:  40000f49 3fffdab0 3fffdab0 40000f49  
<<<stack<<<

 ets Jan  8 2013,rst cause:1, boot mode:(3,7)

load 0x4010f000, len 1384, room 16 
tail 8
chksum 0x2d
csum 0x2d
v09826c6d
~ld
[000172] 

Encoded stack trace

0x4020d73d: ArduinoJson::Internals::JsonPrintable<ArduinoJson::JsonObject>::measureLength() const at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ArduinoJson_ID64/src/ArduinoJson/Deserialization/../Serialization/JsonPrintable.hpp:97
0x40216ab1: wsSend(unsigned int, ArduinoJson::JsonObject&) at Documents/sato/satostation/firmware/espurna/code/espurna/ws.ino:389
0x40216b3f: _wsStart(unsigned int) at Documents/sato/satostation/firmware/espurna/code/espurna/ws.ino:413
0x40218a2b: _wsEvent(AsyncWebSocket*, AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:1983
 (inlined by) ?? at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:1958
 (inlined by) ?? at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:2451
 (inlined by) _wsEvent(AsyncWebSocket*, AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int) at Documents/sato/satostation/firmware/espurna/code/espurna/ws.ino:434
0x4010020c: _umm_free at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/umm_malloc/umm_malloc.c:1287
0x4010068c: free at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/umm_malloc/umm_malloc.c:1733
0x4022dee4: operator delete(void*) at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/abi.cpp:40
0x4010020c: _umm_free at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/umm_malloc/umm_malloc.c:1287
0x4022e802: std::_Function_handler<void (AsyncWebSocket*, AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int), void (*)(AsyncWebSocket*, AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int)>::_M_invoke(std::_Any_data const&, AsyncWebSocket*, AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:2073
0x40222380: std::_Function_base::_Base_manager<AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*)#8}>::_M_manager(std::_Any_data&, std::_Function_base::_Base_manager<AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*)#8}> const&, std::_Manager_operation) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:1931
0x4022f2a9: AsyncWebSocket::_handleEvent(AsyncWebSocketClient*, AwsEventType, void*, unsigned char*, unsigned int) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESP Async WebServer/src/AsyncWebSocket.cpp:810
0x40220a85: _ZN10LinkedListIP20AsyncWebSocketClient14LinkedListNodeE3addERKS1_$isra$101 at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESP Async WebServer/src/StringArray.h:67
0x4022136e: AsyncWebSocketClient::AsyncWebSocketClient(AsyncWebServerRequest*, AsyncWebSocket*) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESP Async WebServer/src/AsyncWebSocket.cpp:455
0x402207d8: std::_Function_base::_Base_manager<AsyncWebSocketClient::AsyncWebSocketClient(AsyncWebServerRequest*, AsyncWebSocket*)::{lambda(void*, AsyncClient*)#8}>::_M_manager(std::_Any_data&, std::_Function_base::_Base_manager<AsyncWebSocketClient::AsyncWebSocketClient(AsyncWebServerRequest*, AsyncWebSocket*)::{lambda(void*, AsyncClient*)#8}> const&, std::_Manager_operation) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:1931
0x40221ed4: std::_Function_handler<void (void*, AsyncClient*), AsyncWebSocketClient::AsyncWebSocketClient(AsyncWebServerRequest*, AsyncWebSocket*)::{lambda(void*, AsyncClient*)#8}>::_M_invoke(std::_Any_data const&, void*, AsyncClient*) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:2069
0x401004d8: malloc at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/umm_malloc/umm_malloc.c:1664
0x402213a5: AsyncWebSocketResponse::_ack(AsyncWebServerRequest*, unsigned int, unsigned int) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESP Async WebServer/src/AsyncWebSocket.cpp:1200
0x40107660: vPortFree at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/heap.c:18
0x4022f308: AsyncWebServerRequest::_onAck(unsigned int, unsigned int) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESP Async WebServer/src/WebRequest.cpp:191
0x402224dd: std::_Function_handler<void (void*, AsyncClient*, unsigned int, unsigned int), AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*, unsigned int, unsigned int)#4}>::_M_invoke(std::_Any_data const&, void*, AsyncClient*, unsigned int, unsigned int) at .platformio/packages/toolchain-xtensa@1.40802.0/xtensa-lx106-elf/include/c++/4.8.2/functional:2073
0x4021b244: AsyncClient::_sent(tcp_pcb*, unsigned short) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESPAsyncTCP/src/ESPAsyncTCP.cpp:382 (discriminator 1)
0x4021b264: AsyncClient::_s_sent(void*, tcp_pcb*, unsigned short) at Documents/sato/satostation/firmware/espurna/code/.pio/libdeps/allterco-shelly1pm-ota/ESPAsyncTCP/src/ESPAsyncTCP.cpp:506
0x402495f9: tcp_input at espressif/arduino/tools/sdk/lwip/src/core/tcp_in.c:370 (discriminator 1)
0x40107650: pvPortMalloc at .platformio/packages/framework-arduinoespressif8266@1.20300.1/cores/esp8266/heap.c:13
0x40247b45: ip_input at espressif/arduino/tools/sdk/lwip/src/core/ipv4/ip.c:559
0x40246f3d: ethernet_input at espressif/arduino/tools/sdk/lwip/src/netif/etharp.c:1379
0x4023673b: pp_tx_idle_timeout at ??:?
0x402366ae: pp_tx_idle_timeout at ??:?
0x4023ebaf: system_get_sdk_version at ??:?
0x40000f49: ?? ??:0
0x40000f49: ?? ??:0

[mcspr]

Does look like basic OOM, since we are running sensor image and trying to send large json blob while first ws client is still connected.

I have not tested WebUI much since then, sorry. Whole communications process needs reworking, including ws server module. Also, using older Core with 12KB less available heap redoubles the issue

I already referenced this issue in #1823 , since it does look like the same issue. Also, #1731

[tonilopezmr]

If I can help, let me know because this is very annoying for me, maybe using CSV to reduce the data blob as a hotfix? not sure how to start with this.

[mcspr]

Ordering somewhat complicates things. We need to wait up until the first connection finishes to send anything. Maybe even restore the old behaviour that sends configuration in chunks, implementing a proper queueing of outgoing data (because we hit network buffer limits / ws queue limits and lose it if not careful).

ESPAsyncWebServer was updated recently with queue size check methods, so i hope it will help to avoid any subclassing / reworking of the ws handler there.

[tonilopezmr]

perfect, then I have time to understand this project to try to fix it in the future if needed it.

[mcspr]

Just a note about the process + ref #1589
Restoring the old way seems to be OK, but we would still use ArduinoJson 5 (which is relatively annoying, but tolerable).
What is taking a bit longer is excessive firmware size that turned up all of a sudden, which is problematic with 1MB boards :/ It feels like some of the templates needs cleaning up too and some real thorough check for rogue inline code that is repeating itself.

[mcspr]

Closing via #1843