search

espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.71k stars 7.3k forks source link

Secure Boot V2 failure: Sig block 0 invalid: Image digest does not match (IDFGH-6787) #8414

Closed badevos closed 2 years ago

badevos commented 2 years ago

----------------------------- Delete below -----------------------------

Reminder: If your issue is a general question, starts similar to "How do I..", or is related to 3rd party development kits/libs, please discuss this on our community forum at https://esp32.com instead.

INSTRUCTIONS

Before submitting a new issue, please follow the checklist and try to find the answer.

If the issue cannot be solved after the steps before, please follow these instructions so we can get the needed information to help you in a quick and effective fashion.

  1. Fill in all the fields under Environment marked with [ ] by picking the correct option for you in each case and deleting the others.
  2. Describe your problem.
  3. Include debug logs from the "monitor" tool, or coredumps.
  4. Providing as much information as possible under Other items if possible will help us locate and fix the problem.
  5. Use Markdown (see formatting buttons above) and the Preview tab to check what the issue will look like.
  6. Delete these instructions from the above to the below marker lines before submitting this issue.

IMPORTANT: If you do not follow these instructions and provide the necessary details, your issue may not be resolved.

----------------------------- Delete above -----------------------------

Environment

Problem Description

//Detailed problem description goes here.

Expected Behavior

Actual Behavior

Steps to reproduce

  1. step1
  2. ...

// If possible, attach a picture of your setup/wiring here.

Code to reproduce this issue

// the code should be wrapped in the ```cpp tag so that it will be displayed better.
#include "esp_log.h"

void app_main()
{

}

// If your code is longer than 30 lines, GIST is preferred.

Debug Logs

Debug log goes here, should contain the backtrace, as well as the reset source if it is a crash.
Please copy the plain text here for us to search the error log. Or attach the complete logs but leave the main part here if the log is *too* long.

Other items if possible

Alvin1Zhang commented 2 years ago

@badevos 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.

badevos commented 2 years ago

Sorry, my fault: I did prepare this, but my details are gone ...

Environment

Problem Description

I have a configuration and some scripts to activate Secure Boot and Flash Encryption and burn the relevant fuses from the bootloader (first run). This does work on the devkit, but does not on our own board. The digest calculation of the app image does not match the one from the bootloader on our own board.

Expected Behavior

Bootloader to run and execute exactly the same on both boards.

Actual Behavior

The digest calculation of the app image does not match the one from the bootloader on our own board.

Steps to reproduce

I have made some scripts (see attachements). Those are shell scripts, but I renamed them to .txt to get them uploaded here. They should be ran in this order:

  1. build.txt
  2. nvs.txt
  3. flash.txt

build.txt nvs.txt flash.txt

The flash memory is connected as follows: ordo-flash

Code to reproduce this issue

I have no specific code, as I rely on the bootloader code.

