Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ESP32S3 efuses real for production won't work, flash crypted, secure boot v2 enabled, .bin signed, with efuses virtual work (IDFGH-7702) #9244

Closed
MikyZ72 opened this issue Jun 28, 2022 · 10 comments
Assignees
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally

Comments

@MikyZ72
Copy link

MikyZ72 commented Jun 28, 2022

Environment

  • Development Kit: [custom board]
  • Kit version [custom board]
  • Module or chip used: [ESP32-S3-WROOM-1-N16R8]
  • IDF version : [ESP-IDF v4.4.1-405-g6c5fb29c2c]
  • Build System: [Espressif IDE (Eclipse IDE) Version: 2.4.2 Build id: 20220308-1406 CMake Ninja]
  • Compiler version: [xtensa-esp32s3-elf-gcc (crosstool-NG esp-2021r2-patch3) 8.4.0]
  • Operating System: [Windows]
  • (Windows only) environment type: [ESP Command Prompt].
  • Using an IDE?: Yes [Espressif IDE (Eclipse IDE) Version: 2.4.2 Build id: 20220308-1406]
  • Power Supply: [external 3.3V from custom board]

Problem Description

Hello guys,
If i flash all .bin system for production (ota, ota_data, factory, partition table, bootloader ecc) with efuses virtual enabled in partition emul_efuse, all work fine.
If i disable virtual efuses for real burn efuses, start the problem, i think to see 2 problems:

  • stop working partition ota: esp_partition_get_sha256 on ota return code 0x2002
  • partition storage (FAT) at all power on the esp_vfs_fat_spiflash_mount format the FAT like it lose the last formatted procedure on power off

I have made many test, sdkconfig and different flash procedures and i have briked 10 module, till now i dont have found solution!

Project

I have 2 project in Espressif IDE (Eclipse):

  • one for my loader (bootloader, partition table and factory app that is my loader.bin) and i flash later all bin files created
  • one for my firmware (ota app that is my firmware.bin) and i flash later only the firmware.bin file

The 2 project have the same sdkconfig and the same custom partition.csv file (they are ugual and i keep ugual)

In both there are enabled Flash encryption AES-256, Secure Boot V2 with sign binary during build with my generated key (openssl), ROM download mode is enabled (insecure for now).
Sign key is the same for the loader project and firmware project
I dont encrypt NVS data

SDKconfig image encryption
image

