Missing logs when NRF_LOG_DEBUG call is inside function

Hi,

However, when I place this call inside this particular method, the logs do not appear. Is there some setting I need to tweak?

Is this function located in the same scope/source file as the preceding NRF_LOG_* call? If not, maybe logging has not been enabled in the other source file?

Hi,

I am putting this NRF_LOG_DEBUG() call in the function app_activate() in the bootloader just before calling image_copy(), while the log I'm not seeing is placed inside image_copy(). Both methods are in the same source file components/libraries/bootloader/nrf_bootloader_fw_activation.c.

Hi,

Thanks for the clarification. image_copy() is one of the final steps of DFU so the bootloader is probably jumping to the application before the debugger has had time to fetch the log message. You can adjust the NRF_BL_RESET_DELAY_MS setting in your sdk_config.h to give the debugger more time to read the RTT buffer.

Hi Vidar,

That seemed to help. However, the bootloader logs have me confused. I have pasted here the logs during OTA DFU after BLE transport of the new app to Bank 1 is finished. The logs end when the new app is started. Here, I should see my logs "Enter image_copy:..." as many times as it is needed to copy the new app from bank 1 to bank 0. However, the only time that it is called it shows that no copy is needed. Am I misunderstanding the process? I would expect it to call image_copy a few times to copy the app from bank 1 to bank 0.

<debug> nrf_dfu_req_handler: All flash operations have completed. DFU completed.
<debug> app: Shutting down transports (found: 1)
<debug> nrf_dfu_ble: Shutting down BLE transport.
<debug> nrf_dfu_ble: Disconnecting.
<debug> nrf_dfu_ble: BLE transport shut down.
<debug> app: Resetting bootloader.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> app: Inside main
<debug> app: In nrf_bootloader_init
<debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
<debug> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<debug> app: Valid App
<debug> app: Enter nrf_dfu_app_continue
<debug> app: Enter image_copy: 0x27000 to 0x27000
<debug> app: No copy needed
<debug> app: Setting app as valid
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FF000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FF000, len=1 pages), queue usage: 0
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FF000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FF000, src=0x2000A38C, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FF000, pending 0
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FE000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FE000, len=1 pages), queue usage: 1
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FE000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FE000, src=0x2000A70C, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FE000, pending 0
<debug> app: Resetting bootloader.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> app: Inside main
<debug> app: In nrf_bootloader_init
<debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
<debug> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<info> app: No firmware to activ<info> app: Inside main
<debug> app: In nrf_bootloader_init
<debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
<debug> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<info> app: No firmware to activate.
<debug> app: App is valid
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Running nrf_bootloader_app_start with address: 0x00001000
<debug> app: Disabling interrupts. NVIC->ICER[0]: 0x0

Hi,

The log(*) seem to indicate that this was Single-bank update. Are you sure the image was loaded to bank 1 and not written directly to bank 0? The bootloader will perform it as a single bank update if there is no active app in bank0 or if the app image is too big to fit in the bank1 slot.

(*)

<debug> app: Enter image_copy: 0x27000 to 0x27000
 <debug> app: No copy needed