[NCS v2.2.0] - Device Firmware Update (DFU) via OTA using BLE

Question

Hi 
 In order to add DFU function to our custom board (integrating nRF52840) over OTA by using BLE, we refer to the guide named " Adding DFU support to your application " and use the same procedure (include the sample) from the " DFU over Bluetooth " section on nRF52840DK. The upload tool we use is nRF Connect Device Manager (Android-verison 1.5.2). 
 The result is that when we select the " Test and confirm " option on Device Manager to upgrade firmware (whatever app_update.bin or dfu_application.zip ), the state will display " Invalid value (3) " after the procedure is completed. We are not sure if the firmware was successfully upgraded. 
 In view of this, we searched this issue on Nordic Q&A and found someone with the same problem. The case is here . We refered to the solution in this case to upgrade firmware using " Confirm Only " option. But the result was the same. We recorded two logs. One from nRF Logger app and the other from Minicom . They are as follows.

Fullscreen 
 6735.nRF_Logger_2023-02-22_10_17_29.log 
 Download 
 
 Device Manager, 2023-02-22
Nordic_LBS (Device Manager)
I	10:17:34.488	[e] Connected to FB:C7:5C:DB:A6:D2
I	10:17:34.925	[e] Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	10:17:35.006	[e] PHY updated (TX: LE 2M, RX: LE 2M)
I	10:17:35.206	[e] Services discovered
I	10:17:35.284	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	10:17:35.311	[e] MTU changed to: 252
I	10:17:35.462	[e] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
I	10:17:35.484	[e] Notifications enabled
I	10:17:35.513	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:17:35.596	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
I	10:17:35.620	[e] Wait for value changed complete
I	10:17:35.664	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
I	10:17:35.687	[e] PHY read (TX: LE 2M, RX: LE 2M)
I	10:17:35.710	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
I	10:17:35.733	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 0, Seq: 1, Command: 6) CBOR {}
I	10:17:35.756	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:17:35.788	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:17:35.913	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-86-00-01-00-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75-73-00-FF
I	10:17:35.942	[e] Received Header (Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
I	10:17:36.002	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-01-06-BF-62-72-63-08-FF
I	10:17:36.026	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
I	10:17:39.612	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
V	10:18:33.530	[j] Starting DFU, mode: CONFIRM_ONLY
I	10:18:33.726	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 2, Command: 0) CBOR {}
I	10:18:33.757	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:18:33.828	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-86-00-01-02-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75-73-00-FF
I	10:18:33.860	[e] Received Header (Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
V	10:18:33.908	[k] Validation response: {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
V	10:18:33.932	[j] Moving from state VALIDATE to state UPLOAD
I	10:18:33.954	Uploading firmware...
I	10:18:53.679	Image (207602 bytes) sent in 19535 ms (avg speed: 10.627182 kB/s)
I	10:18:53.757	[Uploader] Upload completed. 207602 bytes sent in 19717 ms with avg speed: 10.528553 kBytes/s
V	10:18:53.795	[j] Moving from state UPLOAD to state CONFIRM
I	10:18:53.847	[e] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 174, Command: 0) CBOR {"confirm":true,"hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg="}
I	10:18:53.878	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:18:53.911	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-01-AE-00-BF-62-72-63-03-FF
I	10:18:53.938	[e] Received Header (Op: 3, Flags: 0, Len: 6, Group: 1, Seq: 174, Command: 0) CBOR {"rc":3}
E	10:18:53.977	Upgrade failed
Mcu Mgr Error: IN_VALUE (3)
	at j2.e$b.c(Unknown Source:24)
	at k2.f.j(Unknown Source:10)
	at k2.f.c(Unknown Source:0)
	at k2.e.run(Unknown Source:4)
	at android.os.Handler.handleCallback(Handler.java:883)
	at android.os.Handler.dispatchMessage(Handler.java:100)
	at android.os.Looper.loop(Looper.java:214)
	at android.os.HandlerThread.run(HandlerThread.java:67)

I	10:19:01.875	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 175, Command: 0) CBOR {}
I	10:19:01.909	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:01.941	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-F4-00-01-AF-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-68-4D-91-02-80-6C-EF-2A-5C-A1-18-CB-18-21-86-07-A4-B5-B0-84-71-74-B8-92-E1-4F-DB-1C-16-E1-53-18-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75
I	10:19:01.975	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
I	10:19:02.005	[e] Received Header (Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 175, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	10:19:25.226	[j] Starting DFU, mode: TEST_AND_CONFIRM
I	10:19:25.377	[e] Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
I	10:19:25.403	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 176, Command: 0) CBOR {}
I	10:19:25.440	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:25.478	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-F4-00-01-B0-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-68-4D-91-02-80-6C-EF-2A-5C-A1-18-CB-18-21-86-07-A4-B5-B0-84-71-74-B8-92-E1-4F-DB-1C-16-E1-53-18-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75
I	10:19:25.497	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
I	10:19:25.523	[e] Received Header (Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 176, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	10:19:25.551	[k] Validation response: {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	10:19:25.578	[j] Moving from state VALIDATE to state TEST
I	10:19:25.611	[e] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 177, Command: 0) CBOR {"confirm":false,"hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg="}
I	10:19:25.632	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:25.673	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-F4-00-01-B1-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-68-4D-91-02-80-6C-EF-2A-5C-A1-18-CB-18-21-86-07-A4-B5-B0-84-71-74-B8-92-E1-4F-DB-1C-16-E1-53-18-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F5-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75
I	10:19:25.701	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
I	10:19:25.723	[e] Received Header (Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 177, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	10:19:25.747	[i] Test response: {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	10:19:25.770	[j] Moving from state TEST to state RESET
I	10:19:25.807	[e] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 0, Seq: 178, Command: 5) CBOR {}
I	10:19:25.847	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:25.876	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-02-00-00-B2-05-BF-FF
I	10:19:25.896	[e] Received Header (Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 178, Command: 5) CBOR {}
V	10:19:25.917	[g] Reset request success. Waiting for disconnect...
W	10:19:33.614	[e] Error: (0x8): GATT CONN TIMEOUT
I	10:19:33.666	[e] Disconnected
I	10:19:33.701	[g] Device disconnected
V	10:19:33.727	[g] Waiting remaining 2192 ms for the swap operation to complete
V	10:19:35.957	[j] Moving from state RESET to state CONFIRM
I	10:19:47.473	[e] Connected to FB:C7:5C:DB:A6:D2
I	10:19:47.896	[e] Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	10:19:47.974	[e] PHY updated (TX: LE 2M, RX: LE 2M)
I	10:19:48.210	[e] Services discovered
I	10:19:48.262	[e] MTU changed to: 252
I	10:19:48.300	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	10:19:48.529	[e] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
I	10:19:48.572	[e] Notifications enabled
I	10:19:48.606	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:48.661	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
I	10:19:48.690	[e] Wait for value changed complete
I	10:19:48.717	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
I	10:19:48.744	[e] PHY read (TX: LE 2M, RX: LE 2M)
I	10:19:48.774	[e] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 0, Command: 0) CBOR {"confirm":true,"hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg="}
I	10:19:48.802	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 0, Seq: 1, Command: 6) CBOR {}
I	10:19:48.826	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:48.861	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:19:48.891	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-01-00-00-BF-62-72-63-03-FF
I	10:19:48.921	[e] Received Header (Op: 3, Flags: 0, Len: 6, Group: 1, Seq: 0, Command: 0) CBOR {"rc":3}
E	10:19:48.968	Upgrade failed
Mcu Mgr Error: IN_VALUE (3)
	at j2.e$b.c(Unknown Source:24)
	at k2.f.j(Unknown Source:10)
	at k2.f.c(Unknown Source:0)
	at k2.e.run(Unknown Source:4)
	at android.os.Handler.handleCallback(Handler.java:883)
	at android.os.Handler.dispatchMessage(Handler.java:100)
	at android.os.Looper.loop(Looper.java:214)
	at android.os.HandlerThread.run(HandlerThread.java:67)

