flash read err 100 after secure boot/encryption

[dmlee05a]

I successfully flashed with secure boot and encryption six different devices. The seventh appeared to flash successfully, but then went into the flash read err, 1000 loop. I assume that this is non-recoverable. Any suggestions or ideas on what went wrong? Here's the monitor output:

Dave@DESKTOP-CEORO8N MINGW32 /esp/stashcan_1_0
$ make erase_flash
Erasing entire flash...
esptool.py v2.2.1
Connecting........__
Chip is ESP32D0WDQ6 (revision (unknown 0xa))
Uploading stub...
Running stub...
Stub running...
Erasing flash (this may take a while)...
Chip erase completed successfully in 9.8s
Hard resetting...

Dave@DESKTOP-CEORO8N MINGW32 /esp/stashcan_1_0
$ python /esp/esp-idf/components/esptool_py/esptool/esptool.py --chip esp32 --port COM5 --baud 115200 --before default_reset --after no_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0x1000 /esp/stashcan_1_0/build/bootloader/bootloader.bin
esptool.py v2.2.1
Connecting........_
Chip is ESP32D0WDQ6 (revision (unknown 0xa))
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 25920 bytes to 16065...
Wrote 25920 bytes (16065 compressed) at 0x00001000 in 1.4 seconds (effective 145.2 kbit/s)...
Hash of data verified.

Leaving...
Staying in bootloader.

