Duration of DFU for multiple nodes simultaneously

[stefanogradozzi]

Hi,

I made DFU procedure with a distributor (nRF52840 DK) and one target (nRF52840 dongle): procedure completed successfully in approximately 45min

Then I made:DFU procedure with:

a distributor and two target: procedure completed successfully in approximately 90min (that is 2*45min)

a distributor and four target: procedure completed successfully in approximately 180min (that is 4*45min)

a distributor and six target: procedure completed successfully in approximately 270min (that is 6*45min)

a distributor and eight target: procedure completed successfully in approximately 360min (that is 8*45min)

So it seems that if I have N targets,to update,  the DFU procedure will take about N*45min! A lot of time, in particular if N>>1!

Is it possible to know how the procedure is realized? The Distributor sends packets to only a target at a time or it sends packets to all targets simultaneously and then waits for acks?

Thanks in advance for your response

[stefanogradozzi]

Hi,

in addition,

I went on with my DFU procedure test, and I found that I manage to update 10 targets max. When I try to update more than 10 Targest the procedure fails and this is the final part of the report that I receive through serial:

[00:21:56.037,475] <dbg> bt_mesh_blob_cli: chunk_send: 36 / 37 size: 113
[00:21:56.037,475] <dbg> bt_mesh_blob_cli: blob_cli_broadcast: 11 targets
[00:22:05.548,522] <dbg> bt_mesh_blob_cli: broadcast_complete: continuing
[00:22:05.548,553] <dbg> bt_mesh_blob_cli: chunk_send: 37 / 37 size: 28
[00:22:05.548,583] <dbg> bt_mesh_blob_cli: blob_cli_broadcast: 11 targets
[00:22:09.010,528] <dbg> bt_mesh_blob_cli: broadcast_complete: continuing
[00:22:09.010,528] <dbg> bt_mesh_blob_cli: block_check:
[00:22:09.010,559] <dbg> bt_mesh_blob_cli: blob_cli_broadcast: 11 targets
[00:22:09.119,476] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:09.119,506] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:09.119,537] <dbg> bt_mesh_blob_cli: rx_block_status: 0x0044: block: 0 status: 10
[00:22:09.119,537] <wrn> bt_mesh_blob_cli: Dropping 0x0044: 10
[00:22:09.119,567] <err> bt_mesh_dfu_cli: Target 0x0044 failed: 3
[00:22:09.119,567] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x0044, pending: 11
[00:22:09.319,702] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:09.319,732] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:09.319,763] <dbg> bt_mesh_blob_cli: rx_block_status: 0x0049: block: 0 status: 10
[00:22:09.319,763] <wrn> bt_mesh_blob_cli: Dropping 0x0049: 10
[00:22:09.319,793] <err> bt_mesh_dfu_cli: Target 0x0049 failed: 3
[00:22:09.319,793] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x0049, pending: 10
[00:22:09.430,816] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:09.430,877] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:09.430,877] <dbg> bt_mesh_blob_cli: rx_block_status: 0x0039: block: 0 status: 10
[00:22:09.430,908] <wrn> bt_mesh_blob_cli: Dropping 0x0039: 10
[00:22:09.430,908] <err> bt_mesh_dfu_cli: Target 0x0039 failed: 3
[00:22:09.430,938] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x0039, pending: 9
[00:22:09.931,091] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:09.931,121] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:09.931,152] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004b: block: 0 status: 10
[00:22:09.931,152] <wrn> bt_mesh_blob_cli: Dropping 0x004b: 10
[00:22:09.931,182] <err> bt_mesh_dfu_cli: Target 0x004b failed: 3
[00:22:09.931,213] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004b, pending: 8
[00:22:10.032,226] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.032,287] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:10.032,287] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004c: block: 0 status: 10
[00:22:10.032,318] <wrn> bt_mesh_blob_cli: Dropping 0x004c: 10
[00:22:10.032,318] <err> bt_mesh_dfu_cli: Target 0x004c failed: 3
[00:22:10.032,348] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004c, pending: 7
[00:22:10.085,845] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.085,876] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:10.085,906] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004d: block: 0 status: 10
[00:22:10.085,906] <wrn> bt_mesh_blob_cli: Dropping 0x004d: 10
[00:22:10.085,937] <err> bt_mesh_dfu_cli: Target 0x004d failed: 3
[00:22:10.085,937] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004d, pending: 6
[00:22:10.154,693] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.154,724] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:10.154,754] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004e: block: 0 status: 10
[00:22:10.154,754] <wrn> bt_mesh_blob_cli: Dropping 0x004e: 10
[00:22:10.154,785] <err> bt_mesh_dfu_cli: Target 0x004e failed: 3
[00:22:10.154,815] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004e, pending: 5
[00:22:10.230,072] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.230,133] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:10.230,133] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004f: block: 0 status: 10
[00:22:10.230,163] <wrn> bt_mesh_blob_cli: Dropping 0x004f: 10
[00:22:10.230,194] <err> bt_mesh_dfu_cli: Target 0x004f failed: 3
[00:22:10.230,194] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004f, pending: 4
[00:22:10.304,748] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.304,809] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:10.304,809] <dbg> bt_mesh_blob_cli: rx_block_status: 0x0050: block: 0 status: 10
[00:22:10.304,840] <wrn> bt_mesh_blob_cli: Dropping 0x0050: 10
[00:22:10.304,840] <err> bt_mesh_dfu_cli: Target 0x0050 failed: 3
[00:22:10.304,870] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x0050, pending: 3
[00:22:10.386,627] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:10.386,688] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f8ffffff1f
[00:22:10.386,688] <dbg> bt_mesh_blob_cli: rx_block_status: 0x0051: block: 0 status: 10
[00:22:10.386,718] <wrn> bt_mesh_blob_cli: Dropping 0x0051: 10
[00:22:10.386,718] <err> bt_mesh_dfu_cli: Target 0x0051 failed: 3
[00:22:10.386,749] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x0051, pending: 2
[00:22:14.252,777] <dbg> bt_mesh_blob_cli: retry_timeout: 12
[00:22:14.347,717] <dbg> bt_mesh_blob_cli: handle_block_status: status: 10 block: 0 encoding: 2
[00:22:14.347,747] <dbg> bt_mesh_blob_cli: handle_block_status: Missing: f0ffffff1f
[00:22:14.347,747] <dbg> bt_mesh_blob_cli: rx_block_status: 0x004a: block: 0 status: 10
[00:22:14.347,778] <wrn> bt_mesh_blob_cli: Dropping 0x004a: 10
[00:22:14.347,778] <err> bt_mesh_dfu_cli: Target 0x004a failed: 3
[00:22:14.347,808] <dbg> bt_mesh_blob_cli: blob_cli_broadcast_rsp: 0x004a, pending: 1
[00:22:14.347,961] <dbg> bt_mesh_blob_cli: broadcast_complete: continuing
[00:22:14.347,991] <dbg> bt_mesh_blob_cli: block_check_end:
[00:22:14.347,991] <dbg> bt_mesh_blob_cli: end: 0
[00:22:14.348,022] <dbg> bt_mesh_dfu_cli: dfu_failed: 3
[00:22:14.348,052] <dbg> bt_mesh_dfd_srv: dfu_ended: reason: 3, phase: 1, apply: 1
Distribution phase changed to Failed

