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
 

[Chaabane]

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

[Chaabane]

it seems that the erase sequence takes too much time. I explicitly added --i 500 to the dfu serial command and it seems to be working but it take 42 minutes to do DFU instead of 10 minutes.

500ms is the default value based on the help!

[Gerry]

Setting --i to 500 did not solve my Problem.

[Chaabane]

It's not a long term solution anyway. I guess we'll have to wait for nordic support

[tesc]

Hi,

I am very sorry for the delay, it looked like you had found a workaround but now I realize it did not work for you all.

You can try to increase SEND_START_DFU_WAIT_TIME in dfu_transport_mesh.py. (In the python source for nrfutil mesh branch.) Try setting it to 3.0 first, and increase it even a bit more if that is not sufficient. The larger the application, the more you might have to increase it.

Regards,
Terje

[Gerry]

Hi, 

Changing SEND_START_DFU_WAIT_TIME to 3.0 helped to ged rid of the "crash on start package". It now returns with ERROR_INVALID_PARAMETER after a while as you can see below. Further increasing of SEND_START_DFU_WAIT_TIME doesn't help.

Flow control is enabled.
Flushing com-port...
Opened com-port
Starting DFU upgrade of type 4, SoftDevice size: 0, bootloader size: 0, application size: 137740
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: 1378fdff040fea3cfb2759000000010002000000
target -> PC: 16a6045900000001000200000059000000010001000000
target -> PC: 03847800
PC -> target: 1378fdff040fea3cfb2759000000010002000000
target -> PC: 03847800
PC -> target: 1478fcff0000ea3cfb27ffffffff8386000000000c
PC -> target: 1478fcff0000ea3cfb27ffffffff8386000000000c
target -> PC: 0da2010459000000010002000000
target -> PC: 03847800
Sending firmware file
  [------------------------------------]    1%  00:13:09PC -> target: 1978fcff0100ea3cfb2700f0032059620200896202008b620200
PC -> target: 1978fcff0100ea3cfb2700f0032059620200896202008b620200
target -> PC: 03847887
PC -> target: 1978fcff0100ea3cfb2700f0032059620200896202008b620200
target -> PC: 03840082
PC -> target: 1978fcff0100ea3cfb2700f0032059620200896202008b620200
PC -> target: 1978fcff0100ea3cfb2700f0032059620200896202008b620200

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

Can you see, what's going wrong here?

Kind regards 

Gerry

[tesc]

Hi,

It looks from the log like you run the standalone bootloader. That one returns fewer status messages, which may make it a bit hard to figure out.

