search

bblanchon / ArduinoJson

📟 JSON library for Arduino and embedded C++. Simple and efficient.
https://arduinojson.org
MIT License
6.72k stars 1.12k forks source link

SpiRamJsonDocument doc(size) crashes the program. #1726

Closed zekageri closed 2 years ago

zekageri commented 2 years ago

Crash report:

Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x40090ca2  PS      : 0x00060733  A0      : 0x80092d5e  A1      : 0x3ffe7c50
A2      : 0xaaaaaaaa  A3      : 0x0000cdcd  A4      : 0xb33fffff  A5      : 0x00000001
A6      : 0x00060720  A7      : 0x0000abab  A8      : 0x0000cdcd  A9      : 0x00000000
A10     : 0x08fffffd  A11     : 0x3ffba664  A12     : 0x00000050  A13     : 0x00000001  
A14     : 0x08fffffd  A15     : 0x00000000  SAR     : 0x0000000a  EXCCAUSE: 0x0000001d
EXCVADDR: 0xaaaaaaaa  LBEG    : 0x4008c8f4  LEND    : 0x4008c910  LCOUNT  : 0xffffffff  

ELF file SHA256: 0000000000000000

Backtrace: 0x40090ca2:0x3ffe7c50 0x40092d5b:0x3ffe7c80 0x40093499:0x3ffe7ca0 0x400827fd:0x3ffe7cc0 0x400d84a9:0x3ffe7ce0 0x400d879e:0x3ffe7d60 0x4008fc8a:0x3ffe7d80
  #0  0x40090ca2:0x3ffe7c50 in uxPortCompareSet at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:3507
      (inlined by) vPortCPUAcquireMutexIntsDisabledInternal at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/portmux_impl.inc.h:86
      (inlined by) vPortCPUAcquireMutexIntsDisabled at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/portmux_impl.h:98
      (inlined by) vTaskEnterCritical at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:4201
  #1  0x40092d5b:0x3ffe7c80 in multi_heap_internal_lock at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap.c:380
  #2  0x40093499:0x3ffe7ca0 in multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c:305
  #3  0x400827fd:0x3ffe7cc0 in heap_caps_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c:354
  #4  0x400d84a9:0x3ffe7ce0 in SpiRamAllocator::allocate(unsigned int) at src/utilities/globals.h:8
      (inlined by) ArduinoJson6192_F1::AllocatorOwner<SpiRamAllocator>::allocate(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:20
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::allocPool(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:137
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::BasicJsonDocument(unsigned int, SpiRamAllocator) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:44
      (inlined by) pSystem::sendAdminData() at src/utilities/performanceSystem.cpp:151
  #5  0x400d879e:0x3ffe7d60 in psLoopTask(void*) at src/utilities/performanceSystem.cpp:186 (discriminator 1)
  #6  0x4008fc8a:0x3ffe7d80 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

I do get [D][esp32-hal-psram.c:47] psramInit(): PSRAM enabled message at startup.

Function where it crashing:

void pSystem::sendAdminData(){
    if( hsh_Server.adminIsIn && ( millis() - lastAdminDataSend_MS >= ADMIN_DATA_SEND_INTERVAL_MS) ){
        if( millis() - hsh_Server.adminLastExtendTime > 5000 ){
            hsh_Server.adminIsIn = false;
            return;
        }
        refreshDynamicData();
        //DynamicJsonDocument constructedData(1500);
        SpiRamJsonDocument constructedData(1500);
        JsonObject doc = constructedData.to<JsonObject>();
        doc["chipid"]       = chipid;
        doc["rev"]          = rev;
        doc["freq"]         = freq;
        doc["heap"]         = heap;
        doc["freeHeap"]     = freeHeap;
        doc["usedHeap"]     = usedHeap;
        doc["psRamSize"]    = psRamSize;
        doc["freePSRam"]    = freePSRam;
        doc["usedPsram"]    = usedPsram;
        doc["sketchSize"]   = sketchSize;
        doc["freeSketch"]   = freeSketch;
        doc["usedSketch"]   = usedSketch;
        doc["fsTotal"]      = fsTotal;
        doc["fsUsed"]       = fsUsed;
        doc["fsFree"]       = fsFree;
        doc["millis"]       = millis();
        doc["uptime"]       = hsh_timeSystem.getUptime();
        doc["innerTime"]    = hsh_timeSystem.getDateString();
        doc["type"]         = "performanceData";
        hsh_Server.socketSend(doc,1,1500);
        lastAdminDataSend_MS = millis();
    }
}

socket send function:

void sSystem::socketSend(JsonObject& message,int socket,size_t JsonBufferSize,int clientID){
    socketLock();
    char * messageString = (char*)malloc(JsonBufferSize);
    if (messageString != NULL){
        size_t len = serializeJson(message,messageString,JsonBufferSize);
        if( len > 0 ){
            if(socket == MAIN_SOCKET && hsh_Socket.count() > 0){
                if(clientID == -1){
                    hsh_Socket.textAll(messageString,len);
                }else{
                    hsh_Socket.text(clientID,messageString,len);
                }
            }else if(socket == ADMIN_SOCKET && hsh_adminSocket.count() > 0){
                if(clientID == -1){
                    hsh_adminSocket.textAll(messageString,len);
                }else{
                    hsh_adminSocket.text(clientID,messageString,len);
                }
            }
        }else{
            #if SS_DEBUG_MODE
                Serial.println("Socket message empty");
            #endif
        }
        free(messageString);
    }
    socketUnlock();
}

SPIRAM ALLOCATOR tempalte:

#include <Arduino.h>
#include <ArduinoJson.h>

struct SpiRamAllocator {
    void* allocate(size_t size) {return heap_caps_malloc(size, MALLOC_CAP_SPIRAM);}
    void deallocate(void* pointer) {heap_caps_free(pointer);}
    void* reallocate(void* ptr, size_t new_size) {return heap_caps_realloc(ptr, new_size, MALLOC_CAP_SPIRAM);}
};
using SpiRamJsonDocument = BasicJsonDocument<SpiRamAllocator>;

Arduino troubleshooter's report:

ArduinoJson Troubleshooter's report
  1. The issue happens at run time
  2. The issue concerns serialization
  3. Program crashes
  4. Program uses DynamicJsonDocument ( it is SpiRamJsonDocument actually )
  5. Program doesn’t use PROGMEM
  6. Output type is char*

Everything is working with DynamicJsonDocument

Thank you for your help!

zekageri commented 2 years ago

Further crashes: 

Guru Meditation Error: Core  1 panic'ed (Interrupt wdt timeout on CPU1)
Core 1 register dump:
PC      : 0x40090cbd  PS      : 0x00060534  A0      : 0x80092d5e  A1      : 0x3ffe8ff0
A2      : 0x37755354  A3      : 0x0000abab  A4      : 0xb33fffff  A5      : 0x00000001  
A6      : 0x00060520  A7      : 0x0000cdcd  A8      : 0x40114d84  A9      : 0x3ffe8fe0
A10     : 0x3f42375c  A11     : 0x00000069  A12     : 0x3f423a90  A13     : 0x3f4237e8  
A14     : 0x00ff0000  A15     : 0xff000000  SAR     : 0x00000008  EXCCAUSE: 0x00000006
EXCVADDR: 0x00000000  LBEG    : 0x4008c975  LEND    : 0x4008c997  LCOUNT  : 0x00000000

ELF file SHA256: 0000000000000000

Backtrace: 0x40090cbd:0x3ffe8ff0 0x40092d5b:0x3ffe9020 0x40093499:0x3ffe9040 0x400827fd:0x3ffe9060 0x400d24ab:0x3ffe9080 0x400d5aa9:0x3ffe90c0 0x400da3ca:0x3ffe91a0 0x400da52a:0x3ffec200 0x400eece8:0x3ffec2a0 0x400ec079:0x3ffec2f0 0x400ec14e:0x3ffec330 0x400ec3cd:0x3ffec370 0x401785ad:0x3ffec390 0x401780b9:0x3ffec3c0 0x4008fc8a:0x3ffec410
  #0  0x40090cbd:0x3ffe8ff0 in vPortCPUAcquireMutexIntsDisabledInternal at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:3507       
      (inlined by) vPortCPUAcquireMutexIntsDisabled at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/portmux_impl.h:98
      (inlined by) vTaskEnterCritical at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:4201
  #1  0x40092d5b:0x3ffe9020 in multi_heap_internal_lock at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap.c:380
  #2  0x40093499:0x3ffe9040 in multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c:305
  #3  0x400827fd:0x3ffe9060 in heap_caps_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c:354
  #4  0x400d24ab:0x3ffe9080 in SpiRamAllocator::allocate(unsigned int) at src/utilities/fileSystem.cpp:83
      (inlined by) ArduinoJson6192_F1::AllocatorOwner<SpiRamAllocator>::allocate(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:20
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::allocPool(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:137
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::BasicJsonDocument(unsigned int, SpiRamAllocator) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:44
  #5  0x400d5aa9:0x3ffe90c0 in fSystem::isUserSessionExpired(String&) at src/utilities/fileSystem.cpp:83
  #6  0x400da3ca:0x3ffe91a0 in sSystem::authenticateByID(AsyncWebServerRequest*, String&) at lib/ArduinoJson-6.x/src/ArduinoJson/Numbers/parseNumber.hpp:144
  #7  0x400da52a:0x3ffec200 in std::_Function_handler<void (AsyncWebServerRequest*), sSystem::mainEndpoints()::{lambda(AsyncWebServerRequest*)#1}>::_M_invoke(std::_Any_data const&, AsyncWebServerRequest*&&) at lib/ArduinoJson-6.x/src/ArduinoJson/Numbers/parseNumber.hpp:144
      (inlined by) _M_invoke at c:\users\pc\.platformio\packages\toolchain-xtensa32@2.50200.97\xtensa-esp32-elf\include\c++\5.2.0/functional:1871
  #8  0x400eece8:0x3ffec2a0 in std::function<void (AsyncWebServerRequest*)>::operator()(AsyncWebServerRequest*) const at lib\ESPAsyncWebServer-yuboxfixes-0xFEEDC0DE64-cleanup\src/WebServer.cpp:197
      (inlined by) AsyncCallbackWebHandler::handleRequest(AsyncWebServerRequest*) at lib\ESPAsyncWebServer-yuboxfixes-0xFEEDC0DE64-cleanup\src/WebHandlerImpl.h:132
  #9  0x400ec079:0x3ffec2f0 in AsyncWebServerRequest::_parseLine() at lib\ESPAsyncWebServer-yuboxfixes-0xFEEDC0DE64-cleanup\src/WebRequest.cpp:814
  #10 0x400ec14e:0x3ffec330 in AsyncWebServerRequest::_onData(void*, unsigned int) at lib\ESPAsyncWebServer-yuboxfixes-0xFEEDC0DE64-cleanup\src/WebRequest.cpp:814
  #11 0x400ec3cd:0x3ffec370 in std::_Function_handler<void (void*, AsyncClient*, void*, unsigned int), AsyncWebServerRequest::AsyncWebServerRequest(AsyncWebServer*, AsyncClient*)::{lambda(void*, AsyncClient*, void*, unsigned int)#6}>::_M_invoke(std::_Any_data const&, void*&&, AsyncClient*&&, std::_Any_data const&, unsigned int&&) at lib\ESPAsyncWebServer-yuboxfixes-0xFEEDC0DE64-cleanup\src/WebRequest.cpp:814
      (inlined by) _M_invoke at c:\users\pc\.platformio\packages\toolchain-xtensa32@2.50200.97\xtensa-esp32-elf\include\c++\5.2.0/functional:1871
  #12 0x401785ad:0x3ffec390 in std::function<void (void*, AsyncClient*, void*, unsigned int)>::operator()(void*, AsyncClient*, void*, unsigned int) const at lib\AsyncTCPSock\src/AsyncTCP.cpp:360
      (inlined by) AsyncClient::_sockIsReadable() at lib\AsyncTCPSock\src/AsyncTCP.cpp:885
  #13 0x401780b9:0x3ffec3c0 in _asynctcpsock_task(void*) at lib\AsyncTCPSock\src/AsyncTCP.cpp:360
  #14 0x4008fc8a:0x3ffec410 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Core 0 register dump:
PC      : 0x4019dcfa  PS      : 0x00060834  A0      : 0x801657e6  A1      : 0x3ffdb230
A2      : 0x00000000  A3      : 0x80000002  A4      : 0x00000001  A5      : 0x00000001
A6      : 0x00060920  A7      : 0x00000000  A8      : 0x8016407a  A9      : 0x3ffdb200
A10     : 0x00000000  A11     : 0x00060923  A12     : 0x00060920  A13     : 0x3ffdab90
A14     : 0x00000000  A15     : 0x3ffdaf20  SAR     : 0x00000000  EXCCAUSE: 0x00000006
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x00000000

ELF file SHA256: 0000000000000000

Backtrace: 0x4019dcfa:0x3ffdb230 0x401657e3:0x3ffdb250 0x40091445:0x3ffdb270 0x4008fc8a:0x3ffdb290
  #0  0x4019dcfa:0x3ffdb230 in esp_pm_impl_waiti at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/pm_esp32.c:492
  #1  0x401657e3:0x3ffdb250 in esp_vApplicationIdleHook at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/freertos_hooks.c:108
  #2  0x40091445:0x3ffdb270 in prvIdleTask at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/tasks.c:3507
  #3  0x4008fc8a:0x3ffdb290 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

Always related to ArduinoJson/Numbers/parseNumber.hpp:144 and Spiram

zekageri commented 2 years ago

PLATFORMIO INI:

[env:esp32dev]
;platform    = espressif32
platform    = https://github.com/platformio/platform-espressif32.git
board       = esp-wrover-kit
framework   = arduino

board_build.f_cpu   = 240000000L

upload_port     = COM6
upload_speed    = 921600
monitor_speed   = 115200
monitor_filters = esp32_exception_decoder

board_build.flash_size = 16MB
board_build.flash_mode = dio
board_build.partitions = ./hsh_Partition.csv
board_build.f_flash    = 80000000L

build_flags = -DBOARD_HAS_PSRAM
              -mfix-esp32-psram-cache-issue
              -DCORE_DEBUG_LEVEL=5
              -D CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY
              -D CONFIG_SPIRAM_ALLOW_STACK_EXTERNAL_MEMORY

extra_scripts = mklittlefs/replace_fs.py
bblanchon commented 2 years ago

Hi @zekageri,

I can see vPortCPUAcquireMutexIntsDisabled() in both stack traces. This function along with Interrupt wdt timeout on CPU1 suggest that the program deadlocks in heap_caps_malloc().

There is nothing I can do for you. Please contact ESP32 or ESPAsyncWebServer's support, and keep me informed of your progress.

Best regards, Benoit

zekageri commented 2 years ago

Thank you for your response. I did contacted with esp32 support. It looks like I was using an old framework, I upgrade it to the latest and will report back.

zekageri commented 2 years ago

The software crashed before even with this line: ESP.getPsramSize(); in a task. I tried with these:

void checkPS_RAM(){
    char * psRam = (char *) ps_malloc (500 * sizeof (char));
    if (psRam == NULL){
        Serial.println ("PS_RAM: ERROR");
    }else{
        Serial.println ("PS_RAM: OK");
        free(psRam);
    }
}

void psLoopTask(void* parameter) {
    checkPS_RAM();
    vTaskDelete(NULL);
}

Now with this PIO configuration:

[env:arduino-esp32]
;platform    = espressif32
;platform    = https://github.com/platformio/platform-espressif32.git
platform    = https://github.com/platformio/platform-espressif32.git#feature/arduino-upstream
board       = esp32dev ;esp-wrover-kit
framework   = arduino

platform_packages =
   framework-arduinoespressif32 @ https://github.com/espressif/arduino-esp32#master

board_build.f_cpu   = 240000000L

upload_port     = COM6
upload_speed    = 921600
monitor_speed   = 115200
monitor_filters = esp32_exception_decoder

board_build.flash_size = 16MB
board_build.flash_mode = dio
board_build.partitions = ./hsh_Partition.csv
board_build.f_flash    = 80000000L

build_flags =   -DBOARD_HAS_PSRAM
                -mfix-esp32-psram-cache-issue
                -DCORE_DEBUG_LEVEL=5
                -D CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY
                -D CONFIG_SPIRAM_ALLOW_STACK_EXTERNAL_MEMORY

extra_scripts = mklittlefs/replace_fs.py

These things seems to work, but when i use SpiRamAllocator in a websocket callback i got this crash:

Guru Meditation Error: Core  1 panic'ed (Unhandled debug exception). 
Debug exception reason: Stack canary watchpoint triggered (asyncTcpSock) 
Core  1 register dump:
PC      : 0x400f5113  PS      : 0x00060236  A0      : 0x800f5309  A1      : 0x3ffe8340
A2      : 0x3ffe867c  A3      : 0x3f41ae55  A4      : 0x00000000  A5      : 0x0000ff00
A6      : 0x00ff0000  A7      : 0xff000000  A8      : 0x00000025  A9      : 0x3ffe8320
A10     : 0x3ffe867c  A11     : 0x00000000  A12     : 0x00000001  A13     : 0x3ffec38c
A14     : 0x0000000e  A15     : 0xff000000  SAR     : 0x00000018  EXCCAUSE: 0x00000001
EXCVADDR: 0x00000000  LBEG    : 0x4008b04c  LEND    : 0x4008b056  LCOUNT  : 0x00000000  

Backtrace:0x400f5110:0x3ffe83400x400f5306:0x3ffe8360 0x400daf21:0x3ffe8380 0x400db059:0x3ffec3e0 0x400ecd16:0x3ffec460 0x400ea0d5:0x3ffec4b0 0x400ea41a:0x3ffec500 0x400ea639:0x3ffec560 0x4017e735:0x3ffec580 0x4017dfdb:0x3ffec5b0 
  #0  0x400f5110:0x3ffe83400 in String::setSSO(bool) at C:/Users/Pc/.platformio/packages/framework-arduinoespressif32/cores/esp32/WString.h:313
      (inlined by) String::init() at C:/Users/Pc/.platformio/packages/framework-arduinoespressif32/cores/esp32/WString.cpp:149

ELF file SHA256: 0000000000000000

Rebooting...

Which can not be true because my websocket callback works as it is just with DynamicJsonDocument instead of SpiRamJsonDocument.

zekageri commented 2 years ago

So i upgraded to the latest esp32-arduino sdk

Looks like this in the platformio.ini

platform    = https://github.com/platformio/platform-espressif32.git#feature/arduino-upstream
board       = esp32dev
framework   = arduino

platform_packages =
   framework-arduinoespressif32 @ https://github.com/espressif/arduino-esp32#master

aand increased the stack depth of the AsyncTCP task and now the SpiRamJsonDocument seems to work just fine.

Sorry for this ticket. I hope somebody can benefit from it and thank you for your suggestion, help and this amazing library.