Could you please tell me why this happens? Why the limit of 10 Targets? What can I do for updating more than 10 Targets?

Thank you

[AHaug]

Hi,

Is it possible to know how the procedure is realized? The Distributor sends packets to only a target at a time or it sends packets to all targets simultaneously and then waits for acks?

The procedure is described in the Mesh DFU specification found at https://www.bluetooth.com/specifications/specs/. The update firmware image is packed inside a Mesh BLOB (Binary Large Object) which is transferred from the Distributor to the Targets one chunk at the time. All devices that is going to be updated needs to receive the current chunk before moving on to the next chunk. In case you have a noisy environment where a lot of these packs are last, you will have to restart the transmission of the current chunk until every node has received this chunk. This is better explained in the Mesh DFU specification chapter 2.3, where firmware image distribution is described in 2.3.5, 2.3.6 and 2.3.7.

This means that the more devices you intend to update, the longer time it takes. I'm not 100% sure about the directly proportional property you describe w.r.t time length, but I assume that it seems plausible. I will have to do some more investigation to verify this.

In chapter 8. you can also see flowcharts describing this procedure: As an example, here is figure 8.5 showcasing the process for 2 targets: 

When every device has received the new image, the distributor applies the firmware update.

stefanogradozzi said:

I went on with my DFU procedure test, and I found that I manage to update 10 targets max. When I try to update more than 10 Targest the procedure fails

