ESP32 c3 wdt reboot fail (IDFGH-6051)

u-tec-com commented 3 years ago

use C3 in battery/low power product. The wdt reboot system in some situation. But reboot fail

u-tec-com commented 3 years ago

invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalÿESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x7 (TG0WDT_SYS_RST),boot:0xf (SPI_FAST_FLASH_BOOT) Saved PC:0x4004c0dc invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f

Alvin1Zhang commented 3 years ago

@u-tec-com Thanks for reporting. Would you please help provide more details as suggested in the issue template? Information like elf, sdk configuration, backtrace, log outputs, commit ID, hardware and etc. would help us debug further. Thanks.

Alvin1Zhang commented 2 years ago

Thanks for reporting, would you please help share if more details for the issue? Thanks.

AxelLin commented 2 years ago

@Alvin1Zhang What could be the reason to cause "invalid header: 0xffffff7f"?

I had similar issue on a esp32-wroom-32e module: rst:0x10 (RTCWDT_RTC_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT) invalid header: 0xaacc9cbb invalid header: 0xaacc9cbb

I couldn't resolve the issue (cannot reprogram the module any more) and I cannot reproduce the issue on other devices, then I just throw away that module. But I'm curious what can cause the "invalid header"?

bbinet commented 2 years ago

I face the exact same issue as @u-tec-com, with same symptoms:

...
invalid header: 0xffffff7f
invalid header: 0xffffff7f
invalid heade�ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
invalid header: 0xffffff7f
...

We also power our ESP32 C3 on battery while trying to minimize consumption by user the Power Management module with the following configuration:

    esp_pm_config_esp32c3_t pm_config = {
        .max_freq_mhz = 160,
        .min_freq_mhz = 10,
        .light_sleep_enable = true,
    };

I don't know what has initially triggered the watchdog, but after running normally during about a day, the ESP32 C3 is now in a reboot (RTCWDT_RTC_RESET) loop. If I manually reset the ESP32 C3, it restarts normally though.

As a workaround, is there a way to configure the watchdog to act as a normal reset (like if we reset the ESP32 C3 manually), waiting for this problem to be solved?

FYI, we use a ESP32-C3-WROOM-02 module, with ESP-IDF master branch.

bbinet commented 2 years ago

The issue has just occurred a second time on the same esp32c3 after a few days where it was working just fine. @Alvin1Zhang do you know what does mean "invalid header: 0xffffff7f" ?

esp-wzh commented 2 years ago

Hi, @bbinet , when first-stage-bootloader finishes executing and then loads Second stage bootloader from the flash, it will verify Second stage bootloader's header, and if it fails, it will prompt “invalid header: ...”, as you have encountered.

This error is usually caused by reading the wrong data from the flash, based on the above information this is difficult to reproduce, I suspect the problem is on the flash side, can you reproduce the above failure with USB powered? Another suggestion is that you can configure the flash wait time after power on through eFuse, you can search for EFUSE_FLASH_TPUW in the technical reference manual for more information.

For software, RTCWDT_RTC_RESET is already the highest level of reset, it will reset the entire system and RTC domain.

I am curious about if you have been stuck in the reset caused by "invalid header: 0xffffff7f", the reset reason should be TG0WDT_SYS_RST, how do you get RTCWDT_RTC_RESET. Can you show more logs?

esp-wzh commented 2 years ago

One more question, have you enabled flash encryption ? @bbinet

bbinet commented 2 years ago

Thank you @esp-wzh for your support.

No, flash encryption is not enabled.

I don't know why I get RTCWDT_RTC_RESET in the logs and not TG0WDT_SYS_RST, and I don't really have more logs to show as my esp32c3 is stuck showing invalid header: 0xffffff7f, and reset regularly by the watchdog with RTCWDT_RTC_RESET, but the watchdog does not fix the issue:

invalid header: 0xffffff7f
invalid header: 0xffffff7f
invalid heade�ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
invalid header: 0xffffff7f
[many more invalid header: 0xffffff7f]
invalid header: 0xffffff7f
invalid header: 0xffffff7f
invalid heade�ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
invalid header: 0xffffff7f
[many more invalid header: 0xffffff7f]
invalid header: 0xffffff7f
invalid header: 0xffffff7f
invalid heade�ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
invalid header: 0xffffff7f
[many more invalid header: 0xffffff7f]