Bootloader of loader project is customized for run all the time at power on Factory partition and for run all the time ota partition from deep sleep wakeup.
Bootloader of firmware project it's the original from Espressif, isn't customized, but i dont use it.
When bootloader run my loader app from factory partition, after some check i launch deep sleep for hundred ms (100) and at wake up bootloader run ota partition (i use only 2 partition for update: 1 factory and 1 ota, this for don't lose flash space of 3 partition like 1 factory and 2 ota as a espressif default).
Partition table offset is set to "0xb000" for enlarge bootloader space (because crypt and info logs) as a documentation explain.

Partitions

# ESP-IDF Partition Table
# Name, Type, SubType, Offset, Size, Flags
nvs,data,nvs,0xc000,16K,
otadata,data,ota,0x10000,8K,
phy_init,data,phy,0x12000,8K,
emul_efuse,data,efuse,0x14000,8K,
loader,app,factory,0x20000,1M,
app,app,ota_0,0x120000,1920K,
storage,data,fat,0x300000,13M,encrypted

Write to flash

After build, i flash all binary with manual command from prompt:

esptool.py -p COM7 --chip esp32s3 erase_flash

esptool.py -p COM7 --chip esp32s3 --before=default_reset --after=no_reset --no-stub write_flash --flash_mode dio --flash_freq 80m --flash_size 16MB 0x20000 loader.bin 0xb000 partition-table.bin 0x10000 ota_data_initial.bin 0x120000 firmware.bin

esptool.py -p COM7 --chip esp32s3 --before=default_reset --after=no_reset --no-stub write_flash --flash_mode dio --flash_freq 80m --flash_size 16MB 0x0 bootloader.bin

In all command i dont reset after all bin file are flashed and Bootloader as the last as documentation mention because at restart it will start to burn the efuses if all crypt process is fine.
It will reset when i start monitor:
idf.py -p COM7 monitor

Expected Behavior

Firmware.bin file is signed at build and ota partition is crypted at first start of bootloader, i will expect that esp_partition_get_sha256 of ota is valid, but isn't.
Storage partition isn't flashed and i think is empty (maybe is 0xFF) and i will expect at first start that is crypted and after formatted as a FAT when is mounted in automatic from API function,
If i start to upload new ota firmware.bin with bluetooth and my protocol, file is saved in FAT and i run esp_reset(), then factory run check firmware.bin present in FAT and reflash ota partition with it.

Actual Behavior

Due to the ota is invalid my loader dont deep sleep and stay inside itself, wait for ota update via bluetooth with our protocol.
At every power on i see that loader formatting every time the FAT, this is not correct.
If i try to upload new ota firmware.bin with bluetooth and my protocol, function f_getfree on FAT error like the FAT is corrupted or not present

Debug Logs

Flash Log

esptool.py  -p COM7 -b 460800  --chip esp32s3 erase_flash
esptool.py v3.3.2-dev
Serial port COM7
Connecting....
Chip is ESP32-S3
Features: WiFi, BLE
Crystal is 40MHz
MAC: 7c:df:a1:ff:e9:48
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 460800
Changed.
Erasing flash (this may take a while)...
Chip erase completed successfully in 4.1s
Hard resetting via RTS pin...

esptool.py  -p COM7 -b 460800  --chip esp32s3  --before=default_reset --after=no_reset --no-stub write_flash --flash_mode dio --flash_freq 80m --flash_size 16MB 0x20000 loader.bin 0xb000 partition-table.bin 0x10000 ota_data_initial.bin 0x120000 firmware.bin
esptool.py v3.3.2-dev
Serial port COM7
Connecting....
Chip is ESP32-S3
Features: WiFi, BLE
Crystal is 40MHz
MAC: 7c:df:a1:ff:e9:48
Changing baud rate to 460800
Changed.
Enabling default SPI flash mode...
Configuring flash size...
Flash will be erased from 0x00020000 to 0x000b0fff...
Flash will be erased from 0x0000b000 to 0x0000bfff...
Flash will be erased from 0x00010000 to 0x00011fff...
Flash will be erased from 0x00120000 to 0x001d0fff...
Erasing flash...
Took 0.43s to erase flash block
Wrote 593920 bytes at 0x00020000 in 27.8 seconds (170.9 kbit/s)...
Hash of data verified.
Erasing flash...
Took 0.03s to erase flash block
Wrote 3072 bytes at 0x0000b000 in 0.1 seconds (170.4 kbit/s)...
Hash of data verified.
Erasing flash...
Took 0.05s to erase flash block
Wrote 8192 bytes at 0x00010000 in 0.4 seconds (170.7 kbit/s)...
Hash of data verified.
Erasing flash...
Took 0.49s to erase flash block
Wrote 724992 bytes at 0x00120000 in 33.9 seconds (170.9 kbit/s)...
Hash of data verified.

Leaving...
Staying in bootloader.

esptool.py  -p COM7 -b 460800  --chip esp32s3  --before=default_reset --after=no_reset --no-stub write_flash --flash_mode dio --flash_freq 80m --flash_size 16MB 0x0 bootloader.bin
esptool.py v3.3.2-dev
Serial port COM7
Connecting....
Chip is ESP32-S3
Features: WiFi, BLE
Crystal is 40MHz
MAC: 7c:df:a1:ff:e9:48
Changing baud rate to 460800
Changed.
Enabling default SPI flash mode...
Configuring flash size...
Flash will be erased from 0x00000000 to 0x00009fff...
Erasing flash...
Took 0.22s to erase flash block
Wrote 40960 bytes at 0x00000000 in 1.9 seconds (170.8 kbit/s)...
Hash of data verified.

Leaving...
Staying in bootloader.

Monitor Log

idf.py -p COM7 monitor
Executing action: monitor
Running idf_monitor in directory XXX
Executing "C:\Espressif\python_env\idf4.4_py3.10_env\Scripts\python.exe C:\Espressif\frameworks\esp-idf-v4.4\tools/idf_monitor.py -p COM7 -b 115200 --toolchain-prefix xtensa-esp32s3-elf- --target esp32s3 XXX\loader.elf -m 'C:\Espressif\python_env\idf4.4_py3.10_env\Scripts\python.exe' 'C:\Espressif\frameworks\esp-idf-v4.4\tools\idf.py' '-p' 'COM7'"...
←[0;33m--- WARNING: GDB cannot open serial ports accessed as COMx←[0m
←[0;33m--- Using \\.\COM7 instead...←[0m
←[0;33m--- idf_monitor on \\.\COM7 115200 ---←[0m
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd0270,len:0x2fe0
load:0x403b6000,len:0x884
load:0x403ba000,len:0x53d0
entry 0x403b61b8
I (32) boot: ESP-IDF v4.4.1-405-g6c5fb29c2c 2nd stage bootloader
I (32) boot: compile time 10:07:35
I (32) boot: chip revision: 0
I (35) boot.esp32s3: Boot SPI Speed : 80MHz
I (40) boot.esp32s3: SPI Mode       : DIO
I (45) boot.esp32s3: SPI Flash Size : 16MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 0000c000 00004000
I (73) boot:  1 otadata          OTA data         01 00 00010000 00002000
I (81) boot:  2 phy_init         RF data          01 01 00012000 00002000
I (88) boot:  3 emul_efuse       efuse            01 05 00014000 00002000
I (96) boot:  4 loader           factory app      00 00 00020000 00100000
I (103) boot:  5 app              OTA app          00 10 00120000 001e0000
I (111) boot:  6 storage          Unknown data     01 81 00300000 00d00000
I (118) boot: End of partition table
I (123) boot: SELECTED BOOT -1
I (126) esp_image: segment 0: paddr=00020020 vaddr=3c070020 size=0f9b0h ( 63920) map
I (146) esp_image: segment 1: paddr=0002f9d8 vaddr=3fc948c0 size=00640h (  1600) load
I (147) esp_image: segment 2: paddr=00030020 vaddr=42000020 size=6b0f8h (438520) map
I (231) esp_image: segment 3: paddr=0009b120 vaddr=3fc94f00 size=02d34h ( 11572) load
I (233) esp_image: segment 4: paddr=0009de5c vaddr=40374000 size=108c0h ( 67776) load
I (251) esp_image: segment 5: paddr=000ae724 vaddr=50000000 size=00010h (    16) load
I (252) esp_image: segment 6: paddr=000ae73c vaddr=600fe000 size=00028h (    40) load
I (257) esp_image: segment 7: paddr=000ae76c vaddr=00000000 size=01864h (  6244)
I (266) esp_image: Verifying image signature...
I (271) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (280) secure_boot_v2: Verifying with RSA-PSS...
I (288) secure_boot_v2: Signature verified successfully!
I (297) boot: Loaded app from partition at offset 0x20000
I (298) secure_boot_v2: enabling secure boot v2...
I (303) efuse: Batch mode of writing fields is enabled
I (308) esp_image: segment 0: paddr=00000020 vaddr=3fcd0270 size=02fe0h ( 12256)
I (319) esp_image: segment 1: paddr=00003008 vaddr=403b6000 size=00884h (  2180)
I (325) esp_image: segment 2: paddr=00003894 vaddr=403ba000 size=053d0h ( 21456)
I (337) esp_image: Verifying image signature...
I (339) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (347) secure_boot_v2: Verifying with RSA-PSS...
I (355) secure_boot_v2: Signature verified successfully!
I (358) secure_boot_v2: Secure boot digests absent, generating..
I (372) secure_boot_v2: Digests successfully calculated, 1 valid signatures (image offset 0x0)
I (374) secure_boot_v2: 1 signature block(s) found appended to the bootloader.
I (382) secure_boot_v2: Burning public key hash to eFuse
I (390) efuse: Writing EFUSE_BLK_KEY0 with purpose 9
I (460) secure_boot_v2: Digests successfully calculated, 1 valid signatures (image offset 0x20000)
I (460) secure_boot_v2: 1 signature block(s) found appended to the app.
I (465) secure_boot_v2: Application key(0) matches with bootloader key(0).
I (473) secure_boot_v2: Revoking empty key digest slot (1)...
I (479) secure_boot_v2: Revoking empty key digest slot (2)...
I (486) secure_boot_v2: blowing secure boot efuse...
W (491) secure_boot: UART ROM Download mode kept enabled - SECURITY COMPROMISED
I (499) secure_boot: Disable hardware & software JTAG...
I (506) efuse: BURN BLOCK4
I (512) efuse: BURN BLOCK4 - OK (write block == read block)
I (515) efuse: BURN BLOCK0
I (520) efuse: BURN BLOCK0 - OK (all write block bits are set)
I (525) efuse: Batch mode. Prepared fields are committed
I (531) secure_boot_v2: Secure boot permanently enabled
I (537) boot: Checking flash encryption...
I (542) efuse: Batch mode of writing fields is enabled
I (547) flash_encrypt: Generating new flash encryption key...
I (556) efuse: Writing EFUSE_BLK_KEY1 with purpose 2
I (560) efuse: Writing EFUSE_BLK_KEY2 with purpose 3
I (566) flash_encrypt: Disable UART bootloader encryption...
I (571) flash_encrypt: Disable UART bootloader cache...
I (577) flash_encrypt: Disable JTAG...
I (583) efuse: BURN BLOCK6
I (588) efuse: BURN BLOCK6 - OK (write block == read block)
I (592) efuse: BURN BLOCK5
I (598) efuse: BURN BLOCK5 - OK (write block == read block)
I (601) efuse: BURN BLOCK0
I (606) efuse: BURN BLOCK0 - OK (all write block bits are set)
I (611) efuse: Batch mode. Prepared fields are committed
I (617) esp_image: segment 0: paddr=00000020 vaddr=3fcd0270 size=02fe0h ( 12256)
I (627) esp_image: segment 1: paddr=00003008 vaddr=403b6000 size=00884h (  2180)
I (634) esp_image: segment 2: paddr=00003894 vaddr=403ba000 size=053d0h ( 21456)
I (645) esp_image: Verifying image signature...
I (647) secure_boot_v2: Verifying with RSA-PSS...
I (655) secure_boot_v2: Signature verified successfully!
I (1023) flash_encrypt: bootloader encrypted successfully
I (1062) flash_encrypt: partition table encrypted and loaded successfully
I (1062) flash_encrypt: Encrypting partition 1 at offset 0x10000 (length 0x2000)...
I (1127) flash_encrypt: Done encrypting
I (1128) esp_image: segment 0: paddr=00020020 vaddr=3c070020 size=0f9b0h ( 63920) map
I (1141) esp_image: segment 1: paddr=0002f9d8 vaddr=3fc948c0 size=00640h (  1600)
I (1141) esp_image: segment 2: paddr=00030020 vaddr=42000020 size=6b0f8h (438520) map
I (1225) esp_image: segment 3: paddr=0009b120 vaddr=3fc94f00 size=02d34h ( 11572)
I (1227) esp_image: segment 4: paddr=0009de5c vaddr=40374000 size=108c0h ( 67776)
I (1242) esp_image: segment 5: paddr=000ae724 vaddr=50000000 size=00010h (    16)
I (1243) esp_image: segment 6: paddr=000ae73c vaddr=600fe000 size=00028h (    40)
I (1248) esp_image: segment 7: paddr=000ae76c vaddr=00000000 size=01864h (  6244)
I (1257) esp_image: Verifying image signature...
I (1261) secure_boot_v2: Verifying with RSA-PSS...
I (1270) secure_boot_v2: Signature verified successfully!
I (1273) flash_encrypt: Encrypting partition 4 at offset 0x20000 (length 0x100000)...
I (10359) flash_encrypt: Done encrypting
I (10359) esp_image: segment 0: paddr=00120020 vaddr=3c080020 size=11254h ( 70228) map
I (10373) esp_image: segment 1: paddr=0013127c vaddr=3fc948a0 size=0360ch ( 13836)
I (10376) esp_image: segment 2: paddr=00134890 vaddr=40374000 size=0b788h ( 46984)
I (10387) esp_image: segment 3: paddr=00140020 vaddr=42000020 size=7bb64h (506724) map
I (10478) esp_image: segment 4: paddr=001bbb8c vaddr=4037f788 size=05110h ( 20752)
I (10483) esp_image: segment 5: paddr=001c0ca4 vaddr=50000000 size=00010h (    16)
I (10484) esp_image: segment 6: paddr=001c0cbc vaddr=600fe000 size=00028h (    40)
I (10492) esp_image: segment 7: paddr=001c0cec vaddr=00000000 size=0f2e4h ( 62180)
I (10512) esp_image: Verifying image signature...
I (10512) secure_boot_v2: Verifying with RSA-PSS...
I (10515) secure_boot_v2: Signature verified successfully!
I (10518) flash_encrypt: Encrypting partition 5 at offset 0x120000 (length 0x1e0000)...
I (26772) flash_encrypt: Done encrypting
I (26773) flash_encrypt: Encrypting partition 6 at offset 0x300000 (length 0xd00000)...
I (19066) flash_encrypt: Done encrypting
I (19066) flash_encrypt: Setting CRYPT_CNT for permanent encryption
I (19067) efuse: BURN BLOCK0
I (19072) efuse: BURN BLOCK0 - OK (all write block bits are set)
I (19077) flash_encrypt: Flash encryption completed
I (19082) boot: Resetting with flash encryption enabled...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x3 (RTC_SW_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x403bb676
SPIWP:0xee
mode:DIO, clock div:1
Valid secure boot key blocks: 0
secure boot verification succeeded
load:0x3fcd0270,len:0x2fe0
load:0x403b6000,len:0x884
load:0x403ba000,len:0x53d0
entry 0x403b61b8
I (72) boot: ESP-IDF v4.4.1-405-g6c5fb29c2c 2nd stage bootloader
I (72) boot: compile time 10:07:35
I (72) boot: chip revision: 0
I (75) boot.esp32s3: Boot SPI Speed : 80MHz
I (80) boot.esp32s3: SPI Mode       : DIO
I (85) boot.esp32s3: SPI Flash Size : 16MB
I (89) boot: Enabling RNG early entropy source...
I (95) boot: Partition Table:
I (98) boot: ## Label            Usage          Type ST Offset   Length
I (106) boot:  0 nvs              WiFi data        01 02 0000c000 00004000
I (113) boot:  1 otadata          OTA data         01 00 00010000 00002000
I (121) boot:  2 phy_init         RF data          01 01 00012000 00002000
I (128) boot:  3 emul_efuse       efuse            01 05 00014000 00002000
I (136) boot:  4 loader           factory app      00 00 00020000 00100000
I (143) boot:  5 app              OTA app          00 10 00120000 001e0000
I (151) boot:  6 storage          Unknown data     01 81 00300000 00d00000
I (159) boot: End of partition table
I (163) boot: SELECTED BOOT -1
I (166) esp_image: segment 0: paddr=00020020 vaddr=3c070020 size=0f9b0h ( 63920) map
I (188) esp_image: segment 1: paddr=0002f9d8 vaddr=3fc948c0 size=00640h (  1600) load
I (189) esp_image: segment 2: paddr=00030020 vaddr=42000020 size=6b0f8h (438520) map
I (283) esp_image: segment 3: paddr=0009b120 vaddr=3fc94f00 size=02d34h ( 11572) load
I (286) esp_image: segment 4: paddr=0009de5c vaddr=40374000 size=108c0h ( 67776) load
I (305) esp_image: segment 5: paddr=000ae724 vaddr=50000000 size=00010h (    16) load
I (305) esp_image: segment 6: paddr=000ae73c vaddr=600fe000 size=00028h (    40) load
I (311) esp_image: segment 7: paddr=000ae76c vaddr=00000000 size=01864h (  6244)
I (320) esp_image: Verifying image signature...
I (324) secure_boot_v2: Verifying with RSA-PSS...
I (332) secure_boot_v2: Signature verified successfully!
I (342) boot: Loaded app from partition at offset 0x20000
I (342) secure_boot_v2: enabling secure boot v2...
I (347) secure_boot_v2: secure boot v2 is already enabled, continuing..
I (354) boot: Checking flash encryption...
I (359) flash_encrypt: flash encryption is enabled (0 plaintext flashes left)
I (367) boot: Disabling RNG early entropy source...
I (384) opi psram: vendor id : 0x0d (AP)
I (384) opi psram: dev id    : 0x02 (generation 3)
I (384) opi psram: density   : 0x03 (64 Mbit)
I (388) opi psram: good-die  : 0x01 (Pass)
I (392) opi psram: Latency   : 0x01 (Fixed)
I (397) opi psram: VCC       : 0x01 (3V)
I (402) opi psram: SRF       : 0x01 (Fast Refresh)
I (407) opi psram: BurstType : 0x01 (Hybrid Wrap)
I (413) opi psram: BurstLen  : 0x01 (32 Byte)
I (418) opi psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (424) opi psram: DriveStrength: 0x00 (1/1)
I (429) spiram: Found 64MBit SPI RAM device
I (433) spiram: SPI RAM mode: sram 40m
I (438) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (445) cpu_start: Pro cpu up.
I (449) cpu_start: Starting app cpu, entry point is 0x40374fe8
0x40374fe8: call_start_cpu1 at C:/Espressif/frameworks/esp-idf-v4.4/components/esp_system/port/cpu_start.c:160

I (0) cpu_start: App cpu up.
I (470) cpu_start: Pro cpu start user code
I (470) cpu_start: cpu freq: 160000000
I (470) cpu_start: Application information:
I (473) cpu_start: Project name:     loader
I (478) cpu_start: App version:      0.1.0.102
I (483) cpu_start: Compile time:     Jun 28 2022 10:07:00
I (489) cpu_start: ELF file SHA256:  11472b48b48177d1...
I (495) cpu_start: ESP-IDF:          v4.4.1-405-g6c5fb29c2c
I (501) heap_init: Initializing. RAM available for dynamic allocation:
I (509) heap_init: At 3FC9F858 len 000407A8 (257 KiB): D/IRAM
I (515) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (522) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (528) heap_init: At 600FE028 len 00001FD8 (7 KiB): RTCRAM
I (534) spiram: Adding pool of 8192K of external SPI memory to heap allocator
I (543) spi_flash: detected chip: gd
I (546) spi_flash: flash io: dio
I (551) sleep: Configure to isolate all GPIO pins in sleep state
I (557) sleep: Enable automatic switching of GPIO sleep configuration
I (564) coexist: coexist rom version e7ae62f
I (569) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (590) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
W (590) LOADER: Start LOADER(FACTORY)
I (600) gpio: GPIO[8]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
I (610) LED: Led driver init
I (610) FATFS: Mounting FAT filesystem
W (1770) vfs_fat_spiflash: f_mount failed (13)
I (1770) vfs_fat_spiflash: Formatting FATFS partition, allocation unit size=4096
I (2190) vfs_fat_spiflash: Mounting again
E (2190) LOADER: partizione ota0 non valida (8194)
I (2190) LOADER: Reading file...
W (2190) LOADER: Firmware file not present
W (2250) BT_INIT: esp_bt_controller_mem_release not implemented, return OK
I (2250) BT_INIT: BT controller compile version [d913766]
I (2250) phy_init: phy_version 503,13653eb,Jun  1 2022,17:47:08
W (2260) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (2300) system_api: Base MAC address is not set
I (2300) system_api: read default base MAC address from EFUSE
I (2300) BT_INIT: Bluetooth MAC: 7c:df:a1:ff:e9:4a

W (2340) BLE: GAP event default: 14
W (2350) BLE: GAP event default: 15
W (2350) NVS: Get length, key "config" not exists
W (2350) NVS: get key config not present 0x0
W (2350) NVS: primo avvio sezione a zero
W (2360) NVS: Erase, key "config" not exists
I (2370) BLE: xOsSetName sn: S/N NOTSET
I (2380) BLE: Advertising start successfully

EFUSES LOG

espefuse.py -p COM7 summary
Connecting....
Detecting chip type... ESP32-S3
espefuse.py v3.3.2-dev

=== 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_DCACHE (BLOCK0)                                Disables DCache                                    = False R/W (0b0)
DIS_DOWNLOAD_ICACHE (BLOCK0)                       Disables Icache when SoC is in Download mode       = True R/W (0b1)
DIS_DOWNLOAD_DCACHE (BLOCK0)                       Disables Dcache 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)
DIS_APP_CPU (BLOCK0)                               Disables APP CPU                                   = False R/W (0b0)
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
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)
FLASH_ECC_MODE (BLOCK0)                            Configures the ECC mode for SPI flash
   = 16-byte to 18-byte mode 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
UART_PRINT_CONTROL (BLOCK0)                        Sets the default UART boot message output mode     = Enabled R/W (0b00)
FLASH_TYPE (BLOCK0)                                Selects SPI flash type                             = 4 data lines R/W (0b0)
FLASH_PAGE_SIZE (BLOCK0)                           Sets the size of flash page                        = 0 R/W (0b00)
FLASH_ECC_EN (BLOCK0)                              Enables ECC in Flash boot mode                     = False R/W (0b0)
FORCE_SEND_RESUME (BLOCK0)                         Forces ROM code to send an SPI flash resume comman = False R/W (0b0)
                                                   d during SPI boot
DIS_USB_OTG_DOWNLOAD_MODE (BLOCK0)                 Disables USB-OTG download feature in UART download = True R/W (0b1)
                                                    boot mode
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          = 58722049 R/W (0x03800701)
RD_DIS (BLOCK0)                                    Disables software reading from BLOCK4-10           = 6 R/- (0b0000110)

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:ff:e9:48 (OK) R/W
WAFER_VERSION (BLOCK1)                             WAFER version                                      = 1 R/W (0b001)
PKG_VERSION (BLOCK1)                               ??? Package version                                = ESP32-S3 R/W (0x0)
BLOCK1_VERSION (BLOCK1)                            ??? BLOCK1 efuse version                           = 1 R/W (0b001)
OPTIONAL_UNIQUE_ID (BLOCK2)                        ??? Optional unique 128-bit ID
   = 1b 78 5e 1d 94 57 86 5d ff 64 bb 0e 2a 59 8f ca 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

Security fuses:
SOFT_DIS_JTAG (BLOCK0)                             Software disables JTAG by programming odd number o = 7 R/W (0b111)
                                                   f 1 bit(s). JTAG can be re-enabled via HMAC periph
                                                   eral
HARD_DIS_JTAG (BLOCK0)                             Hardware disables JTAG permanently                 = True R/W (0b1)
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)                   Revokes use of secure boot key digest 0            = False R/W (0b0)
SECURE_BOOT_KEY_REVOKE1 (BLOCK0)                   Revokes use of secure boot key digest 1            = True R/W (0b1)
SECURE_BOOT_KEY_REVOKE2 (BLOCK0)                   Revokes use of secure boot key digest 2            = True R/W (0b1)
KEY_PURPOSE_0 (BLOCK0)                             KEY0 purpose                                       = SECURE_BOOT_DIGEST0 R/- (0x9)
KEY_PURPOSE_1 (BLOCK0)                             KEY1 purpose                                       = XTS_AES_256_KEY_1 R/- (0x2)
KEY_PURPOSE_2 (BLOCK0)                             KEY2 purpose                                       = XTS_AES_256_KEY_2 R/- (0x3)
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                                = True R/W (0b1)
SECURE_BOOT_AGGRESSIVE_REVOKE (BLOCK0)             Enables aggressive secure boot key revocation mode = False R/W (0b0)
STRAP_JTAG_SEL (BLOCK0)                            Enable selection between usb_to_jtagor pad_to_jtag = False R/W (0b0)
                                                    through GPIO3
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: SECURE_BOOT_DIGEST0
  Encryption key0 or user data
   = 5f 62 63 99 6e c4 90 7b 3b d1 57 e2 8c 26 08 90 ea 4c de 6b ba 42 91 2d f4 37 db c5 b2 a3 cf 8b R/-
BLOCK_KEY1 (BLOCK5)
  Purpose: XTS_AES_256_KEY_1
  Encryption key1 or user data
   = ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? -/-
BLOCK_KEY2 (BLOCK6)
  Purpose: XTS_AES_256_KEY_2
  Encryption key2 or user data
   = ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? ?? -/-
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 (BLOCK0)                                   Disables the USB OTG hardware                      = False R/W (0b0)
USB_EXCHG_PINS (BLOCK0)                            Exchanges USB D+ and D- pins                       = False R/W (0b0)
EXT_PHY_ENABLE (BLOCK0)                            Enables external USB PHY                           = False R/W (0b0)
BTLC_GPIO_ENABLE (BLOCK0)                          Enables BTLC GPIO                                  = 0 R/W (0b00)
DIS_USB_JTAG (BLOCK0)                              Disable usb_serial_jtag-to-jtag function           = True R/W (0b1)
DIS_USB_SERIAL_JTAG (BLOCK0)                       Disable usb_serial_jtag module                     = False R/W (0b0)
USB_PHY_SEL (BLOCK0)                               Select internal/external PHY for USB OTGand usb_se = False R/W (0b0)
                                                   rial_jtag

Vdd_Spi Config fuses:
VDD_SPI_XPD (BLOCK0)                               The VDD_SPI regulator is powered on                = True R/W (0b1)
VDD_SPI_TIEH (BLOCK0)                              The VDD_SPI power supply voltage at reset
   = Connect to VDD_RTC_IO R/W (0b1)
VDD_SPI_FORCE (BLOCK0)                             Force using VDD_SPI_XPD and VDD_SPI_TIEH to config = True R/W (0b1)
                                                   ure VDD_SPI LDO
PIN_POWER_SELECTION (BLOCK0)                       Sets default power supply for GPIO33..37           = VDD_SPI R/W (0b1)

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

Flash voltage (VDD_SPI) set to 3.3V by efuse.

Other items if possible

@espressif-bot espressif-bot added the Status: Opened Issue is new label Jun 28, 2022
@github-actions github-actions bot changed the title ESP32S3 efuses real for production won't work, flash crypted, secure boot v2 enabled, .bin signed, with efuses virtual work ESP32S3 efuses real for production won't work, flash crypted, secure boot v2 enabled, .bin signed, with efuses virtual work (IDFGH-7702) Jun 28, 2022
@MikyZ72
Copy link
Author

MikyZ72 commented Jul 4, 2022

Hello Espressif guys,
no one respond here?
We have a few thousand modules waiting to be sell and isn't possible that we must debug Espressif code!
Problem is that esp_partition_write don't write in correct way the flash when is enabled the flash encryption, it broken bootloader code, partition table code, factory and ota in the flash.

Please help us...

What is the problem:

  • frequency 80m flash and 40m RAM isnt ok?
  • 16M flash?
  • partition size?
  • VFS and wear levelling don't work whit flash encrypted?
  • some timeout not ok

@mahavirj
Copy link
Member

mahavirj commented Jul 4, 2022

@MikyZ72

From eFuse summary, both secure boot and flash encryption schemes have been correctly configured. Following bootloader log confirms this.

I (347) secure_boot_v2: secure boot v2 is already enabled, continuing..
I (354) boot: Checking flash encryption...
I (359) flash_encrypt: flash encryption is enabled (0 plaintext flashes left)

Moreover, bootloader is also successful in verifying firmware (its signature and hence integrity) and then it successfully hands over control to it.

Due to the ota is invalid my loader dont deep sleep and stay inside itself, wait for ota update via bluetooth with our protocol.
At every power on i see that loader formatting every time the FAT, this is not correct.

I have few questions here:

  1. If you try ESP-IDF provided fatfs example, do you still run into same issue?
  2. Can you please highlight on your changes or maybe share your sample project?

CC @igrr

@MikyZ72
Copy link
Author

MikyZ72 commented Jul 5, 2022

Good morning @mahavirj ,
many thanks for your reply...

After a hundred test we find that problem is with PSRAM enabled, encryption and in specific esp_partition_write stop work.
In our project if we disable PSRAM all work fine.

We have also try Espressif example flash_encryption and with PSRAM disabled work fine, if we enable it, also the example stop to work.
Please look example wrong output, the readed sequence of byte are not ugual to what it have just writed and the readed crypted byte are all 0xFF:

This is esp32s3 chip with 2 CPU core(s), WiFi/BLE, silicon revision 0, 16MB external flash
FLASH_CRYPT_CNT eFuse value is 1
Flash encryption feature is enabled in DEVELOPMENT mode
Erasing partition "storage" (0x1000 bytes)
Writing data with esp_partition_write:
I (483) example: 0x3fcf40e0   00 01 02 03 04 05 06 07  08 09 0a 0b 0c 0d 0e 0f  |................|
I (493) example: 0x3fcf40f0   10 11 12 13 14 15 16 17  18 19 1a 1b 1c 1d 1e 1f  |................|
Reading with esp_partition_read:
I (503) example: 0x3fcf40c0   c7 85 a3 a7 01 03 02 c7  33 74 7b 1f d3 c6 1a f8  |........3t{.....|
I (513) example: 0x3fcf40d0   97 0d 13 fa 8f 5e 0b 66  92 ae 0c a4 e9 fa bc bb  |.....^.f........|
Reading with spi_flash_read:
I (523) example: 0x3fcf40c0   ff ff ff ff ff ff ff ff  ff ff ff ff ff ff ff ff  |................|
I (533) example: 0x3fcf40d0   ff ff ff ff ff ff ff ff  ff ff ff ff ff ff ff ff  |................|
I (553) nvs: NVS partition "nvs" is encrypted.``` 

@mahavirj
Copy link
Member

mahavirj commented Jul 5, 2022

@MikyZ72

We have also try Espressif example flash_encryption and with PSRAM disabled work fine, if we enable it, also the example stop to work.

Thanks for confirming! Can you please share your sdkconfig in case you made any modifications to default configuration? Also you are trying this on ESP32-S3-WROOM-1-N16R8 (just to double confirm)?

@MikyZ72
Copy link
Author

MikyZ72 commented Jul 6, 2022

Hi @mahavirj ,
here the sdkconfig of flash encryption example with PSRAM enabled

sdkconfig.txt

Yes i confirm that module is ESP32-S3-WROOM-1-N16R8

@Emill
Copy link

Emill commented Jul 7, 2022

I can also confirm this issue, running on ESP32-S3-WROOM-1-N16R8.

Flash encryption is enabled (BLOCK_KEY0 has been set, KEY_PURPOSE_0 = XTS_AES_128_KEY, RD_DIS = 1, WR_DIS = 0x00800100, SPI_BOOT_CRYPT_CNT = 1). Secure boot has not been enabled.

Without PSRAM enabled in menuconfig, spi_flash_write_encrypted works fine. After erase, write and read, the read value matches the value written.

After enabling PSRAM in menuconfig, setting it to octal mode and leaving all other PSRAM settings as-is, the spi_flash_write_encrypted method now misbehaves by writing garbage to other locations in the flash.

For example, I tried to write 65536 bytes of data filled with 0x5a to flash address 0x110000 using spi_flash_write_encrypted where the corresponding block has been erased. If I immediately after read back the first bytes, I get 44 63 F7 FF instead. After a reboot, the bootloader fails to boot due to "invalid header" (i.e. the first bytes of the flash are now corrupt).

I dumped the raw contents using esptool.py read_flash to see what had happened. It appears it has written 64 byte garbage chunks to the start of every 16 384 byte blocks, i.e. bytes 0x0000 - 0x003f, 0x4000 - 0x403f, 0x8000 - 0x803f and so on until the end of the flash are all filled with random garbage. The rest of the flash is untouched. Even if I try to decrypt the contents using espsecure.py, the result still looks like garbage.

@Emill
Copy link

Emill commented Jul 7, 2022

I did some more debugging.

First I tested the latest release/v5.0 branch to see if that would help. I had to migrate to the new esp_flash_ functions, but that did not change the end result; it is still broken.

I then found out that the driver writes the correct data, but instead of writing to addr, it seems it writes to (addr << 8) instead (modulo 16 MB). After copying 64 bytes of data from address 0x00C000 in my flash dump (see my previous post) to address 0x1100C0 in the flash dump, and then decrypting the whole flash dump using espsecure.py, the data at address 0x1100C0 is then correctly decrypted (i.e. 5A 5A 5A ...). This confirms that the AES-XTS hardware encrypts for the correct address, but the SPI1 peripheral writes the result to the wrong address (addr << 8).

The reason the flash dump contains 64 byte "garbage" every 16 384 byte blocks is due to the spi_flash_chip_generic_write_encrypted function splits up the data in 64 byte blocks and then writes them individually. 64 << 8 is 16 384, so that's where that offset comes from.

By using a debugger and setting a breakpoint at the beginning of spimem_flash_ll_user_start, at this point dev->user1.usr_addr_bitlen contains the correct value 24 - 1. Also dev->addr contains the correct value 0x00110000 (when writing to that address). I however noticed that dev->cache_fctrl.usr_cmd_4byte contained 1, which has the header file documentation "Set this bit to enable SPI1 transfer with 32 bits address. The value of SPI_MEM_USR_ADDR_BITLEN should be 31.". This is the cause of the issue which causes SPI1 to write to the incorrect flash address.

I saw that the octal PSRAM uses 32-bit address. After some investigation I found that the esp_rom_opiflash_exec_cmd function sets this value to 1 without revertinig it. That function is called for SPI1 during PSRAM initialization. It seems PSRAM only uses SPI0 later on, so it should be safe to revert it after PSRAM initialization is complete. Flash Encryption write operation uses SPI1.

So for now I added this line:

SET_PERI_REG_BITS(SPI_MEM_CACHE_FCTRL_REG(1), SPI_MEM_CACHE_USR_CMD_4BYTE_V, 0, SPI_MEM_CACHE_USR_CMD_4BYTE_S);

to the function spi_flash_set_rom_required_regs (outside the #if block). This seems to solve the issue for the N16R8 module. I'm not sure if it's a correct solution for modules with larger flashes though.

Another alternative might be to set dev->cache_fctrl.usr_cmd_4byte = bitlen == 32 ? 1 : 0; in spimem_flash_ll_set_usr_address. But then it's done unnecessarily often maybe.

@MikyZ72
Copy link
Author

MikyZ72 commented Jul 9, 2022

Hello Emill,
thank for the big and complete information, but we are in production and we have exchange our code for deactivate PSRAM and dont use more this feature, now we are not able to wait some more fix or more time, we must sell the product (thousands).
Now we sell product with code that don't respect our first specifications, and we have pay the module with PSRAM presence for nothing, plus we dont now if in the future (when there is the stable solution) we are able to re-enable PSRAM and update the product via ota without problem.
This bug i think don't must be happen in Espressif code/company, mostly in the encryption parts, now i feel and i'm afraid that all code isn't tested in good way and maybe we have many problem with the product on our customer.

@moefear85
Copy link

moefear85 commented Jul 9, 2022

@MikyZ72

We have a few thousand modules waiting to be sell and isn't possible that we must debug Espressif code!

This bug i think don't must be happen in Espressif code/company, mostly in the encryption parts

I personally share your frustration and have often wondered if espressif intends to sell only to hobbyists. But on the other hand, there is a huge price difference between esp products and other companies. No other company offers an mcu with integrated wifi/bt/usb/psram for such a low price (which I find attractive, like probably yourself too). I try to remind myself about that everytime I grind my teeth wondering why something isn't working as I hoped. Moreover, the price of psram is merely a few cents depending on where/how one purchases.

More importantly, how often does a microsoft update end up doing more damage than help? Or a linux kernel upgrade that causes some driver to stop working? I used to rely heavily on PIC controllers in the past, specifically the Microchip Code Configurator. All of a sudden they bump the version, and it stopped calculating pwm frequencies correctly. Every SDK has bugs at any moment.

@espressif-bot espressif-bot added Status: Selected for Development Issue is selected for development and removed Status: Opened Issue is new labels Jul 10, 2022
@espressif-bot espressif-bot added Status: Reviewing Issue is being reviewed Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Resolution: Done Issue is done internally and removed Status: Selected for Development Issue is selected for development Status: Reviewing Issue is being reviewed Resolution: NA Issue resolution is unavailable labels Jul 12, 2022
espressif-bot pushed a commit that referenced this issue Jul 15, 2022
@mythbuster5
Copy link
Collaborator

@Emill Hi, thanks for your fix, and your suggestion is great.

Take stability in to consideration, two parts to be modified. So, you can pick this commit 8538153 and things will be ok.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally
Projects
None yet
Development

No branches or pull requests

6 participants