I have been at this for a few days now so I need to ask for help.
Configuration:
-
SDK13
-
SD 4.0.2
-
NRF52832, custom board
-
Linux (Mint) dev system
Actions taken:
-
Using the blog post at devzone.nordicsemi.com/.../
-
Erase the flash completely, flash Soft Device and application, successful, prints "Hello" over debug no problem. Also make a sound on our buzzer in case debug output is not working.
-
Followed blog to build slightly amended BL with new public/private key and merged with same SD hex to build bl_sd.hex.
-
erased flash completely
-
Programmed via JLink drag-and-drop device
-
BL successfully boots and enters DFU mode as expected:
###RTT Client: Connection lost. Going to reconnect. ###RTT Client: Connecting to J-Link RTT Server via localhost:19021 Connected. SEGGER J-Link V6.18 - Real time terminal output J-Link OB-SAM3U128-V2-NordicSemi compiled Jul 24 2017 17:30:12 V1.0, SN=682396899 Process: JLinkExe :INFO:Inside main :DEBUG:In nrf_bootloader_init :DEBUG:In real nrf_dfu_init :DEBUG:running nrf_dfu_settings_init :DEBUG:Enter nrf_dfu_continue :DEBUG:Valid App :DEBUG:In weak nrf_dfu_enter_check :DEBUG:weak nrf_dfu_enter_check: return false :DEBUG:Enter nrf_dfu_app_is_valid :DEBUG:Return false in CRC :DEBUG:In nrf_dfu_transports_init :DEBUG:num transports: 1 :DEBUG:vector table: 0x00075000 :DEBUG:vector table: 0x00075000 :DEBUG:Error code - sd_softdevice_vector_table_base_set: 0x00000000 :DEBUG:Before SOFTDEVICE_HANDLER_APPSH_INIT :DEBUG:After SOFTDEVICE_HANDLER_APPSH_INIT :INFO:Error code - sd_ble_cfg_set: 0x00000000 :DEBUG:Enabling softdevice. :DEBUG:RAM start at 0x20002060. :DEBUG:Softdevice enabled :DEBUG:After nrf_dfu_transports_init :DEBUG:------- nrf_dfu_flash_init------- :DEBUG:Waiting for events
-
Created Package for NRF Toolbox using same application hex:
nrfutil pkg generate --hw-version 52 --application-version 1 --application ~/workspace_nordic/wtl_viking_nrf52_small/wtl-generic-armgcc/_build/wtl_viking_nrf52_release.hex --sd-req 0x98 --key-file /home/fwdev/workspace_nordic/wtl_viking_nrf52_ivan/wtl-generic-armgcc/private.key app_dfu_package.zip
-
Placed package on Android phone
-
Using toolbox App, send package to device. Note: Tried All and App only, only an App is present so the same result occurred.
:DEBUG:Received select object :INFO:Valid Command: NRF_DFU_OBJECT_OP_SELECT :DEBUG:Sending Object Info: [0x60, 0x06, 0x01 max: 0:x00000100 0:x00000000, CRC:0x00000000] :DEBUG:Set receipt notif :DEBUG:Sending Response: [0x2, 0x1] :DEBUG:Received create object :INFO:Before OP create command :INFO:Valid Command Create :DEBUG:Sending Response: [0x1, 0x1] :INFO:Before OP write command :INFO:Before OP write command :INFO:Before OP write command :INFO:Before OP write command :INFO:Before OP write command :INFO:Before OP write command :INFO:Before OP write command :DEBUG:Received calculate CRC :INFO:Valid Command CRC :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00000087, CRC:0x81349d7e] :DEBUG:Received execute object :INFO:Before OP execute command :INFO:Valid command execute :INFO: :INFO:PB: Init packet data len: 58 :INFO:Handling signed command :INFO:Req version: 1, Expected: 1 :INFO:Calculating init packet hash :INFO:Verify signature :INFO:Image verified :INFO:Running hash check :DEBUG:Enter nrf_dfu_find_cache :DEBUG:Bank content :DEBUG:Bank type: 0 :DEBUG:Bank 0 code: 0x01: Size: 32336 :DEBUG:Bank 1 code: 0x00: Size: 0 :DEBUG:free_size before bank select: 339968 :DEBUG:free_size: 307200, size_req: 32336 :DEBUG:Using second bank :INFO:Write address set to 0x00027000 :INFO:DFU prevalidate SUCCESSFUL! :INFO:Prevalidate OK. :INFO:Saving init command... :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Writing settings... :DEBUG:Received select object :INFO:Valid Data Read info :DEBUG:Sending Object Info: [0x60, 0x06, 0x01 max: 0:x00001000 0:x00000000, CRC:0x00000000] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x00027000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00000000, CRC: 0x00000000 :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x00027000 :INFO:Storing 256 B at: 0x00027100 :INFO:Storing 256 B at: 0x00027200 :INFO:Storing 256 B at: 0x00027300 :INFO:Storing 256 B at: 0x00027400 :INFO:Storing 256 B at: 0x00027500 :INFO:Storing 256 B at: 0x00027600 :INFO:Storing 256 B at: 0x00027700 :INFO:Storing 256 B at: 0x00027800 :INFO:Storing 256 B at: 0x00027900 :INFO:Storing 256 B at: 0x00027a00 :INFO:Storing 256 B at: 0x00027b00 :INFO:Storing 256 B at: 0x00027c00 :INFO:Storing 256 B at: 0x00027d00 :INFO:Storing 256 B at: 0x00027e00 :INFO:Storing 256 B at: 0x00027f00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00001000, CRC:0xd6e14dc3] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x00028000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00001000, CRC: 0xd6e14dc3 :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x00028000 :INFO:Storing 256 B at: 0x00028100 :INFO:Storing 256 B at: 0x00028200 :INFO:Storing 256 B at: 0x00028300 :INFO:Storing 256 B at: 0x00028400 :INFO:Storing 256 B at: 0x00028500 :INFO:Storing 256 B at: 0x00028600 :INFO:Storing 256 B at: 0x00028700 :INFO:Storing 256 B at: 0x00028800 :INFO:Storing 256 B at: 0x00028900 :INFO:Storing 256 B at: 0x00028a00 :INFO:Storing 256 B at: 0x00028b00 :INFO:Storing 256 B at: 0x00028c00 :INFO:Storing 256 B at: 0x00028d00 :INFO:Storing 256 B at: 0x00028e00 :INFO:Storing 256 B at: 0x00028f00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00002000, CRC:0x12a6dd01] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x00029000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00002000, CRC: 0x12a6dd01 :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x00029000 :INFO:Storing 256 B at: 0x00029100 :INFO:Storing 256 B at: 0x00029200 :INFO:Storing 256 B at: 0x00029300 :INFO:Storing 256 B at: 0x00029400 :INFO:Storing 256 B at: 0x00029500 :INFO:Storing 256 B at: 0x00029600 :INFO:Storing 256 B at: 0x00029700 :INFO:Storing 256 B at: 0x00029800 :INFO:Storing 256 B at: 0x00029900 :INFO:Storing 256 B at: 0x00029a00 :INFO:Storing 256 B at: 0x00029b00 :INFO:Storing 256 B at: 0x00029c00 :INFO:Storing 256 B at: 0x00029d00 :INFO:Storing 256 B at: 0x00029e00 :INFO:Storing 256 B at: 0x00029f00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00003000, CRC:0x1e1a6feb] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x0002a000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00003000, CRC: 0x1e1a6feb :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x0002a000 :INFO:Storing 256 B at: 0x0002a100 :INFO:Storing 256 B at: 0x0002a200 :INFO:Storing 256 B at: 0x0002a300 :INFO:Storing 256 B at: 0x0002a400 :INFO:Storing 256 B at: 0x0002a500 :INFO:Storing 256 B at: 0x0002a600 :INFO:Storing 256 B at: 0x0002a700 :INFO:Storing 256 B at: 0x0002a800 :INFO:Storing 256 B at: 0x0002a900 :INFO:Storing 256 B at: 0x0002aa00 :INFO:Storing 256 B at: 0x0002ab00 :INFO:Storing 256 B at: 0x0002ac00 :INFO:Storing 256 B at: 0x0002ad00 :INFO:Storing 256 B at: 0x0002ae00 :INFO:Storing 256 B at: 0x0002af00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00004000, CRC:0xe2f7810f] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x0002b000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00004000, CRC: 0xe2f7810f :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x0002b000 :INFO:Storing 256 B at: 0x0002b100 :INFO:Storing 256 B at: 0x0002b200 :INFO:Storing 256 B at: 0x0002b300 :INFO:Storing 256 B at: 0x0002b400 :INFO:Storing 256 B at: 0x0002b500 :INFO:Storing 256 B at: 0x0002b600 :INFO:Storing 256 B at: 0x0002b700 :INFO:Storing 256 B at: 0x0002b800 :INFO:Storing 256 B at: 0x0002b900 :INFO:Storing 256 B at: 0x0002ba00 :INFO:Storing 256 B at: 0x0002bb00 :INFO:Storing 256 B at: 0x0002bc00 :INFO:Storing 256 B at: 0x0002bd00 :INFO:Storing 256 B at: 0x0002be00 :INFO:Storing 256 B at: 0x0002bf00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00005000, CRC:0x421a36a2] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x0002c000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00005000, CRC: 0x421a36a2 :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x0002c000 :INFO:Storing 256 B at: 0x0002c100 :INFO:Storing 256 B at: 0x0002c200 :INFO:Storing 256 B at: 0x0002c300 :INFO:Storing 256 B at: 0x0002c400 :INFO:Storing 256 B at: 0x0002c500 :INFO:Storing 256 B at: 0x0002c600 :INFO:Storing 256 B at: 0x0002c700 :INFO:Storing 256 B at: 0x0002c800 :INFO:Storing 256 B at: 0x0002c900 :INFO:Storing 256 B at: 0x0002ca00 :INFO:Storing 256 B at: 0x0002cb00 :INFO:Storing 256 B at: 0x0002cc00 :INFO:Storing 256 B at: 0x0002cd00 :INFO:Storing 256 B at: 0x0002ce00 :INFO:Storing 256 B at: 0x0002cf00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00006000, CRC:0x34776a0b] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x0002d000, num: 1 :INFO:Creating object with size: 4096. Offset: 0x00006000, CRC: 0x34776a0b :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x0002d000 :INFO:Storing 256 B at: 0x0002d100 :INFO:Storing 256 B at: 0x0002d200 :INFO:Storing 256 B at: 0x0002d300 :INFO:Storing 256 B at: 0x0002d400 :INFO:Storing 256 B at: 0x0002d500 :INFO:Storing 256 B at: 0x0002d600 :INFO:Storing 256 B at: 0x0002d700 :INFO:Storing 256 B at: 0x0002d800 :INFO:Storing 256 B at: 0x0002d900 :INFO:Storing 256 B at: 0x0002da00 :INFO:Storing 256 B at: 0x0002db00 :INFO:Storing 256 B at: 0x0002dc00 :INFO:Storing 256 B at: 0x0002dd00 :INFO:Storing 256 B at: 0x0002de00 :INFO:Storing 256 B at: 0x0002df00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00007000, CRC:0x0412220c] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :DEBUG:Received create object :INFO:Before OP create :INFO:Valid Data Create :DEBUG:Erasing: 0x0002e000, num: 1 :INFO:Creating object with size: 3664. Offset: 0x00007000, CRC: 0x0412220c :DEBUG:Sending Response: [0x1, 0x1] :INFO:Storing 256 B at: 0x0002e000 :INFO:Storing 256 B at: 0x0002e100 :INFO:Storing 256 B at: 0x0002e200 :INFO:Storing 256 B at: 0x0002e300 :INFO:Storing 256 B at: 0x0002e400 :INFO:Storing 256 B at: 0x0002e500 :INFO:Storing 256 B at: 0x0002e600 :INFO:Storing 256 B at: 0x0002e700 :INFO:Storing 256 B at: 0x0002e800 :INFO:Storing 256 B at: 0x0002e900 :INFO:Storing 256 B at: 0x0002ea00 :INFO:Storing 256 B at: 0x0002eb00 :INFO:Storing 256 B at: 0x0002ec00 :INFO:Storing 256 B at: 0x0002ed00 :INFO:Storing 80 B at: 0x0002ee00 :DEBUG:Received calculate CRC :INFO:Before OP crc :DEBUG:Sending CRC: [0x60, 0x03, 0x01, 0:x00007e50, CRC:0x3a39947f] :DEBUG:Received execute object :INFO:Before OP execute :INFO:Valid Data Execute :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :INFO:Waiting for 0 pending flash operations before doing postvalidate. :INFO:Doing postvalidate :INFO:Current bank is bank 1 :INFO:Running SD version check ============== :INFO:Successfully ran the postvalidation check! :INFO:Invalidating old application in bank 0. :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Waiting for other flash operation to finish. :DEBUG:Waiting for other flash operation to finish. :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Sending Response: [0x4, 0x1] :INFO:Inside main :DEBUG:In nrf_bootloader_init :DEBUG:In real nrf_dfu_init :DEBUG:running nrf_dfu_settings_init :DEBUG:Enter nrf_dfu_continue :DEBUG:Valid App :DEBUG:Enter nrf_dfu_app_continue :DEBUG:Erasing: 0x0001f000, num: 1 :DEBUG:Erasing: 0x00027000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00020000, num: 1 :DEBUG:Erasing: 0x00028000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00021000, num: 1 :DEBUG:Erasing: 0x00029000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00022000, num: 1 :DEBUG:Erasing: 0x0002a000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00023000, num: 1 :DEBUG:Erasing: 0x0002b000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00024000, num: 1 :DEBUG:Erasing: 0x0002c000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00025000, num: 1 :DEBUG:Erasing: 0x0002d000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Erasing: 0x00026000, num: 1 :DEBUG:Erasing: 0x0002e000, num: 1 :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:Setting app as valid :DEBUG:Erasing old settings at: 0x0007f000 :DEBUG:Erasing: 0x0007f000, num: 1 :DEBUG:Writing 0x00000057 words :DEBUG:Writing settings... :DEBUG:In weak nrf_dfu_enter_check :DEBUG:weak nrf_dfu_enter_check: return false :DEBUG:Enter nrf_dfu_app_is_valid :DEBUG:Return true. App was valid :DEBUG:Enter nrf_dfu_app_is_valid :DEBUG:Return true. App was valid :DEBUG:Jumping to: 0x0001f000
Running nrf_bootloader_app_start with address: 0x0001f000
Disabling interrupts
Setting SD vector table base: 0x0001f000
-
App does not run after Apparently successful DFU despite the fact that it says App is Valid (twice!) and enters nrf_bootloader_app_start().
-
App does not run after reset
:INFO:Inside main :DEBUG:In nrf_bootloader_init :DEBUG:In real nrf_dfu_init :DEBUG:running nrf_dfu_settings_init :DEBUG:Enter nrf_dfu_continue :DEBUG:Valid App :DEBUG:In weak nrf_dfu_enter_check :DEBUG:weak nrf_dfu_enter_check: return false :DEBUG:Enter nrf_dfu_app_is_valid :DEBUG:Return true. App was valid :DEBUG:Enter nrf_dfu_app_is_valid :DEBUG:Return true. App was valid :DEBUG:Jumping to: 0x0001f000
Running nrf_bootloader_app_start with address: 0x0001f000
Disabling interrupts
Setting SD vector table base: 0x0001f000
- Flashing app directly using nrfjproj produces the same results
- Building and flashing the App at 0x28000 doesn't work, even if I erase the page at 0x1F000
- I note that the DFU update programs all the settings and:
nrfjprog -f nrf52 --memrd 0x7F020
reads: 0x0007F020: 00000001
As expected.
Ironically, I don;t really require the DFU, it would be nice to recover 'Bricked' devices and maybe program individual units during development but the real requirement is to download and install an updated App using the running App.
I implemented the download and flash no problem and tried to use
nrf_bootloader_app_start(0x70000);
To simply execute the Application, to no avail. It hangs in exactly the same way.
Note: The application WORKS when flashed at 0x1F000 into a newly emptied flash with just the SD programmed (before or afterward).
The Bootloader I built runs correctly and is located correctly so I would like to know if any thoughts come to mind for anyone as to why the application does not actually run.