The first error message is NRF_INVALID_STATE (0x83, or in decimal 133). I talked to our mesh guys, and when you get NRF_INVALID_STATE after having sent the first data packet, it (usually) means there is not enough available space for the new download so it cannot begin. The bootloader then jumps back to the previous stage (you will see that after the NRF_INVALID_STATE return message the first 1978fc... messages from target to PC are repeated, and the target is back in that state.

Regards,
Terje

[Gerry]

Hi, is it a problem of the size (318kB Hexfile) or can we solve this with the Flash_placement?

Fullscreen 7433.flash_placement.xml Download

<!DOCTYPE Linker_Placement_File>
<Root name="Flash Section Placement">
  <MemorySegment name="FLASH" start="$(FLASH_PH_START)" size="$(FLASH_PH_SIZE)">
    <ProgramSection load="no" name=".reserved_flash" start="$(FLASH_PH_START)" size="$(FLASH_START)-$(FLASH_PH_START)" />
    <ProgramSection alignment="0x100" load="Yes" name=".vectors" start="$(FLASH_START)" />
    <ProgramSection alignment="4" load="Yes" name=".init" />
    <ProgramSection alignment="4" load="Yes" name=".init_rodata" />
    <ProgramSection alignment="4" load="Yes" name=".text" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".sdh_soc_observers" inputsections="*(SORT(.sdh_soc_observers*))" address_symbol="__start_sdh_soc_observers" end_symbol="__stop_sdh_soc_observers" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".sdh_ble_observers" inputsections="*(SORT(.sdh_ble_observers*))" address_symbol="__start_sdh_ble_observers" end_symbol="__stop_sdh_ble_observers" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".pwr_mgmt_data" inputsections="*(SORT(.pwr_mgmt_data*))" address_symbol="__start_pwr_mgmt_data" end_symbol="__stop_pwr_mgmt_data" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".log_const_data" inputsections="*(SORT(.log_const_data*))" address_symbol="__start_log_const_data" end_symbol="__stop_log_const_data" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".nrf_balloc" inputsections="*(.nrf_balloc*)" address_symbol="__start_nrf_balloc" end_symbol="__stop_nrf_balloc" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".sdh_state_observers" inputsections="*(SORT(.sdh_state_observers*))" address_symbol="__start_sdh_state_observers" end_symbol="__stop_sdh_state_observers" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".sdh_stack_observers" inputsections="*(SORT(.sdh_stack_observers*))" address_symbol="__start_sdh_stack_observers" end_symbol="__stop_sdh_stack_observers" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".sdh_req_observers" inputsections="*(SORT(.sdh_req_observers*))" address_symbol="__start_sdh_req_observers" end_symbol="__stop_sdh_req_observers" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".nrf_queue" inputsections="*(.nrf_queue*)" address_symbol="__start_nrf_queue" end_symbol="__stop_nrf_queue" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".cli_command" inputsections="*(.cli_command*)" address_symbol="__start_cli_command" end_symbol="__stop_cli_command" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".crypto_data" inputsections="*(SORT(.crypto_data*))" address_symbol="__start_crypto_data" end_symbol="__stop_crypto_data" />
    <ProgramSection alignment="4" keep="Yes" load="No" name=".nrf_sections" address_symbol="__start_nrf_sections" />
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".log_dynamic_data"  inputsections="*(SORT(.log_dynamic_data*))" runin=".log_dynamic_data_run"/>
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".fs_data"  inputsections="*(.fs_data*)" runin=".fs_data_run"/>
    <ProgramSection alignment="4" keep="Yes" load="Yes" name=".cli_sorted_cmd_ptrs"  inputsections="*(.cli_sorted_cmd_ptrs*)" runin=".cli_sorted_cmd_ptrs_run"/>
    <ProgramSection alignment="4" load="Yes" name=".dtors" />
    <ProgramSection alignment="4" load="Yes" name=".ctors" />
    <ProgramSection alignment="4" load="Yes" name=".rodata" />
    <ProgramSection alignment="4" load="Yes" name=".ARM.exidx" address_symbol="__exidx_start" end_symbol="__exidx_end" />
    <ProgramSection alignment="4" load="Yes" runin=".fast_run" name=".fast" />
    <ProgramSection alignment="4" load="Yes" runin=".data_run" name=".data" />
    <ProgramSection alignment="4" load="Yes" runin=".tdata_run" name=".tdata" />
  </MemorySegment>
  <MemorySegment name="RAM" start="$(RAM_PH_START)" size="$(RAM_SIZE)">
    <ProgramSection load="no" name=".reserved_ram" start="$(RAM_PH_START)" size="$(RAM_START)-$(RAM_PH_START)" />
    <ProgramSection alignment="0x100" load="No" name=".vectors_ram" start="$(RAM_START)" address_symbol="__app_ram_start__"/>
    <ProgramSection alignment="4" keep="Yes" load="No" name=".nrf_sections_run" address_symbol="__start_nrf_sections_run" />
    <ProgramSection alignment="4" keep="Yes" load="No" name=".log_dynamic_data_run" address_symbol="__start_log_dynamic_data" end_symbol="__stop_log_dynamic_data" />
    <ProgramSection alignment="4" keep="Yes" load="No" name=".fs_data_run" address_symbol="__start_fs_data" end_symbol="__stop_fs_data" />
    <ProgramSection alignment="4" keep="Yes" load="No" name=".cli_sorted_cmd_ptrs_run" address_symbol="__start_cli_sorted_cmd_ptrs" end_symbol="__stop_cli_sorted_cmd_ptrs" />
    <ProgramSection alignment="4" keep="Yes" load="No" name=".nrf_sections_run_end" address_symbol="__end_nrf_sections_run" />
    <ProgramSection alignment="4" load="No" name=".fast_run" />
    <ProgramSection alignment="4" load="No" name=".data_run" />
    <ProgramSection alignment="4" load="No" name=".tdata_run" />
    <ProgramSection alignment="4" load="No" name=".bss" />
    <ProgramSection alignment="4" load="No" name=".tbss" />
    <ProgramSection alignment="4" load="No" name=".non_init" />
    <ProgramSection alignment="4" size="__HEAPSIZE__" load="No" name=".heap" />
    <ProgramSection alignment="8" size="__STACKSIZE__" load="No" place_from_segment_end="Yes" name=".stack"  address_symbol="__StackLimit" end_symbol="__StackTop"/>
    <ProgramSection alignment="8" size="__STACKSIZE_PROCESS__" load="No" name=".stack_process" />
  </MemorySegment>
</Root>

FLASH_PH_START=0x0

FLASH_PH_SIZE=0x100000

RAM_PH_START=0x20000000

RAM_PH_SIZE=0x40000

FLASH_START=0x26000

FLASH_SIZE=0xf8000

RAM_START=0x200032c8

RAM_SIZE=0x3f000

Regards

Gerry

[tesc]

Hi,

It is not the size of the hexfile itself, but the size of the data described therein. I.e. the final size of that bulk of data. If you have hard coded entries in for instance UICR, or otherwise outside of the contiguous binary that you download, which ends up in the hex file used for generating the update, then that will result in a large binary that will not fit. So if you have done something like that then yes, removing that from the binary may solve the issue.

If not the above, then it may just be that the new firmware is too big to fit in flash in addition to the existing bootloader and SoftDevice.

Regards,
Terje

[Gerry]

Hi,

I have some UICR-Code to set the voltage to 3.3V and I also found some in the SDK according the reset pin. After commenting this out, there is no change in behavior. I also checked the size in Segger Studio and compared it to the dfu_example, that works fine.

my Client:

dfu_example:

There seems to be no big difference in size and this should easily fit into flash 2 times. Is there a Bootloader other than the standalone version to get more messages?

regards 

Gerry