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

[aja-nunam]

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 -

Fullscreen ble_fota_working.txt Download

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)

[Aleksander Nowakowski]

Hi, could you share the logs from not working phone, like you did from the working one?

[aja-nunam]

Hello, it's just limited to the picture that I have attached. Would there be additional data that would be logged into the file, cause whatever was shown in the side window seems to be what is present in the log file attached, nothing more than that.

[Aleksander Nowakowski]

Well, the logs should show the same output that you get in the working case. What happens after clicking the dfu button?

Did you try nRF Connect Device Manager app? That one is more focused on Mcumgr, where nRF Connect is more generic.

[aja-nunam]

Please find the logs saved and attached as is, for the phone which is not working

nRF Connect, 2022-07-07
Nunam-Dot (F7:F9:70:4A:AB:1C)
V	11:32:48.464	Connecting to F7:F9:70:4A:AB:1C...
D	11:32:48.464	gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
D	11:32:48.905	[Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
I	11:32:48.905	Connected to F7:F9:70:4A:AB:1C
D	11:32:48.917	[Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
V	11:32:48.934	Discovering services...
D	11:32:48.934	gatt.discoverServices()
I	11:32:49.189	PHY updated (TX: LE 2M, RX: LE 2M)
I	11:32:49.586	Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
D	11:32:49.604	[Callback] Services discovered with status: 0
I	11:32:49.605	Services discovered
V	11:32:49.622	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	11:32:49.622	gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
I	11:32:49.717	Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 5000ms)
I	11:32:54.231	Connection parameters updated (interval: 40.0ms, latency: 0, timeout: 420ms)

[aja-nunam]

Yes, have tried with nRF Connect Device Manager app as well. The same issue persists with that. Even a simple hello world bin file signed with the same key does not work with these phones, while it works with iPhone flawlessly.