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]

Hi,

I changed these values in dfu_transport_mesh.py
ACK_WAIT_TIME = 2
SEND_START_DFU_WAIT_TIME = 5

also changed the nrfutil parameter -i to 1000 

Now it works approx. every 5th time I start DFU.

When it fails, it outputs:

 0> <t:     141603>, nrf_mesh_dfu.c,  390, 	New firmware!
 0> <t:     141606>, mesh.c,  783, DFU event:13
 0> <t:     141608>, mesh.c,  744, DFU update application 
 0> <t:     141611>, mesh.c,  795, DFU me 
 0> <t:     141612>, mesh.c,  796, optimal_bank_address: 573440 
 0> <t:     141615>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     141619>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 1).
 0> <t:     141623>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:     306203>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     306207>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 0).
 0> <t:     306211>, nrf_mesh_dfu.c,  561, 	SERIAL TX!
 0> <t:     471073>, nrf_mesh_dfu.c,  430, 	DFU start
 0> <t:     471075>, mesh.c,  783, DFU event:9
 0> <t:     471077>, mesh.c,  810, DFU start 
 0> <t:     471080>, nrf_mesh_dfu.c,  528, 	RADIO TX! SLOT 3, count 6, interval: exponential, handle: FFFC
 0> <t:     553710>, nrf_mesh_dfu.c,  329, Erase complete (0x8C000)
 0> <t:     553713>, nrf_mesh_dfu.c,  333, Flash idle.

and RTT:

Flushing com-port...
Opened com-port
Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, application size: 122412
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: 1378fdff040f587ed7dc59000000010003000000
target -> PC: 16a6045900000001000300000059000000010002000000
target -> PC: 03847800
PC -> target: 1378fdff040f587ed7dc59000000010003000000
target -> PC: 03847800
PC -> target: 1478fcff0000587ed7dcffffffff8b77000000000c
PC -> target: 1478fcff0000587ed7dcffffffff8b77000000000c
target -> PC: 0da2010459000000010003000000
target -> PC: 03847800
Sending firmware file
  [------------------------------------]    1%  00:30:54PC -> target: 1978fcff0100587ed7dc00f0032059620200896202008b620200
target -> PC: 03847887
PC -> target: 1978fcff0100587ed7dc00f0032059620200896202008b620200
PC -> target: 1978fcff0100587ed7dc00f0032059620200896202008b620200
PC -> target: 1978fcff0100587ed7dc00f0032059620200896202008b620200
PC -> target: 1978fcff0100587ed7dc00f0032059620200896202008b620200
target -> PC: 628200896202008b6202001978fcff0100587ed7dc00f0032059620200896202008b6202001978fcff0100587ed7dc00f0032059620200896202008b6202001978fcff0100587ed7dc00f0032059620200896202008b6202001978fcff0100587ed7dc
target -> PC: 03840084


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

I agree, the issue changed, but there still seems to be a problem.

Do you have an Idea?

EDIT: Updating the servers over the air, using this client as relay works fine now (this didn't work, when I opened this ticket)

[Hung Bui]

I'm not sure what could be wrong now. 

Is it possible to provide us your source code that we can test on the NRF52 DK and can reproduce the issue here . We need to add some debug log to see at which point it crashed. Please give us the detailed instruction how you test that firmware as well. 

Also please make sure you have increased the application version when you want to update the same firmware. 

[Gerry]

Good idea, you can download the project from here. It includes the SDKs and it's good to compile.

To reproduce the issue:

- Open the the project connectivity_client under \source\connectivity_client and compile it (using SES)

- Change the values for Comport and client_version in Version.ini under \DFU

- Connect a PCA10056 and run Prog_Client.bat under \DFU

- Run DFU_Client.bat under \DFU

Here DFU_Client.bat updates the client successful sometimes, but most of the time it ends with ERROR_INVALID_DATA (135) on a DFU data packet.

[Hung Bui]

Hi Gerry, 

I'm testing here and seeing the same problem. For some reason with your client.hex file the bootloader crashed when receiving the init packet. I tested with even bigger image but it didn't crash. 

I noticed that when doing DFU with your image, one of the init packet is transmitted twice (didn't get ack): 

Same can be seen in your log. This doesn't happens with other image. 

I increased the ACK_WAIT_TIME to 5 and SEND_START_DFU_WAIT_TIME  to 5 then it worked now. 

I guess it's something to do with the timing. We will need to improve this to avoid dependence on the image size.

But for now I would suggest to just increase those timing numbers. It won't affect the overall update time, only affect the init packets sending time at the beginning. 

[Gerry]

Hi Hung,

yes this really helped. Thanks a lot for your support. I think, this could also be interesting for others (especially the optimal_bank_address()), so feel free to make this ticket public if you want.

Regards Gerry