Crash and reboot during boot with v23.8.22

T3rm1 commented 1 year ago

What happened?

My ESP32-WROOM-32E no longer boots with newest commit.

Looks like it crashes when trying to open the configuration file.

Log for uploading image

``` Processing generic (board: esp32dev; framework: arduino; platform: espressif32@6.3.2) --------------------------------------------------------------------------------------------------------------------------------------------------Verbose mode can be enabled via `-v, --verbose` option Firmware Revision: v23.8.22 No custom_patches specified CONFIGURATION: https://docs.platformio.org/page/boards/espressif32/esp32dev.html PLATFORM: Espressif 32 (6.3.2) > Espressif ESP32 Dev Module HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash DEBUG: Current (cmsis-dap) External (cmsis-dap, esp-bridge, esp-prog, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa) PACKAGES: - framework-arduinoespressif32 @ 3.20009.0 (2.0.9) - tool-esptoolpy @ 1.40501.0 (4.5.1) - tool-mkfatfs @ 2.0.1 - tool-mklittlefs @ 1.203.210628 (2.3) - tool-mkspiffs @ 2.230.0 (2.30) - tool-openocd-esp32 @ 2.1100.20220706 (11.0) - toolchain-xtensa-esp32 @ 8.4.0+2021r2-patch5 LDF: Library Dependency Finder -> https://bit.ly/configure-pio-ldf LDF Modes: Finder ~ chain, Compatibility ~ soft Found 47 compatible libraries Scanning dependencies... Dependency Graph |-- ESP Async WebServer @ 1.2.3+sha.1dde9cf |-- ArduinoJson @ 6.21.3 |-- espMqttClient @ 1.4.4+sha.f633972 |-- RF24 @ 1.4.7 |-- U8g2 @ 2.35.4 |-- sunset @ 1.1.7 |-- LittleFS @ 2.0.0 |-- Hoymiles @ 0.0.1 |-- Ethernet @ 2.0.0 |-- Update @ 2.0.0 |-- ResetReason |-- TimeoutHelper |-- DNSServer @ 2.0.0 |-- WiFi @ 2.0.0 |-- MqttSubscribeParser |-- Ticker @ 2.0.0 Building in release mode Retrieving maximum program size .pio\build\generic\firmware.elf Checking size .pio\build\generic\firmware.elf Advanced Memory Usage is available via "PlatformIO Home > Project Inspect" RAM: [== ] 20.0% (used 65576 bytes from 327680 bytes) Flash: [======== ] 77.9% (used 1531013 bytes from 1966080 bytes) Configuring upload protocol... AVAILABLE: cmsis-dap, esp-bridge, esp-prog, espota, esptool, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa CURRENT: upload_protocol = esptool Looking for upload port... Using manually specified: COM3 Uploading .pio\build\generic\firmware.bin esptool.py v4.5.1 Serial port COM3 Connecting.... Chip is ESP32-D0WD (revision v1.0) Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None Crystal is 40MHz MAC: 8c:ce:4e:89:64:b0 Uploading stub... Running stub... Stub running... Changing baud rate to 460800 Changed. Configuring flash size... Flash will be erased from 0x00001000 to 0x00005fff... Flash will be erased from 0x00008000 to 0x00008fff... Flash will be erased from 0x0000e000 to 0x0000ffff... Flash will be erased from 0x00010000 to 0x00187fff... Compressed 17488 bytes to 12168... Writing at 0x00001000... (100 %) Wrote 17488 bytes (12168 compressed) at 0x00001000 in 0.5 seconds (effective 301.9 kbit/s)... Hash of data verified. Compressed 3072 bytes to 129... Writing at 0x00008000... (100 %) Wrote 3072 bytes (129 compressed) at 0x00008000 in 0.0 seconds (effective 594.1 kbit/s)... Hash of data verified. Compressed 8192 bytes to 47... Writing at 0x0000e000... (100 %) Wrote 8192 bytes (47 compressed) at 0x0000e000 in 0.1 seconds (effective 1021.1 kbit/s)... Hash of data verified. Compressed 1536768 bytes to 1012698... Writing at 0x00010000... (1 %) Writing at 0x0001567d... (3 %) Writing at 0x00019672... (4 %) Writing at 0x0001d773... (6 %) Writing at 0x00021769... (8 %) Writing at 0x00025764... (9 %) Writing at 0x0002975f... (11 %) Writing at 0x0002d75a... (12 %) Writing at 0x00031755... (14 %) Writing at 0x00035750... (16 %) Writing at 0x0003974b... (17 %) Writing at 0x0003db74... (19 %) Writing at 0x00047346... (20 %) Writing at 0x000538c5... (22 %) Writing at 0x0005eb0c... (24 %) Writing at 0x00068fba... (25 %) Writing at 0x00077165... (27 %) Writing at 0x00083864... (29 %) Writing at 0x00089beb... (30 %) Writing at 0x00090185... (32 %) Writing at 0x00096fe3... (33 %) Writing at 0x0009e29f... (35 %) Writing at 0x000a3cba... (37 %) Writing at 0x000aa11e... (38 %) Writing at 0x000b016d... (40 %) Writing at 0x000b6103... (41 %) Writing at 0x000bbfff... (43 %) Writing at 0x000c15bb... (45 %) Writing at 0x000c75aa... (46 %) Writing at 0x000cdf28... (48 %) Writing at 0x000d3232... (50 %) Writing at 0x000d85dd... (51 %) Writing at 0x000dd90e... (53 %) Writing at 0x000e2c1e... (54 %) Writing at 0x000e7f82... (56 %) Writing at 0x000ed53b... (58 %) Writing at 0x000f24c5... (59 %) Writing at 0x000f7bab... (61 %) Writing at 0x000fccd8... (62 %) Writing at 0x00101e05... (64 %) Writing at 0x0010724b... (66 %) Writing at 0x0010cee0... (67 %) Writing at 0x001124c5... (69 %) Writing at 0x001176c8... (70 %) Writing at 0x0011cbd4... (72 %) Writing at 0x00121e50... (74 %) Writing at 0x00127256... (75 %) Writing at 0x0012c814... (77 %) Writing at 0x00131de1... (79 %) Writing at 0x00137566... (80 %) Writing at 0x0013d42e... (82 %) Writing at 0x00142f9f... (83 %) Writing at 0x001489c8... (85 %) Writing at 0x0014e3e7... (87 %) Writing at 0x00154aab... (88 %) Writing at 0x0015d41b... (90 %) Writing at 0x00165fe6... (91 %) Writing at 0x0016b070... (93 %) Writing at 0x0017277a... (95 %) Writing at 0x00177e6b... (96 %) Writing at 0x0017d10d... (98 %) Writing at 0x001827a7... (100 %) Wrote 1536768 bytes (1012698 compressed) at 0x00010000 in 22.9 seconds (effective 537.2 kbit/s)... Hash of data verified. Leaving... Hard resetting via RTS pin... ========================================================== [SUCCESS] Took 33.11 seconds ========================================================== Environment Status Duration ------------- -------- ------------ generic SUCCESS 00:00:33.112 ========================================================== 1 succeeded in 00:00:33.112 ========================================================== ```