I	10:19:49.002	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-01-06-BF-62-72-63-08-FF
I	10:19:49.036	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
I	10:19:52.590	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
I	10:20:01.416	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 2, Command: 0) CBOR {}
I	10:20:01.458	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:20:01.582	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-F4-00-01-02-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-68-4D-91-02-80-6C-EF-2A-5C-A1-18-CB-18-21-86-07-A4-B5-B0-84-71-74-B8-92-E1-4F-DB-1C-16-E1-53-18-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75
I	10:20:01.667	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
I	10:20:01.697	[e] Received Header (Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":false,"confirmed":false,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":false,"permanent":false}],"splitStatus":0}
I	10:20:26.721	[e] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 0, Seq: 3, Command: 5) CBOR {}
I	10:20:26.809	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:20:26.865	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-02-00-00-03-05-BF-FF
I	10:20:26.894	[e] Received Header (Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 3, Command: 5) CBOR {}
W	10:20:27.683	[e] Error: (0x8): GATT CONN TIMEOUT
I	10:20:27.725	[e] Disconnected
I	10:20:48.442	[e] Connected to FB:C7:5C:DB:A6:D2
I	10:20:48.872	[e] Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	10:20:48.956	[e] PHY updated (TX: LE 2M, RX: LE 2M)
I	10:20:49.167	[e] Services discovered
I	10:20:49.223	[e] MTU changed to: 252
I	10:20:49.278	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	10:20:49.322	[e] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
I	10:20:49.353	[e] Notifications enabled
I	10:20:49.389	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:20:49.461	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
I	10:20:49.491	[e] Wait for value changed complete
I	10:20:49.528	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
I	10:20:49.563	[e] PHY read (TX: LE 2M, RX: LE 2M)
I	10:20:49.601	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
I	10:20:49.647	[e] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 0, Seq: 1, Command: 6) CBOR {}
I	10:20:49.674	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:20:49.701	[e] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
I	10:20:49.748	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-F4-00-01-00-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-74-BE-73-50-F1-1B-50-18-09-1B-27-01-AA-83-E0-36-10-AC-C3-40-E8-19-90-C0-1C-D4-59-CF-6E-60-09-F3-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-30-2E-30-2E-30-64-68-61-73-68-58-20-68-4D-91-02-80-6C-EF-2A-5C-A1-18-CB-18-21-86-07-A4-B5-B0-84-71-74-B8-92-E1-4F-DB-1C-16-E1-53-18-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75
I	10:20:49.822	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
I	10:20:49.859	[e] Received Header (Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"dL5zUPEbUBgJGycBqoPgNhCsw0DoGZDAHNRZz25gCfM=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"aE2RAoBs7ypcoRjLGCGGB6S1sIRxdLiS4U/bHBbhUxg=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
I	10:20:49.913	[e] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-01-06-BF-62-72-63-08-FF
I	10:20:49.953	[e] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
I	10:20:53.566	[e] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)