Debug Logs

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x1e (SPets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x1e (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:0x3fff0038,len:10140
ho 0 tail 12 room 4
load:0x40078000,len:22792
ho 0 tail 12 room 4
load:0x40080400,len:3464
0x40080400: _init at ??:?

entry 0x40080640
I (31) boot: ESP-IDF v4.4 2nd stage bootloader
I (31) boot: compile time 14:43:01
I (31) boot: chip revision: 3
I (31) boot.esp32: SPI Speed      : 40MHz
I (35) boot.esp32: SPI Mode       : DIO
I (38) boot.esp32: SPI Flash Size : 4MB
I (42) boot: Enabling RNG early entropy source...
I (46) boot: Partition Table:
I (49) boot: ## Label            Usage          Type ST Offset   Length
I (55) boot:  0 nvs_key          NVS keys         01 04 00011000 00001000
I (62) boot:  1 nvs              WiFi data        01 02 00012000 00020000
I (68) boot:  2 otadata          OTA data         01 00 00032000 00002000
I (75) boot:  3 phy_init         RF data          01 01 00034000 00001000
I (81) boot:  4 coredump         Unknown data     01 03 00035000 00020000
I (88) boot:  5 ota_0            OTA app          00 10 00060000 001a0000
I (94) boot:  6 ota_1            OTA app          00 11 00210000 001a0000
I (101) boot: End of partition table
I (104) boot: No factory image, trying OTA 0
I (108) esp_image: segment 0: paddr=00060020 vaddr=3f400020 size=0db6ch ( 56172) map
I (136) esp_image: segment 1: paddr=0006db94 vaddr=3ffb0000 size=01570h (  5488) load
I (138) esp_image: segment 2: paddr=0006f10c vaddr=40080000 size=00f0ch (  3852) load
I (141) esp_image: segment 3: paddr=00070020 vaddr=400d0020 size=6b1c0h (438720) map
I (304) esp_image: segment 4: paddr=000db1e8 vaddr=40080f0c size=0ae44h ( 44612) load
I (323) esp_image: segment 5: paddr=000e6034 vaddr=50000000 size=00010h (    16) load
I (323) esp_image: segment 6: paddr=000e604c vaddr=00000000 size=09f84h ( 40836) 
I (341) esp_image: Verifying image signature...
I (342) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (343) secure_boot_v2: Verifying with RSA-PSS...
I (351) secure_boot_v2: Signature verified successfully!
I (357) boot: Loaded app from partition at offset 0x60000
I (414) boot: Set actual ota_seq=1 in otadata[0]
I (414) secure_boot_v2: enabling secure boot v2...
I (414) efuse: Batch mode of writing fields is enabled
I (417) esp_image: segment 0: paddr=00001020 vaddr=3fff0038 size=0279ch ( 10140) 
I (427) esp_image: segment 1: paddr=000037c4 vaddr=40078000 size=05908h ( 22792) 
I (439) esp_image: segment 2: paddr=000090d4 vaddr=40080400 size=00d88h (  3464) 
I (441) esp_image: Verifying image signature...
I (443) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (451) secure_boot_v2: Verifying with RSA-PSS...
Sig block 0 invalid: Image digest does not match
E (459) secure_boot_v2: Secure Boot V2 verification failed.
E (465) esp_image: Secure boot signature verification failed
I (470) esp_image: Calculating simple hash to check for corruption...
E (486) esp_image: Image hash failed - image is corrupt
W (486) esp_image: image corrupted on flash
E (486) secure_boot_v2: bootloader image appears invalid! error 8194
I (491) efuse: Batch mode of writing fields is cancelled
E (496) boot: Secure Boot v2 failed (8194)
E (500) boot: OTA app partition slot 0 is not bootable
I (505) esp_image: segment 0: paddr=00210020 vaddr=3f400020 size=0db6ch ( 56172) map
I (532) esp_image: segment 1: paddr=0021db94 vaddr=3ffb0000 size=01570h (  5488) load
I (535) esp_image: segment 2: paddr=0021f10c vaddr=40080000 size=00f0ch (  3852) load
I (538) esp_image: segment 3: paddr=00220020 vaddr=400d0020 size=6b1c0h (438720) map
I (701) esp_image: segment 4: paddr=0028b1e8 vaddr=40080f0c size=0ae44h ( 44612) load
I (719) esp_image: segment 5: paddr=00296034 vaddr=50000000 size=00010h (    16) load
I (720) esp_image: segment 6: paddr=0029604c vaddr=00000000 size=09f84h ( 40836) 
I (738) esp_image: Verifying image signature...
I (738) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (739) secure_boot_v2: Verifying with RSA-PSS...
I (747) secure_boot_v2: Signature verified successfully!
I (754) boot: Loaded app from partition at offset 0x210000
I (807) boot: Set actual ota_seq=2 in otadata[0]
I (807) secure_boot_v2: enabling secure boot v2...
I (807) efuse: Batch mode of writing fields is enabled
I (809) esp_image: segment 0: paddr=00001020 vaddr=3fff0038 size=0279ch ( 10140) 
I (820) esp_image: segment 1: paddr=000037c4 vaddr=40078000 size=05908h ( 22792) 
I (832) esp_image: segment 2: paddr=000090d4 vaddr=40080400 size=00d88h (  3464) 
I (834) esp_image: Verifying image signature...
I (836) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (844) secure_boot_v2: Verifying with RSA-PSS...
Sig block 0 invalid: Image digest does not match
E (852) secure_boot_v2: Secure Boot V2 verification failed.
E (857) esp_image: Secure boot signature verification failed
I (863) esp_image: Calculating simple hash to check for corruption...
E (879) esp_image: Image hash failed - image is corrupt
W (879) esp_image: image corrupted on flash
E (879) secure_boot_v2: bootloader image appears invalid! error 8194
I (884) efuse: Batch mode of writing fields is cancelled
E (889) boot: Secure Boot v2 failed (8194)
E (893) boot: OTA app partition slot 1 is not bootable
E (898) boot: No bootable app partitions in the partition table

Other items if possible

my sdkconfig: sdkconfig.txt the generated booloader (signed): bootloader.bin.gz my partytion table: partitions.csv

badevos commented 2 years ago

Some more info: The application works without secure boot, with exactly the same partition table.

I tried by manually burning the digest on both devkit and proprietary board: It works on devkit It fails on proprietary board. key was burned as follows:

espefuse.py burn_key_digest ./secure_boot_signing_key.pem

This is a bootlog with debug info for the failing case:

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_RESET),boot:0x1e (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:0x3fff0038,len:12820
load:0x40078000,len:24040
load:0x40080400,len:3844
0x40080400: _init at ??:?

entry 0x4008067c
I (30) boot: ESP-IDF v4.4 2nd stage bootloader
I (30) boot: compile time 14:49:09
D (30) bootloader_flash: non-XMC chip detected by SFDP Read (FF), skip.
D (34) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (40) boot: chip revision: 3
D (43) boot.esp32: magic e9
D (45) boot.esp32: segments 03
D (48) boot.esp32: spi_mode 02
D (51) boot.esp32: spi_speed 00
D (54) boot.esp32: spi_size 02
I (57) boot.esp32: SPI Speed      : 40MHz
I (60) boot.esp32: SPI Mode       : DIO
I (64) boot.esp32: SPI Flash Size : 4MB
D (67) boot: Enabling RTCWDT(9000 ms)
I (71) boot: Enabling RNG early entropy source...
D (75) bootloader_flash: mmu set paddr=00010000 count=1 size=c00 src_addr=10000 src_addr_aligned=10000
D (84) boot: mapped partition table 0x10000 at 0x3f400000
D (90) flash_parts: partition table verified, 8 entries
I (94) boot: Partition Table:
I (97) boot: ## Label            Usage          Type ST Offset   Length
D (103) boot: load partition table entry 0x3f400000
D (108) boot: type=1 subtype=4
I (111) boot:  0 nvs_key          NVS keys         01 04 00011000 00001000
D (117) boot: load partition table entry 0x3f400020
D (122) boot: type=1 subtype=2
I (125) boot:  1 nvs              WiFi data        01 02 00012000 00020000
D (131) boot: load partition table entry 0x3f400040
D (136) boot: type=1 subtype=0
I (139) boot:  2 otadata          OTA data         01 00 00032000 00002000
D (145) boot: load partition table entry 0x3f400060
D (150) boot: type=1 subtype=1
I (153) boot:  3 phy_init         RF data          01 01 00034000 00001000
D (159) boot: load partition table entry 0x3f400080
D (164) boot: type=1 subtype=3
I (167) boot:  4 coredump         Unknown data     01 03 00035000 00020000
D (173) boot: load partition table entry 0x3f4000a0
D (178) boot: type=0 subtype=10
I (181) boot:  5 ota_0            OTA app          00 10 00060000 001a0000
D (187) boot: load partition table entry 0x3f4000c0
D (192) boot: type=0 subtype=11
I (195) boot:  6 ota_1            OTA app          00 11 00210000 001a0000
I (201) boot: End of partition table
D (205) boot: OTA data offset 0x32000
D (208) bootloader_flash: mmu set paddr=00030000 count=1 size=2000 src_addr=32000 src_addr_aligned=30000
D (217) boot: otadata[0]: sequence values 0xffffffff
D (222) boot: otadata[1]: sequence values 0xffffffff
D (227) boot: OTA sequence numbers both empty (all-0xFF) or partition table does not have bootable ota_apps (app_count=2)
I (237) boot: No factory image, trying OTA 0
D (241) boot: Trying partition index 0 offs 0x60000 size 0x1a0000
D (247) esp_image: reading image header @ 0x60000
D (252) bootloader_flash: mmu set block paddr=0x00060000 (was 0xffffffff)
D (258) esp_image: image header: 0xe9 0x07 0x02 0x03 40080d70
I (264) esp_image: segment 0: paddr=00060020 vaddr=3f400020 size=0db6ch ( 56172) map
D (271) esp_image: free data page_count 0x00000032
D (276) bootloader_flash: mmu set paddr=00060000 count=1 size=db6c src_addr=60020 src_addr_aligned=60000
D (305) bootloader_flash: mmu set block paddr=0x00060000 (was 0xffffffff)
I (305) esp_image: segment 1: paddr=0006db94 vaddr=3ffb0000 size=01570h (  5488) load
D (308) esp_image: free data page_count 0x00000032
D (312) bootloader_flash: mmu set paddr=00060000 count=1 size=1570 src_addr=6db94 src_addr_aligned=60000
D (324) bootloader_flash: mmu set block paddr=0x00060000 (was 0xffffffff)
I (328) esp_image: segment 2: paddr=0006f10c vaddr=40080000 size=00f0ch (  3852) load
D (336) esp_image: free data page_count 0x00000032
D (340) bootloader_flash: mmu set paddr=00060000 count=2 size=f0c src_addr=6f10c src_addr_aligned=60000
D (351) bootloader_flash: mmu set block paddr=0x00070000 (was 0xffffffff)
I (356) esp_image: segment 3: paddr=00070020 vaddr=400d0020 size=6b234h (438836) map
D (363) esp_image: free data page_count 0x00000032
D (368) bootloader_flash: mmu set paddr=00070000 count=7 size=6b234 src_addr=70020 src_addr_aligned=70000
D (534) bootloader_flash: mmu set block paddr=0x000d0000 (was 0xffffffff)
I (535) esp_image: segment 4: paddr=000db25c vaddr=40080f0c size=0ae44h ( 44612) load
D (537) esp_image: free data page_count 0x00000032
D (542) bootloader_flash: mmu set paddr=000d0000 count=2 size=ae44 src_addr=db25c src_addr_aligned=d0000
D (569) bootloader_flash: mmu set block paddr=0x000e0000 (was 0xffffffff)
I (569) esp_image: segment 5: paddr=000e60a8 vaddr=50000000 size=00010h (    16) load
D (572) esp_image: free data page_count 0x00000032
D (577) bootloader_flash: mmu set paddr=000e0000 count=1 size=10 src_addr=e60a8 src_addr_aligned=e0000
D (586) bootloader_flash: mmu set block paddr=0x000e0000 (was 0xffffffff)
I (592) esp_image: segment 6: paddr=000e60c0 vaddr=00000000 size=09f10h ( 40720) 
D (599) esp_image: free data page_count 0x00000032
D (604) bootloader_flash: mmu set paddr=000e0000 count=1 size=9f10 src_addr=e60c0 src_addr_aligned=e0000
D (628) bootloader_flash: mmu set block paddr=0x000e0000 (was 0xffffffff)
I (628) esp_image: Verifying image signature...
D (628) bootloader_flash: mmu set paddr=000e0000 count=1 size=20 src_addr=effe0 src_addr_aligned=e0000
D (636) boot: Calculated secure boot hash: edbd38f7f2d5f8a9e31df6f5f3adf03ca45c970663d0194c592f810da6078a73
D (646) bootloader_flash: mmu set paddr=000f0000 count=1 size=1000 src_addr=f0000 src_addr_aligned=f0000
D (655) efuse: In EFUSE_BLK2__DATA0_REG is used 32 bits starting with 0 bit
D (661) efuse: In EFUSE_BLK2__DATA1_REG is used 32 bits starting with 0 bit
D (668) efuse: In EFUSE_BLK2__DATA2_REG is used 32 bits starting with 0 bit
D (675) efuse: In EFUSE_BLK2__DATA3_REG is used 32 bits starting with 0 bit
D (682) efuse: In EFUSE_BLK2__DATA4_REG is used 32 bits starting with 0 bit
D (688) efuse: In EFUSE_BLK2__DATA5_REG is used 32 bits starting with 0 bit
D (695) efuse: In EFUSE_BLK2__DATA6_REG is used 32 bits starting with 0 bit
D (702) efuse: In EFUSE_BLK2__DATA7_REG is used 32 bits starting with 0 bit
I (709) secure_boot_v2: Verifying with RSA-PSS...
I (717) secure_boot_v2: Signature verified successfully!
I (723) boot: Loaded app from partition at offset 0x60000
I (780) boot: Set actual ota_seq=1 in otadata[0]
I (780) secure_boot_v2: enabling secure boot v2...
I (780) efuse: Batch mode of writing fields is enabled
D (782) esp_image: reading image header @ 0x1000
D (787) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (793) esp_image: image header: 0xe9 0x03 0x02 0x02 4008067c
I (799) esp_image: segment 0: paddr=00001020 vaddr=3fff0038 size=03214h ( 12820) 
D (806) esp_image: free data page_count 0x00000032
D (810) bootloader_flash: mmu set paddr=00000000 count=1 size=3214 src_addr=1020 src_addr_aligned=0
D (824) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (826) esp_image: segment 1: paddr=0000423c vaddr=40078000 size=05de8h ( 24040) 
D (833) esp_image: free data page_count 0x00000032
D (837) bootloader_flash: mmu set paddr=00000000 count=1 size=5de8 src_addr=423c src_addr_aligned=0
D (855) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (855) esp_image: segment 2: paddr=0000a02c vaddr=40080400 size=00f04h (  3844) 
D (860) esp_image: free data page_count 0x00000032
D (864) bootloader_flash: mmu set paddr=00000000 count=1 size=f04 src_addr=a02c src_addr_aligned=0
D (875) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (880) esp_image: Verifying image signature...
D (884) bootloader_flash: mmu set paddr=00000000 count=1 size=20 src_addr=af40 src_addr_aligned=0
D (893) bootloader_flash: mmu set paddr=00000000 count=1 size=a0 src_addr=af60 src_addr_aligned=0
D (901) boot: Calculated secure boot hash: 016f10ab3292a26218a9a70297a9fab505218aae92a5e44a4e594152b01315d0
D (911) bootloader_flash: mmu set paddr=00000000 count=1 size=1000 src_addr=b000 src_addr_aligned=0
D (919) efuse: In EFUSE_BLK2__DATA0_REG is used 32 bits starting with 0 bit
D (926) efuse: In EFUSE_BLK2__DATA1_REG is used 32 bits starting with 0 bit
D (933) efuse: In EFUSE_BLK2__DATA2_REG is used 32 bits starting with 0 bit
D (939) efuse: In EFUSE_BLK2__DATA3_REG is used 32 bits starting with 0 bit
D (946) efuse: In EFUSE_BLK2__DATA4_REG is used 32 bits starting with 0 bit
D (953) efuse: In EFUSE_BLK2__DATA5_REG is used 32 bits starting with 0 bit
D (959) efuse: In EFUSE_BLK2__DATA6_REG is used 32 bits starting with 0 bit
D (966) efuse: In EFUSE_BLK2__DATA7_REG is used 32 bits starting with 0 bit
I (973) secure_boot_v2: Verifying with RSA-PSS...
Sig block 0 invalid: Image digest does not match
E (982) secure_boot_v2: Secure Boot V2 verification failed.
E (987) esp_image: Secure boot signature verification failed
I (992) esp_image: Calculating simple hash to check for corruption...
D (998) bootloader_flash: mmu set paddr=00000000 count=1 size=9f40 src_addr=1000 src_addr_aligned=0
D (1018) boot: Calculated hash: f20a58a787f66d9eb4dc0ea46c5be9bd9150de836b73a8d30309bcb9e020d045
E (1018) esp_image: Image hash failed - image is corrupt
D (1021) boot: Expected hash: e843adf9931a550bf592be648fbe5620f7bdfe639e5c5806ceb805fda0fe67fd
W (1029) esp_image: image corrupted on flash
E (1033) secure_boot_v2: bootloader image appears invalid! error 8194
I (1039) efuse: Batch mode of writing fields is cancelled
E (1044) boot: Secure Boot v2 failed (8194)
E (1048) boot: OTA app partition slot 0 is not bootable
D (1053) boot: Trying partition index 1 offs 0x210000 size 0x1a0000
D (1059) esp_image: reading image header @ 0x210000
D (1064) bootloader_flash: mmu set block paddr=0x00210000 (was 0xffffffff)
D (1070) esp_image: image header: 0xe9 0x07 0x02 0x03 40080d70
I (1076) esp_image: segment 0: paddr=00210020 vaddr=3f400020 size=0db6ch ( 56172) map
D (1083) esp_image: free data page_count 0x00000032
D (1088) bootloader_flash: mmu set paddr=00210000 count=1 size=db6c src_addr=210020 src_addr_aligned=210000
D (1118) bootloader_flash: mmu set block paddr=0x00210000 (was 0xffffffff)
I (1118) esp_image: segment 1: paddr=0021db94 vaddr=3ffb0000 size=01570h (  5488) load
D (1121) esp_image: free data page_count 0x00000032
D (1125) bootloader_flash: mmu set paddr=00210000 count=1 size=1570 src_addr=21db94 src_addr_aligned=210000
D (1137) bootloader_flash: mmu set block paddr=0x00210000 (was 0xffffffff)
I (1141) esp_image: segment 2: paddr=0021f10c vaddr=40080000 size=00f0ch (  3852) load
D (1149) esp_image: free data page_count 0x00000032
D (1154) bootloader_flash: mmu set paddr=00210000 count=2 size=f0c src_addr=21f10c src_addr_aligned=210000
D (1165) bootloader_flash: mmu set block paddr=0x00220000 (was 0xffffffff)
I (1170) esp_image: segment 3: paddr=00220020 vaddr=400d0020 size=6b234h (438836) map
D (1177) esp_image: free data page_count 0x00000032
D (1182) bootloader_flash: mmu set paddr=00220000 count=7 size=6b234 src_addr=220020 src_addr_aligned=220000
D (1349) bootloader_flash: mmu set block paddr=0x00280000 (was 0xffffffff)
I (1349) esp_image: segment 4: paddr=0028b25c vaddr=40080f0c size=0ae44h ( 44612) load
D (1352) esp_image: free data page_count 0x00000032
D (1356) bootloader_flash: mmu set paddr=00280000 count=2 size=ae44 src_addr=28b25c src_addr_aligned=280000
D (1384) bootloader_flash: mmu set block paddr=0x00290000 (was 0xffffffff)
I (1384) esp_image: segment 5: paddr=002960a8 vaddr=50000000 size=00010h (    16) load
D (1387) esp_image: free data page_count 0x00000032
D (1391) bootloader_flash: mmu set paddr=00290000 count=1 size=10 src_addr=2960a8 src_addr_aligned=290000
D (1401) bootloader_flash: mmu set block paddr=0x00290000 (was 0xffffffff)
I (1407) esp_image: segment 6: paddr=002960c0 vaddr=00000000 size=09f10h ( 40720) 
D (1415) esp_image: free data page_count 0x00000032
D (1419) bootloader_flash: mmu set paddr=00290000 count=1 size=9f10 src_addr=2960c0 src_addr_aligned=290000
D (1443) bootloader_flash: mmu set block paddr=0x00290000 (was 0xffffffff)
I (1443) esp_image: Verifying image signature...
D (1444) bootloader_flash: mmu set paddr=00290000 count=1 size=20 src_addr=29ffe0 src_addr_aligned=290000
D (1452) boot: Calculated secure boot hash: edbd38f7f2d5f8a9e31df6f5f3adf03ca45c970663d0194c592f810da6078a73
D (1462) bootloader_flash: mmu set paddr=002a0000 count=1 size=1000 src_addr=2a0000 src_addr_aligned=2a0000
D (1471) efuse: In EFUSE_BLK2__DATA0_REG is used 32 bits starting with 0 bit
D (1478) efuse: In EFUSE_BLK2__DATA1_REG is used 32 bits starting with 0 bit
D (1485) efuse: In EFUSE_BLK2__DATA2_REG is used 32 bits starting with 0 bit
D (1492) efuse: In EFUSE_BLK2__DATA3_REG is used 32 bits starting with 0 bit
D (1498) efuse: In EFUSE_BLK2__DATA4_REG is used 32 bits starting with 0 bit
D (1505) efuse: In EFUSE_BLK2__DATA5_REG is used 32 bits starting with 0 bit
D (1512) efuse: In EFUSE_BLK2__DATA6_REG is used 32 bits starting with 0 bit
D (1519) efuse: In EFUSE_BLK2__DATA7_REG is used 32 bits starting with 0 bit
I (1526) secure_boot_v2: Verifying with RSA-PSS...
I (1534) secure_boot_v2: Signature verified successfully!
I (1541) boot: Loaded app from partition at offset 0x210000
I (1596) boot: Set actual ota_seq=2 in otadata[0]
I (1596) secure_boot_v2: enabling secure boot v2...
I (1596) efuse: Batch mode of writing fields is enabled
D (1599) esp_image: reading image header @ 0x1000
D (1603) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
D (1610) esp_image: image header: 0xe9 0x03 0x02 0x02 4008067c
I (1615) esp_image: segment 0: paddr=00001020 vaddr=3fff0038 size=03214h ( 12820) 
D (1622) esp_image: free data page_count 0x00000032
D (1627) bootloader_flash: mmu set paddr=00000000 count=1 size=3214 src_addr=1020 src_addr_aligned=0
D (1641) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (1643) esp_image: segment 1: paddr=0000423c vaddr=40078000 size=05de8h ( 24040) 
D (1650) esp_image: free data page_count 0x00000032
D (1654) bootloader_flash: mmu set paddr=00000000 count=1 size=5de8 src_addr=423c src_addr_aligned=0
D (1672) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (1672) esp_image: segment 2: paddr=0000a02c vaddr=40080400 size=00f04h (  3844) 
D (1677) esp_image: free data page_count 0x00000032
D (1682) bootloader_flash: mmu set paddr=00000000 count=1 size=f04 src_addr=a02c src_addr_aligned=0
D (1692) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (1697) esp_image: Verifying image signature...
D (1701) bootloader_flash: mmu set paddr=00000000 count=1 size=20 src_addr=af40 src_addr_aligned=0
D (1710) bootloader_flash: mmu set paddr=00000000 count=1 size=a0 src_addr=af60 src_addr_aligned=0
D (1719) boot: Calculated secure boot hash: 016f10ab3292a26218a9a70297a9fab505218aae92a5e44a4e594152b01315d0
D (1728) bootloader_flash: mmu set paddr=00000000 count=1 size=1000 src_addr=b000 src_addr_aligned=0
D (1737) efuse: In EFUSE_BLK2__DATA0_REG is used 32 bits starting with 0 bit
D (1744) efuse: In EFUSE_BLK2__DATA1_REG is used 32 bits starting with 0 bit
D (1751) efuse: In EFUSE_BLK2__DATA2_REG is used 32 bits starting with 0 bit
D (1758) efuse: In EFUSE_BLK2__DATA3_REG is used 32 bits starting with 0 bit
D (1764) efuse: In EFUSE_BLK2__DATA4_REG is used 32 bits starting with 0 bit
D (1771) efuse: In EFUSE_BLK2__DATA5_REG is used 32 bits starting with 0 bit
D (1778) efuse: In EFUSE_BLK2__DATA6_REG is used 32 bits starting with 0 bit
D (1785) efuse: In EFUSE_BLK2__DATA7_REG is used 32 bits starting with 0 bit
I (1792) secure_boot_v2: Verifying with RSA-PSS...
Sig block 0 invalid: Image digest does not match
E (1800) secure_boot_v2: Secure Boot V2 verification failed.
E (1806) esp_image: Secure boot signature verification failed
I (1811) esp_image: Calculating simple hash to check for corruption...
D (1817) bootloader_flash: mmu set paddr=00000000 count=1 size=9f40 src_addr=1000 src_addr_aligned=0
D (1837) boot: Calculated hash: f20a58a787f66d9eb4dc0ea46c5be9bd9150de836b73a8d30309bcb9e020d045
E (1837) esp_image: Image hash failed - image is corrupt
D (1840) boot: Expected hash: e843adf9931a550bf592be648fbe5620f7bdfe639e5c5806ceb805fda0fe67fd
W (1848) esp_image: image corrupted on flash
E (1852) secure_boot_v2: bootloader image appears invalid! error 8194
I (1858) efuse: Batch mode of writing fields is cancelled
E (1863) boot: Secure Boot v2 failed (8194)
E (1867) boot: OTA app partition slot 1 is not bootable
D (1872) boot: Can't boot from zero-length partition
E (1877) boot: No bootable app partitions in the partition table
gb-123-git commented 2 years ago

+1 I am also having the same problem.

I am using ESP32-DevkitC-VE (Wrover Module) with 8MB Flash.

If I burn the digest using : espefuse.py --port COM6 burn_key_digest X:\secure_boot_signing_key.pem, I get

"Sig block 0 invalid: Image digest does not match"

If I don't burn the digest manually, I get similar message as you are getting in your first post. I also have encryption enabled. The app works perfectly if SecurebootV2 is not enabled.

For far bricked 2 devkits in the process.

gb-123-git commented 2 years ago

@badevos - Did you sign your Partition-table.bin also ? Reason I am asking is that closely looking at your logs (and mine) it seems that the Bootlader is able to verify the signature of the partition table but not the application (ota) which is strange... I may be wrong though...

badevos commented 2 years ago

Hi, I did not 'sign' the partition table. As far as I can tell from the logs, the digest from the bootloader image is correct, but the one calculated from the application (ota, either 1 or 2) does not match. The partition table however is parsed correctly, as I do indeed flash the application in both OTA slots and both images are tried from the correct addresses, i.e. the addresses specified in the partition table. The signatures are appended (with some padding/alignment) after the actual binary file and there is no overlap in my case.

gb-123-git commented 2 years ago

@mahavirj already confirmed that partition does not need to be signed in Secure Boot V2. (https://esp32.com/viewtopic.php?f=13&t=26199).

I was merely trying to understand why line is showing (after partition table) I (351) secure_boot_v2: Signature verified successfully! and then before loading app : I (451) secure_boot_v2: Verifying with RSA-PSS... Sig block 0 invalid: Image digest does not match E (459) secure_boot_v2: Secure Boot V2 verification failed.

I am also getting similar result on my end.

I cant understand why the hash results are different:

D (1837) boot: Calculated hash: f20a58a787f66d9eb4dc0ea46c5be9bd9150de836b73a8d30309bcb9e020d045 E (1837) esp_image: Image hash failed - image is corrupt D (1840) boot: Expected hash: e843adf9931a550bf592be648fbe5620f7bdfe639e5c5806ceb805fda0fe67fd

badevos commented 2 years ago

Meanwhile I tried to read back the content of the memory and dump it to a file. This fails as well.

For example to read back the bootloader, I tried:

esptool.py dump_mem 0x1000 0xd000 ./bootloader_dump.bin
esptool.py v3.2-dev
Found 1 serial ports
Serial port /dev/ttyUSB0
Connecting....
Detecting chip type... Unsupported detection protocol, switching and trying again...
Connecting....
Detecting chip type... ESP32
Chip is ESP32-D0WD-V3 (revision 3)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 40:91:51:20:8d:c8
Uploading stub...
Running stub...
Stub running...

A fatal error occurred: Invalid head of packet (0x46): Possible serial noise or corruption.

I also tried with -b 460800, as this is the baudrate used for flashing. Just reading (esptool .py read_mem 0x1000 resp) did not work either.

This error I do get on both devkit and proprietary board. Although the fuses burned on the boards should still allow to read/write to the flash.

Attached is the output of espefuse.py summary for both boards: fuses_proprietary.txt fuses_devkit.txt

As mentioned, the system does work on the devkit in my case, hence the secure boot key is burned as well as the flash encryption key on this board. On our proprietary board, no fuses have been burned yet, I hope to find a fix, since I only have 2 boards available ...

gb-123-git commented 2 years ago

I noticed ABS_DONE_1 is not burnt in your proprietary board. But be careful, if you burn it as 1 manually, you might not be able to go back!

Block 2 is burnt in both cases. Did they automatically get burnt or did you burn them manually ?

badevos commented 2 years ago

Block 2 is burned automatically in the devkit and manually in the proprietary board. Automatic burning in the bootloader occurs after successfull verification of the application signature, which is a phase I never reached on proprietary board off course.

KonstantinKondrashov commented 2 years ago

Hi @badevos! You tried to read out the flash content of bootloader using cmd esptool.py dump_mem 0x1000 0xd000 ./bootloader_dump.bin, but actually it reads memory area not flash content. The right cmd for this read_flash. esptool.py read_flash 0x1000 0xd000 bootloader_dump.bin Could you try to read out the app.bin from flash and check it with the verify_signature cmd? espsecure.py verify_signature build/bootloader/bootloader.bin -v 2 --keyfile secure_boot_signing_key.pem I suspect that that app on the flash is not correct. (maybe using script hids some error messages during flashing).

gb-123-git commented 2 years ago

Here is the method I tried seeing your post : esptool.py read_flash 0x1000 0xd000 bootloader_dump.bin espsecure.py decrypt_flash_data --keyfile X:\Key.bin --output bootloader_dec.bin --address 0x1000 --flash_crypt_conf 0xf bootloader_dump.bin 'espsecure.py verify_signature bootloader_dec.bin -v 2 --keyfile X:\secure_boot_signing_key.pem'

Error I get : A fatal error occurred: Signature block 0 invalid. Signature could not be verified with the provided key.

I am using the following command to sign :
espsecure.py sign_data --version 2 --keyfile X:\secure_boot_signing_key.pem --output bootloader_signed.bin bootloader.bin

gb-123-git commented 2 years ago

@KonstantinKondrashov : Do you think there is a problem with espsecure.py signing tool ?

Does it matter if I am using --flash_mode qout --flash_freq 80m ?

gb-123-git commented 2 years ago

Here is what I did again : espsecure.py sign_data --version 2 --keyfile X:\secure_boot_signing_key.pem --output bootloader_signed.bin bootloader.bin espsecure.py verify_signature encodedBINs\bootloader_signed.bin -v 2 --keyfile X:\secure_boot_signing_key.pem -> Signature block 0 is valid. -> Signature Verification Successful !

espsecure.py encrypt_flash_data --keyfile X:\Key.bin --address 0x1000 --output bootloader_enc.bin bootloader_signed.bin esptool.py write_flash 0x1000 bootloader_enc.bin

For reading again : esptool.py read_flash 0x1000 0xd000 bootloader_dump.bin espsecure.py decrypt_flash_data --keyfile X:\Key.bin --output bootloader_dec.bin --address 0x1000 --flash_crypt_conf 0xf bootloader_dump.bin espsecure.py verify_signature bootloader_dec.bin -v 2 --keyfile X:\secure_boot_signing_key.pem -> A fatal error occurred: Signature block 0 invalid. Signature could not be verified with the provided key.

mahavirj commented 2 years ago

@gb-123-git

As I understand from summary and information shared by @badevos, this issue is happening only on custom hardware. Is that case with you as well?

Note: I am going through all logs, I will share my findings soon.

mahavirj commented 2 years ago 
I (414) efuse: Batch mode of writing fields is enabled
I (417) esp_image: segment 0: paddr=00001020 vaddr=3fff0038 size=0279ch ( 10140) 
I (427) esp_image: segment 1: paddr=000037c4 vaddr=40078000 size=05908h ( 22792) 
I (439) esp_image: segment 2: paddr=000090d4 vaddr=40080400 size=00d88h (  3464) 
I (441) esp_image: Verifying image signature...
I (443) secure_boot_v2: Secure boot V2 is not enabled yet and eFuse digest keys are not set
I (451) secure_boot_v2: Verifying with RSA-PSS...
Sig block 0 invalid: Image digest does not match
E (459) secure_boot_v2: Secure Boot V2 verification failed.

One thing to add:

Bootloader first does signature verification for firmware and then for its own image. In this case, from logs above we can see that bootloader signature verification has failed. So, this is definitely an issue with bootloader image itself. Do you use (signed) bootloader binary as generated by build system? Also please confirm if same binary works on Espressif Devkit but fails on your hardware?

gb-123-git commented 2 years ago

@mahavirj No. I am using ESP32-DevkitC-VE V4 (WROVER-E with 8 MB Flash) directly made by Espressif.

I am manually signing the bootloader.bin after the build succeeds by using : espsecure.py sign_data --version 2 --keyfile X:\secure_boot_signing_key.pem --output bootloader_signed.bin bootloader.bin I am also signing the partition.bin, firmware.bin

Then I am merging the bin using : esptool.py --chip esp32 merge_bin -o merged-firmware.bin --flash_mode qout --flash_freq 80m 0x1000 bootloader_signed.bin 0xD000 partition_signed.bin 0x40000 app_signed.bin

Then I am encrypting the data: espsecure.py encrypt_flash_data --keyfile X:\Key.bin --address 0x0 --output firmware_enc.bin merged-firmware.bin

Then flashing : esptool.py write_flash 0x0 firmware_enc.bin

Just to further clarify, I have unchecked the option of 'Sign Binaries during build'

mahavirj commented 2 years ago

@gb-123-git

I am using ESP32-DevkitC-VE V4 (WROVER-E with 8 MB Flash) directly made by Espressif.

I would request to file new issue in that case. Original report in this issue is specific to custom hardware only, as I understand it.

Does it matter if I am using --flash_mode qout --flash_freq 80m ?

It is possible that esptool is re-writing bootloader header here, if settings in flashing command and actual build configuration of bootloader do not match. This can cause digest mismatch issue, because bootloader image on host and on device are now different. You may read out bootloader from flash again and compare it against original image to confirm this.

Have you set same flash configuration during build as well? Can you please share your log during write_flash command?

gb-123-git commented 2 years ago

@mahavirj I get the following on the cmd prompt: esptool.py v3.2 Found 3 serial ports Serial port COM6 Connecting.... Detecting chip type... Unsupported detection protocol, switching and trying again... Connecting....... Detecting chip type... ESP32 Chip is ESP32-D0WDQ5-V3 (revision 3) Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None Crystal is 40MHz MAC: 7x:8x:cx:ex:5x:6x Uploading stub... Running stub... Stub running... Configuring flash size... Flash will be erased from 0x00000000 to 0x00xxxxxx... Compressed 1994752 bytes to 1915940... Wrote 1994752 bytes (1915940 compressed) at 0x00000000 in 169.7 seconds (effective 94.0 kbit/s)... Hash of data verified.

I have verified that the menuconfig also has 'qout', 80m and 8MB in settings which is same as the command I am executing

I had tried flashing with dio mode @ 40m also but result is the same.

badevos commented 2 years ago

Hi,

I first followed the suggestions from @KonstantinKondrashov to read back some images from the flash. verification of the bootloader that was read back fails, similar to what @gb-123-git posted.

Also @mahavirj is questioning the correctness of the bootloader, which is relevant for my furthern analysis.

The difference in my case for both boards it the size of the flash memory. This has been set to 8MB in my case, in order to be able preparing a build that would run on the devkit. Yet my own board only has 4MB of flash. And I used config option: ESPTOOLPY_FLASHSIZE_DETECT which states in it's help:

  If this option is set, flashing the project will automatically detect
  the flash size of the target chip and update the bootloader image
  before it is flashed.

I converted the binary files (produced by the build system and read back from the flash) to hex to capture 'some' differences. my command to convert: od -t x1 -A x -w 16 ./bootloader_dump.bin > bootloader_dump.txt

The comparison reveals that the binary images are actually equal, except for a single byte, in the very first line. for the bootloader.bin, as produced by the build system: this is the first line: 000000 e9 03 02 30 7c 06 08 40 ee 00 00 00 00 00 03 00 00 00 00 00 00 00 00 01 38 00 ff 3f 14 32 00 00 for the bootloader_dump.bin, as read back from the flash, this is the first line: 000000 e9 03 02 20 7c 06 08 40 ee 00 00 00 00 00 03 00 00 00 00 00 00 00 00 01 38 00 ff 3f 14 32 00 00 (The first six digits is the offset, the rest is the actual data).

The fourth byte is 0x30 vs. 0x20, meaning that they are not equal, and signature verification should fail for that reason.

A side question I have, I did not know the exact size of the bootloader, so I did read the complete bootloader partition, which is bigger than what was originally flashed. I can imagine that the size of the file provided to espsecure verify_signature ... is important. Can this be confirmed please?

I assume that disabling ESPTOOLPY_FLASHSIZE_DETECT and applying the correct size information can solve this, I need more time to test in detail, (and be carefull in the steps I take, I have limited boards available)

@gb-123-git: would it be an option on your side to adjust the flash size according to your board and disable ESPTOOLPY_FLASHSIZE_DETECT to test things out. There is also an option to esptool.py to provide the size. In my case I used --detect which I shouldn't do.

Feedback?

gb-123-git commented 2 years ago

@badevos
let me disable the 'ESPTOOLPY_FLASHSIZE_DETECT' and then test it out. Should be able to do this in the next 15-20 mins

UPDATE : I tried by disabling the ESPTOOLPY_FLASHSIZE_DETECT but the result is the same. Still not getting verified.

I think there was a similar issue #6050 but it was closed and applied to IDF 4.3 & IDF 4.2. Do you think it could have cropped back up in IDF v4.4 ?

KonstantinKondrashov commented 2 years ago

@badevos

A side question I have, I did not know the exact size of the bootloader, so I did read the complete bootloader partition, which is bigger than what was originally flashed. I can imagine that the size of the file provided to espsecure verify_signature ... is important. Can this be confirmed please?

The file size for this verify_signature command should not be smaller than the original file, if you read out more than necessary, then anyway it will verify the signature correctly.

The fourth byte is 0x30 vs. 0x20, meaning that they are not equal, and signature verification should fail for that reason.

Yes, Hash is calculated over the whole image including this header up to end including padding + checksum.

I assume that disabling ESPTOOLPY_FLASHSIZE_DETECT and applying the correct size information can solve this,

Yes, you need to specify the certain flash size ESPTOOLPY_FLASHSIZE instead of detection option.

mahavirj commented 2 years ago

@badevos

The comparison reveals that the binary images are actually equal, except for a single byte, in the very first line. for the bootloader.bin, as produced by the build system: this is the first line: 000000 e9 03 02 30 7c 06 08 40 ee 00 00 00 00 00 03 00 00 00 00 00 00 00 00 01 38 00 ff 3f 14 32 00 00 for the bootloader_dump.bin, as read back from the flash, this is the first line: 000000 e9 03 02 20 7c 06 08 40 ee 00 00 00 00 00 03 00 00 00 00 00 00 00 00 01 38 00 ff 3f 14 32 00 00 (The first six digits is the offset, the rest is the actual data).

The fourth byte is 0x30 vs. 0x20, meaning that they are not equal, and signature verification should fail for that reason.

This makes sense now.

If we compare this data against image header then this field corresponds to flash size (4-bit field) and this has been updated (see esp_image_flash_size_t for details on flash size) in header of bootloader image on device.

I would recommend using --flash-size keep to esptool which would ensure to keep flash size in header intact.

gb-123-git commented 2 years ago

I can confirm my ESP32 has started to work.

The header size seemed to be an issue as it was getting over-riden by a different value while flashing bootloader.

@badevos - You can safely try flashing your board. In case you are flashing/building using PlatformIO, your value in menuconfig / sdkconfig will NOT work. It will be over-ridden by platform.ini or your boardconfig.json

Also note : The Flash mode in sdkconfig refers to the second bootloader. The one you flash with write_flash refers to the 1st bootloader. I read somewhere that if you use 'QIO' in first bootloader, it will not work. You should stick to DIO for safety.

gb-123-git commented 2 years ago

@mahavirj @KonstantinKondrashov

Thanks for your support!

@badevos

Thanks for posting this issue. It has given me a lot of insight on how this works.. I am still here to help you out in case you need it.

badevos commented 2 years ago

@gb-123-git: thanks for your confirmation.

I don't use platform-io, yet I understand the confusion due to platform.ini and/or boardconfig.json. I did not merge any binaries together as I rely on the bootloader for the encryption and fuse burning at runtime (current situation). This allows me to verify the fuses and then finally burn the latest fuses.

Your remarks regarding 'qio'/'dio' doesn't ring a bell with me.

Unfortunately I have a priority change and I can't test this further on short term. Nevertheless within a few weeks I have to prepare production scripts and pick this up again then. Sorry for the inconvenience.

gb-123-git commented 2 years ago

@badevos

My job is already done and I have successfully implemented the secure rom v2 at my end. I was just thanking you for posting this issue as it gave me a deeper insight and helped me fix my problem.

I just wanted to help you fix your board as well. :)

mahavirj commented 2 years ago

@badevos @gb-123-git

Further update on this issue:

I will close this issue for now. Please feel free to comment here in case you would like to keep this issue open or any further concerns.

martinjaeger commented 3 months ago

@mahavirj Has this issue been fixed in the meantime? I still can't flash using idf.py flash with Secure Boot enabled, even with newest 4.7 release of esptool.py.