Log during boot

``` 12:39:56.964 > Starting OpenDTU 12:39:56.964 > Initialize FS... done 12:39:56.968 > Reading configuration... [ 34][E][vfs_api.cpp:105] open(): /littlefs/config.json does not exist, no permits for creation 12:39:56.978 > Failed to read file, using default configuration 12:39:56.981 > done 12:39:56.983 > Reading PinMapping... [ 47][E][vfs_api.cpp:105] open(): /littlefs/pin_mapping.json does not exist, no permits for creation 12:39:56.992 > using default config done 12:39:56.995 > Initialize Network... done 12:39:57.105 > Setting Hostname... Initialize NTP... done 12:39:57.109 > Initialize SunPosition... done 12:39:57.110 > Initialize MqTT... done 12:39:57.113 > Initialize WebApi... done 12:39:57.120 > Initialize Display... done 12:39:57.123 > Initialize LEDs... done 12:39:57.123 > Check for default DTU serial... generate serial based on ESP chip id: 199980104208... Guru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled. 12:39:57.140 > 12:39:57.140 > Core 1 register dump: 12:39:57.140 > PC : 0x4008bcba PS : 0x00060430 A0 : 0x80116b3d A1 : 0x3ffb1e70 12:39:57.148 > A2 : 0x00000000 A3 : 0x3ffb9188 A4 : 0x00000008 A5 : 0x00000001 12:39:57.157 > A6 : 0x000000a4 A7 : 0x0000002f A8 : 0x00000004 A9 : 0x00000000 12:39:57.165 > A10 : 0x00000001 A11 : 0x3ffca0b8 A12 : 0x00000004 A13 : 0x00000001 12:39:57.173 > A14 : 0x00060620 A15 : 0x00000001 SAR : 0x00000018 EXCCAUSE: 0x0000001c 12:39:57.182 > EXCVADDR: 0x00000004 LBEG : 0x4008bc81 LEND : 0x4008bc91 LCOUNT : 0xfffffffa 12:39:57.187 > 12:39:57.187 > 12:39:57.187 > Backtrace: 0x4008bcb7:0x3ffb1e70 0x40116b3a:0x3ffb1e90 0x40116e79:0x3ffb1eb0 0x401a0858:0x3ffb1ed0 0x401a0901:0x3ffb1f00 0x40195d32:0x3ffb1f20 0x401962f9:0x3ffb1f60 0x40196521:0x3ffb1f90 0x400eefdd:0x3ffb2020 0x400d5a2d:0x3ffb2050 0x400eeccb:0x3ffb2240 0x40109582:0x3ffb2290 12:39:57.663 > 12:39:57.663 > #0 0x4008bcb7:0x3ffb1e70 in strncmp at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/string/strncmp.c:6512:39:57.663 > #1 0x40116b3a:0x3ffb1e90 in translate_path at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/vfs/vfs.c:296 12:39:57.663 > #2 0x40116e79:0x3ffb1eb0 in esp_vfs_open at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/vfs/vfs.c:397 12:39:57.663 > #3 0x401a0858:0x3ffb1ed0 in _fopen_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fopen.c:129 12:39:57.663 > #4 0x401a0901:0x3ffb1f00 in fopen at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fopen.c:168 12:39:57.663 > #5 0x40195d32:0x3ffb1f20 in VFSFileImpl::VFSFileImpl(VFSImpl*, char const*, char const*) at C:/Users/T3rm1/.platformio/packages/framework-arduinoespressif32/libraries/FS/src/vfs_api.cpp:330 12:39:57.663 > #6 0x401962f9:0x3ffb1f60 in void __gnu_cxx::new_allocator::construct(VFSFileImpl*, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\ext/new_allocator.h:136 12:39:57.663 > (inlined by) void std::allocator_traits >::construct(std::allocator&, VFSFileImpl*, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/alloc_traits.h:475 12:39:57.663 > (inlined by) std::_Sp_counted_ptr_inplace, (__gnu_cxx::_Lock_policy)2>::_Sp_counted_ptr_inplace(std::allocator, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr_base.h:545 12:39:57.663 > (inlined by) std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count, VFSImpl*, char const*&, char const*&>(VFSFileImpl*&, std::_Sp_alloc_shared_tag >, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr_base.h:677 12:39:57.663 > (inlined by) std::__shared_ptr::__shared_ptr, VFSImpl*, char const*&, char const*&>(std::_Sp_alloc_shared_tag >, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr_base.h:1342 12:39:57.663 > (inlined by) std::shared_ptr::shared_ptr, VFSImpl*, char const*&, char const*&>(std::_Sp_alloc_shared_tag >, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr.h:359 12:39:57.663 > (inlined by) std::shared_ptr std::allocate_shared, VFSImpl*, char const*&, char const*&>(std::allocator const&, VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr.h:706 12:39:57.663 > (inlined by) std::shared_ptr std::make_shared(VFSImpl*&&, char const*&, char const*&) at c:\users\t3rm1\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/shared_ptr.h:722 12:39:57.663 > #7 0x40196521:0x3ffb1f90 in VFSImpl::open(char const*, char const*, bool) at C:/Users/T3rm1/.platformio/packages/framework-arduinoespressif32/libraries/FS/src/vfs_api.cpp:64 12:39:57.663 > #8 0x400eefdd:0x3ffb2020 in fs::FS::open(char const*, char const*, bool) at C:/Users/T3rm1/.platformio/packages/framework-arduinoespressif32/libraries/FS/src/FS.cpp:234 12:39:57.663 > #9 0x400d5a2d:0x3ffb2050 in ConfigurationClass::write() at src/Configuration.cpp:20 12:39:57.663 > #10 0x400eeccb:0x3ffb2240 in setup() at src/main.cpp:141 12:39:57.663 > #11 0x40109582:0x3ffb2290 in loopTask(void*) at C:/Users/T3rm1/.platformio/packages/framework-arduinoespressif32/cores/esp32/main.cpp:42 12:39:57.663 > 12:39:57.663 > 12:39:57.663 > 12:39:57.663 > 12:39:57.663 > ELF file SHA256: 9b90468d1745b5b0 12:39:57.665 > 12:39:57.665 > E (472) esp_core_dump_flash: Core dump flash config is corrupted! CRC=0x7bd5c66f instead of 0x0 12:39:57.665 > Rebooting... ```