Dave@DESKTOP-CEORO8N MINGW32 /esp/stashcan_1_0
$ make flash monitor
Flashing binaries to serial port COM5 (app at offset 0x10000)...
(Secure boot enabled, so bootloader not flashed automatically. See 'make bootloader' output)
esptool.py v2.2.1
Connecting........_____....
Chip is ESP32D0WDQ6 (revision (unknown 0xa))
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Auto-detected Flash size: 4MB
Compressed 8192 bytes to 47...
Wrote 8192 bytes (47 compressed) at 0x0000e000 in 0.0 seconds (effective 2979.3 kbit/s)...
Hash of data verified.
Compressed 1062436 bytes to 604344...
Wrote 1062436 bytes (604344 compressed) at 0x00010000 in 53.9 seconds (effective 157.8 kbit/s)...
Hash of data verified.
Compressed 3140 bytes to 192...
Wrote 3140 bytes (192 compressed) at 0x00008000 in 0.0 seconds (effective 717.8 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting...
MONITOR
--- idf_monitor on COM5 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371
ets Jun 8 2016 00:22:57

[ESP_Angus]

Hi dmlee,

There are a few possibilities, total loss of the device is possible but not the most likely explanation. Can you please post the output of "espefuse.py -p PORT summary" for this device?

Are you pre-burning the keys to efuse, or are the keys being generated by the device on first boot?

[dmlee05a]

Angus,
I am not pre-burning the keys.
Here's the efuse summary:
espefuse.py v2.2.1
Connecting......
Security fuses:
FLASH_CRYPT_CNT Flash encryption mode counter = 0 R/W (0x0)
FLASH_CRYPT_CONFIG Flash encryption config (key tweak bits) = 15 R/W (0xf)
CONSOLE_DEBUG_DISABLE Disable ROM BASIC interpreter fallback = 1 R/W (0x1)
ABS_DONE_0 secure boot enabled for bootloader = 1 R/W (0x1)
ABS_DONE_1 secure boot abstract 1 locked = 0 R/W (0x0)
JTAG_DISABLE Disable JTAG = 1 R/W (0x1)
DISABLE_DL_ENCRYPT Disable flash encryption in UART bootloader = 1 R/W (0x1)
DISABLE_DL_DECRYPT Disable flash decryption in UART bootloader = 1 R/W (0x1)
DISABLE_DL_CACHE Disable flash cache in UART bootloader = 1 R/W (0x1)
BLK1 Flash encryption key
= 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 -/-
BLK2 Secure boot key
= 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 -/-
BLK3 Variable Block 3
= 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 Efuse write disable mask = 384 R/W (0x180)
RD_DIS Efuse read disablemask = 3 R/W (0x3)
CODING_SCHEME Efuse variable block length scheme = 0 R/W (0x0)
KEY_STATUS Usage of efuse block 3 (reserved) = 0 R/W (0x0)

Config fuses:
XPD_SDIO_FORCE Ignore MTDI pin (GPIO12) for VDD_SDIO on reset = 0 R/W (0x0)
XPD_SDIO_REG If XPD_SDIO_FORCE, enable VDD_SDIO reg on reset = 0 R/W (0x0)
XPD_SDIO_TIEH If XPD_SDIO_FORCE & XPD_SDIO_REG, 1=3.3V 0=1.8V = 0 R/W (0x0)
SPI_PAD_CONFIG_CLK Override SD_CLK pad (GPIO6/SPICLK) = 0 R/W (0x0)
SPI_PAD_CONFIG_Q Override SD_DATA_0 pad (GPIO7/SPIQ) = 0 R/W (0x0)
SPI_PAD_CONFIG_D Override SD_DATA_1 pad (GPIO8/SPID) = 0 R/W (0x0)
SPI_PAD_CONFIG_HD Override SD_DATA_2 pad (GPIO9/SPIHD) = 0 R/W (0x0)
SPI_PAD_CONFIG_CS0 Override SD_CMD pad (GPIO11/SPICS0) = 0 R/W (0x0)
DISABLE_SDIO_HOST Disable SDIO host = 0 R/W (0x0)

Identity fuses:
MAC MAC Address
= 84:0d:8e:18:29:b0 (CRC 38 OK) R/W
CHIP_VERSION Chip version = 10 -/W (0xa)
CHIP_PACKAGE Chip package identifier = 0 -/W (0x0)

Flash voltage (VDD_SDIO) determined by GPIO12 on reset (High for 1.8V, Low/NC for 3.3V).

[ESP_Angus]

It looks like power was interrupted during the first boot encryption process, so Secure Boot has been enabled (ABS_DONE_0==1) but flash encryption is not (FLASH_CRYPT_CNT==0), but the bootloader (and maybe other parts of the flash) have been partially encrypted.

Unfortunately, this probably does mean this ESP32 is bricked. If you had pregenerated keys, you can recover from the situation, but without the keys and with secure boot enabled, it's not possible to correct the flash contents.

[WiFive]

Seems like power was removed while device was encrypting flash contents and it did not finish.

[dmlee05a]

Thanks for the help. The circuit board it is on is backed up by a battery as well as powered by the USB connector. It would have to have been a local glitch of the onboard voltage regulator, but wifi wasn't running, so the power demand shouldn't have been that high. Unfortunately, this has happened twice more since I posted originally (out of about a dozen boards).

[ESP_Angus]

I'm going to make a change in the bootloader so that flash encryption is enabled before secure boot, because it's a bad design that this first boot time window can cause a bricked device (secure boot already on before the bootloader & app are encrypted).

However, if you're having this a lot from a product which should be running stably (no scope for accidental serial resets, etc) then it may indicate some other problem. Do you have a way to monitor the serial output during the first boot?

Angus

[dmlee05a]

Angus,
I appreciate the support. Do you have a timetable for modifying the bootloader?
I currently don't have a way to monitor the serial output, but I'll look into it.
Is there a difference in power requirements for flashing non-secure boot/ non-encrypted versus secure boot/encrypted? The flash command has an --after hard_reset flag. Could that be involved?

FYI, these results are from a manufacturing pilot run of 300 units. Our process is to first flash a self-test program on the circuit board and then flash the application code after final assembly. We have not had a single problem with the self-test flashing, but of course it is non secure boot, non-encrypted. The secure boot/encryption flashing step is the last step in the process, and that is where we are having this problem so we have stopped after the first 25 or so units.
Thanks again.

[WiFive]

The first boot needs stable power until encryption is done so if you are using an auto-reset circuit and a hard reset option it will start immediately after flashing. You need a way to tell when encryption is done and your app has booted like an LED.

[dmlee05a]

WiFive,
That seems counter to the script that the idf is telling me to use. In production we are using the python script that was printed out after the make. There are no delays or tests built into that script.

In the example I used here, I did a "make flash". However in the production environment, I used the idf generated script (both approaches resulted in bricked units):
python esptool.py --chip esp32 --port /dev/ttyUSB0 --baud 115200 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0xe000 boot_app0.bin 0x10000 stashcan_1_0.bin 0x8000 default.bin

Does this suggest that the script could be the source of the issue, and I need to modify it? If so, the documentation needs to be more explicit.

Thanks.