diff --git a/boot/bootutil/src/bootutil_misc.c b/boot/bootutil/src/bootutil_misc.c index 0091165d5..56e791043 100644 --- a/boot/bootutil/src/bootutil_misc.c +++ b/boot/bootutil/src/bootutil_misc.c @@ -155,6 +155,9 @@ int boot_trailer_scramble_offset(const struct flash_area *fa, size_t alignment, { int ret = 0; + BOOT_LOG_DBG("boot_trailer_scramble_offset: flash_area %p, alignment %u", + fa, (unsigned int)alignment); + /* Not allowed to enforce alignment smaller than device allows */ if (alignment < flash_area_align(fa)) { alignment = flash_area_align(fa); @@ -176,6 +179,9 @@ int boot_trailer_scramble_offset(const struct flash_area *fa, size_t alignment, *off = flash_area_get_size(fa) - ALIGN_DOWN(boot_trailer_sz(alignment), alignment); } + BOOT_LOG_DBG("boot_trailer_scramble_offset: final alignment %u, offset %u", + (unsigned int)alignment, (unsigned int)*off); + return ret; } @@ -187,6 +193,8 @@ int boot_header_scramble_off_sz(const struct flash_area *fa, int slot, size_t *o size_t loff = 0; struct flash_sector sector; + BOOT_LOG_DBG("boot_header_scramble_off_sz: slot %d", slot); + (void)slot; #if defined(MCUBOOT_SWAP_USING_OFFSET) /* In case of swap offset, header of secondary slot image is positioned @@ -215,6 +223,8 @@ int boot_header_scramble_off_sz(const struct flash_area *fa, int slot, size_t *o } *off = loff; + BOOT_LOG_DBG("boot_header_scramble_off_sz: size %u", (unsigned int)*size); + return ret; } @@ -601,6 +611,9 @@ boot_erase_region(const struct flash_area *fa, uint32_t off, uint32_t size, bool { int rc = 0; + BOOT_LOG_DBG("boot_erase_region: flash_area %p, offset %d, size %d, backwards == %d", + fa, off, size, (int)backwards); + if (off >= flash_area_get_size(fa) || (flash_area_get_size(fa) - off) < size) { rc = -1; goto end; @@ -608,6 +621,8 @@ boot_erase_region(const struct flash_area *fa, uint32_t off, uint32_t size, bool uint32_t end_offset = 0; struct flash_sector sector; + BOOT_LOG_DBG("boot_erase_region: device with erase"); + if (backwards) { /* Get the lowest page offset first */ rc = flash_area_get_sector(fa, off, §or); @@ -681,6 +696,8 @@ boot_erase_region(const struct flash_area *fa, uint32_t off, uint32_t size, bool off += 1; } } + } else { + BOOT_LOG_DBG("boot_erase_region: device without erase"); } end: diff --git a/boot/bootutil/src/bootutil_public.c b/boot/bootutil/src/bootutil_public.c index 1c3a347e2..cb689be3b 100644 --- a/boot/bootutil/src/bootutil_public.c +++ b/boot/bootutil/src/bootutil_public.c @@ -324,7 +324,7 @@ boot_write_magic(const struct flash_area *fap) memset(&magic[0], erased_val, sizeof(magic)); memcpy(&magic[BOOT_MAGIC_ALIGN_SIZE - BOOT_MAGIC_SZ], BOOT_IMG_MAGIC, BOOT_MAGIC_SZ); - BOOT_LOG_DBG("writing magic; fa_id=%d off=0x%lx (0x%lx)", + BOOT_LOG_DBG("boot_write_magic: fa_id=%d off=0x%lx (0x%lx)", flash_area_get_id(fap), (unsigned long)off, (unsigned long)(flash_area_get_off(fap) + off)); rc = flash_area_write(fap, pad_off, &magic[0], BOOT_MAGIC_ALIGN_SIZE); @@ -350,9 +350,14 @@ boot_write_trailer(const struct flash_area *fap, uint32_t off, uint32_t align; int rc; + BOOT_LOG_DBG("boot_write_trailer: for %p at %d, size = %d", + fap, off, inlen); + align = flash_area_align(fap); align = ALIGN_UP(inlen, align); if (align > BOOT_MAX_ALIGN) { + /* This should never happen */ + assert(0); return -1; } erased_val = flash_area_erased_val(fap); @@ -593,6 +598,9 @@ boot_set_next(const struct flash_area *fa, bool active, bool confirm) struct boot_swap_state slot_state; int rc; + BOOT_LOG_DBG("boot_set_next: fa %p active == %d, confirm == %d", + fa, (int)active, (int)confirm); + if (active) { /* The only way to set active slot for next boot is to confirm it, * as DirectXIP will conclude that, since slot has not been confirmed @@ -603,6 +611,7 @@ boot_set_next(const struct flash_area *fa, bool active, bool confirm) rc = boot_read_swap_state(fa, &slot_state); if (rc != 0) { + BOOT_LOG_DBG("boot_set_next: error %d reading state", rc); return rc; } @@ -730,6 +739,8 @@ boot_set_confirmed_multi(int image_index) rc = flash_area_open(FLASH_AREA_IMAGE_PRIMARY(image_index), &fap); if (rc != 0) { + BOOT_LOG_DBG("boot_set_confirmed_multi: error %d opening image %d", + rc, image_index); return BOOT_EFLASH; } @@ -757,13 +768,14 @@ int boot_image_load_header(const struct flash_area *fa_p, struct image_header *hdr) { - uint32_t size; + uint32_t size = 0; int rc = flash_area_read(fa_p, 0, hdr, sizeof *hdr); + BOOT_LOG_DBG("boot_image_load_header: from %p, result %d", fa_p, rc); + if (rc != 0) { - rc = BOOT_EFLASH; BOOT_LOG_ERR("Failed reading image header"); - return BOOT_EFLASH; + return BOOT_EFLASH; } if (hdr->ih_magic != IMAGE_MAGIC) { @@ -780,6 +792,8 @@ boot_image_load_header(const struct flash_area *fa_p, if (!boot_u32_safe_add(&size, hdr->ih_img_size, hdr->ih_hdr_size) || size >= flash_area_get_size(fa_p)) { + BOOT_LOG_ERR("Image size bigger than designated area: %lu > %lu", + (unsigned long)size, (unsigned long)flash_area_get_size(fa_p)); return BOOT_EBADIMAGE; } diff --git a/boot/bootutil/src/ed25519_psa.c b/boot/bootutil/src/ed25519_psa.c index 12ba20ac1..5b8a4ed7c 100644 --- a/boot/bootutil/src/ed25519_psa.c +++ b/boot/bootutil/src/ed25519_psa.c @@ -29,6 +29,8 @@ int ED25519_verify(const uint8_t *message, size_t message_len, psa_key_id_t kid; int ret = 0; /* Fail by default */ + BOOT_LOG_DBG("ED25519_verify: PSA implementation"); + /* Initialize PSA Crypto */ status = psa_crypto_init(); if (status != PSA_SUCCESS) { diff --git a/boot/bootutil/src/encrypted.c b/boot/bootutil/src/encrypted.c index 434f74dcc..929701e0f 100644 --- a/boot/bootutil/src/encrypted.c +++ b/boot/bootutil/src/encrypted.c @@ -43,6 +43,9 @@ #include "bootutil/enc_key.h" #include "bootutil/sign_key.h" #include "bootutil/crypto/common.h" +#include "bootutil/bootutil_log.h" + +BOOT_LOG_MODULE_DECLARE(mcuboot); #include "bootutil_priv.h" @@ -383,6 +386,8 @@ boot_decrypt_key(const uint8_t *buf, uint8_t *enckey) uint8_t *cpend; size_t olen; #endif + + BOOT_LOG_DBG("boot_decrypt_key"); #if defined(MCUBOOT_ENCRYPT_EC256) bootutil_ecdh_p256_context ecdh_p256; #endif @@ -597,8 +602,11 @@ boot_enc_load(struct boot_loader_state *state, int slot, #endif int rc; + BOOT_LOG_DBG("boot_enc_load: slot %d", slot); + /* Already loaded... */ if (enc_state[slot].valid) { + BOOT_LOG_DBG("boot_enc_load: already loaded"); return 1; } diff --git a/boot/bootutil/src/encrypted_psa.c b/boot/bootutil/src/encrypted_psa.c index 04b5fbee4..6f60a1955 100644 --- a/boot/bootutil/src/encrypted_psa.c +++ b/boot/bootutil/src/encrypted_psa.c @@ -134,9 +134,11 @@ boot_decrypt_key(const uint8_t *buf, uint8_t *enckey) uint8_t iv_and_key[PSA_CIPHER_IV_LENGTH(PSA_KEY_TYPE_AES, PSA_ALG_CTR) + BOOT_ENC_KEY_SIZE]; + BOOT_LOG_DBG("boot_decrypt_key: PSA ED25519"); + psa_ret = psa_crypto_init(); if (psa_ret != PSA_SUCCESS) { - BOOT_LOG_ERR("AES crypto init failed %d", psa_ret); + BOOT_LOG_ERR("PSA crypto init failed %d", psa_ret); return -1; } diff --git a/boot/bootutil/src/image_ecdsa.c b/boot/bootutil/src/image_ecdsa.c index 4604913b4..30c7d0d0f 100644 --- a/boot/bootutil/src/image_ecdsa.c +++ b/boot/bootutil/src/image_ecdsa.c @@ -28,6 +28,9 @@ #include #include "mcuboot_config/mcuboot_config.h" +#include "bootutil/bootutil_log.h" + +BOOT_LOG_MODULE_DECLARE(mcuboot); #if defined(MCUBOOT_SIGN_EC256) || defined(MCUBOOT_SIGN_EC384) @@ -46,6 +49,8 @@ bootutil_verify_sig(uint8_t *hash, uint32_t hlen, uint8_t *sig, size_t slen, uint8_t *pubkey; uint8_t *end; + BOOT_LOG_DBG("bootutil_verify_sig: ECDSA builtin key %d", key_id); + pubkey = (uint8_t *)bootutil_keys[key_id].key; end = pubkey + *bootutil_keys[key_id].len; bootutil_ecdsa_init(&ctx); @@ -75,6 +80,8 @@ bootutil_verify_sig(uint8_t *hash, uint32_t hlen, uint8_t *sig, size_t slen, bootutil_ecdsa_context ctx; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("bootutil_verify_sig: ECDSA embedded key %hhd", key_id); + /* Use builtin key for image verification, no key parsing is required. */ ctx.key_id = key_id; bootutil_ecdsa_init(&ctx); diff --git a/boot/bootutil/src/image_ed25519.c b/boot/bootutil/src/image_ed25519.c index ffb8cec3b..4d83bb3d7 100644 --- a/boot/bootutil/src/image_ed25519.c +++ b/boot/bootutil/src/image_ed25519.c @@ -21,8 +21,11 @@ #include "bootutil/crypto/common.h" #endif -#include "bootutil_priv.h" +#include "bootutil/bootutil_log.h" #include "bootutil/crypto/sha.h" +#include "bootutil_priv.h" + +BOOT_LOG_MODULE_DECLARE(mcuboot); #define EDDSA_SIGNATURE_LENGTH 64 #define NUM_ED25519_BYTES 32 @@ -90,7 +93,11 @@ bootutil_verify(uint8_t *buf, uint32_t blen, uint8_t *pubkey; uint8_t *end; + BOOT_LOG_DBG("bootutil_verify: ED25519 key_id %d", (int)key_id); + if (slen != EDDSA_SIGNATURE_LENGTH) { + BOOT_LOG_DBG("bootutil_verify: expected slen %d, got %u", + EDDSA_SIGNATURE_LENGTH, (unsigned int)slen); FIH_SET(fih_rc, FIH_FAILURE); goto out; } @@ -101,6 +108,7 @@ bootutil_verify(uint8_t *buf, uint32_t blen, #if !defined(MCUBOOT_KEY_IMPORT_BYPASS_ASN) rc = bootutil_import_key(&pubkey, end); if (rc) { + BOOT_LOG_DBG("bootutil_verify: import key failed %d", rc); FIH_SET(fih_rc, FIH_FAILURE); goto out; } @@ -110,6 +118,7 @@ bootutil_verify(uint8_t *buf, uint32_t blen, * There is no check whether this is the correct key, * here, by the algorithm selected. */ + BOOT_LOG_DBG("bootutil_verify: bypass ASN1"); if (*bootutil_keys[key_id].len < NUM_ED25519_BYTES) { FIH_SET(fih_rc, FIH_FAILURE); goto out; @@ -144,7 +153,11 @@ bootutil_verify_sig(uint8_t *hash, uint32_t hlen, { FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("bootutil_verify_sig: ED25519 key_id %d", (int)key_id); + if (hlen != IMAGE_HASH_SIZE) { + BOOT_LOG_DBG("bootutil_verify_sig: expected hlen %d, got %d", + IMAGE_HASH_SIZE, hlen); FIH_SET(fih_rc, FIH_FAILURE); goto out; } @@ -167,6 +180,8 @@ bootutil_verify_img(uint8_t *img, uint32_t size, { FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("bootutil_verify_img: ED25519 key_id %d", (int)key_id); + FIH_CALL(bootutil_verify, fih_rc, img, size, sig, slen, key_id); diff --git a/boot/bootutil/src/image_rsa.c b/boot/bootutil/src/image_rsa.c index 778a92b46..5479b75eb 100644 --- a/boot/bootutil/src/image_rsa.c +++ b/boot/bootutil/src/image_rsa.c @@ -28,6 +28,9 @@ #include #include "mcuboot_config/mcuboot_config.h" +#include "bootutil/bootutil_log.h" + +BOOT_LOG_MODULE_DECLARE(mcuboot); #ifdef MCUBOOT_SIGN_RSA #include "bootutil_priv.h" @@ -267,6 +270,8 @@ bootutil_verify_sig(uint8_t *hash, uint32_t hlen, uint8_t *sig, size_t slen, uint8_t *cp; uint8_t *end; + BOOT_LOG_DBG("bootutil_verify_sig: RSA key_id %d", key_id); + bootutil_rsa_init(&ctx); cp = (uint8_t *)bootutil_keys[key_id].key; diff --git a/boot/bootutil/src/image_validate.c b/boot/bootutil/src/image_validate.c index 521251a40..eec678724 100644 --- a/boot/bootutil/src/image_validate.c +++ b/boot/bootutil/src/image_validate.c @@ -41,6 +41,9 @@ #include "bootutil/fault_injection_hardening.h" #include "mcuboot_config/mcuboot_config.h" +#include "bootutil/bootutil_log.h" + +BOOT_LOG_MODULE_DECLARE(mcuboot); #ifdef MCUBOOT_ENC_IMAGES #include "bootutil/enc_key.h" @@ -107,6 +110,7 @@ bootutil_img_hash(struct boot_loader_state *state, (void)tmp_buf_sz; #endif #endif + BOOT_LOG_DBG("bootutil_img_hash"); #ifdef MCUBOOT_ENC_IMAGES if (state == NULL) { @@ -120,6 +124,7 @@ bootutil_img_hash(struct boot_loader_state *state, /* Encrypted images only exist in the secondary slot */ if (MUST_DECRYPT(fap, image_index, hdr) && !boot_enc_valid(enc_state, 1)) { + BOOT_LOG_DBG("bootutil_img_hash: error encrypted image found in primary slot"); return -1; } #endif @@ -187,6 +192,8 @@ bootutil_img_hash(struct boot_loader_state *state, #endif if (rc) { bootutil_sha_drop(&sha_ctx); + BOOT_LOG_DBG("bootutil_img_validate Error %d reading data chunk %p %u %u", + rc, fap, off, blk_sz); return rc; } #ifdef MCUBOOT_ENC_IMAGES @@ -280,6 +287,8 @@ bootutil_find_key(uint8_t *keyhash, uint8_t keyhash_len) const struct bootutil_key *key; uint8_t hash[IMAGE_HASH_SIZE]; + BOOT_LOG_DBG("bootutil_find_key"); + if (keyhash_len > IMAGE_HASH_SIZE) { return -1; } @@ -308,6 +317,8 @@ bootutil_find_key(uint8_t image_index, uint8_t *key, uint16_t key_len) int rc; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("bootutil_find_key: image_index %d", image_index); + bootutil_sha_init(&sha_ctx); bootutil_sha_update(&sha_ctx, key, key_len); bootutil_sha_finish(&sha_ctx, hash); @@ -518,6 +529,8 @@ bootutil_img_validate(struct boot_loader_state *state, FIH_DECLARE(security_counter_valid, FIH_FAILURE); #endif + BOOT_LOG_DBG("bootutil_img_validate: flash area %p", fap); + #if defined(EXPECTED_HASH_TLV) && !defined(MCUBOOT_SIGN_PURE) #if defined(MCUBOOT_SWAP_USING_OFFSET) && defined(MCUBOOT_SERIAL_RECOVERY) rc = bootutil_img_hash(state, hdr, fap, tmp_buf, tmp_buf_sz, hash, seed, seed_len, @@ -538,7 +551,8 @@ bootutil_img_validate(struct boot_loader_state *state, /* If Pure type signature is expected then it has to be there */ rc = bootutil_check_for_pure(hdr, fap); if (rc != 0) { - goto out; + BOOT_LOG_DBG("bootutil_img_validate: pure expected"); + goto out; } #endif @@ -552,6 +566,7 @@ bootutil_img_validate(struct boot_loader_state *state, rc = bootutil_tlv_iter_begin(&it, hdr, fap, IMAGE_TLV_ANY, false); if (rc) { + BOOT_LOG_DBG("bootutil_img_validate: TLV iteration failed %d", rc); goto out; } @@ -560,9 +575,11 @@ bootutil_img_validate(struct boot_loader_state *state, #else img_sz = it.tlv_end; #endif + BOOT_LOG_DBG("bootutil_img_validate: TLV off %u, end %u", it.tlv_off, it.tlv_end); if (img_sz > bootutil_max_image_size(state, fap)) { rc = -1; + BOOT_LOG_DBG("bootutil_img_validate: TLV beyond image size"); goto out; } @@ -593,6 +610,7 @@ bootutil_img_validate(struct boot_loader_state *state, } } if (!found) { + BOOT_LOG_DBG("bootutil_img_validate: TLV %d not permitted", type); FIH_SET(fih_rc, FIH_FAILURE); goto out; } @@ -602,6 +620,7 @@ bootutil_img_validate(struct boot_loader_state *state, #if defined(EXPECTED_HASH_TLV) && !defined(MCUBOOT_SIGN_PURE) case EXPECTED_HASH_TLV: { + BOOT_LOG_DBG("bootutil_img_validate: EXPECTED_HASH_TLV == %d", EXPECTED_HASH_TLV); /* Verify the image hash. This must always be present. */ if (len != sizeof(hash)) { rc = -1; @@ -625,6 +644,7 @@ bootutil_img_validate(struct boot_loader_state *state, #ifdef EXPECTED_KEY_TLV case EXPECTED_KEY_TLV: { + BOOT_LOG_DBG("bootutil_img_validate: EXPECTED_KEY_TLV == %d", EXPECTED_KEY_TLV); /* * Determine which key we should be checking. */ @@ -655,6 +675,7 @@ bootutil_img_validate(struct boot_loader_state *state, #ifdef EXPECTED_SIG_TLV case EXPECTED_SIG_TLV: { + BOOT_LOG_DBG("bootutil_img_validate: EXPECTED_SIG_TLV == %d", EXPECTED_SIG_TLV); /* Ignore this signature if it is out of bounds. */ if (key_id < 0 || key_id >= bootutil_key_cnt) { key_id = -1; diff --git a/boot/bootutil/src/loader.c b/boot/bootutil/src/loader.c index 62f980b69..6654245ad 100644 --- a/boot/bootutil/src/loader.c +++ b/boot/bootutil/src/loader.c @@ -283,6 +283,19 @@ static int boot_version_cmp(const struct image_version *ver1, const struct image_version *ver2) { +#if !defined(MCUBOOT_VERSION_CMP_USE_BUILD_NUMBER) + BOOT_LOG_DBG("boot_version_cmp: ver1 %u.%u.%u vs ver2 %u.%u.%u", + (unsigned)ver1->iv_major, (unsigned)ver1->iv_minor, + (unsigned)ver1->iv_revision, (unsigned)ver2->iv_major, + (unsigned)ver2->iv_minor, (unsigned)ver2->iv_revision); +#else + BOOT_LOG_DBG("boot_version_cmp: ver1 %u.%u.%u.%u vs ver2 %u.%u.%u.%u", + (unsigned)ver1->iv_major, (unsigned)ver1->iv_minor, + (unsigned)ver1->iv_revision, (unsigned)ver1->iv_build_num, + (unsigned)ver2->iv_major, (unsigned)ver2->iv_minor, + (unsigned)ver2->iv_revision, (unsigned)ver2->iv_build_num); +#endif + if (ver1->iv_major > ver2->iv_major) { return 1; } @@ -554,6 +567,7 @@ boot_verify_slot_dependencies(struct boot_loader_state *state, uint32_t slot) fap = BOOT_IMG_AREA(state, slot); assert(fap != NULL); + BOOT_LOG_DBG("boot_verify_slot_dependencies"); #if defined(MCUBOOT_SWAP_USING_OFFSET) it.start_off = boot_get_state_secondary_offset(state, fap); #endif @@ -581,6 +595,8 @@ boot_verify_slot_dependencies(struct boot_loader_state *state, uint32_t slot) rc = LOAD_IMAGE_DATA(boot_img_hdr(state, slot), fap, off, &dep, len); if (rc != 0) { + BOOT_LOG_DBG("boot_verify_slot_dependencies: error %d reading dependency %p %d %d", + rc, fap, off, len); rc = BOOT_EFLASH; goto done; } @@ -593,6 +609,7 @@ boot_verify_slot_dependencies(struct boot_loader_state *state, uint32_t slot) /* Verify dependency and modify the swap type if not satisfied. */ rc = boot_verify_slot_dependency(state, &dep); if (rc != 0) { + BOOT_LOG_DBG("boot_verify_slot_dependencies: not satisfied"); /* Dependency not satisfied */ goto done; } @@ -1005,6 +1022,9 @@ boot_validate_slot(struct boot_loader_state *state, int slot, struct image_header *hdr; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_validate_slot: slot %d, expected_swap_type %d", + slot, expected_swap_type); + #if !defined(MCUBOOT_SWAP_USING_OFFSET) (void)expected_swap_type; #endif @@ -1250,6 +1270,8 @@ boot_scramble_region(const struct flash_area *fa, uint32_t off, uint32_t size, b { int rc = 0; + BOOT_LOG_DBG("boot_scramble_region: %p %d %d %d", fa, off, size, (int)backwards); + if (size == 0) { goto done; } @@ -1264,6 +1286,7 @@ boot_scramble_region(const struct flash_area *fa, uint32_t off, uint32_t size, b const size_t write_block = flash_area_align(fa); uint32_t end_offset; + BOOT_LOG_DBG("boot_scramble_region: device without erase, overwriting"); memset(buf, flash_area_erased_val(fa), sizeof(buf)); if (backwards) { @@ -1273,11 +1296,14 @@ boot_scramble_region(const struct flash_area *fa, uint32_t off, uint32_t size, b } else { end_offset = ALIGN_DOWN((off + size), write_block); } + BOOT_LOG_DBG("boot_scramble_region: start offset %u, end offset %u", off, end_offset); while (off != end_offset) { /* Write over the area to scramble data that is there */ rc = flash_area_write(fa, off, buf, write_block); if (rc != 0) { + BOOT_LOG_DBG("boot_scramble_region: error %d for %p %d %u", + rc, fa, off, (unsigned int)write_block); break; } @@ -2348,6 +2374,8 @@ context_boot_go(struct boot_loader_state *state, struct boot_rsp *rsp) bool has_upgrade; volatile int fih_cnt; + BOOT_LOG_DBG("context_boot_go"); + #if defined(__BOOTSIM__) /* The array of slot sectors are defined here (as opposed to file scope) so * that they don't get allocated for non-boot-loader apps. This is @@ -3216,6 +3244,8 @@ static void boot_fetch_slot_state_sizes(void) assert(rc == 0); if (rc != 0) { + BOOT_LOG_DBG("boot_fetch_slot_state_sizes: error %d for %d", + rc, fa_id); goto finish; } } diff --git a/boot/bootutil/src/swap_misc.c b/boot/bootutil/src/swap_misc.c index ac9412b0f..a4c39c20a 100644 --- a/boot/bootutil/src/swap_misc.c +++ b/boot/bootutil/src/swap_misc.c @@ -80,7 +80,7 @@ swap_scramble_trailer_sectors(const struct boot_loader_state *state, size_t off; int rc; - BOOT_LOG_DBG("Scrambling trailer; fa_id=%d", flash_area_get_id(fap)); + BOOT_LOG_DBG("swap_scramble_trailer_sectors: fa_id=%d", flash_area_get_id(fap)); /* Delete starting from last sector and moving to beginning */ rc = boot_trailer_scramble_offset(fap, BOOT_WRITE_SZ(state), &off); diff --git a/boot/bootutil/src/tlv.c b/boot/bootutil/src/tlv.c index 629bc235d..a69b3d8bd 100644 --- a/boot/bootutil/src/tlv.c +++ b/boot/bootutil/src/tlv.c @@ -21,9 +21,12 @@ #include #include "bootutil/bootutil.h" +#include "bootutil/bootutil_log.h" #include "bootutil/image.h" #include "bootutil_priv.h" +BOOT_LOG_MODULE_DECLARE(mcuboot); + /* * Initialize a TLV iterator. * @@ -43,6 +46,8 @@ bootutil_tlv_iter_begin(struct image_tlv_iter *it, const struct image_header *hd uint32_t off_; struct image_tlv_info info; + BOOT_LOG_DBG("bootutil_tlv_iter_begin: type %d, prot == %d", type, (int)prot); + if (it == NULL || hdr == NULL || fap == NULL) { return -1; } @@ -108,6 +113,9 @@ bootutil_tlv_iter_next(struct image_tlv_iter *it, uint32_t *off, uint16_t *len, return -1; } + BOOT_LOG_DBG("bootutil_tlv_iter_next: searching for %d (%d is any) starting at %d ending at %d", + it->type, IMAGE_TLV_ANY, it->tlv_off, it->tlv_end); + while (it->tlv_off < it->tlv_end) { if (it->hdr->ih_protect_tlv_size > 0 && it->tlv_off == it->prot_end) { it->tlv_off += sizeof(struct image_tlv_info); @@ -115,11 +123,14 @@ bootutil_tlv_iter_next(struct image_tlv_iter *it, uint32_t *off, uint16_t *len, rc = LOAD_IMAGE_DATA(it->hdr, it->fap, it->tlv_off, &tlv, sizeof tlv); if (rc) { + BOOT_LOG_DBG("bootutil_tlv_iter_next: load failed with %d for %p %d", + rc, it->fap, it->tlv_off); return -1; } /* No more TLVs in the protected area */ if (it->prot && it->tlv_off >= it->prot_end) { + BOOT_LOG_DBG("bootutil_tlv_iter_next: protected TLV %d not found", it->type); return 1; } @@ -130,12 +141,15 @@ bootutil_tlv_iter_next(struct image_tlv_iter *it, uint32_t *off, uint16_t *len, *off = it->tlv_off + sizeof(tlv); *len = tlv.it_len; it->tlv_off += sizeof(tlv) + tlv.it_len; + BOOT_LOG_DBG("bootutil_tlv_iter_next: TLV %d found at %d (size %d)", + *type, *off, *len); return 0; } it->tlv_off += sizeof(tlv) + tlv.it_len; } + BOOT_LOG_DBG("bootutil_tlv_iter_next: TLV %d not found", it->type); return 1; } diff --git a/boot/zephyr/firmware_loader.c b/boot/zephyr/firmware_loader.c index d0f70af4a..1df848634 100644 --- a/boot/zephyr/firmware_loader.c +++ b/boot/zephyr/firmware_loader.c @@ -40,6 +40,8 @@ boot_image_validate(const struct flash_area *fa_p, static uint8_t tmpbuf[BOOT_TMPBUF_SZ]; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_image_validate: encrypted == %d", (int)IS_ENCRYPTED(hdr)); + /* NOTE: The first argument to boot_image_validate, for enc_state pointer, * is allowed to be NULL only because the single image loader compiles * with BOOT_IMAGE_NUMBER == 1, which excludes the code that uses @@ -71,6 +73,8 @@ boot_image_validate_once(const struct flash_area *fa_p, int rc; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_image_validate_once: flash area %p", fap_p); + memset(&state, 0, sizeof(struct boot_swap_state)); rc = boot_read_swap_state(fa_p, &state); if (rc != 0) @@ -108,6 +112,8 @@ static fih_ret validate_image_slot(int slot, struct boot_rsp *rsp) int rc = -1; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("validate_image_slot: slot %d", slot); + rc = flash_area_open(slot, &_fa_p); assert(rc == 0); @@ -156,6 +162,8 @@ boot_go(struct boot_rsp *rsp) bool boot_firmware_loader = false; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_go: firmware loader"); + #ifdef CONFIG_BOOT_FIRMWARE_LOADER_ENTRANCE_GPIO if (io_detect_pin() && !io_boot_skip_serial_recovery()) { diff --git a/boot/zephyr/main.c b/boot/zephyr/main.c index 758a90840..d993c3483 100644 --- a/boot/zephyr/main.c +++ b/boot/zephyr/main.c @@ -463,6 +463,7 @@ int main(void) mcuboot_status_change(MCUBOOT_STATUS_STARTUP); #ifdef CONFIG_BOOT_SERIAL_ENTRANCE_GPIO + BOOT_LOG_DBG("Checking GPIO for serial recovery"); if (io_detect_pin() && !io_boot_skip_serial_recovery()) { boot_serial_enter(); @@ -470,13 +471,17 @@ int main(void) #endif #ifdef CONFIG_BOOT_SERIAL_PIN_RESET + BOOT_LOG_DBG("Checking RESET pin for serial recovery"); if (io_detect_pin_reset()) { boot_serial_enter(); } #endif #if defined(CONFIG_BOOT_USB_DFU_GPIO) + BOOT_LOG_DBG("Checking GPIO for USB DFU request"); if (io_detect_pin()) { + BOOT_LOG_DBG("Entering USB DFU"); + usb_dfu_requested = true; #ifdef CONFIG_MCUBOOT_INDICATION_LED @@ -498,6 +503,7 @@ int main(void) BOOT_LOG_INF("Waiting for USB DFU"); #if defined(CONFIG_BOOT_USB_DFU_WAIT) + BOOT_LOG_DBG("Waiting for USB DFU for %dms", CONFIG_BOOT_USB_DFU_WAIT_DELAY_MS); mcuboot_status_change(MCUBOOT_STATUS_USB_DFU_WAITING); wait_for_usb_dfu(K_MSEC(CONFIG_BOOT_USB_DFU_WAIT_DELAY_MS)); BOOT_LOG_INF("USB DFU wait time elapsed"); @@ -529,12 +535,14 @@ int main(void) if (FIH_EQ(fih_rc, FIH_BOOT_HOOK_REGULAR)) { FIH_CALL(boot_go, fih_rc, &rsp); } + BOOT_LOG_DBG("Left boot_go with success == %d", FIH_EQ(fih_rc, FIH_SUCCESS) ? 1 : 0); #ifdef CONFIG_BOOT_SERIAL_BOOT_MODE if (io_detect_boot_mode()) { /* Boot mode to stay in bootloader, clear status and enter serial * recovery mode */ + BOOT_LOG_DBG("Staying in serial recovery"); boot_serial_enter(); } #endif diff --git a/boot/zephyr/single_loader.c b/boot/zephyr/single_loader.c index 28e9cdf15..31c4a8bf7 100644 --- a/boot/zephyr/single_loader.c +++ b/boot/zephyr/single_loader.c @@ -44,6 +44,8 @@ boot_image_validate(const struct flash_area *fa_p, static uint8_t tmpbuf[BOOT_TMPBUF_SZ]; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_image_validate: encrypted == %d", (int)IS_ENCRYPTED(hdr)); + /* NOTE: The first argument to boot_image_validate, for enc_state pointer, * is allowed to be NULL only because the single image loader compiles * with BOOT_IMAGE_NUMBER == 1, which excludes the code that uses @@ -75,6 +77,8 @@ boot_image_validate_once(const struct flash_area *fa_p, int rc; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_image_validate_once: flash area %p", fap_p); + memset(&state, 0, sizeof(struct boot_swap_state)); rc = boot_read_swap_state(fa_p, &state); if (rc != 0) @@ -112,6 +116,8 @@ boot_go(struct boot_rsp *rsp) int rc = -1; FIH_DECLARE(fih_rc, FIH_FAILURE); + BOOT_LOG_DBG("boot_go: Single loader"); + rc = flash_area_open(FLASH_AREA_IMAGE_PRIMARY(0), &_fa_p); assert(rc == 0);