Could you state how you updated the maximum amount of targets? I.e what changes did you make to the distributor

Kind regards,
Andreas

[AHaug]

Thank you for verifying. Yes, this seems to be the correct way. CONFIG_BT_MESH_DFD_SRV_TARGETS_MAX defaults to 8, and setting it to 16 should allow for more Targets.

Could you try to increase the timeout value when you start initiate the dfd start command?

Kind regards,
Andreas

[stefanogradozzi]

How can I increase the timeout?

Can you give me an example of the correct instruction?

mesh models dfd start 2 0 ...

Thanks

[AHaug]

Yes of course, I see I was a bit too quick yesterday. Here's the command:

> mesh models dfd start  <AppKeyIdx> <SlotIdx> [<Group> [<PolicyApply> [<TTL> [<TimeoutBase> [<XferMode>]]]]]

For instance

> mesh models dfd start 0 0 0xc000 0 2 2

You find the explanation of the dfd commands here: https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/zephyr/connectivity/bluetooth/api/mesh/shell.html#mesh-models-dfd-get

Kind regards,
Andreas

[stefanogradozzi]

Hi,

I increased as you said the timeout value ( I set it to 1) and this resolved the previous issue, but at the same time created another one!

Now, when I simply try to update one target, these are the last messages sent by Distributor through serial communication at the end of the process:

Distribution phase changed to Applying Update
[17:22:01.676,086] <dbg> bt_mesh_dfu_cli: apply:
[17:22:01.676,086] <dbg> bt_mesh_blob_cli: blob_cli_broadcast: 1 targets
[17:22:01.982,879] <dbg> bt_mesh_dfu_cli: handle_status: 0 phase: 6, cur state: 4
[17:22:01.982,910] <dbg> bt_mesh_dfu_cli: handle_status: Target 0x001d receiving transfer
[17:22:10.910,430] <dbg> bt_mesh_blob_cli: retry_timeout: 5
[17:22:20.075,195] <dbg> bt_mesh_blob_cli: retry_timeout: 4
[17:22:29.234,588] <dbg> bt_mesh_blob_cli: retry_timeout: 3
[17:22:38.400,756] <dbg> bt_mesh_blob_cli: retry_timeout: 2
[17:22:47.553,466] <dbg> bt_mesh_blob_cli: retry_timeout: 1
[17:22:47.553,497] <dbg> bt_mesh_blob_cli: retry_timeout: Transfer timed out.
[17:22:47.553,497] <dbg> bt_mesh_blob_cli: drop_remaining_targets:
[17:22:47.553,527] <wrn> bt_mesh_blob_cli: Dropping 0x001d: 9
[17:22:47.553,527] <err> bt_mesh_dfu_cli: Target 0x001d failed: 3
[17:22:47.553,558] <dbg> bt_mesh_blob_cli: broadcast_complete: continuing
[17:22:47.553,588] <dbg> bt_mesh_dfu_cli: dfu_failed: 3
[17:22:47.553,588] <dbg> bt_mesh_dfd_srv: dfu_ended: reason: 3, phase: 3, apply: 1
Distribution phase changed to Failed

So, Distribution seems to fail but, surprise, after these messages (two or three seconds) I can see my target resetting (at reset I switch on a led for a couple of seconds) and, when I verifiy if new firmware was properly updated on Target (I read a variable of mine which contains new firmware version), the result is OK, that is: actually, Distribution doesn't fail but ends successfully!

Why this happen?

It seems that as log as there are retries, the target doesn't begin to apply new firmware...

Let me know, thanks

[AHaug]

Hi,

Apologies for the long response time. I had to verify something from the developers:

Regarding the linear relation between DFU duration and number of devices. It is true that time required is almost linear if unicast transfer is done. If group transfer is used transfer time will increase only little bit due to additional number of nodes in a group.

Regarding the maximum amount of supported targets, the configuration for maximum supported targets should be what we're looking for, i.e the bt_mesh_dfd configuration referring to https://docs.nordicsemi.com/bundle/ncs-latest/page/kconfig/index.html#CONFIG_BT_MESH_DFD_SRV_TARGETS_MAX

Kind regards,
Andreas