MCUBoot: Image in the primary slot is not valid!

[Farhang]

Hi Nordic Team,

I have a custom application running based on nRF NCS 1.5.0 with MCUboot enabled.

I'm having an issue where MCUboot simply doesn't jump to the application.
This comes and goes when I add/remove code from my main application... but with no noticible pattern. I wonder if image size is a factor and thing are overlapping in Flash image...

only using 42% of Flash for app.

1> Memory region Used Size Region Size %age Used
1> FLASH: 207828 B 495104 B 41.98%
1> SRAM: 66368 B 256 KB 25.32%
1> IDT_LIST: 88 B 2 KB 4.30%

Running partition manager report on build...\partitions.yml

I believe this is the standard setup where MCUboot take up to 48K and 2 app banks

flash_primary (0x100000 - 1024kB):
+-------------------------------------------------+
| 0x0: mcuboot (0xc000 - 48kB) |
+---0xc000: mcuboot_primary (0x79000 - 484kB)-----+
| 0xc000: mcuboot_pad (0x200 - 512B) |
+---0xc200: mcuboot_primary_app (0x78e00 - 483kB)-+
| 0xc200: app (0x78e00 - 483kB) |
+-------------------------------------------------+
| 0x85000: mcuboot_secondary (0x79000 - 484kB) |
| 0xfe000: settings_storage (0x2000 - 8kB) |
+-------------------------------------------------+

sram_primary (0x40000 - 256kB):
+--------------------------------------------+
| 0x20000000: sram_primary (0x40000 - 256kB) |
+--------------------------------------------+

I can get more debug but here's some I got via enabling minimal logging via RTT in MCUboot.conf

*** Booting Zephyr OS build v2.4.99-ncs1 ***
I: Starting bootloader
I: det pin = 12 rc = 1
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Swap type: none
E: Image in the primary slot is not valid!
E: fih_rc=1, succ=0
E: Unable to find bootable image

One clue is.... I started a bit of investigation into "merged.hex" and how it is created. I was surprised to see mergehex.py combines 4 different images with argument "--overlap=replace"

C:\Python38\python.exe C:/depot/ncs/zephyr/scripts/mergehex.py -o C:/depot/application/build_nrf52840dk_nrf52840/zephyr/merged.hex --overlap=replace C:/depot/application/build_nrf52840dk_nrf52840/mcuboot/zephyr/zephyr.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/mcuboot_primary.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/zephyr.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/app_signed.hex

When I looked at those 4 images there is a LOT of overlap. Shouldn't the final image just consist of mcuboot image and app_signed?

For example: "app_signed.hex" and "zephyr.hex" are almost identical, they start the same but app_signed.hex has signature at the end which is normal, see below for similarities at start.

This is strange to me why zephyr.hex needs to be included in the mergehex while app_signed has everything as far as the app goes, or is there a piece that I am missing? 

This is just one clue, but I haven't determined if this is causing the MCUboot not jumping to app. In other times when it does work, the overlap/replace redundancies are still in place. So I'm not sure if this is the cause.

Thanks for your assistance in advance, this is blocking progress of development for us.

[Simon]

Would you be able to do some debugging/add some printk's, and figure exactly where it's failing? If it's boot_image_check() or boot_is_header_valid().

My guess is that it fails here: boot_image_check()-->bootutil_image_validate()-->FIH_CALL(boot_fih_memequal, fih_rc, hash, buf, sizeof(hash)) (compare calculated hash to hash stored in TLV). As mentioned in MCUboot-->Integrity Check: "Calculated SHA256 must match SHA256 TLV contents".

Since the calculated hash of the application will not correspond to the stored hash, since you're changing it: "This comes and goes when I add/remove code from my main application".

One clue is.... I started a bit of investigation into "merged.hex" and how it is created. I was surprised to see mergehex.py combines 4 different images with argument "--overlap=replace"

C:\Python38\python.exe C:/depot/ncs/zephyr/scripts/mergehex.py -o C:/depot/application/build_nrf52840dk_nrf52840/zephyr/merged.hex --overlap=replace C:/depot/application/build_nrf52840dk_nrf52840/mcuboot/zephyr/zephyr.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/mcuboot_primary.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/zephyr.hex C:/depot/application/build_nrf52840dk_nrf52840/zephyr/app_signed.hex

When I looked at those 4 images there is a LOT of overlap. Shouldn't the final image just consist of mcuboot image and app_signed?

 The overlap parameter will decide what happens when an overlap between two images happens, and it can be set to three different options:

If I understand it correctly, since overlap is set to "replace", the hex file app_signed.hex will be used, since it's mentioned last.

Best regards,

Simon

[Farhang]

