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

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.

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.

*** 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

Parents Reply Children
  • Hello,

    Sure, we also tried nRF connect Mobile App. The result seems to be the same as nRF Connect Device Manager. We also recorded the same two logs as above, please refer to below.

    nRF Connect, 2023-02-24
    Nordic_LBS (FB:C7:5C:DB:A6:D2)
    V	12:37:45.235	Connecting to FB:C7:5C:DB:A6:D2...
    D	12:37:45.235	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
    D	12:37:45.731	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    I	12:37:45.731	Connected to FB:C7:5C:DB:A6:D2
    D	12:37:45.734	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    V	12:37:45.769	Discovering services...
    D	12:37:45.769	gatt.discoverServices()
    I	12:37:46.169	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
    I	12:37:46.247	PHY updated (TX: LE 2M, RX: LE 2M)
    D	12:37:46.446	[Callback] Services discovered with status: 0
    I	12:37:46.446	Services discovered
    V	12:37:46.489	Generic Attribute (0x1801)
    - Service Changed [I] (0x2A05)
       Client Characteristic Configuration (0x2902)
    - Client Supported Features [R W] (0x2B29)
    - Database Hash [R] (0x2B2A)
    Generic Access (0x1800)
    - Device Name [R] (0x2A00)
    - Appearance [R] (0x2A01)
    - Peripheral Preferred Connection Parameters [R] (0x2A04)
    Nordic LED Button Service (00001523-1212-efde-1523-785feabcd123)
    - Button [N R] (00001524-1212-efde-1523-785feabcd123)
       Client Characteristic Configuration (0x2902)
    - LED [W] (00001525-1212-efde-1523-785feabcd123)
    SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
    - SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
       Client Characteristic Configuration (0x2902)
    D	12:37:46.490	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
    D	12:37:46.494	gatt.setCharacteristicNotification(00001524-1212-efde-1523-785feabcd123, true)
    I	12:37:46.536	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    I	12:37:50.892	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
    V	12:38:06.354	[McuMgr] Connecting...
    D	12:38:06.383	[McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
    D	12:38:06.484	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
    I	12:38:06.508	[McuMgr] Connected to FB:C7:5C:DB:A6:D2
    D	12:38:06.539	[McuMgr] wait(300)
    V	12:38:06.878	[McuMgr] Discovering services...
    D	12:38:06.928	[McuMgr] gatt.discoverServices()
    I	12:38:06.972	[McuMgr] Services discovered
    V	12:38:06.994	[McuMgr] Primary service found
    V	12:38:07.020	[McuMgr] Requesting new MTU...
    D	12:38:07.042	[McuMgr] gatt.requestMtu(498)
    I	12:38:07.170	[McuMgr] MTU changed to: 252
    D	12:38:07.196	[McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
    V	12:38:07.223	[McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
    D	12:38:07.245	[McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
    I	12:38:07.374	[McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
    I	12:38:07.395	[McuMgr] Notifications enabled
    V	12:38:07.418	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:38:07.441	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:38:07.474	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-01-00-00-FF-06-A0
    I	12:38:07.615	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
    A	12:38:07.644	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
    W	12:38:07.669	[McuMgr] Error: NOT_SUPPORTED (8)
    A	12:38:07.704	[McuMgr] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
    V	12:38:07.727	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:38:07.752	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:38:07.788	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-02-00-01-00-00-BF-FF
    I	12:38:07.900	[McuMgr] 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-38-0E-FF-30-BC-E4-CF-5F-CB-96-45-CB-3B-A3-DD-14-77-18-75-12-43-C6-65-61-E7-88-C2-9D-09-84-01-05-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
    A	12:38:07.940	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"OA7/MLzkz1/LlkXLO6PdFHcYdRJDxmVh54jCnQmEAQU=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
    V	12:38:07.989	[McuMgr] Uploading firmware...
    A	12:39:14.733	[McuMgr] 207407 bytes sent in 66441 ms (3.12 kB/s)
    A	12:39:14.754	[McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 63, Seq: 172, Command: 0) CBOR {}
    V	12:39:14.770	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:39:14.790	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:39:14.861	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-3F-AC-00-BF-FF
    I	12:39:14.921	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-3F-AC-00-BF-62-72-63-08-FF
    A	12:39:14.956	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 63, Seq: 172, Command: 0) CBOR {"rc":8}
    W	12:39:14.980	[McuMgr] Error: NOT_SUPPORTED (8)
    V	12:39:15.074	[McuMgr] New state: CONFIRM
    A	12:39:15.105	[McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 173, Command: 0) CBOR {"confirm":true,"hash":"phFNTVe46n2ysXg5vBmU1R93N/xGepwVXosV7+arIF4="}
    V	12:39:15.130	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:39:15.159	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:39:15.205	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-32-00-01-AD-00-BF-67-63-6F-6E-66-69-72-6D-F5-64-68-61-73-68-58-20-A6-11-4D-4D-57-B8-EA-7D-B2-B1-78-39-BC-19-94-D5-1F-77-37-FC-46-7A-9C-15-5E-8B-15-EF-E6-AB-20-5E-FF
    I	12:39:15.323	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-01-AD-00-BF-62-72-63-03-FF
    A	12:39:15.349	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 1, Seq: 173, Command: 0) CBOR {"rc":3}
    W	12:39:15.366	[McuMgr] Error: IN_VALUE (3)
    V	12:39:15.405	[McuMgr] Disconnecting...
    D	12:39:15.424	[McuMgr] gatt.disconnect()
    D	12:39:15.466	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 0 (DISCONNECTED)
    I	12:39:15.485	[McuMgr] Disconnected
    D	12:39:15.514	[McuMgr] gatt.close()
    D	12:39:43.805	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
    E	12:39:43.805	Error 8 (0x8): GATT CONN TIMEOUT
    I	12:39:43.805	Disconnected
    D	12:39:43.848	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
    D	12:39:53.863	gatt.close()
    D	12:39:53.869	wait(200)
    V	12:39:54.072	Connecting to FB:C7:5C:DB:A6:D2...
    D	12:39:54.073	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
    D	12:39:54.609	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    I	12:39:54.609	Connected to FB:C7:5C:DB:A6:D2
    D	12:39:54.635	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    V	12:39:54.656	Discovering services...
    D	12:39:54.656	gatt.discoverServices()
    I	12:39:55.045	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
    I	12:39:55.127	PHY updated (TX: LE 2M, RX: LE 2M)
    D	12:39:55.330	[Callback] Services discovered with status: 0
    I	12:39:55.330	Services discovered
    V	12:39:55.354	Generic Attribute (0x1801)
    - Service Changed [I] (0x2A05)
       Client Characteristic Configuration (0x2902)
    - Client Supported Features [R W] (0x2B29)
    - Database Hash [R] (0x2B2A)
    Generic Access (0x1800)
    - Device Name [R] (0x2A00)
    - Appearance [R] (0x2A01)
    - Peripheral Preferred Connection Parameters [R] (0x2A04)
    Nordic LED Button Service (00001523-1212-efde-1523-785feabcd123)
    - Button [N R] (00001524-1212-efde-1523-785feabcd123)
       Client Characteristic Configuration (0x2902)
    - LED [W] (00001525-1212-efde-1523-785feabcd123)
    SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
    - SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
       Client Characteristic Configuration (0x2902)
    D	12:39:55.354	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
    D	12:39:55.359	gatt.setCharacteristicNotification(00001524-1212-efde-1523-785feabcd123, true)
    I	12:39:55.407	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    I	12:39:59.727	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
    V	12:40:11.675	[McuMgr] Connecting...
    D	12:40:11.700	[McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
    D	12:40:11.790	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
    I	12:40:11.808	[McuMgr] Connected to FB:C7:5C:DB:A6:D2
    D	12:40:11.828	[McuMgr] wait(300)
    V	12:40:12.162	[McuMgr] Discovering services...
    D	12:40:12.195	[McuMgr] gatt.discoverServices()
    I	12:40:12.240	[McuMgr] Services discovered
    V	12:40:12.261	[McuMgr] Primary service found
    V	12:40:12.290	[McuMgr] Requesting new MTU...
    D	12:40:12.318	[McuMgr] gatt.requestMtu(498)
    I	12:40:12.423	[McuMgr] MTU changed to: 252
    D	12:40:12.446	[McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
    V	12:40:12.479	[McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
    D	12:40:12.501	[McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
    I	12:40:12.639	[McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
    I	12:40:12.661	[McuMgr] Notifications enabled
    V	12:40:12.688	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:12.710	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:12.738	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-01-00-00-FF-06-A0
    I	12:40:12.850	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
    A	12:40:12.878	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
    W	12:40:12.902	[McuMgr] Error: NOT_SUPPORTED (8)
    A	12:40:12.937	[McuMgr] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
    V	12:40:12.955	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:12.976	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:13.012	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-02-00-01-00-00-BF-FF
    I	12:40:13.147	[McuMgr] 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-38-0E-FF-30-BC-E4-CF-5F-CB-96-45-CB-3B-A3-DD-14-77-18-75-12-43-C6-65-61-E7-88-C2-9D-09-84-01-05-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-A6-11-4D-4D-57-B8-EA-7D-B2-B1-78-39-BC-19-94-D5-1F-77-37-FC-46-7A-9C-15-5E-8B-15-EF-E6-AB-20-5E-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	12:40:13.192	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
    A	12:40:13.218	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"OA7/MLzkz1/LlkXLO6PdFHcYdRJDxmVh54jCnQmEAQU=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"phFNTVe46n2ysXg5vBmU1R93N/xGepwVXosV7+arIF4=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
    V	12:40:13.260	[McuMgr] Uploading firmware...
    A	12:40:13.291	[McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 63, Seq: 1, Command: 0) CBOR {}
    V	12:40:13.311	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:13.338	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:13.384	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-3F-01-00-BF-FF
    I	12:40:13.548	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-3F-01-00-BF-62-72-63-08-FF
    A	12:40:13.568	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 63, Seq: 1, Command: 0) CBOR {"rc":8}
    W	12:40:13.587	[McuMgr] Error: NOT_SUPPORTED (8)
    V	12:40:13.620	[McuMgr] New state: TEST
    A	12:40:13.639	[McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 2, Command: 0) CBOR {"confirm":false,"hash":"phFNTVe46n2ysXg5vBmU1R93N/xGepwVXosV7+arIF4="}
    V	12:40:13.655	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:13.673	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:13.709	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-32-00-01-02-00-BF-67-63-6F-6E-66-69-72-6D-F4-64-68-61-73-68-58-20-A6-11-4D-4D-57-B8-EA-7D-B2-B1-78-39-BC-19-94-D5-1F-77-37-FC-46-7A-9C-15-5E-8B-15-EF-E6-AB-20-5E-FF
    I	12:40:13.839	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-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-38-0E-FF-30-BC-E4-CF-5F-CB-96-45-CB-3B-A3-DD-14-77-18-75-12-43-C6-65-61-E7-88-C2-9D-09-84-01-05-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-A6-11-4D-4D-57-B8-EA-7D-B2-B1-78-39-BC-19-94-D5-1F-77-37-FC-46-7A-9C-15-5E-8B-15-EF-E6-AB-20-5E-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	12:40:13.870	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
    A	12:40:13.895	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"OA7/MLzkz1/LlkXLO6PdFHcYdRJDxmVh54jCnQmEAQU=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"phFNTVe46n2ysXg5vBmU1R93N/xGepwVXosV7+arIF4=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
    V	12:40:13.973	[McuMgr] New state: RESET
    A	12:40:14.005	[McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 0, Seq: 3, Command: 5) CBOR {}
    V	12:40:14.032	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:14.059	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:14.108	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-00-03-05-BF-FF
    I	12:40:14.249	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-02-00-00-03-05-BF-FF
    A	12:40:14.271	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 3, Command: 5) CBOR {}
    D	12:40:14.988	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
    E	12:40:14.988	Error 8 (0x8): GATT CONN TIMEOUT
    I	12:40:14.988	Disconnected
    D	12:40:15.044	[McuMgr] [Callback] Connection state changed with status: 8 and new state: 0 (DISCONNECTED)
    W	12:40:15.062	[McuMgr] Error: (0x8): GATT CONN TIMEOUT
    I	12:40:15.080	[McuMgr] Disconnected
    D	12:40:15.104	[McuMgr] gatt.close()
    D	12:40:15.154	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
    V	12:40:24.326	[McuMgr] Connecting...
    D	12:40:24.347	[McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
    V	12:40:24.379	[McuMgr] New state: CONFIRM
    D	12:40:35.659	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    D	12:40:35.686	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
    I	12:40:35.715	[McuMgr] Connected to FB:C7:5C:DB:A6:D2
    D	12:40:35.741	[McuMgr] wait(300)
    V	12:40:36.075	[McuMgr] Discovering services...
    D	12:40:36.111	[McuMgr] gatt.discoverServices()
    I	12:40:36.149	[McuMgr] Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
    I	12:40:36.174	[McuMgr] PHY updated (TX: LE 2M, RX: LE 2M)
    I	12:40:36.408	[McuMgr] Services discovered
    V	12:40:36.465	[McuMgr] Primary service found
    V	12:40:36.490	[McuMgr] Requesting new MTU...
    D	12:40:36.516	[McuMgr] gatt.requestMtu(498)
    I	12:40:36.550	[McuMgr] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    I	12:40:36.669	[McuMgr] MTU changed to: 252
    D	12:40:36.691	[McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
    V	12:40:36.721	[McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
    D	12:40:36.741	[McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
    I	12:40:36.872	[McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
    I	12:40:36.895	[McuMgr] Notifications enabled
    V	12:40:36.930	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:36.953	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:36.988	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-01-00-00-FF-06-A0
    I	12:40:37.037	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
    A	12:40:37.066	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
    W	12:40:37.090	[McuMgr] Error: NOT_SUPPORTED (8)
    A	12:40:37.153	[McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 0, Command: 0) CBOR {"confirm":true,"hash":"phFNTVe46n2ysXg5vBmU1R93N/xGepwVXosV7+arIF4="}
    V	12:40:37.171	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D	12:40:37.201	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I	12:40:37.241	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-32-00-01-00-00-BF-67-63-6F-6E-66-69-72-6D-F5-64-68-61-73-68-58-20-A6-11-4D-4D-57-B8-EA-7D-B2-B1-78-39-BC-19-94-D5-1F-77-37-FC-46-7A-9C-15-5E-8B-15-EF-E6-AB-20-5E-FF
    I	12:40:37.360	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-01-00-00-BF-62-72-63-03-FF
    A	12:40:37.384	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 1, Seq: 0, Command: 0) CBOR {"rc":3}
    W	12:40:37.401	[McuMgr] Error: IN_VALUE (3)
    V	12:40:37.437	[McuMgr] Disconnecting...
    D	12:40:37.453	[McuMgr] gatt.disconnect()
    D	12:40:37.484	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 0 (DISCONNECTED)
    I	12:40:37.505	[McuMgr] Disconnected
    D	12:40:37.533	[McuMgr] gatt.close()
    D	12:40:37.580	gatt.close()
    D	12:40:37.582	wait(200)
    V	12:40:37.786	Connecting to FB:C7:5C:DB:A6:D2...
    D	12:40:37.786	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
    D	12:40:37.834	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    I	12:40:37.834	Connected to FB:C7:5C:DB:A6:D2
    D	12:40:37.838	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    V	12:40:37.895	Discovering services...
    D	12:40:37.895	gatt.discoverServices()
    I	12:40:38.247	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
    D	12:40:38.451	[Callback] Services discovered with status: 0
    I	12:40:38.451	Services discovered
    V	12:40:38.464	Generic Attribute (0x1801)
    - Service Changed [I] (0x2A05)
       Client Characteristic Configuration (0x2902)
    - Client Supported Features [R W] (0x2B29)
    - Database Hash [R] (0x2B2A)
    Generic Access (0x1800)
    - Device Name [R] (0x2A00)
    - Appearance [R] (0x2A01)
    - Peripheral Preferred Connection Parameters [R] (0x2A04)
    Nordic LED Button Service (00001523-1212-efde-1523-785feabcd123)
    - Button [N R] (00001524-1212-efde-1523-785feabcd123)
       Client Characteristic Configuration (0x2902)
    - LED [W] (00001525-1212-efde-1523-785feabcd123)
    SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
    - SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
       Client Characteristic Configuration (0x2902)
    D	12:40:38.465	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
    D	12:40:38.469	gatt.setCharacteristicNotification(00001524-1212-efde-1523-785feabcd123, true)
    I	12:40:38.559	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    I	12:40:40.767	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
    D	12:41:02.960	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
    E	12:41:02.960	Error 8 (0x8): GATT CONN TIMEOUT
    I	12:41:02.960	Disconnected
    D	12:41:03.051	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
    

    *** 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 24 2023 12:22:47
    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
    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
    build time: Feb 23 2023 15:47:32
    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
    ############### Test Log - Another Image ###############
    Connected
    *** 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 24 2023 12:22:47
    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
    

    Here is the process we did.

    1. Scan results on nRF Connect. you can see the Nordic_LBS device.

    2. Connect to the Nordic_LBS device. the result as follows.

    3. Click "DFU" icon in the upper right corner and choose "Confirm only" option to update.

    4. This is the result after the "Confirm only" process is completed.

    5. Then use "Test and Confirm" option to try again.

    6. This is the result after the "Test and Confirm" process is completed.

    7. Finally, execute the "nrfjprog -r" command to test if the board will boot from the new image.

    Thanks.

    Best Regards,

    Kevin

Related