ERROR_INVALID_DATA at mesh DFU

[Gerry]

Hi 

I try to implement DFU to our application using Mesh_SDK 2.0.1 and 
nRF5_SDK_15.0.0 

When I use the DFU-Example everything works fine. I then implemented the 
DFU-code from the example to our client application to be able to update it 
(without provisioning of servers at the moment). 

To program the device I use: 

cd pc-nrfutil-mesh_dfu 
nrfutil dfu genpkg --application 
../../Source/connectivity_client/build/connectivity_client_Debug/connectivit 
y_client.hex --company-id 0x00000059 --application-id 1 
--application-version 1 --sd-req 0x00A9 --mesh client.zip 
cd dfu 
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o 
../client.hex 
cd .. 
nrfjprog --eraseall 
nrfjprog --program 
../../Mesh_SDK/bin/softdevice/s140_nrf52_6.0.0_softdevice.hex --chiperase 
nrfjprog --program 
bootloader/mesh_bootloader_serial_gccarmemb_nrf52840_xxAA.hex 
nrfjprog --program 
../../Source/connectivity_client/build/connectivity_client_Debug/connectivit 
y_client.hex 
nrfjprog --program client.hex 
nrfjprog --reset 

For DFU I use: 

cd pc-nrfutil-mesh_dfu 
nrfutil dfu genpkg --application 
../../Source/connectivity_client/build/connectivity_client_Debug/connectivit 
y_client.hex --company-id 0x00000059 --application-id 1 
--application-version 2 --sd-req 0x00A9 --mesh client.zip 
cd dfu 
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o 
../client.hex 
cd .. 
nrfutil --verbose dfu serial -pkg client.zip -p COM19 -b 115200 -fc --mesh 

This seems to work in the beginning, but then throws an error: 

Flushing com-port... 

Opened com-port 

Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, 
application size: 131356 

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: 1378fdff040fc9d339f459000000010005000000 
target -> PC: 16a6045900000001000500000059000000010001000000 
target -> PC: 03847800 
PC -> target: 1378fdff040fc9d339f459000000010005000000 
target -> PC: 03847800 
PC -> target: 1478fcff0000c9d339f4ffffffff4780000000000c 
target -> PC: 03847800 
Sending firmware file 

[------------------------------------] 1% 00:11:50PC -> target: 
1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847883 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 


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


What could be the problem here? 

Kind regards 



Gerry 

[tesc]

Hi,

Although probably not related to the error, I see that the application version actually sent is version 5 (59000000010005000000), while the command suggest it should be version 2 (nrfutil dfu genpkg (...)
--application-version 2 (...).)

I see from the log that there are actually two errors. The latest one is ERROR_INVALID_DATA (135), in hexadecimal 0x87, and it happens four times:

target -> PC: 03847887 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 
PC -> target: 1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847887 

Before that there is error 0x83 ERROR_INVALID_STATE:

1978fcff0100c9d339f400f0032059620200896202008b620200 
target -> PC: 03847883 

The ERROR_INVALID_STATE may occur if the following was not handled correctly:

target -> PC: 16a6045900000001000500000059000000010001000000

This is the NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED_NO_AUTH event.

Is the handler added the same way as in the DFU example, and does it handle the NRF_MESH_EVT_DFU_FIRMWARE_OUTDATED_NO_AUTH case, also as in the DFU example, calling either nrf_mesh_dfu_request() or nrf_mesh_dfu_relay()? Failing to do so might lead to the invalid state experienced.

Regards,
Terje

[Gerry]

Thanks for your response Terje

I copied the code from your link into my project, to make sure everything is correct. I also put some log-messages into the events to see what happens on the client.

At programming, my application-id is now set to 100, the application-version is set to 5
nrfutil dfu genpkg --application ../../Source/connectivity_client/build/connectivity_client_Debug/connectivity_client.hex --company-id 0x00000059 --application-id 100 --application-version 5 --sd-req 0x00A9 --mesh client.zip
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o ../client.hex

