Problem with mesh DFU

[Gerry]

Hi,

I already asked a similar question 6 month ago (ticket) but we never got a solution to this.

Now, after 15 month of development, our mesh-applications are almost finished and we really need DFU.

To be able to upload code, I open a private ticket here.

Our mesh-client is now running on Mesh SDK 3.1.0 and SDK 15.2. This client is supposed to get DFU-updates via UART0.

Our script for programming the client:

@echo off
for /f "tokens=1,2 delims==" %%a in (version.ini) do (
	if %%a==client_version set client_version=%%b
)
echo __________Connectivity Client Version: %client_version%__________
@echo:
echo __________Device page erstellen____________________
cd pc-nrfutil-mesh_dfu
cd dfu
REM bootloader_config_default.json erstellen (bestehende Version der Firmware)
set /a "prior_version=%client_version%-1"
 (
   echo {
   echo     "bootloader_config": {
   echo        "bootloader_id": 1,
   echo        "bootloader_version": 1,
   echo        "company_id": 89,
   echo        "application_id": 1,
   echo        "application_version": %prior_version%
   echo    }
   echo }
 ) > bootloader_config_default.json
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o ../client.hex
cd ..
@echo:
echo __________Programmieren____________________________
nrfjprog --recover -f NRF52
REM use --verify to verify programming with --program
nrfjprog --eraseall
nrfjprog --program ../../Mesh_SDK/bin/softdevice/s140_nrf52_6.0.0_softdevice.hex --chiperase --verify
nrfjprog --program bootloader/mesh_bootloader_serial_gccarmemb_nrf52840_xxAA.hex --verify
nrfjprog --program ../../Source/connectivity_client/build/connectivity_client_Release/connectivity_client.hex --verify
nrfjprog --program client.hex --verify
nrfjprog --memrd 0x10001014
nrfjprog --readcode my_flash_dump.txt
nrfjprog --reset
@echo:
cd ..

pause

Our script for updating the client: 

@echo off
for /f "tokens=1,2 delims==" %%a in (version.ini) do (
if %%a==client_version set client_version=%%b
if %%a==Comport set Comport=%%b
)
@echo off
echo __________Connectivity Client Version: %client_version%__________

cd pc-nrfutil-mesh_dfu
@echo:
echo __________DFU file erstellen_______________________
nrfutil dfu genpkg --application ..\..\Source\connectivity_client\build\connectivity_client_release\connectivity_client.hex --company-id 0x00000059 --application-id 1 --application-version %client_version% --sd-req 0x00A9 --mesh client.zip
@echo:
echo __________DFU Update an COM%Comport%_______________________
nrfutil --verbose dfu serial -pkg client.zip -p COM%Comport% -b 115200 -i 300 -fc --mesh
@echo:
cd ..
pause

The output when updating:

__________DFU Update an COM6_______________________
Upgrading target on COM6 with DFU package C:\Users\se\Desktop\Oblamatik\Connectivityair_15.2_3.10\DFU\pc-nrfutil-mesh_dfu\client.zip. Flow control is enabled.
Flushing com-port...
Opened com-port
Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, application size: 122220
Sending DFU start packet, afterwards we wait for the flash on target to be initialized before continuing.
PC -> target: 0502aabbccdd
target -> PC: 0582aabbccdd
Got echo response
Sending DFU init packet
PC -> target: 1378fdff040f65c3e7d559000000010002000000
target -> PC: 16a6045900000001000200000059000000010001000000
target -> PC: 03847800
PC -> target: 1378fdff040f65c3e7d559000000010002000000
target -> PC: 03847800
PC -> target: 1478fcff000065c3e7d5ffffffff5b77000000000c
target -> PC: 0da2010459000000010002000000
target -> PC: 03847800
Sending firmware file
  [------------------------------------]    1%  00:11:52PC -> target: 1978fcff010065c3e7d500f0032059620200896202008b620200