Simon I forgot to mention, I do a clean/ full rebuild, so I assume all hashes are recalculated properly, no?

I will do more debugging as you suggested and report back.

RE: overlap=replace, I didn't change the build to this option, it was already set to that. Is that standard or not?

I guess I can look at an sample/example and see how merge is done for a standard project.

[Simon]

Farhang said:

Simon I forgot to mention, I do a clean/ full rebuild, so I assume all hashes are recalculated properly, no?

I will do more debugging as you suggested and report back.

Okay, sounds good. I'll be waiting for your report

Farhang said:

RE: overlap=replace, I didn't change the build to this option, it was already set to that. Is that standard or not?

I guess I can look at an sample/example and see how merge is done for a standard project.

Yes, it's standard. It will make it such that the app_signed.hex file is used instead of the zephyr.hex file. Check my answer here for a more detailed explanation:

"merged.hex will contain the files <your sample>\<build folder>\mcuboot\zephyr\zephyr.hex as well as <your sample>\<build folder>\zephyr\app_signed.hex. If you're building a nonsecure application (nrf9160dk_nrf9160ns) the merged hex file will include <your sample>\<build folder>\spm\zephyr\zephyr.hex also. When you program the merged.hex file, it will program all the mentioned hex files at once."

Best regards,

Simon

[Farhang]

Simon OK So I went and did debugging, originally the hashes were not matching as you guessed. But then adding more debug statements in MCUBoot and/or reducing the CONFIG_MAIN_STACK from 10KB to 4KB led to hashes matching but a new problem arose. It goes all the way to do_boot() but doesn't hit the breakpoint in the main() in app.

It keep resetting over and over.

What is the appropriate stack size for MCUboot Main?

Is there another blog post/question I need to be looking at for MCUboot resetting over and over?

Am I violating any rules by putting breakpoints in MCUboot? Adding a breakpoint doesn't add contents to protected areas in FLASH does it?

[Farhang]

The current status of my MCUboot.conf file

#
# Copyright (c) 2020 Nordic Semiconductor ASA
#
# SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
#
CONFIG_SIZE_OPTIMIZATIONS=y

# Disable memory guard to avoid false faults in application after boot
CONFIG_HW_STACK_PROTECTION=n

CONFIG_SYSTEM_CLOCK_DISABLE=y
CONFIG_SYSTEM_CLOCK_NO_WAIT=y
CONFIG_PM=n

CONFIG_MAIN_STACK_SIZE=4096
CONFIG_MBEDTLS_CFG_FILE="mcuboot-mbedtls-cfg.h"
CONFIG_DEBUG=y

CONFIG_BOOT_MAX_IMG_SECTORS=256
CONFIG_BOOT_BOOTSTRAP=n

CONFIG_BOOT_ENCRYPT_RSA=n
CONFIG_BOOT_SIGNATURE_TYPE_RSA=y
CONFIG_BOOT_SIGNATURE_TYPE_ECDSA_P256=n
CONFIG_BOOT_SIGNATURE_KEY_FILE="..\\..\\..\\application\\mcuboot_private.pem"
#CONFIG_DISABLE_FLASH_PATCH=y //should be used in production for max security. read more about flash patching

# Flash
CONFIG_FLASH=y
CONFIG_BOOT_ERASE_PROGRESSIVELY=y
CONFIG_SOC_FLASH_NRF_EMULATE_ONE_BYTE_WRITE_ACCESS=y

# Logger
#3 lines below switched to y will enable RTT logging in MCUboot
CONFIG_LOG_BACKEND_RTT=n
CONFIG_RTT_CONSOLE=n
CONFIG_LOG=n
CONFIG_LOG_MINIMAL=n
CONFIG_MCUBOOT_LOG_LEVEL_DBG=n
CONFIG_LOG_BACKEND_UART=n
CONFIG_UART_CONSOLE=n

#CONFIG_LOG_DEFAULT_LEVEL=4
#CONFIG_LOG_OVERRIDE_LEVEL=4
#CONFIG_LOG_MAX_LEVEL=4 
#CONFIG_LOG_IMMEDIATE=n
#CONFIG_LOG_PROCESS_THREAD=y

#CONFIG_LOG_DEFAULT_LEVEL=2
#CONFIG_LOG_MAX_LEVEL=3
#CONFIG_LOG_PRINTK=y
#CONFIG_LOG_BACKEND_SHOW_COLOR=n
#CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP=n

CONFIG_MCUBOOT_SERIAL=y
CONFIG_BOOT_SERIAL_DETECT_PORT="GPIO_0"
CONFIG_BOOT_SERIAL_DETECT_PIN=12
CONFIG_BOOT_SERIAL_DETECT_PIN_VAL=0