At DFU, my application-id is now set to 100, the application-version is set to 6
nrfutil dfu genpkg --application ../../Source/connectivity_client/build/connectivity_client_Debug/connectivity_client.hex --company-id 0x00000059 --application-id 100 --application-version 6 --sd-req 0x00A9 --mesh client.zip
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o ../client.hex
nrfutil --verbose dfu serial -pkg client.zip -p COM%Comport% -b 115200 -fc --mesh

Flushing com-port...
Opened com-port
Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, application size: 131912
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: 1378fdff040f8feb68ab59000000640006000000
target -> PC: 16a6045900000064000600000059000000010001000000
target -> PC: 03847800
PC -> target: 1378fdff040f8feb68ab59000000640006000000
target -> PC: 03847800
PC -> target: 1478fcff00008feb68abffffffffd280000000000c
target -> PC: 0da2020459000000640006000000
target -> PC: 03847800
Sending firmware file
  [------------------------------------]    1%  00:11:51PC -> target: 1978fcff01008feb68ab00f0032059620200896202008b620200
target -> PC: 03847800
PC -> target: 1978fcff02008feb68ab8d6202008f6202009162020000000000
target -> PC: 03847800
PC -> target: 1978fcff03008feb68ab00000000000000000000000093620200
target -> PC: 03847800
....

The transfer works, but in my Log messages I can see, that in fw_updated_event_is_for_me() the app_id and app_version are wrong
and the client tries to relay instead of request himself (application-id should be 100 at programming and DFU)

Log-messages of the client:
 0> <t:     487812>, mesh.c,  715, DFU Firmware Outdated
 0> <t:     487814>, mesh.c,  688, DFU NRF_MESH_DFU_TYPE_APPLICATION current app_id: 1 transfer: 100
 0> <t:     487818>, mesh.c,  689, DFU NRF_MESH_DFU_TYPE_APPLICATION current company_id: 89 transfer: 89
 0> <t:     487821>, mesh.c,  690, DFU NRF_MESH_DFU_TYPE_APPLICATION current app_version: 1 transfer: 6
 0> <t:     487825>, mesh.c,  725, DFU Update DFU relay
 0> <t:     619917>, mesh.c,  732, DFU Start
 
 I had expected a current app_version: 5 and a current app_id: 100
 
 Can you see, what's wrong here?
 
 Kind regards
 Gerry
 

[tesc]

Hi,

This sounds a bit strange. Can you do a debug session on the DFU target and see where it gets stuck? (I.e. if it does not go to an assert handler you can stop it and see if it is stuck somewhere.)

Regards,
Terje

[Gerry]

when i pause the debug session, after this happens i get to the disassembler. Addr2line.exe gives no result for this address.

the client seems to work relaying DFU but fails to update its own firmware.

[Gerry]

Hi Terje

When I run my scripts with the DFU_Example, it works, so my scripts seem to be ok.
Then I compared the Log-output of the working DFU-Example and of my client.

