zephyr: Improve logging

Improve logging to make it easier to track image validation
failures in development.

Signed-off-by: Dominik Ermel <dominik.ermel@nordicsemi.no>

Author: de-nordic

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()) {

boot/zephyr/main.c

@@ -463,20 +463,25 @@ 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();
     }
 #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
@@ -488,6 +493,12 @@ int main(void)
 #elif defined(CONFIG_BOOT_USB_DFU_WAIT)
     usb_dfu_requested = true;
 #endif
+    BOOT_LOG_DBG("Waiting for USB DFU for %dms", CONFIG_BOOT_USB_DFU_WAIT_DELAY_MS);
+    rc = usb_enable(NULL);
+    if (rc) {
+        BOOT_LOG_ERR("Cannot enable USB");
+    } else {
+        BOOT_LOG_INF("Waiting for USB DFU");
 
 #if defined(CONFIG_BOOT_USB_DFU_GPIO) || defined(CONFIG_BOOT_USB_DFU_WAIT)
     if (usb_dfu_requested) {
@@ -529,12 +540,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

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);