To Reproduce Bug

Just compile code and upload to ESP32.

Expected Behavior

No boot loop.

Install Method

Self-Compiled

What git-hash/version of OpenDTU?

08ca2214102ea0c3fd9cd5fbc496d391f0e7ed3f

Anything else?

No problems with commit 7e283369e96da333d32366e406e58a80d276b2ec

tbnobody commented 1 year ago

I've just used a new ESP (as you did because you don't have any config data on your partition) and it worked without any problems. Have you tried to erase the ESP and completly reprogram it?

T3rm1 commented 1 year ago

Yes, I erased it with the PlatformIO extension. Did that multiple times. Same result. I tested it with an old version and that works fine. Added that information to first post.

tbnobody commented 1 year ago

I don't think that the erase was successfull... Otherwise you should see a

Starting OpenDTU
Initialize FS... ./components/esp_littlefs/src/littlefs/lfs.c:1229:error: Corrupted dir pair at {0x0, 0x1}
E (18) esp_littlefs: mounfft failed,  (-84)

at the first boot. Did you also try a power cycle?

Not sure what's wrong with your ESP, but it doesn't seem to be a general issue.

T3rm1 commented 1 year ago

I erased it several times and also uploaded it several times. Maybe I didn't do it when I logged the output. I also did multiple power cycles. Well, my ESP works with the old version from March. I switched back to that one for now. But since it is working, this usually means that the code changes introduced a bug.