The esp32c3 restarts normally only when I manually reset the esp32c3 through the EN pin: how do the RTCWDT_RTC_RESET compares to a manual EN pin reset (what are the differences)?

Regarding configuring EFUSE_FLASH_TPUW in eFuse, which value should I set? And could you explain how to proceed to write to the eFuse?

Also, I will try to power my esp32c3 board from USB during a few days, and see if I can reproduce the issue.

esp-wzh commented 2 years ago

@bbinet thanks for the reply! A difference between RTCWDT_RTC_RESET and POWERON_RESET is that when you click the reset button it wil re-power the FLASH. So I think this problem is most likely caused by FLASH entering some unknown error state. Have you only had this problem with one module so far? Or encountered it on multiple modules?

(Considering these I don't think burn EFUSE_FLASH_TPUW is effective for this problem, please ignore this suggestion)

bbinet commented 2 years ago

@esp-wzh Ok so if POWERON_RESET re-power the FLASH and fixes the issue, is there a way to configure RTCWDT_RTC_RESET to do the same and re-power the FLASH too?

For the moment we encounter this issue with a single esp32c3 (but we are in a prototype phase so we have tested only 2 of them). Also @u-tec-com, on how many modules do you face this issue?

esp-wzh commented 2 years ago

@bbinet, Sorry it doesn't support re-power FLASH by watchdog because FLASH is independent of esp32c3 chip.

Mosher23 commented 2 years ago

I am experiencing same issue on my M5Stack Stamp-C3 board. After flashing with ESPHome Web tool i receive following logs.

esp-wzh commented 2 years ago

Hi, @Mosher23 , Thanks for your feedback! As far as I know ESPHome does not currently support esp32c3, how did you flash it?

Mosher23 commented 2 years ago

Hello @esp-wzh, i flashed it using ESP Web and compiled on my ESPHome instance 2022.05. I can choose C3 from board selection.

esp-wzh commented 2 years ago

Judging from your log, it is because a bin that does not meet the requirements of the ESP Firmware Image Format, or it is downloaded to the wrong location in FLASH. Maybe you can erase the flash and try it again, If it still doesn't work, you can create issue in the esphome project!

Mosher23 commented 2 years ago

Judging from your log, it is because a bin that does not meet the requirements of the ESP Firmware Image Format, or it is downloaded to the wrong location in FLASH. Maybe you can erase the flash and try it again, If it still doesn't work, you can create issue in the esphome project!

Could you give some hints on how to erase it?

esp-wzh commented 2 years ago

@Mosher23 , You can erase flash with esptool. Install it and run

esptool.py erase_flash

Mosher23 commented 2 years ago

Thank you! I have just tried it and it doesn't work. I get a fatal errror

`esptool.py erase_flash esptool.py v4.0 Found 2 serial ports Serial port /dev/cu.usbmodem51850299911 Connecting.... Detecting chip type... ESP32-C3 Chip is ESP32-C3 (revision 3) Features: Wi-Fi Crystal is 40MHz MAC: 84:f7:03:a8:d5:68 Uploading stub...

A fatal error occurred: Failed to write to target RAM (result was 01070000: Operation timed out)`

esp-wzh commented 2 years ago

But it works fine on my side... It's so weird, maybe there is a problem with the boot mode switching circuit of your dev-board, do you have any other boards encountering these problems? @Mosher23

Mosher23 commented 2 years ago

@esp-wzh I have zero problems with other boards. But it is also my first C3 board.

HiFiPhile commented 2 years ago

I've met 2 times this issue.

IDF version: v5.0-dev-3055-g179ea878c7
Build System: idf.py
Compiler version: gcc version 8.4.0 (crosstool-NG esp-2021r2-patch3)
Operating System: Windows

sdkconfig.zip

1st time

Module or chip used: Customized PCB ESP32-C3-MINI-1
Power Supply: Energy harvesting
No flash encryption

Same log output as @u-tec-com, unbricked with a manual reset.

2nd time

Module or chip used: Customized PCB ESP32-C3-WROOM
Power Supply: USB 5V
Flash Encryption enabled

This time the power is properly supplied. I didn't unbrick it successfully with a manual reset (via idf_monitor.py).

invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c

d:\mcu\esp32c3\project\prod>idf_monitor.py -p COM17
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \\.\COM17 instead...
--- idf_monitor on \\.\COM17 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
�ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xd (SPI_FAST_FLASH_BOOT)
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c
invalid header: 0xf64ab65c

Then I tried to read the efuse and it unbricked.

D:\mcu\esp32c3\linkify\prod>python -m espefuse --port COM17 summary
Connecting....
Detecting chip type... ESP32-C3
espefuse.py v4.1

=== Run "summary" command ===
EFUSE_NAME (Block) Description  = [Meaningful Value] [Readable/Writeable] (Hex Value)
----------------------------------------------------------------------------------------
Config fuses:
DIS_ICACHE (BLOCK0)                                Disables ICache                                    = False R/W (0b0)
DIS_DOWNLOAD_ICACHE (BLOCK0)                       Disables Icache when SoC is in Download mode       = True R/W (0b1)
DIS_FORCE_DOWNLOAD (BLOCK0)                        Disables forcing chip into Download mode           = False R/W (0b0)
DIS_CAN (BLOCK0)                                   Disables the TWAI Controller hardware              = False R/W (0b0)
VDD_SPI_AS_GPIO (BLOCK0)                           Set this bit to vdd spi pin function as gpio       = False R/W (0b0)
BTLC_GPIO_ENABLE (BLOCK0)                          Enable btlc gpio                                   = 0 R/W (0b00)
POWERGLITCH_EN (BLOCK0)                            Set this bit to enable power glitch function       = False R/W (0b0)
POWER_GLITCH_DSENSE (BLOCK0)                       Sample delay configuration of power glitch         = 0 R/W (0b00)
DIS_DIRECT_BOOT (BLOCK0)                           Disables direct boot mode                          = True R/W (0b1)
DIS_USB_SERIAL_JTAG_ROM_PRINT (BLOCK0)             Disables USB-Serial-JTAG ROM printing              = False R/W (0b0)
UART_PRINT_CONTROL (BLOCK0)                        Sets the default UART boot message output mode     = Enabled R/W (0b00)
FORCE_SEND_RESUME (BLOCK0)                         Force ROM code to send a resume command during SPI = False R/W (0b0)
                                                    bootduring SPI boot
ERR_RST_ENABLE (BLOCK0)                            Use BLOCK0 to check error record registers         = without check R/W (0b0)
BLOCK_USR_DATA (BLOCK3)                            User data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W

Efuse fuses:
WR_DIS (BLOCK0)                                    Disables programming of individual eFuses          = 8388864 R/W (0x00800100)
RD_DIS (BLOCK0)                                    Disables software reading from BLOCK4-10           = 1 R/W (0b0000001)

Flash Config fuses:
FLASH_TPUW (BLOCK0)                                Configures flash startup delay after SoC power-up, = 0 R/W (0x0)
                                                    unit is (ms/2). When the value is 15, delay is 7.
                                                   5 ms

Identity fuses:
SECURE_VERSION (BLOCK0)                            Secure version (used by ESP-IDF anti-rollback feat = 0 R/W (0x0000)
                                                   ure)
MAC (BLOCK1)                                       Factory MAC Address
   = 7c:df:a1:d1:d3:d4 (OK) R/W
WAFER_VERSION (BLOCK1)                             WAFER version                                      = 3 R/W (0b011)
PKG_VERSION (BLOCK1)                               Package version                                    = ESP32-C3 R/W (0b000)
BLOCK1_VERSION (BLOCK1)                            BLOCK1 efuse version                               = 0 R/W (0b000)
OPTIONAL_UNIQUE_ID (BLOCK2)                        Optional unique 128-bit ID
   = 2c 36 4a a1 25 75 82 77 dc a6 fb d8 35 10 bf 0a R/W
BLOCK2_VERSION (BLOCK2)                            Version of BLOCK2                                  = 6 R/W (0b110)
CUSTOM_MAC (BLOCK3)                                Custom MAC Address
   = 00:00:00:00:00:00 (OK) R/W

Jtag Config fuses:
SOFT_DIS_JTAG (BLOCK0)                             Software disables JTAG. When software disabled, JT = 0 R/W (0b000)
                                                   AG can be activated temporarily by HMAC peripheral
DIS_PAD_JTAG (BLOCK0)                              Permanently disable JTAG access via pads. USB JTAG = True R/W (0b1)
                                                    is controlled separately.

Security fuses:
DIS_DOWNLOAD_MANUAL_ENCRYPT (BLOCK0)               Disables flash encryption when in download boot mo = True R/W (0b1)
                                                   des
SPI_BOOT_CRYPT_CNT (BLOCK0)                        Enables encryption and decryption, when an SPI boo = Enable R/W (0b111)
                                                   t mode is set. Enabled when 1 or 3 bits are set,di
                                                   sabled otherwise
SECURE_BOOT_KEY_REVOKE0 (BLOCK0)                   If set, revokes use of secure boot key digest 0    = False R/W (0b0)
SECURE_BOOT_KEY_REVOKE1 (BLOCK0)                   If set, revokes use of secure boot key digest 1    = False R/W (0b0)
SECURE_BOOT_KEY_REVOKE2 (BLOCK0)                   If set, revokes use of secure boot key digest 2    = False R/W (0b0)
KEY_PURPOSE_0 (BLOCK0)                             KEY0 purpose                                       = XTS_AES_128_KEY R/- (0x4)
KEY_PURPOSE_1 (BLOCK0)                             KEY1 purpose                                       = USER R/W (0x0)
KEY_PURPOSE_2 (BLOCK0)                             KEY2 purpose                                       = USER R/W (0x0)
KEY_PURPOSE_3 (BLOCK0)                             KEY3 purpose                                       = USER R/W (0x0)
KEY_PURPOSE_4 (BLOCK0)                             KEY4 purpose                                       = USER R/W (0x0)
KEY_PURPOSE_5 (BLOCK0)                             KEY5 purpose                                       = USER R/W (0x0)
SECURE_BOOT_EN (BLOCK0)                            Enables secure boot                                = False R/W (0b0)
SECURE_BOOT_AGGRESSIVE_REVOKE (BLOCK0)             Enables aggressive secure boot key revocation mode = False R/W (0b0)
DIS_DOWNLOAD_MODE (BLOCK0)                         Disables all Download boot modes                   = False R/W (0b0)
ENABLE_SECURITY_DOWNLOAD (BLOCK0)                  Enables secure UART download mode (read/write flas = False R/W (0b0)
                                                   h only)
BLOCK_KEY0 (BLOCK4)
  Purpose: XTS_AES_128_KEY
    Encryption key0 or user data
   = ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? -/-
BLOCK_KEY1 (BLOCK5)
  Purpose: USER
               Encryption key1 or user data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W
BLOCK_KEY2 (BLOCK6)
  Purpose: USER
               Encryption key2 or user data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W
BLOCK_KEY3 (BLOCK7)
  Purpose: USER
               Encryption key3 or user data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W
BLOCK_KEY4 (BLOCK8)
  Purpose: USER
               Encryption key4 or user data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W
BLOCK_KEY5 (BLOCK9)
  Purpose: USER
               Encryption key5 or user data
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W
BLOCK_SYS_DATA2 (BLOCK10)                          System data (part 2)
   = 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 R/W

Spi_Pad_Config fuses:
SPI_PAD_CONFIG_CLK (BLOCK1)                        SPI CLK pad                                        = 0 R/W (0b000000)
SPI_PAD_CONFIG_Q (BLOCK1)                          SPI Q (D1) pad                                     = 0 R/W (0b000000)
SPI_PAD_CONFIG_D (BLOCK1)                          SPI D (D0) pad                                     = 0 R/W (0b000000)
SPI_PAD_CONFIG_CS (BLOCK1)                         SPI CS pad                                         = 0 R/W (0b000000)
SPI_PAD_CONFIG_HD (BLOCK1)                         SPI HD (D3) pad                                    = 0 R/W (0b000000)
SPI_PAD_CONFIG_WP (BLOCK1)                         SPI WP (D2) pad                                    = 0 R/W (0b000000)
SPI_PAD_CONFIG_DQS (BLOCK1)                        SPI DQS pad                                        = 0 R/W (0b000000)
SPI_PAD_CONFIG_D4 (BLOCK1)                         SPI D4 pad                                         = 0 R/W (0b000000)
SPI_PAD_CONFIG_D5 (BLOCK1)                         SPI D5 pad                                         = 0 R/W (0b000000)
SPI_PAD_CONFIG_D6 (BLOCK1)                         SPI D6 pad                                         = 0 R/W (0b000000)
SPI_PAD_CONFIG_D7 (BLOCK1)                         SPI D7 pad                                         = 0 R/W (0b000000)

Usb Config fuses:
DIS_USB_JTAG (BLOCK0)                              Disables USB JTAG. JTAG access via pads is control = True R/W (0b1)
                                                   led separately
DIS_USB_DEVICE (BLOCK0)                            Disables USB DEVICE                                = False R/W (0b0)
USB_EXCHG_PINS (BLOCK0)                            Exchanges USB D+ and D- pins                       = False R/W (0b0)
DIS_USB_SERIAL_JTAG_DOWNLOAD_MODE (BLOCK0)         Disables USB-Serial-JTAG download feature in UART  = False R/W (0b0)
                                                   download boot mode

Wdt Config fuses:
WDT_DELAY_SEL (BLOCK0)                             Selects RTC WDT timeout threshold at startup       = False R/W (0b0)

d:\mcu\esp32c3\project\prod>idf_monitor.py -p COM17
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \\.\COM17 instead...
--- idf_monitor on \\.\COM17 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xd (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd6110,len:0x15e4
load:0x403ce000,len:0x8d8
load:0x403cf600,len:0x31a4
entry 0x403ce000
I (30) boot: ESP-IDF v5.0-dev-2586-ga82e6e63d9-dirty 2nd stage bootloader
I (30) boot: compile time 12:36:10
I (30) boot: chip revision: 3
I (34) boot.esp32c3: SPI Speed      : 80MHz
I (39) boot.esp32c3: SPI Mode       : DIO
I (43) boot.esp32c3: SPI Flash Size : 4MB
I (48) boot: Enabling RNG early entropy source...
I (54) boot: Partition Table:
I (57) boot: ## Label            Usage          Type ST Offset   Length
I (65) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (79) boot:  2 coredump         Unknown data     01 03 00010000 00010000
I (87) boot:  3 factory          factory app      00 00 00020000 00140000
I (94) boot:  4 ota_0            OTA app          00 10 00160000 00140000
I (102) boot:  5 ota_1            OTA app          00 11 002a0000 00140000
I (109) boot:  6 otadata          OTA data         01 00 003e0000 00002000
I (117) boot:  7 nvs_key          NVS keys         01 04 003e2000 00001000
I (124) boot: End of partition table
I (129) esp_image: segment 0: paddr=00160020 vaddr=3c0a0020 size=1ef18h (126744) map
I (159) esp_image: segment 1: paddr=0017ef40 vaddr=3fc91c00 size=010d8h (  4312) load
I (160) esp_image: segment 2: paddr=00180020 vaddr=42000020 size=9620ch (614924) map
I (271) esp_image: segment 3: paddr=00216234 vaddr=3fc92cd8 size=019fch (  6652) load
I (273) esp_image: segment 4: paddr=00217c38 vaddr=40380000 size=11b1ch ( 72476) load
I (291) esp_image: segment 5: paddr=0022975c vaddr=50000010 size=00010h (    16) load
I (297) boot: Loaded app from partition at offset 0x160000
I (297) boot: Checking flash encryption...
I (300) flash_encrypt: flash encryption is enabled (0 plaintext flashes left)
I (307) boot: Disabling RNG early entropy source...

esp-wzh commented 2 years ago

Hi~@HiFiPhile,

I think the first thing to do is to confirm whether the data in the flash is still correct

For the first times, whether the boot is successful after powering on again? If it always prompts invalid header error. You can try to use the read_flash command of esptool to dump the data in the flash and compare it with the bin you downloaded to check whether the data in the flash is damaged.

You can also use the same method to check the chip with flash encryption enabled, but you need to use the encrypt_flash_data command of espsecure to encrypt the plaintext bin and then compare it with the dumped bin

HiFiPhile commented 2 years ago

I think the first thing to do is to confirm whether the data in the flash is still correct

The flash data is correct. The first time I recovered it with a manual reset.

Yesterday it happened again with my 2nd board, this time a reset with idf_monitor recovered it. Unfortunately I didn't activate log to file so I don't know the cause of reset.

I'm going to open the shield of ESP32-C3-WROOM and hook a logic analyzer into SPI flash and wait next failure, hope I don't need to wait 2 weeks:

If the timing is wrong, I suspect sleep gpio workaround.
if the timing is right, it could be flash MMU & cache.

HiFiPhile commented 2 years ago

Hi @u-tec-com @bbinet ,

Have you seen anymore this issue ?

I've set up logic analyzer & monitor log to wait the issue to trigger. I've only seen 3 times this issue in 4 months, I hope this time it won't take too much time.

bbinet commented 2 years ago

@HiFiPhile Since I've changed my code to deep sleep most of the time, I've not seen the issue anymore.

bbinet commented 2 years ago

I've finally reproduced the same issue on another esp32-c3 which was also in deep sleep most of the time. This new esp32-c3 was powered from an AC-DC converter (220V to 5V).

@esp-wzh So I have reproduced the issue on 2 different esp32-c3, either battery powered or powered from the mains...

niwantha33 commented 2 years ago

Try manually

check revision (Chip is ESP32-C3 (revision 3) )

esptool.py --chip auto --port /dev/ttyUSB0 chip_id

Detected flash size: 4MB

esptool.py --chip auto --port /dev/ttyUSB0 flash_id

Flash

esptool.py --chip esp32c3 --port /dev/ttyUSB0 write_flash -z 0x0 [firmware]

HiFiPhile commented 2 years ago

@niwantha33 hi, did you meet this issues ? What you posted seems off-topic.

HiFiPhile commented 2 years ago

@esp-wzh I saw d3c6fff25aed52b9082286ad8621054ed39f7cd4, is it related to this issue ?

I've flash power down enabled, how about you @bbinet ?

The issue is still not happening on my test setup after 2 weeks....

esp-wzh commented 2 years ago

@HiFiPhile , Yes this is a possible reason if you power down the flash during sleep. Usually Flash power down has timing requirements, take XM25QH32C datasheet as an example, You must at least make the Flash voltage drop below 0.6V and keep it for at least 100us to reset the Flash normally. So if you cannot guarantee the wake-up time, it is not recommended to power down the flash during sleep.

bbinet commented 2 years ago

@esp-wzh I saw d3c6fff, is it related to this issue ?

I've flash power down enabled, how about you @bbinet ?

Yes, me too: CONFIG_ESP_SLEEP_POWER_DOWN_FLASH=y

bbinet commented 2 years ago

I'm going to set CONFIG_ESP_SLEEP_POWER_DOWN_FLASH=n and see if I still reproduce the issue.

@esp-wzh CONFIG_ESP_SLEEP_POWER_DOWN_FLASH is only used for light sleep, not deep sleep, right?

esp-wzh commented 2 years ago

Yes, this option is only valid for lightsleep, it will perform strict checks before lightsleep to ensure that the sleep time is longer than the power-down time required by Flash, otherwise the device will still not power-down. And deepsleep IDF will definitely power down the Flash, it is necessary to manually evaluate the risk that the sleep time is less than the time required for the Flash to power down.(d3c6fff The `esp_deep_sleep_start` will not power down flash described in this commit is wrong, it will be corrected later)

HiFiPhile commented 2 years ago

I captured the voltage of VDD_SPI of ESP32-C3-WROOM module on my board, it turns out it violate heavily the timing of XM25QH32C.

Even though I still can't confirm it's the cause of this issue, this timing is problematic.

DS1Z_QuickPrint1

Lowest voltage is about 680mV so a chip reset is not guaranteed because the 1uF capacitor.

@esp-wzh As not every user knows the capacitor of VDD_SPI, I suggest add the words of DO NOT enable this option on ESP32-C3-WROOM or ESP32-C3-MINI-1 on flash power down option.

HiFiPhile commented 2 years ago

I've to stop my test, for a month I couldn't make it to reproduce.

Now I stopped using CONFIG_ESP_SLEEP_POWER_DOWN_FLASH and hope it was indeed the issue.

@esp-wzh Do you have any comment regarding my oscilloscope capture ? Does Espressif knows VDD_SPI timing of ESP32C3 modules violate Flash specification with sleep power down ?

esp-zlq commented 2 years ago

I captured the voltage of VDD_SPI of ESP32-C3-WROOM module on my board, it turns out it violate heavily the timing of XM25QH32C.

Even though I still can't confirm it's the cause of this issue, this timing is problematic.

Lowest voltage is about 680mV so a chip reset is not guaranteed because the 1uF capacitor.

@esp-wzh As not every user knows the capacitor of VDD_SPI, I suggest add the words of DO NOT enable this option on ESP32-C3-WROOM or ESP32-C3-MINI-1 on flash power down option.

@HiFiPhile Could you provide the test code, so that we can debug the waveform for more information?

HiFiPhile commented 2 years ago

@esp-zlq VDD_SPI.zip It was tested under 179ea878c7, but I can't reproduce on HEAD 36f49f361c001b49c538364056bc5d2d04c6f321. Once wifi is initiated VDD_SPI is always on regardless CONFIG_ESP_SLEEP_POWER_DOWN_FLASH.

I observed there is no VDD_SPI toggle to reset flash with RTC_SW_SYS_RST, so once entering wdt reboot loop the chip can't exit the deadloop. I think ROM code update is needed to add flash reset.

esp-wzh commented 1 year ago

We think that this problem is most likely caused by insufficient flash power-off time during lightsleep and we have updated the design guidelines on whether Flash is necessary to power down during sleep in the document.

https://docs.espressif.com/projects/esp-idf/en/latest/esp32c3/api-reference/system/sleep_modes.html#power-down-of-flash

https://github.com/espressif/esp-idf/blob/master/components/esp_hw_support/Kconfig#L51

If there are no more problems and reports we will close this issue.

bbinet commented 1 year ago

on my side, this issue is fixed since I've set CONFIG_ESP_SLEEP_POWER_DOWN_FLASH=n

Alvin1Zhang commented 1 year ago

Thanks for sharing the updates, feel free to reopen.

vanwykc commented 1 year ago

I've experienced similar boot fail behavior, BUT it happened at random power-up events. The product is mains powered. Flipped the switch a number of times and then boot failed with:

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x9 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004c0d4
invalid header: 0xffffff7f

The above happened quite repeatably (and very frustratingly) with 1 fail every 10 to 15 power-cycles.

After trying various things (including the above suggestion of CONFIG_ESP_SLEEP_POWER_DOWN_FLASH=n , I changed CONFIG_ESPTOOLPY_FLASHMODE from "qio" to "dio".
Built and flashed the bin. Flipped the switch over 100 times without any boot failures.

Interestingly though:

I noticed in my sdkconfig file: Under # Serial flasher config: CONFIG_ESPTOOLPY_FLASHMODE_QIO=y CONFIG_ESPTOOLPY_FLASHMODE="dio"

AND

Under # Deprecated options for backward compatibility: CONFIG_FLASHMODE_QIO=y

From previous bad experiences, I don't edit the sdkconfig directly any more, but stick to idf.py menuconfig rather. I went through the settings, but couldn't find where I could change those remaining QIO references to "n" ...

I'm hoping that the "dio" mode overrides the QIO=y options.

AxelLin commented 1 year ago

@esp-wzh

I just observed "invalid header: 0xffffff7f" once. This time it seems boot ok as below boot log, and I cannot reproduce it again. Is it safe to ignore it?

ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x15 (USB_UART_CHIP_RESET),boot:0xf (SPI_FAST_FLASH_BOOT) Saved PC:0x4004d2c0 invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f invalid header: 0xffffff7f SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x12dc load:0x403cc710,len:0x9d8 load:0x403ce710,len:0x2c00 entry 0x403cc710 I (286) cpu_start: Unicore app I (286) cpu_start: Pro cpu up. I (470) cpu_start: Pro cpu start user code I (470) cpu_start: cpu freq: 160000000 Hz ...

esp-wzh commented 1 year ago

@AxelLin, Thanks for report.

The reason for this problem is that you use USB-Serial-JTAG to perform a reset at the moment of the Flash erase operation.

USB reset will not re-power on Flash (which is different from Power on reset when you use UART console to reset the chip), resulting in that the Flash state is not ready when the chip accesses Flash after reset.

I think this kind of problem only exists when you use the USB console to debug, of course we will fix this problem on future chips.

If you do not want to see these errors print, you can program eFuse EFUSE_FLASH_TPUW, it will delay the chip in ROM for a while before accessing Flash.

2023-06-20_16-44

ordonezt commented 2 months ago

@esp-wzh Hello, I have some confusions about the EFUSE_FLASH_TPUW EFuse.

Image taken from the ESP32-C3 datasheet page 119:

If the value is less than 15, the waiting time is the configurable value. Otherwise, the waiting time is always 30 ms

How can be more than 15 if the efuse is only 4 bits (maximum value is 15)

Otherwise, the waiting time is always 30 ms

Is 30ms the default time? So if I change this EFuse I can only reduce the flash waiting time, not increase it, rigth?

ordonezt commented 2 months ago

I'm having the same invalid header: 0xffffff7f issue. I'm using an ESP32-C3FH4 module with ESP32-C3-MINI-1-AT-V2.4.2.0 firmware (also tried with v3.3.0.0)

To reproduce the issue I just need to restart the esp32 module a couple of times (sometimes 4, sometimes more than 20) using the CHIP_EN pin.

Once the issue start I can't exit from that state until a power off / power on cycle, the CHIP_EN reset doesn't help.

Here I have some logs of the issue:

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xd (SPI_FAST_FLASH_BOOT)
invalid header: 0xffffff7f (Repeated 528 times over 1,28 seconds)
...
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
...
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x7 (TG0WDT_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT)
Saved PC:0x4004d1f8
invalid header: 0xffffff7f
...
ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x10 (RTCWDT_RTC_RST),boot:0xd (SPI_FAST_FLASH_BOOT) (Every 3 seconds)
invalid header: 0xffffff7f
...

Should I try to program the EFUSE_FLASH_TPUW efuse?

esp-wzh commented 2 months ago

Hi~ @ordonezt

How can be more than 15 if the efuse is only 4 bits (maximum value is 15)

If and only if the configuration value is equal to 15, the delay time is 30ms.

Is 30ms the default time? So if I change this EFuse I can only reduce the flash waiting time, not increase it, rigth?

Default time is zero, the default value is 0, which means no waiting, because tsome software initialization has already taken up about 5ms.

Both tPWD and tVSL violations can trigger this problem. On C3, I am more worried about tPWD violation, because as discussed in this thread, the reference design has a capacitor on VDD_SPI, which may cause the Flash chip power not drop below Vpwd voltage quickly when the chip is reset.

When the chip needs to be reset, the low level time of CHIP_EN can be increased to avoid this problem.

ordonezt commented 2 months ago

@esp-wzh thank you so much for the clarification and quick response!

When the chip needs to be reset, the low level time of CHIP_EN can be increased to avoid this problem.

Do you have any estimated value on the minimum CHIP_EN low level time?

Default time is zero, the default value is 0, which means no waiting, because tsome software initialization has already taken up about 5ms.

Do you have any recommendations on the value to program to EFUSE_FLASH_TPUW or should I start with the minimum value and increase it until the error goes away?

In the first set of pictures you can see the moment were the error ocurrs. The low level time of CHIP_EN is about 1500 ms Logic analizer: Green waveform: CHIP_EN Pin Red waveform: U0TXD logic_invalid_header

Oscilloscope: CHIP_EN Pin dso_invalid_header

The second set of pictures is from a reset during the invalid header error state. The low level time of CHIP_EN is about 200 ms. Logic analizer: Green waveform: CHIP_EN Pin Red waveform: U0TXD logic_reset_200ms

Oscilloscope: CHIP_EN Pin dso_reset_200ms

esp-wzh commented 2 months ago

Do you have any estimated value on the minimum CHIP_EN low level time?

Theoretically, no configuration is required, but if your application does not mind the startup time, the larger the better (the maximum is 30ms)

In the first set of pictures you can see the moment were the error ocurrs. The low level time of CHIP_EN is about 1500 ms

Does it mean that even if CHIP_EN lasts for 1.5 seconds, the error may still occur? This doesn't make sense.

Can you try to capture the voltage waveform on the VDD_SPI pin (with CHIP_EN pin) when the error occurs?

ordonezt commented 2 months ago

Does it mean that even if CHIP_EN lasts for 1.5 seconds, the error may still occur? This doesn't make sense.

Yes

Can you try to capture the voltage waveform on the VDD_SPI pin (with CHIP_EN pin) when the error occurs?

Sure, here is a capture of CHIP_EN (yellow) and VDD_SPI (blue) when the error occurs, the total time of CHIP_EN on low level state is about 980 ms. dso_invalid_header_vdd

And here is the logic analyzer capture of the same pulse logic_invalid_header_vdd

And here I have a capture of a CHIP_EN 50ms pulse during the error state. CHIP_EN (yellow) and VDD_SPI (blue) dso_reset_50ms

espressif / esp-idf