Unable to do BLE FOTA using "nRF Connect for Android"

Setup -

1. Zephyr 2.7.0 for firmware build .bin file and signed using imgtool.

2. Working phones - iPhone, Custom Android ROM (Android 12).

3. Not working phones - Xiaomi Note 4, Samsung M51 (Android 12)

Procedure followed -

1. Built the firmware with above mentioned steps, and signed the image.

2. Transferred over the zephyr.signed.bin file to phone.

3. Tried BLE DFU from nRF Connect for Android on phones mentioned in Setup(3).

4. Tried BLE DFU from nRF Connect on phones mentioned in Setup(2).

5. Same file was shared across all the phones.

Issue observed -

1. In Step 4, the firmware update was successful.

2. In Step 3, the firmware update was not attempted with error "DFU File Error".

Relevant logs and images -

1. Not Working -

2. Working -

nRF Connect, 2022-06-29
DT22011203220001 (D4:7B:D2:BF:EA:93)
V	13:10:25.476	Connecting to D4:7B:D2:BF:EA:93...
D	13:10:25.476	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	13:10:26.097	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
D	13:10:26.100	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	13:10:26.102	Connected to D4:7B:D2:BF:EA:93
V	13:10:26.109	Discovering services...
D	13:10:26.109	gatt.discoverServices()
I	13:10:26.801	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
D	13:10:26.966	[Callback] Services discovered with status: 0
I	13:10:26.966	Services discovered
V	13:10:26.980	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 W] (0x2A00)
- Appearance [R] (0x2A01)
- Peripheral Preferred Connection Parameters [R] (0x2A04)
SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
- SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
   Client Characteristic Configuration (0x2902)