tbnobody commented 1 year ago

You could try several other versions to determine until which version it works.

T3rm1 commented 1 year ago

Ok, I spent way more time on this than planned but I hope this helps you. Ran a git bisect and tested several builds:

F:\src\OpenDTU> git bisect good
5bbc67bc49d2fb32298916f23e8c2e5be17078d6 is the first bad commit
commit 5bbc67bc49d2fb32298916f23e8c2e5be17078d6
Author: Thomas Basler <thomas@familie-basler.net>
Date:   Mon Jul 31 22:52:38 2023 +0200

    Fix: Clear parser buffers to prevent random numbers if no data was received

 lib/Hoymiles/src/parser/AlarmLogParser.cpp         | 1 +
 lib/Hoymiles/src/parser/DevInfoParser.cpp          | 2 ++
 lib/Hoymiles/src/parser/StatisticsParser.cpp       | 1 +
 lib/Hoymiles/src/parser/SystemConfigParaParser.cpp | 1 +
 4 files changed, 5 insertions(+)

Everything before that commit worked. But looking at the changes I don't know how this could cause the error.

Edit: Just to be 100 % sure I tested those two commits again and I can reproduce the issue: 5bbc67bc49d2fb32298916f23e8c2e5be17078d6 - Not working. Boot loop. 2eeb7423bfe98ddb33c2bf2871c77ced04dc5200 - No boot loop.

stefan123t commented 3 months ago

@T3rm1 given this issue is open for more than a year, could you try it with one of the latest release versions ? https://github.com/tbnobody/OpenDTU/releases Either 24.08.05 or 24.06.29 should be running fairly fine IMHO, though 24.08.01 should be avoided for some issue introduced with it and fixed yesterday.

tbnobody / OpenDTU