PC -> target: 1978fcff010065c3e7d500f0032059620200896202008b620200
target -> PC: 03847887
target -> PC: 03840082
PC -> target: 1978fcff010065c3e7d500f0032059620200896202008b620200
PC -> target: 1978fcff010065c3e7d500f0032059620200896202008b620200
PC -> target: 1978fcff010065c3e7d500f0032059620200896202008b620200


Failed to upgrade target. Error is: Device returned status code ERROR_INVALID_DATA (135) on a DFU data packet.

and sometimes it outputs:

 Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, application size: 122220
Sending DFU start packet, afterwards we wait for the flash on target to be initialized before continuing.
PC -> target: 0502aabbccdd
target -> PC: 0582aabbccdd
Got echo response
Sending DFU init packet
PC -> target: 1378fdff040fed78a76359000000010002000000
target -> PC: 16a6045900000001000200000059000000010001000000
target -> PC: 03847800
PC -> target: 1378fdff040fed78a76359000000010002000000
target -> PC: 03847800
PC -> target: 1478fcff0000ed78a763ffffffff5b77000000000c
PC -> target: 1478fcff0000ed78a763ffffffff5b77000000000c
PC -> target: 1478fcff0000ed78a763ffffffff5b77000000000c
PC -> target: 1478fcff0000ed78a763ffffffff5b77000000000c
PC -> target: 1478fcff0000ed78a763ffffffff5b77000000000c


Failed to upgrade target. Error is: Crashed on start packet

RTT outputs the following during the DFU-update:

 0> <t:    1523878>, nrf_mesh_dfu.c,  390, 	New firmware!
 0> <t:    1523881>, mesh.c,  744, DFU update application 
 0> <t:    1523883>, mesh.c,  778, DFU me 
 0> <t:    1523885>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:    1523889>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 5).
 0> <t:    1523893>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:    1590164>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:    1590168>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 0).
 0> <t:    1590172>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:    1656741>, nrf_mesh_dfu.c,  430, 	DFU start
 0> <t:    1656743>, mesh.c,  792, DFU start 
 0> <t:    1656746>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 1, count 6, interval: exponential, handle: FFFC
 0> <t:    1739614>, nrf_mesh_dfu.c,  329, Erase complete (0x44000)
 0> <t:    1739617>, nrf_mesh_dfu.c,  333, Flash idle.

I already tried making changes like described here, but this didn't help.

What could be the problem here?

Best regards

Gerry

[Gerry]

Ok, I programmed your hexfile (DFU-example) and then run my DFU script for the client.

This works well, the RTT-output looks as follows:

 0> <t:          1>, main.c,  223, ----- Bluetooth Mesh DFU Example -----
 0> <t:          3>, main.c,  232, rom_base   26201
 0> <t:          5>, main.c,  233, rom_end    42BE8
 0> <t:          7>, main.c,  234, rom_length 1C9E7
 0> <t:          9>, main.c,  236, bank_addr   43000
 0> <t:      12921>, serial_handler_prov.c,  267, Generating encryption keypair...
 0> <t:      17768>, main.c,  241, optimal bank addr   8C000
 0> <t:      17770>, main.c,  242, Initialization complete!
 0> <t:      22540>, main.c,  263, Enabling serial interface...
 0> <t:      22543>, mesh_app_utils.c,   65, Device UUID (raw): D617B16F3FEC8643A3C33E33908A3BED
 0> <t:      22546>, mesh_app_utils.c,   70, Device UUID : 6FB117D6-EC3F-4386-A3C3-3E33908A3BED
 0> <t:      22554>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFE
 0> <t:      22559>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:      22565>, main.c,  271, DFU example started!
 0> <t:    2101608>, serial_handler_openmesh.c,   51, 	DFU Data!
 0> <t:    2101611>, nrf_mesh_dfu.c,  390, 	New firmware!
 0> <t:    2101614>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:    2101618>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 7).
 0> <t:    2101622>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:    2200674>, serial_handler_openmesh.c,   51, 	DFU Data!
 0> <t:    2200677>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:    2200681>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 30).
 0> <t:    2200684>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:    2299386>, serial_handler_openmesh.c,   51, 	DFU Data!
 0> <t:    2299389>, nrf_mesh_dfu.c,  430, 	DFU start
 0> <t:    2299392>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 3, count 6, interval: exponential, handle: FFFC
 0> <t:    2401288>, serial_handler_openmesh.c,   51, 	DFU Data!
 0> <t:    2401291>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 4, count 3, interval: exponential, handle: FFFC
 0> <t:    2424970>, serial_handler_openmesh.c,   51, 	DFU Data!
 0> <t:    2424973>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 5, count 3, interval: exponential, handle: FFFC