D	13:10:26.981	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
I	13:10:27.068	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	13:10:30.984	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)
V	13:10:50.792	[McuMgr] Connecting...
D	13:10:50.794	[McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
D	13:10:50.832	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
I	13:10:50.845	[McuMgr] Connected to D4:7B:D2:BF:EA:93
D	13:10:50.846	[McuMgr] wait(300)
V	13:10:51.147	[McuMgr] Discovering services...
D	13:10:51.148	[McuMgr] gatt.discoverServices()
I	13:10:51.174	[McuMgr] Services discovered
V	13:10:51.175	[McuMgr] Primary service found
V	13:10:51.198	[McuMgr] Requesting new MTU...
D	13:10:51.199	[McuMgr] gatt.requestMtu(498)
I	13:10:51.281	[McuMgr] MTU changed to: 252
D	13:10:51.282	[McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
V	13:10:51.284	[McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
D	13:10:51.287	[McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I	13:10:51.369	[McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
I	13:10:51.370	[McuMgr] Notifications enabled
A	13:10:51.376	[McuMgr] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
V	13:10:51.377	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
D	13:10:51.378	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
I	13:10:51.407	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-02-00-01-00-00-BF-FF
I	13:10:51.506	[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-E8-F4-0F-1E-14-19-DA-D6-B0-F7-4F-B0-01-F1-67-70-D0-84-78-C2-C2-A4-CC-BC-97-66-69-A4-20-C7-81-45-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	13:10:51.512	[McuMgr] Received Header (Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"6PQPHhQZ2taw90+wAfFncNCEeMLCpMy8l2ZppCDHgUU=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
V	13:10:51.537	[McuMgr] Uploading firmware...
A	13:11:18.235	[McuMgr] 229500 bytes sent in 25734 ms (8.92 kB/s)
A	13:11:18.262	[McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 63, Seq: 16, Command: 0) CBOR {}
V	13:11:18.263	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
D	13:11:18.264	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
I	13:11:18.267	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-3F-10-00-BF-FF
I	13:11:18.325	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-3F-10-00-BF-62-72-63-08-FF
A	13:11:18.326	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 63, Seq: 16, Command: 0) CBOR {"rc":8}
W	13:11:18.328	[McuMgr] Error: NOT_SUPPORTED (8)
V	13:11:18.333	[McuMgr] New state: TEST
A	13:11:18.335	[McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 17, Command: 0) CBOR {"confirm":false,"hash":"GFRGqyqtKCsVcCScKiLlA0K66SimU8Z6B5jUHsKhHBo="}
V	13:11:18.336	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
D	13:11:18.337	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
I	13:11:18.354	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-32-00-01-11-00-BF-67-63-6F-6E-66-69-72-6D-F4-64-68-61-73-68-58-20-18-54-46-AB-2A-AD-28-2B-15-70-24-9C-2A-22-E5-03-42-BA-E9-28-A6-53-C6-7A-07-98-D4-1E-C2-A1-1C-1A-FF
I	13:11:18.594	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-F4-00-01-11-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-E8-F4-0F-1E-14-19-DA-D6-B0-F7-4F-B0-01-F1-67-70-D0-84-78-C2-C2-A4-CC-BC-97-66-69-A4-20-C7-81-45-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-18-54-46-AB-2A-AD-28-2B-15-70-24-9C-2A-22-E5-03-42-BA-E9-28-A6-53-C6-7A-07-98-D4-1E-C2-A1-1C-1A-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	13:11:18.595	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
A	13:11:18.597	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 17, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"6PQPHhQZ2taw90+wAfFncNCEeMLCpMy8l2ZppCDHgUU=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"GFRGqyqtKCsVcCScKiLlA0K66SimU8Z6B5jUHsKhHBo=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	13:11:18.601	[McuMgr] New state: RESET
A	13:11:18.618	[McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 0, Seq: 18, Command: 5) CBOR {}
V	13:11:18.620	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
D	13:11:18.620	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
I	13:11:18.622	[McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-00-12-05-BF-FF
I	13:11:18.684	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-02-00-00-12-05-BF-FF
A	13:11:18.686	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 18, Command: 5) CBOR {}
D	13:11:19.508	[Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
E	13:11:19.508	Error 8 (0x8): GATT CONN TIMEOUT
I	13:11:19.508	Disconnected
D	13:11:19.509	[McuMgr] [Callback] Connection state changed with status: 8 and new state: 0 (DISCONNECTED)
W	13:11:19.511	[McuMgr] Error: (0x8): GATT CONN TIMEOUT
I	13:11:19.511	[McuMgr] Disconnected
D	13:11:19.512	[McuMgr] gatt.close()
D	13:11:19.557	[Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
V	13:11:28.700	[McuMgr] Connecting...
D	13:11:28.701	[McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
V	13:11:28.704	[McuMgr] New state: CONFIRM
D	13:11:45.060	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
I	13:11:45.064	[McuMgr] Connected to D4:7B:D2:BF:EA:93
D	13:11:45.067	[McuMgr] wait(300)
D	13:11:45.074	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V	13:11:45.375	[McuMgr] Discovering services...
D	13:11:45.375	[McuMgr] gatt.discoverServices()
I	13:11:45.594	[McuMgr] Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
I	13:11:45.760	[McuMgr] Services discovered
V	13:11:45.761	[McuMgr] Primary service found
V	13:11:45.763	[McuMgr] Requesting new MTU...
D	13:11:45.764	[McuMgr] gatt.requestMtu(498)
I	13:11:45.796	[McuMgr] MTU changed to: 252
D	13:11:45.797	[McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
V	13:11:45.798	[McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
D	13:11:45.799	[McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I	13:11:45.820	[McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
I	13:11:45.821	[McuMgr] Notifications enabled
A	13:11:45.824	[McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 0, Command: 0) CBOR {"confirm":true,"hash":"GFRGqyqtKCsVcCScKiLlA0K66SimU8Z6B5jUHsKhHBo="}
V	13:11:45.825	[McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
D	13:11:45.825	[McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
I	13:11:45.828	[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-18-54-46-AB-2A-AD-28-2B-15-70-24-9C-2A-22-E5-03-42-BA-E9-28-A6-53-C6-7A-07-98-D4-1E-C2-A1-1C-1A-FF
I	13:11:45.864	[McuMgr] Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	13:11:45.999	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-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-18-54-46-AB-2A-AD-28-2B-15-70-24-9C-2A-22-E5-03-42-BA-E9-28-A6-53-C6-7A-07-98-D4-1E-C2-A1-1C-1A-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-E8-F4-0F-1E-14-19-DA-D6-B0-F7-4F-B0-01-F1-67-70-D0-84-78-C2-C2-A4-CC-BC-97-66-69-A4-20-C7-81-45-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	13:11:46.000	[McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 73-00-FF
A	13:11:46.002	[McuMgr] Received Header (Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"0.0.0","hash":"GFRGqyqtKCsVcCScKiLlA0K66SimU8Z6B5jUHsKhHBo=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.0.0","hash":"6PQPHhQZ2taw90+wAfFncNCEeMLCpMy8l2ZppCDHgUU=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
V	13:11:46.007	[McuMgr] Disconnecting...
D	13:11:46.009	[McuMgr] gatt.disconnect()
D	13:11:46.011	[McuMgr] [Callback] Connection state changed with status: 0 and new state: 0 (DISCONNECTED)
I	13:11:46.012	[McuMgr] Disconnected
D	13:11:46.013	[McuMgr] gatt.close()
D	13:11:46.027	gatt.close()
D	13:11:46.028	wait(200)
V	13:11:46.228	Connecting to D4:7B:D2:BF:EA:93...
D	13:11:46.228	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	13:11:46.234	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	13:11:46.234	Connected to D4:7B:D2:BF:EA:93
I	13:11:46.235	MTU changed to: 252
D	13:11:46.237	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	13:11:46.239	MTU changed to: 252
V	13:11:46.249	Discovering services...
D	13:11:46.249	gatt.discoverServices()
V	13:11:46.251	Discovering services...
D	13:11:46.251	gatt.discoverServices()
V	13:11:46.252	Discovering services...
D	13:11:46.252	gatt.discoverServices()
I	13:11:46.764	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
D	13:11:46.893	[Callback] Services discovered with status: 0
I	13:11:46.893	Services discovered
V	13:11:46.899	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)
SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
- SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
   Client Characteristic Configuration (0x2902)
D	13:11:46.900	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
I	13:11:46.988	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
I	13:11:49.913	Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 420ms)

  • "DFU FILE ERROR" says, that the file seems invalid. Are you using the same file on iOS and Android for the test? Is it a ".bin" file, signed? In nRF Connect Device Manager are you seeing any error when selecting the file?

  • in the interest of not having to repeat the problem statement again, shall describe the issue in a structure which makes sense to me.

    I am not sure as to what the exact issue is, but what concerns me is that the BLE DFU does not work. We have been using the exact build environment since the start of this year, same command to sign, same process for going ahead with our Firmware Upgrade process in short.

    Now where we observed issue.

    Setup -

    1. FOTA Upgrade files being used (Signed using the same key) - nunam_dot_v2.5.3.bin and helloWorld.bin (no other file is used)

    2. Board which takes the firmware is based on nRF52833.

    3. iOS - nRF Connect application

    4. Android - nRF Connect and nRF Device Manager applications

    Scenario 1 -

    1. Using iOS nRF Connect application (older than 2.5.3) with both files mentioned in Setup (1).

    2. Logs were provided for this "Bad header received" error occurs.

    3. File upload itself does not start in this scenario.

    Scenario 2 -

    1. Using iOS nRF Connect application (version 2.5.3 update received on Saturday 9th July, 2022) with both files mentioned in Setup(1).

    2. File upload works.

    3. Firmware upgrade is successful.

    Scenario 3 -

    1. Using Android nRF Connect application with both files mentioned in Setup (1).

    2. Logs were provided for this "DFU File Error" seen in the application.

    3. File upload itself does not start in this scenario.

    Scenario 4 -

    1. Using Android nRF Device Manager application with both files mentioned in Setup (1).

    2. This shows the error "Invalid Image file" logs were provided for this as well, which was basically connect -> get error on screen -> disconnect (provided on Friday from nRF Logger).

    3. File upload itself does not start in this scenario.

    Above scenarios are what is seen. Now considering that, if the reason for DFU Failure was a bad file, it should not have succeeded in Scenario 2. As to what the actual issue is, I am not aware. We have been following the same process, and never faced this issue. When we saw this issue, we raised the issue.

    Based on this, if you have any specific requests for logs on any of this, feel free to mention. Or if there are any scenarios that were no covered, and would want to be covered, shall do it. Thank you.

  • Ok, now I get it. It's a different issue on iOS and Android. I'm happy that the iOS version now works for you.

    Let's discuss the Android issue then. It's very interesting, that it used to work for you before. I don't recall modifying anything related to file validation directly. Each bin file contains a header, added during signing, with some TLV fields, including a magic value. I'd have to check what kind of validation is done on Android and compared it to iOS. Than may take some time, as I'm on vacations right now, but I'll ask around for help. Could you share here that helloWorld.bin file?

Related