In the minicom log, there is a test log " ########## Test Log - Another Image ########## ". It means that the current image is using the new image. In addition, you can also confirm the " build time " log to check if the active image is changed.

Fullscreen 
 4682.minicom_nrf52840dk_dfu_ble-2023-02-22.log 
 Download 
 
 *** Booting Zephyr OS build v3.2.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Swap type: none
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot*** Booting Zephyr OS build v3.2.99-ncs1 ***
Starting Bluetooth Peripheral LBS example
build time: Feb 21 2023 16:50:30
I: 2 Sectors of 4096 bytes
I: alloc wra: 0, fe8
I: data wra: 0, 0
I: SoftDevice Controller build revision: 
I: 6d 90 41 2a 38 e8 ad 17 |m.A*8...
I: 29 a5 03 38 39 27 d7 85 |)..89'..
I: 1f 85 d8 e1 |.... 
I: No ID address. App must call settings_load()
Bluetooth initialized
Advertising successfully started
Connected
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: test
I: Swap type: test
*** Booting Zephyr OS build v3.2.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=good, swap_type=0x2, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Swap type: test
I: Starting swap using move algorithm.
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot*** Booting Zephyr OS build v3.2.99-ncs1 ***
Starting Bluetooth Peripheral LBS example
########## Test Log - Another Image ##########
build time: Feb 21 2023 16:49:34
I: 2 Sectors of 4096 bytes
I: alloc wra: 0, fd0
I: data wra: 0, 1c
I: SoftDevice Controller build revision: 
I: 6d 90 41 2a 38 e8 ad 17 |m.A*8...
I: 29 a5 03 38 39 27 d7 85 |)..89'..
I: 1f 85 d8 e1 |.... 
I: No ID address. App must call settings_load()
Bluetooth initialized
Advertising successfully started
Connected
I: Swap type: revert
I: Swap type: revert
*** Booting Zephyr OS build v3.2.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x2, copy_done=0x1, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Swap type: revert
I: Starting swap using move algorithm.
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot*** Booting Zephyr OS build v3.2.99-ncs1 ***
Starting Bluetooth Peripheral LBS example
build time: Feb 21 2023 16:50:30
I: 2 Sectors of 4096 bytes
I: alloc wra: 0, fd0
I: data wra: 0, 1c
I: SoftDevice Controller build revision: 
I: 6d 90 41 2a 38 e8 ad 17 |m.A*8...
I: 29 a5 03 38 39 27 d7 85 |)..89'..
I: 1f 85 d8 e1 |.... 
I: No ID address. App must call settings_load()
Bluetooth initialized
Advertising successfully started
Connected
I: Swap type: none
I: Swap type: none