DFU-Example:
 
 0> <t:     707308>, nrf_mesh_dfu.c,  390,  New firmware!
 0> <t:     707311>, main.c,  127, DFU Firmware Outdated
 0> <t:     707313>, main.c,  130, DFU Update DFU request
 0> <t:     707316>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     707319>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 3).
 0> <t:     707323>, nrf_mesh_dfu.c,  561,  SERIAL TX!
 0> <t:     773536>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     773540>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 0).
 0> <t:     773544>, nrf_mesh_dfu.c,  561,  SERIAL TX!
 0> <t:     839642>, nrf_mesh_dfu.c,  430,  DFU start
 0> <t:     839645>, main.c,  145, DFU Start
 0> <t:     839647>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 1, count 6, interval: exponential, handle: FFFC
 0> <t:     903019>, nrf_mesh_dfu.c,  329, Erase complete (0x41000)
 0> <t:     903022>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:     970994>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 2, count 3, interval: exponential, handle: FFFC
 0> <t:     971009>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:     971013>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:     987713>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 3, count 3, interval: exponential, handle: FFFC
 0> <t:     987725>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:     987728>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1004452>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 4, count 3, interval: exponential, handle: FFFC
 0> <t:    1004464>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1004467>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1021170>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 5, count 3, interval: exponential, handle: FFFC
 0> <t:    1021182>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1021186>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1037914>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 6, count 3, interval: exponential, handle: FFFC
 0> <t:    1037927>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1037930>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1054665>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 7, count 3, interval: exponential, handle: FFFC
 0> <t:    1054677>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1054681>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1071736>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 1, count 3, interval: exponential, handle: FFFC
 0> <t:    1071749>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1071752>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1088808>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 2, count 3, interval: exponential, handle: FFFC
 0> <t:    1088820>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1088824>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1105543>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 3, count 3, interval: exponential, handle: FFFC
 0> <t:    1105555>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1105559>, nrf_mesh_dfu.c,  333, Flash idle.
 0> <t:    1122268>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 4, count 3, interval: exponential, handle: FFFC
 0> <t:    1122280>, nrf_mesh_dfu.c,  324, Write complete (0x2003FE90)
 0> <t:    1122283>, nrf_mesh_dfu.c,  333, Flash idle.
 ....
 
 My client:
 
 0> <t:     343469>, nrf_mesh_dfu.c,  390,  New firmware!
 0> <t:     343471>, mesh.c,  715, DFU Firmware Outdated
 0> <t:     343474>, mesh.c,  718, DFU Update DFU request
 0> <t:     343476>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     343480>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 2).
 0> <t:     343484>, nrf_mesh_dfu.c,  561,  SERIAL TX!
 0> <t:     409368>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 0, count 255, interval: periodic, handle: FFFD
 0> <t:     409372>, nrf_mesh_dfu.c,  534, Killing a TX slot prematurely (repeats done: 0).
 0> <t:     409375>, nrf_mesh_dfu.c,  561,  SERIAL TX!
 0> <t:     475887>, nrf_mesh_dfu.c,  430,  DFU start
 0> <t:     475890>, mesh.c,  732, DFU Start
 0> <t:     475892>, nrf_mesh_dfu.c,  528,  RADIO TX! SLOT 5, count 6, interval: exponential, handle: FFFC
 0> <t:     566814>, nrf_mesh_dfu.c,  329, Erase complete (0x47000)
 0> <t:     566817>, nrf_mesh_dfu.c,  333, Flash idle.
 no further messages, client crashed here or at least doesn't listen to the UART no more. Might also be a tomeout.
 

ROM-Info of the application:

<t:      58439>, mesh.c,  597, rom_base   26101
<t:      58441>, mesh.c,  598, rom_end    460FC
<t:      58443>, mesh.c,  599, rom_length 1FFFB
<t:      58445>, mesh.c,  600, bank_addr   47000

 What could lead to this? I compared my code to the DFU-Example, but I can't find the difference.
 
 Regards
 Gerry
 

[Gerry]

Hi Terje

If I power cycle the device after programming, the "Crash on first packet" disapears. Then I only have an ERROR_INVALID_DATA.

The output now looks as follows:

for programming i use:

(
  echo {
  echo     "bootloader_config": {
  echo        "bootloader_id": 1,
  echo        "bootloader_version": 1,
  echo        "company_id": 89,
  echo        "application_id": 1,
  echo        "application_version": 1
  echo    }
  echo }
) > bootloader_config_default.json
python device_page_generator.py -d nrf52840_xxAA -sd "s140_6.0.0" -o ../client.hex
cd ..
nrfjprog --eraseall
nrfjprog --program ../../Mesh_SDK/bin/softdevice/s140_nrf52_6.0.0_softdevice.hex --chiperase
nrfjprog --program bootloader/mesh_bootloader_serial_gccarmemb_nrf52840_xxAA.hex
nrfjprog --program ../../Source/connectivity_client/build/connectivity_client_Debug/connectivity_client.hex
nrfjprog --program client.hex
nrfjprog --reset

For DFU:

nrfutil dfu genpkg --application ../../Source/connectivity_client/build/connectivity_client_Debug/connectivity_client.hex --company-id 0x00000059 --application-id 1 --application-version 2 --sd-req 0x00A9 --mesh client.zip

nrfutil --verbose dfu serial -pkg client.zip -p COM%Comport% -b 115200 -fc --mesh

Can you see what's going wrong here?

Regards

Gerry

[Chaabane]

I'm having the same problem aswell, any leads ?