...

my client-application uses the same UART-pins like the DFU-example with UART0

Seems like the problem only occurs, when my client is running at DFU start.

[Hung Bui]

Have you implemented the fix in your original DFU application ? 
Could you printout the optimal_bank_addr calculation when it's calculated inside mesh_evt_handler() ? 

Getting RTT logging inside dfu_evt_handler() also important to know what wrong in your case ("Abort event. Reason:")

[Gerry]

Since this now seems to be a problem with my client project, I uploaded my project here.

It includes the SDKs and should be good to compile. The client project can be found under source/connectivity_client.

The scripts I use for programming and DFU are in the folder DFU (Prog_Client.bat and DFU_Client.bat)

It seems to me like a timing issue, since DFU worked one time now. (1 time out of maybe 20-30 times I tried)

[Gerry]

Yes, the fix is implemented. I now also made an extended Log-output to see all events inside mesh_evt_handler() 

static void mesh_evt_handler(const nrf_mesh_evt_t* p_evt)
{
    __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU event:%u\n",p_evt->type);
    switch (p_evt->type)
    {
        case NRF_MESH_EVT_TX_COMPLETE:
            sending_message = false;
            break;
        case NRF_MESH_EVT_FLASH_STABLE:
            break;
        case NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED:
        case NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED_NO_AUTH:
            if (fw_updated_event_is_for_me(&p_evt->params.dfu))
            {
                __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU me \n");
                __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "optimal_bank_address: %u \n", optimal_bank_address());
                ERROR_CHECK(nrf_mesh_dfu_request(p_evt->params.dfu.fw_outdated.transfer.dfu_type,
                                                 &p_evt->params.dfu.fw_outdated.transfer.id,
                                                 optimal_bank_address()));
            }
            else
            {
                __LOG(LOG_SRC_APP, LOG_LEVEL_INFO, "DFU relay \n");
                ERROR_CHECK(nrf_mesh_dfu_relay(p_evt->params.dfu.fw_outdated.transfer.dfu_type,
                                               &p_evt->params.dfu.fw_outdated.transfer.id));
            }
            break;

The RTT-output is:

 0> <t:     215501>, nrf_mesh_dfu.c,  390, 	New firmware!
 0> <t:     215504>, mesh.c,  783, DFU event:13
 0> <t:     215506>, mesh.c,  744, DFU update application 
 0> <t:     215508>, mesh.c,  795, DFU me 
 0> <t:     215510>, mesh.c,  796, optimal_bank_address: 573440 
 0> <t:     215513>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     215517>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 1).
 0> <t:     215521>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:     314224>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     314228>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 0).
 0> <t:     314231>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:     413564>, nrf_mesh_dfu.c,  430, 	DFU start
 0> <t:     413567>, mesh.c,  783, DFU event:9
 0> <t:     413569>, mesh.c,  810, DFU start 
 0> <t:     413572>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 5, count 6, interval: exponential, handle: FFFC
 0> <t:     496202>, nrf_mesh_dfu.c,  329, Erase complete (0x8C000)
 0> <t:     496205>, nrf_mesh_dfu.c,  333, Flash idle.

So optimal_bank_addr is o573440 and the last event is: 9/start

[Hung Bui]

Hi Gerry, 

Seems to be a timing issue to me as well, but was the nrftutil still report ERROR_INVALID_DATA (135)  ? or it's "crashed on start packet" ? 

It doesn't seems to me it's the same issue like before, the bank size issue is solved. 

You can try to follow this https://devzone.nordicsemi.com/f/nordic-q-a/43335/mesh-dfu-nrf52840-with-other-binary-file to check if that helps ?