The following steps show the process we did. 
 1. After connect to the nRF52840DK, click " Image " section and choose " ADVANED ". Then " READ " the image. It will send the current image information. 
 
 2. Choose " BASIC " and select a image file (binary or zip file). After click " START ", it will ask you to select mode. Here we choose " Confirm only " and click " START ". 
 
 3. After the process is completed, the " State " will change. The message is " Invalid value (3) ". 
 
 4. Check the image information as the same as the first step and you will see that there are two images in nRF52840DK. But the active image is not the new one but the original one. 
 
 5. Next, test the " Test and confirm " option as the same as the second step. 
 
 6. The result is also the same as the " Confirm only " method. 
 
 7. " READ " image again and you will see the active image is changed to the new one and their locations have also changed. 
 
 8. Send a " RESET " command to nRF52840DK to test if it will use the new image after reset. 
 
 9. " READ " image again and you will see the active is changed to the original one but not the new one, since the image was not successfully confirmed. 
 
 Can anyone help with this? 
 Please feel free to let me know if you need more information. 
 Thanks. 
 
 Best Regards, 
 Kevin

Kevin Lin · Accepted Answer

Hi, 
 I got a real nRF52840DK and tried the same procedure. The result is the same. 
 But after I thought about it carefully, the content of the test code file you gave earlier is not much different from mine, and there is no problem with the DFU test method I used, so the remaining part of the difference is the computer that builds the code. 
 After changing to a new computer and testing the same steps, the DFU function is successful, and the preview-DK board can also use the DFU function normally. I am not sure if the path of the original computer to install the SDK is not the default path causing this problem, but after reinstalling the SDK on the original computer with the default path, DFU is also normal. 
 Please refer to the pictures and attached files below for the results.

Fullscreen 
 nrf52840dk_dfu_ble_2023-03-14.log 
 Download 
 
 *** Booting Zephyr OS build v3.2.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: none
I: Swap type: none
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot*** Booting Zephyr OS build v3.2.99-ncs1 ***
Starting Bluetooth Peripheral LBS example
build time: Mar 14 2023 16:02:42

