ESP32-D0WDQ6 crash after flash

[muhlpachr]

PS C:\Users\michal\test> jag flash
v COM13
Enter WiFi network (SSID): ros2p
Enter WiFi password for 'ros2p': ******
Flashing device over serial on port 'COM13' ...
esptool.py v3.0
Serial port COM13
Connecting......
Chip is ESP32-D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 80:7d:3a:e4:d7:a0
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 15392 bytes to 10770...
Wrote 15392 bytes (10770 compressed) at 0x00001000 in 0.1 seconds (effective 877.9 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 119...
Wrote 3072 bytes (119 compressed) at 0x00008000 in 0.0 seconds (effective 3120.2 kbit/s)...
Hash of data verified.
Compressed 1102176 bytes to 727320...
Wrote 1102176 bytes (727320 compressed) at 0x00010000 in 10.7 seconds (effective 826.2 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
PS C:\Users\michal\test> jag monitor
Starting serial monitor of port 'COM13' ...
ets Jun  8 2016 00:22:57

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:2
load:0x3fff0030,len:188
ho 0 tail 12 room 4
load:0x40078000,len:12180
load:0x40080400,len:2936
entry 0x400805c8
clearing RTC memory: RTC memory is in inconsistent state
[flash reg] address 0x3f430000, size 0x00200000
----
Decode system message with:
----
jag decode --system WyNVBVVYU1UGdjEuNi42U1UAWyRVI1UQAAAAAAAAAAAAAAAAAAAAAFsjVQRVRVNVCUVYQ0VQVElPTlNVAFsjVQJVU1sjVRpbI1UDVUZVAEky1lsjVQNVRlUBSTNdWyNVA1VGVQJJMyhbI1UDVUZVA0kzCVsjVQNVRlUESVI0WyNVA1VGVQVsAACcBVsjVQNVRlUGSQL2WyNVA1VGVQdJFbtbI1UDVUZVCEkV0FsjVQNVRlUJSRVVWyNVA1VGVQpJBDdbI1UDVUZVC0kCfVsjVQNVRlUMSRW7WyNVA1VGVQ1JFdBbI1UDVUZVDkkVVVsjVQNVRlUPSQKVWyNVA1VGVRBJArdbI1UDVUZVEUkUjlsjVQNVRlUSSSQQWyNVA1VGVRNJZJlbI1UDVUZVFEkVu1sjVQNVRlUVSRXQWyNVA1VGVRZJFVVbI1UDVUZVF0lkrFsjVQNVRlUYSWTBWyNVA1VGVRlJFLM=
----
Decode system message with:
----
jag decode --system WyNVBVVYU1UGdjEuNi42U1UAWyRVI1UQAAAAAAAAAAAAAAAAAAAAAFsjVQRVRVNVCUVYQ0VQVElPTlNVAFsjVQJVU1sjVRZbI1UDVUZVAEky1lsjVQNVRlUBSTNdWyNVA1VGVQJJMyhbI1UDVUZVA0kzCVsjVQNVRlUESVJEWyNVA1VGVQVsAACcPVsjVQNVRlUGSQREWyNVA1VGVQdJAn1bI1UDVUZVCEkVu1sjVQNVRlUJSRXQWyNVA1VGVQpJFVVbI1UDVUZVC0kClVsjVQNVRlUMSQK3WyNVA1VGVQ1JFI5bI1UDVUZVDkkkEFsjVQNVRlUPSWSZWyNVA1VGVRBJFbtbI1UDVUZVEUkV0FsjVQNVRlUSSRVVWyNVA1VGVRNJZKxbI1UDVUZVFElkwVsjVQNVRlUVSRSz
[jaguar] ERROR: rebooting due to
Entering deep sleep for 1000ms
ets Jun  8 2016 00:22:57

jag version
Version:         v1.0.3
SDK version:     v1.6.6
Build date:      2022-02-10T16:35:08Z

EXCEPTION error.
  0: flash_kv_init_            <sdk>/device_impl.toit:103:3
  1: KeyValue_                 <sdk>/device_impl.toit:88:14
  2: FlashStore_.init_         <sdk>/device_impl.toit:37:17
  3: FlashStore_.instance      <sdk>/device_impl.toit:42:46
  4: FlashStore.get            <sdk>/device.toit:59:28
  5: ProgramManager.last       /home/runner/work/jaguar/jaguar/src/programs.toit:31:23
  6: serve.<block>             /home/runner/work/jaguar/jaguar/src/jaguar.toit:61:21
  7: catch.<block>             <sdk>/core/exceptions.toit:114:10
  8: catch                     <sdk>/core/exceptions.toit:112:1
  9: catch                     <sdk>/core/exceptions.toit:63:10
 10: serve                     /home/runner/work/jaguar/jaguar/src/jaguar.toit:60:16
 11: main.<block>.<block>      /home/runner/work/jaguar/jaguar/src/jaguar.toit:32:33
 12: catch.<block>             <sdk>/core/exceptions.toit:114:10
 13: catch                     <sdk>/core/exceptions.toit:112:1
 14: catch                     <sdk>/core/exceptions.toit:63:10
 15: main.<block>              /home/runner/work/jaguar/jaguar/src/jaguar.toit:32:18
 16: main                      /home/runner/work/jaguar/jaguar/src/jaguar.toit:29:1
 17: __entry__.<lambda>        <sdk>/core/entry.toit:48:20

EXCEPTION error.
  0: flash_kv_init_            <sdk>/device_impl.toit:103:3
  1: KeyValue_                 <sdk>/device_impl.toit:88:14
  2: FlashStore_.init_         <sdk>/device_impl.toit:37:17
  3: FlashStore_.instance      <sdk>/device_impl.toit:42:46
  4: FlashStore.delete         <sdk>/device.toit:67:21
  5: ProgramManager.last=      /home/runner/work/jaguar/jaguar/src/programs.toit:39:14
  6: serve                     /home/runner/work/jaguar/jaguar/src/jaguar.toit:73:18
  7: main.<block>.<block>      /home/runner/work/jaguar/jaguar/src/jaguar.toit:32:33
  8: catch.<block>             <sdk>/core/exceptions.toit:114:10
  9: catch                     <sdk>/core/exceptions.toit:112:1
 10: catch                     <sdk>/core/exceptions.toit:63:10
 11: main.<block>              /home/runner/work/jaguar/jaguar/src/jaguar.toit:32:18
 12: main                      /home/runner/work/jaguar/jaguar/src/jaguar.toit:29:1
 13: __entry__.<lambda>        <sdk>/core/entry.toit:48:20

[kasperl]

My guess would be that somehow the NVS partition has become corrupt. Maybe Jaguar needs to handle that and erase the partition? Or maybe it should report it in a nicer way so it is possible for the user to erase the flash manually.

[kasperl]

We believe this corruption may have been fixed in toitlang/jaguar@81eac4d, so closing this for now. Feel free to reopen the issue (or post a new one) and thanks for reporting this!

[muhlpachr]

No change with v1.0.5.
I wonder how fix in program upload can affect crash just after jag flash (without any program upload) ?

[kasperl]

Maybe you can try erasing the flash before we conclude too much about v1.0.5? The problem might very well still be there, but if there is flash corruption due to concurrent flashing operations (something that should no longer be the case in v1.0.5), we will not know if we've fixed it before you try to erase your flash and start over:

$HOME/.cache/jaguar/esptool --chip esp32 erase_flash

Thanks!

[muhlpachr]

On that particular board I was not able to upload any program because I did not pass through jag flash.
So root cause of trouble is not definitely concurrent program upload.

After erase_flash chip/board is fine.

You should definitely support erase_flash at least as option for flash or separate operation in jag.
Thank you.

[muhlpachr]

And report error in more readable way or add autofix while trying access flash_kv during boot.

[kasperl]

Filed toitlang/jaguar#134 to track this. Thanks!