uart:~$ I: 2 Sectors of 4096 bytes
I: alloc wra: 0, fe8
I: data wra: 0, 0
I: SoftDevice Controller build revision: 
I: 6d 90 41 2a 38 e8 ad 17 |m.A*8...
I: 29 a5 03 38 39 27 d7 85 |)..89'..
I: 1f 85 d8 e1 |.... 
I: No ID address. App must call settings_load()
Bluetooth initialized
Advertising successfully started
Connected
W: Ignoring data for unknown channel ID 0x003a
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
I: Swap type: none
D: writing magic; fa_id=5 off=0x75ff0 (0xf7ff0)
D: writing image_ok; fa_id=5 off=0x75fe8 (0xf7fe8)
D: writing swap_info; fa_id=5 off=0x75fd8 (0xf7fd8), swap_type=0x3 image_num=0x0
I: Swap type: perm
I: Swap type: perm
*** Booting Zephyr OS build v3.2.99-ncs1 ***
I: Starting bootloader
I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=good, swap_type=0x3, copy_done=0x3, image_ok=0x1
I: Boot source: none
I: Swap type: perm
I: Starting swap using move algorithm.
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot*** Booting Zephyr OS build v3.2.99-ncs1 ***
Starting Bluetooth Peripheral LBS example
build time: Mar 14 2023 15:55:08
I: 2 Sectors of 4096 bytes
I: alloc wra: 0, fd0
I: data wra: 0, 1c
I: SoftDevice Controller build revision: 
I: 6d 90 41 2a 38 e8 ad 17 |m.A*8...
I: 29 a5 03 38 39 27 d7 85 |)..89'..
I: 1f 85 d8 e1 |....

I: No ID address. App must call settings_load()
Bluetooth initialized
Advertising successfully started
uart:~$ Connected
W: Ignoring data for unknown channel ID 0x003a
I: Swap type: none
I: Swap type: none

nRF Connect for Mobile (iOS) 
 
 Device Manager (iOS)

Incidentally, because of our project design, the nRF52840 chip plays a central role connecting a peripheral device. However, if the DFU function is to be used, the chip must play the role of a peripheral. Can the chip play the role of the central and peripheral at the same time? Is there any method or information that can be used for reference? 
 According to the above question, do I need to create a new thread? 
 
 Thank you for all your help. 
 Best Regards, 
 Kevin

Aleksander Nowakowski · Answer

Hi, 
 In your design, what is the device acting as peripheral? Is it another device, or a phone? 
 When you have a single connection (e.g. phone - device), both sides can have list of services for the other to use. Both sides can do service discovery, read and write each others characteristics as clients and send notifications as servers. 
 But if you want to have a connection "device A - device B" plus sometimes "phone - device A" to update it, you need to implement it on the fw side. Technically it is possible, but Menon should know much more. 
 I would recommend creating a new thread for a different issue.

Aleksander Nowakowski · Answer

Hi, 
 I will go with you through the code of mcumgr subsystem from where you're getting the error. 
 First, have a look here: https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt.c#L585 . This is where handlers for different commands are registered. The confirm or test commands are sent as Write to IMG_MGMT_ID_STATE command to Image group, that means we need to check img_mgmt_state_write method.: 
 https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt_state.c#L274 
 We are looking for places where an error called MGMT_ERR_EINVAL is returned as rc . 
 I assume the decoding here: https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt_state.c#L290 works, as it is called both when you have confirm=false and confirm=true . The first case seems to be working properly. It sets the pending flag to true . After reset the device is swapping images and runs the new image, which is correct. This method fails when confirm is true , which means the error must come later. 
 The hash sent is equal in both cases, so this also doesn't end here: https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt_state.c#L305 
 Then, the next possible place is here: https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt_state.c#L315 where the manager is looking for the image to be confirmed. This method is defined here: https://github.com/nrfconnect/sdk-zephyr/blob/0cd59b0c43aa0c9d6682066aca74ac05be094169/subsys/mgmt/mcumgr/grp/img_mgmt/src/img_mgmt.c#L233-L247 indicating that perhaps CONFIG_IMG_MGMT_UPDATABLE_IMAGE_NUMBER isn't set properly. 
 Check this out: 
 https://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.9.1/kconfig/CONFIG_IMG_MGMT_UPDATABLE_IMAGE_NUMBER.html#std-kconfig-CONFIG_IMG_MGMT_UPDATABLE_IMAGE_NUMBER 
 If that's not the case, try going further that path. But I suspect that may be it. The next method is just returning the state of images, which is again called for test and confirm, so should work the same way. 
 Hope that helped!

[NCS v2.2.0] - Device Firmware Update (DFU) via OTA using BLE

Top Replies