search

NordicSemiconductor / Android-DFU-Library

Device Firmware Update library and Android app
http://www.nordicsemi.com/dfu
BSD 3-Clause "New" or "Revised" License
773 stars 274 forks source link

dfu update failed (device disconnected) #376

Open Rem193 opened 1 year ago

Rem193 commented 1 year ago

DFU Bootloader version (please complete the following information):

Device information (please complete the following information):

Your question

DFU doesn't work , I get errors:

[DFU] Device has disconnected , on Redmi 9C
[DFU] Connection failed (0x85): GATT ERROR,  on Samsung S20 FE

I notice when my phones are bonded to the nRF device the DFU is working.

DFU library 1.11.0 is working on Redmi 9C with or without bonding.

Logs

On Redmi 9C

V   14:32:01.612    [DFU] DFU service started
V   14:32:01.627    [DFU] Opening file...
I   14:32:01.632    [DFU] Firmware file opened successfully
V   14:32:01.640    [DFU] Connecting to DFU target...
D   14:32:01.647    [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D   14:32:01.915    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I   14:32:01.930    [DFU] Connected to DF:F1:8D:6E:05:FD
V   14:32:01.941    [DFU] Discovering services...
D   14:32:01.958    [DFU] gatt.discoverServices()
I   14:32:02.929    [DFU] Services discovered
V   14:32:02.941    [DFU] Reading DFU version number...
D   14:32:02.951    [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
I   14:32:02.960    [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 01-00
A   14:32:02.969    [DFU] Version number read: 0.1
W   14:32:02.980    [DFU] Application with buttonless update found
V   14:32:02.991    [DFU] Jumping to the DFU Bootloader...
V   14:32:03.001    [DFU] Requesting new MTU...
D   14:32:03.011    [DFU] gatt.requestMtu(517)
I   14:32:03.021    [DFU] MTU changed to: 23
V   14:32:03.029    [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D   14:32:03.036    [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D   14:32:03.045    [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I   14:32:03.086    [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
V   14:32:03.096    [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A   14:32:03.105    [DFU] Notifications enabled
V   14:32:03.115    [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
D   14:32:03.125    [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
A   14:32:03.187    [DFU] Jump to bootloader sent (Op Code = 1, Upload Mode = 4)
I   14:32:03.284    [DFU] Disconnected by the remote device
D   14:32:03.308    [DFU] gatt.refresh() (hidden)
D   14:32:03.335    [DFU] gatt.disconnect()
D   14:32:03.351    [DFU] gatt.close()
D   14:32:03.369    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
V   14:32:03.386    [DFU] DFU service started
I   14:32:03.394    [DFU] Firmware file opened successfully
V   14:32:03.400    [DFU] Connecting to DFU target...
D   14:32:03.405    [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D   14:32:03.871    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I   14:32:03.898    [DFU] Connected to DF:F1:8D:6E:05:FD
V   14:32:03.922    [DFU] Discovering services...
D   14:32:03.958    [DFU] gatt.discoverServices()
I   14:32:04.696    [DFU] Services discovered
V   14:32:04.713    [DFU] Reading DFU version number...
D   14:32:04.727    [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
I   14:32:04.742    [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 06-00
A   14:32:04.754    [DFU] Version number read: 0.6
V   14:32:04.766    [DFU] Requesting new MTU...
D   14:32:04.779    [DFU] gatt.requestMtu(517)
I   14:32:04.799    [DFU] MTU changed to: 23
V   14:32:04.812    [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D   14:32:04.825    [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D   14:32:04.835    [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I   14:32:04.866    [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
V   14:32:04.877    [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A   14:32:04.885    [DFU] Notifications enabled
V   14:32:04.895    [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
D   14:32:04.905    [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
I   14:32:04.913    [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
A   14:32:04.922    [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)
V   14:32:04.928    [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
D   14:32:04.935    [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
I   14:32:04.942    [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-90-C3-00-00
A   14:32:04.947    [DFU] Firmware image size sent (0b, 0b, 50064b)
E   14:32:09.287    [DFU] Device has disconnected
D   14:32:09.314    [DFU] gatt.disconnect()
D   14:32:09.335    [DFU] gatt.close()
D   14:32:09.375    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED

on Samsung S20 FE

V 14:32:01.612 [DFU] DFU service started
V 14:32:01.627 [DFU] Opening file...
I 14:32:01.632 [DFU] Firmware file opened successfully
V 14:32:01.640 [DFU] Connecting to DFU target...
D 14:32:01.647 [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D 14:32:01.915 [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I 14:32:01.930 [DFU] Connected to DF:F1:8D:6E:05:FD
V 14:32:01.941 [DFU] Discovering services...
D 14:32:01.958 [DFU] gatt.discoverServices()
I 14:32:02.929 [DFU] Services discovered
V 14:32:02.941 [DFU] Reading DFU version number...
D 14:32:02.951 [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
I 14:32:02.960 [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 01-00
A 14:32:02.969 [DFU] Version number read: 0.1
W 14:32:02.980 [DFU] Application with buttonless update found
V 14:32:02.991 [DFU] Jumping to the DFU Bootloader...
V 14:32:03.001 [DFU] Requesting new MTU...
D 14:32:03.011 [DFU] gatt.requestMtu(517)
I 14:32:03.021 [DFU] MTU changed to: 23
V 14:32:03.029 [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D 14:32:03.036 [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D 14:32:03.045 [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I 14:32:03.086 [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
V 14:32:03.096 [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A 14:32:03.105 [DFU] Notifications enabled
V 14:32:03.115 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
D 14:32:03.125 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
A 14:32:03.187 [DFU] Jump to bootloader sent (Op Code = 1, Upload Mode = 4)
I 14:32:03.284 [DFU] Disconnected by the remote device
D 14:32:03.308 [DFU] gatt.refresh() (hidden)
D 14:32:03.335 [DFU] gatt.disconnect()
D 14:32:03.351 [DFU] gatt.close()
D 14:32:03.369 [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
V 14:32:03.386 [DFU] DFU service started
I 14:32:03.394 [DFU] Firmware file opened successfully
V 14:32:03.400 [DFU] Connecting to DFU target...
D 14:32:03.405 [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D 14:32:03.871 [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
I 14:32:03.898 [DFU] Connected to DF:F1:8D:6E:05:FD
V 14:32:03.922 [DFU] Discovering services...
D 14:32:03.958 [DFU] gatt.discoverServices()
I 14:32:04.696 [DFU] Services discovered
V 14:32:04.713 [DFU] Reading DFU version number...
D 14:32:04.727 [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
I 14:32:04.742 [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 06-00
A 14:32:04.754 [DFU] Version number read: 0.6
V 14:32:04.766 [DFU] Requesting new MTU...
D 14:32:04.779 [DFU] gatt.requestMtu(517)
I 14:32:04.799 [DFU] MTU changed to: 23
V 14:32:04.812 [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D 14:32:04.825 [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D 14:32:04.835 [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
I 14:32:04.866 [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
V 14:32:04.877 [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A 14:32:04.885 [DFU] Notifications enabled
V 14:32:04.895 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
D 14:32:04.905 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
I 14:32:04.913 [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
A 14:32:04.922 [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)
V 14:32:04.928 [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
D 14:32:04.935 [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
I 14:32:04.942 [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-90-C3-00-00
A 14:32:04.947 [DFU] Firmware image size sent (0b, 0b, 50064b)
E 14:32:09.287 [DFU] Device has disconnected
D 14:32:09.314 [DFU] gatt.disconnect()
D 14:32:09.335 [DFU] gatt.close()
D 14:32:09.375 [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
philips77 commented 1 year ago

Hello, First of all, sorry for super late response. I was buried with other tasks.

DFU library 1.11.0 is working on Redmi 9C with or without bonding.

I wonder why. In Legacy DFU, unless you use forceScan flag, the bootloader is assumed to use the same MAC address then the app. In both logs above it seems like the reconnection to the bootlaoder succeeded, the correct Version number is read and only after sending the sizes the device disconnects.

Are you sending the same fw using 2.3.0 and 1.11.0? Could you share log from 1.11.0?

Rem193 commented 1 year ago

Hello, yes same FW.

I used the same FW and same phone Redmi 9C.

Are you sending the same fw using 2.3.0 and 1.11.0? Could you share log from 1.11.0?

Yes same fw, I bumped on my project the DFU library from 1.11.0 to 1.12.0 and it work well too

How I initialize the DfuServiceInitiator

// Kick off DFU
final DfuServiceInitiator starter = new DfuServiceInitiator(bleAddress)
    .setDeviceName(bluetoothManager.getAdapter().getRemoteDevice(bleAddress).getName())
                .setForceDfu(true)
                .setNumberOfRetries(DFU_NUMBER_OF_RETRIES)
                .setPacketsReceiptNotificationsEnabled(true)
                .setPacketsReceiptNotificationsValue(PACKETS_RECEIPT_NOTIFICATIONS_VALUE)
                .setKeepBond(keepBond);

Logs

DFU lib 2.3.0

2023-10-03 13:58:39.157 16070-16396 DfuImpl              I  Scanning for new address finished with: null
2023-10-03 13:58:39.180 16070-16396 DfuBaseService       I  Starting DFU service in foreground
2023-10-03 13:58:39.223 16070-16396 DfuBaseService       I  Connecting to the device...
2023-10-03 13:58:39.226 16070-16396 BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 13:58:39.226 16070-16396 BluetoothGatt        D  registerApp()
2023-10-03 13:58:39.226 16070-16396 BluetoothGatt        D  registerApp() - UUID=8f634e8f-bacb-4580-8d66-8a9cbe911629
2023-10-03 13:58:39.231 16070-16213 BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-03 13:59:09.256 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=133 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:09.257 16070-16213 DfuBaseService       E  Connection state change error: 133 newState: 0
2023-10-03 13:59:09.257 16070-16396 DfuBaseService       I  Connection error after: 30036 ms
2023-10-03 13:59:09.258 16070-16396 DfuBaseService       E  Device not reachable. Check if the device with address XX:XX:XX:XX:XX:XX is in range, is advertising and is connectable
2023-10-03 13:59:09.259 16070-16396 DfuBaseService       I  Attempt: 1
2023-10-03 13:59:09.260 16070-16396 BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:09.263 16070-16396 DfuBaseService       I  Refreshing result: true
2023-10-03 13:59:09.263 16070-16396 DfuBaseService       I  Cleaning up...
2023-10-03 13:59:09.263 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:09.266 16070-16396 BluetoothGatt        D  close()
2023-10-03 13:59:09.266 16070-16396 BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-03 13:59:09.268 16070-16396 DfuBaseService       I  Restarting the service
2023-10-03 13:59:09.289 16070-16396 DfuBaseService       I  Starting DFU service in foreground
2023-10-03 13:59:09.316 16070-16396 DfuBaseService       I  Connecting to the device...
2023-10-03 13:59:09.319 16070-16396 BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 13:59:09.319 16070-16396 BluetoothGatt        D  registerApp()
2023-10-03 13:59:09.319 16070-16396 BluetoothGatt        D  registerApp() - UUID=fd1557c6-0b8c-405e-85a3-af2b8b335726
2023-10-03 13:59:09.326 16070-16213 BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-03 13:59:39.346 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=133 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:39.346 16070-16213 DfuBaseService       E  Connection state change error: 133 newState: 0
2023-10-03 13:59:39.347 16070-16396 DfuBaseService       I  Connection error after: 30033 ms
2023-10-03 13:59:39.347 16070-16396 DfuBaseService       E  Device not reachable. Check if the device with address XX:XX:XX:XX:XX:XX is in range, is advertising and is connectable
2023-10-03 13:59:39.348 16070-16396 DfuBaseService       I  Attempt: 2
2023-10-03 13:59:39.349 16070-16396 BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:39.352 16070-16396 DfuBaseService       I  Refreshing result: true
2023-10-03 13:59:39.352 16070-16396 DfuBaseService       I  Cleaning up...
2023-10-03 13:59:39.353 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:39.358 16070-16396 BluetoothGatt        D  close()
2023-10-03 13:59:39.358 16070-16396 BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-03 13:59:39.361 16070-16396 DfuBaseService       I  Restarting the service
2023-10-03 13:59:39.380 16070-16396 DfuBaseService       I  Starting DFU service in foreground
2023-10-03 13:59:39.405 16070-16396 DfuBaseService       I  Connecting to the device...
2023-10-03 13:59:39.410 16070-16396 BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 13:59:39.410 16070-16396 BluetoothGatt        D  registerApp()
2023-10-03 13:59:39.410 16070-16396 BluetoothGatt        D  registerApp() - UUID=eabd4319-5649-4408-96fc-77c422e97aca
2023-10-03 13:59:39.417 16070-16213 BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-03 13:59:40.088 16070-16070 DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-03 13:59:40.095 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:40.095 16070-16213 DfuBaseService       I  Connected to GATT server
2023-10-03 13:59:40.100 16070-16213 BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:40.102 16070-16213 DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-03 13:59:40.521 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-03 13:59:41.104 16070-16213 BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-03 13:59:41.105 16070-16213 DfuBaseService       I  Services discovered
2023-10-03 13:59:41.129 16070-16396 DfuImpl              I  Reading DFU version number...
2023-10-03 13:59:41.206 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=39 latency=0 timeout=500 status=0
2023-10-03 13:59:41.209 16070-16396 DfuImpl              I  Version number read: 0.1 -> Application with Legacy buttonless update from SDK 7.0 or newer
2023-10-03 13:59:41.214 16070-16396 DfuImpl              W  Application with legacy buttonless update found
2023-10-03 13:59:41.216 16070-16396 DfuImpl              I  Requesting MTU = 517
2023-10-03 13:59:41.218 16070-16396 BluetoothGatt        D  configureMTU() - device: XX:XX:XX:XX:XX:XX mtu: 517
2023-10-03 13:59:41.302 16070-16213 BluetoothGatt        D  onConfigureMTU() - Device=XX:XX:XX:XX:XX:XX mtu=23 status=0
2023-10-03 13:59:41.303 16070-16213 DfuImpl              I  MTU changed to: 23
2023-10-03 13:59:41.304 16070-16396 DfuImpl              I  Enabling notifications...
2023-10-03 13:59:41.305 16070-16396 BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-03 13:59:41.423 16070-16396 DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-03 13:59:41.501 16070-16396 DfuBaseService       I  Disconnecting from the device...
2023-10-03 13:59:41.502 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:41.511 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:41.511 16070-16213 DfuBaseService       I  Disconnected from GATT server
2023-10-03 13:59:41.513 16070-16396 DfuImpl              I  Device disconnected
2023-10-03 13:59:41.518 16070-16396 BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:41.521 16070-16396 DfuBaseService       I  Refreshing result: true
2023-10-03 13:59:41.521 16070-16396 DfuBaseService       I  Cleaning up...
2023-10-03 13:59:41.522 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:41.526 16070-16396 BluetoothGatt        D  close()
2023-10-03 13:59:41.526 16070-16396 BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-03 13:59:41.528 16070-16396 DfuImpl              I  Restarting to bootloader mode
2023-10-03 13:59:41.552 16070-16213 BluetoothLeScanner   D  onScannerRegistered() - status=0 scannerId=8 mScannerId=0
2023-10-03 13:59:41.606 16070-16070 DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2023-10-03 13:59:41.991 16070-16396 BluetoothAdapter     D  isLeEnabled(): ON
2023-10-03 13:59:42.003 16070-16396 DfuImpl              I  Scanning for new address finished with: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:42.025 16070-16396 DfuBaseService       I  Starting DFU service in foreground
2023-10-03 13:59:42.054 16070-16396 DfuBaseService       I  Connecting to the device...
2023-10-03 13:59:42.056 16070-16396 BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 13:59:42.056 16070-16396 BluetoothGatt        D  registerApp()
2023-10-03 13:59:42.056 16070-16396 BluetoothGatt        D  registerApp() - UUID=8af95345-a3dd-434b-85c5-b846d306a75f
2023-10-03 13:59:42.060 16070-16213 BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-03 13:59:42.333 16070-16070 DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-03 13:59:42.337 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:42.338 16070-16213 DfuBaseService       I  Connected to GATT server
2023-10-03 13:59:42.342 16070-16213 BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:42.345 16070-16213 DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-03 13:59:42.807 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 13:59:43.016 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-03 13:59:43.161 16070-16213 BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-03 13:59:43.162 16070-16213 DfuBaseService       I  Services discovered
2023-10-03 13:59:43.188 16070-16396 DfuImpl              I  Reading DFU version number...
2023-10-03 13:59:43.213 16070-16396 DfuImpl              I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2023-10-03 13:59:43.220 16070-16396 DfuImpl              W  Legacy DFU bootloader found
2023-10-03 13:59:43.220 16070-16396 DfuImpl              I  Requesting MTU = 517
2023-10-03 13:59:43.222 16070-16396 BluetoothGatt        D  configureMTU() - device: XX:XX:XX:XX:XX:XX mtu: 517
2023-10-03 13:59:43.233 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 13:59:43.256 16070-16213 BluetoothGatt        D  onConfigureMTU() - Device=XX:XX:XX:XX:XX:XX mtu=23 status=0
2023-10-03 13:59:43.258 16070-16213 DfuImpl              I  MTU changed to: 23
2023-10-03 13:59:43.259 16070-16396 DfuImpl              I  Enabling notifications...
2023-10-03 13:59:43.260 16070-16396 BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-03 13:59:43.305 16070-16396 DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-03 13:59:43.348 16070-16396 DfuImpl              I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-03 13:59:43.730 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 13:59:47.736 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=8 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:47.736 16070-16213 DfuBaseService       W  Target device disconnected with status: 8
2023-10-03 13:59:47.738 16070-16396 DfuBaseService       E  Unable to write Op Code: device disconnected
2023-10-03 13:59:47.738 16070-16396 DfuBaseService       I  Cleaning up...
2023-10-03 13:59:47.738 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:47.742 16070-16396 BluetoothGatt        D  close()
2023-10-03 13:59:47.742 16070-16396 BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-03 13:59:47.746 16070-16396 DfuBaseService       I  Restarting the service (1 /3)
2023-10-03 13:59:47.756 16070-16070 DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2023-10-03 13:59:47.776 16070-16396 DfuBaseService       I  Starting DFU service in foreground
2023-10-03 13:59:47.851 16070-16396 DfuBaseService       I  Connecting to the device...
2023-10-03 13:59:47.853 16070-16396 BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 13:59:47.853 16070-16396 BluetoothGatt        D  registerApp()
2023-10-03 13:59:47.853 16070-16396 BluetoothGatt        D  registerApp() - UUID=3fe11183-9959-4223-b18c-a88669e4e803
2023-10-03 13:59:47.856 16070-16213 BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-03 13:59:49.204 16070-16070 DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-03 13:59:49.213 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:49.214 16070-16213 DfuBaseService       I  Connected to GATT server
2023-10-03 13:59:49.218 16070-16213 BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:49.221 16070-16213 DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-03 13:59:49.633 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-03 13:59:50.224 16070-16213 BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-03 13:59:50.224 16070-16213 DfuBaseService       I  Services discovered
2023-10-03 13:59:50.246 16070-16396 DfuImpl              I  Reading DFU version number...
2023-10-03 13:59:50.272 16070-16396 DfuImpl              I  Version number read: 0.1 -> Application with Legacy buttonless update from SDK 7.0 or newer
2023-10-03 13:59:50.276 16070-16396 DfuImpl              W  Application with legacy buttonless update found
2023-10-03 13:59:50.278 16070-16396 DfuImpl              I  Requesting MTU = 517
2023-10-03 13:59:50.280 16070-16396 BluetoothGatt        D  configureMTU() - device: XX:XX:XX:XX:XX:XX mtu: 517
2023-10-03 13:59:50.325 16070-16213 BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=39 latency=0 timeout=500 status=0
2023-10-03 13:59:50.327 16070-16213 BluetoothGatt        D  onConfigureMTU() - Device=XX:XX:XX:XX:XX:XX mtu=23 status=0
2023-10-03 13:59:50.329 16070-16213 DfuImpl              I  MTU changed to: 23
2023-10-03 13:59:50.329 16070-16396 DfuImpl              I  Enabling notifications...
2023-10-03 13:59:50.332 16070-16396 BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-03 13:59:50.424 16070-16396 DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-03 13:59:50.542 16070-16396 DfuBaseService       I  Disconnecting from the device...
2023-10-03 13:59:50.544 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:50.553 16070-16213 BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 13:59:50.553 16070-16213 DfuBaseService       I  Disconnected from GATT server
2023-10-03 13:59:50.554 16070-16396 DfuImpl              I  Device disconnected
2023-10-03 13:59:50.557 16070-16396 BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:50.560 16070-16396 DfuBaseService       I  Refreshing result: true
2023-10-03 13:59:50.560 16070-16396 DfuBaseService       I  Cleaning up...
2023-10-03 13:59:50.561 16070-16396 BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-03 13:59:50.563 16070-16396 BluetoothGatt        D  close()

DFU lib 1.12.0

2023-10-03 14:12:46.616 18024-18554 DfuBaseService    I  Connecting to the device...
2023-10-03 14:12:46.620 18024-18554 BluetoothGatt     D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-03 14:12:46.620 18024-18554 BluetoothGatt     D  registerApp()
2023-10-03 14:12:46.620 18024-18554 BluetoothGatt     D  registerApp() - UUID=f82f727e-7c97-4908-ba76-f753dd0c30cf
2023-10-03 14:12:46.625 18024-18454 BluetoothGatt     D  onClientRegistered() - status=0 clientIf=8
2023-10-03 14:12:46.769 18024-18024 DfuBaseService    I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-03 14:12:46.782 18024-18454 BluetoothGatt     D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-03 14:12:46.782 18024-18454 DfuBaseService    I  Connected to GATT server
2023-10-03 14:12:46.791 18024-18454 BluetoothGatt     D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-03 14:12:46.798 18024-18454 DfuBaseService    I  Attempting to start service discovery... succeed
2023-10-03 14:12:47.246 18024-18454 BluetoothGatt     D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 14:12:47.455 18024-18454 BluetoothGatt     D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-03 14:12:47.592 18024-18454 BluetoothGatt     D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-03 14:12:47.592 18024-18454 DfuBaseService    I  Services discovered
2023-10-03 14:12:47.672 18024-18454 BluetoothGatt     D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 14:12:48.483 18024-18454 BluetoothGatt     D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-03 14:12:48.606 18024-18554 DfuImpl           I  Reading DFU version number...
2023-10-03 14:12:48.641 18024-18554 DfuImpl           I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2023-10-03 14:12:48.645 18024-18554 DfuImpl           W  Legacy DFU bootloader found
2023-10-03 14:12:48.645 18024-18554 DfuImpl           I  Requesting MTU = 517
2023-10-03 14:12:48.645 18024-18554 BluetoothGatt     D  configureMTU() - device: XX:XX:XX:XX:XX:XX mtu: 517
2023-10-03 14:12:48.687 18024-18454 BluetoothGatt     D  onConfigureMTU() - Device=XX:XX:XX:XX:XX:XX mtu=23 status=0
2023-10-03 14:12:48.687 18024-18454 DfuImpl           I  MTU changed to: 23
2023-10-03 14:12:49.689 18024-18554 DfuImpl           I  Enabling notifications...
2023-10-03 14:12:49.691 18024-18554 BluetoothGatt     D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-03 14:12:50.746 18024-18554 DfuImpl           I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-03 14:12:50.804 18024-18554 DfuImpl           I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-03 14:12:57.329 18024-18554 DfuImpl           I  Sending the Initialize DFU Parameters START (Op Code = 2, Value = 0)
2023-10-03 14:12:57.373 18024-18554 DfuImpl           I  Sending 14 bytes of init packet
2023-10-03 14:12:57.373 18024-18554 DfuImpl           I  Sending init packet (Value = FF-FF-DD-DD-FF-FF-FF-FF-01-00-64-00-DF-26)
2023-10-03 14:12:57.382 18024-18554 DfuImpl           I  Sending the Initialize DFU Parameters COMPLETE (Op Code = 2, Value = 1)
2023-10-03 14:12:57.462 18024-18554 DfuImpl           I  Sending the number of packets before notifications (Op Code = 8, Value = 12)
2023-10-03 14:12:57.508 18024-18554 DfuImpl           I  Sending Receive Firmware Image request (Op Code = 3)
2023-10-03 14:12:57.577 18024-18554 DfuImpl           I  Uploading firmware...
philips77 commented 1 year ago

Did you try disabling MTU request when using 2.3.0? It can be fine using DfuServiceInitiator. I'll go though the difference between those 2 tomorrow.

Rem193 commented 1 year ago

I disabled the MTU request with 2.3.0 but I got the same behavior.

DfuServiceInitiator

// Kick off DFU
final DfuServiceInitiator starter = new DfuServiceInitiator(bleAddress)
        .setDeviceName(bluetoothManager.getAdapter().getRemoteDevice(bleAddress).getName())
        .setForceDfu(true)
        .disableMtuRequest()
        .setNumberOfRetries(DFU_NUMBER_OF_RETRIES)
        .setPacketsReceiptNotificationsEnabled(true)
        .setPacketsReceiptNotificationsValue(PACKETS_RECEIPT_NOTIFICATIONS_VALUE)
        .setKeepBond(keepBond);

Logs 2.3.0

2023-10-04 09:42:19.854  7438-7951  DfuBaseService       I  Starting DFU service in foreground
2023-10-04 09:42:19.895  7438-7951  DfuBaseService       I  Connecting to the device...
2023-10-04 09:42:19.898  7438-7951  BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-04 09:42:19.899  7438-7951  BluetoothGatt        D  registerApp()
2023-10-04 09:42:19.899  7438-7951  BluetoothGatt        D  registerApp() - UUID=803c2bb5-b4a9-4d68-ac5d-021cb39482e0
2023-10-04 09:42:19.902  7438-7456  BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-04 09:42:20.345  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-04 09:42:20.346  7438-7456  BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:20.346  7438-7456  DfuBaseService       I  Connected to GATT server
2023-10-04 09:42:20.350  7438-7456  BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:20.352  7438-7456  DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-04 09:42:20.844  7438-7456  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:21.049  7438-7456  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-04 09:42:21.193  7438-7456  BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-04 09:42:21.193  7438-7456  DfuBaseService       I  Services discovered
2023-10-04 09:42:21.214  7438-7951  DfuImpl              I  Reading DFU version number...
2023-10-04 09:42:21.237  7438-7951  DfuImpl              I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2023-10-04 09:42:21.241  7438-7951  DfuImpl              W  Legacy DFU bootloader found
2023-10-04 09:42:21.242  7438-7951  DfuImpl              I  Enabling notifications...
2023-10-04 09:42:21.243  7438-7951  BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-04 09:42:21.253  7438-7456  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:21.300  7438-7951  DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-04 09:42:21.344  7438-7951  DfuImpl              I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-04 09:42:21.781  7438-7456  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:25.786  7438-7456  BluetoothGatt        D  onClientConnectionState() - status=8 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:25.786  7438-7456  DfuBaseService       W  Target device disconnected with status: 8
2023-10-04 09:42:25.787  7438-7951  DfuBaseService       E  Unable to write Op Code: device disconnected
2023-10-04 09:42:25.787  7438-7951  DfuBaseService       I  Cleaning up...
2023-10-04 09:42:25.788  7438-7951  BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:25.791  7438-7951  BluetoothGatt        D  close()
2023-10-04 09:42:25.792  7438-7951  BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-04 09:42:25.794  7438-7951  DfuBaseService       I  Restarting the service (1 /3)
2023-10-04 09:42:25.798  7438-7438  DfuBaseService       I  Action received:  android.bluetooth.device.action.ACL_DISCONNECTED
2023-10-04 09:42:25.814  7438-7951  DfuBaseService       I  Starting DFU service in foreground
2023-10-04 09:42:25.872  7438-7951  DfuBaseService       I  Connecting to the device...
2023-10-04 09:42:25.874  7438-7951  BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-04 09:42:25.875  7438-7951  BluetoothGatt        D  registerApp()
2023-10-04 09:42:25.875  7438-7951  BluetoothGatt        D  registerApp() - UUID=b9ca2e06-c459-4a90-a26f-010691bab74d
2023-10-04 09:42:25.883  7438-7456  BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-04 09:42:26.249  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-04 09:42:26.253  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:26.254  7438-7909  DfuBaseService       I  Connected to GATT server
2023-10-04 09:42:26.258  7438-7909  BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:26.261  7438-7909  DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-04 09:42:26.679  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-04 09:42:27.245  7438-7909  BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-04 09:42:27.246  7438-7909  DfuBaseService       I  Services discovered
2023-10-04 09:42:27.273  7438-7951  DfuImpl              I  Reading DFU version number...
2023-10-04 09:42:27.295  7438-7951  DfuImpl              I  Version number read: 0.1 -> Application with Legacy buttonless update from SDK 7.0 or newer
2023-10-04 09:42:27.298  7438-7951  DfuImpl              W  Application with legacy buttonless update found
2023-10-04 09:42:27.300  7438-7951  DfuImpl              I  Enabling notifications...
2023-10-04 09:42:27.301  7438-7951  BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-04 09:42:27.330  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=39 latency=0 timeout=500 status=0
2023-10-04 09:42:27.381  7438-7951  DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-04 09:42:27.529  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=19 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:27.529  7438-7909  DfuBaseService       W  Target device disconnected with status: 19
2023-10-04 09:42:27.530  7438-7951  DfuImpl              I  Device disconnected
2023-10-04 09:42:27.532  7438-7951  BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:27.534  7438-7951  DfuBaseService       I  Refreshing result: true
2023-10-04 09:42:27.534  7438-7951  DfuBaseService       I  Cleaning up...
2023-10-04 09:42:27.535  7438-7951  BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:27.538  7438-7951  BluetoothGatt        D  close()
2023-10-04 09:42:27.538  7438-7951  BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-04 09:42:27.539  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2023-10-04 09:42:27.541  7438-7951  DfuImpl              I  Restarting to bootloader mode
2023-10-04 09:42:27.552  7438-7951  DfuBaseService       I  Starting DFU service in foreground
2023-10-04 09:42:27.593  7438-7951  DfuBaseService       I  Connecting to the device...
2023-10-04 09:42:27.598  7438-7951  BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-04 09:42:27.598  7438-7951  BluetoothGatt        D  registerApp()
2023-10-04 09:42:27.598  7438-7951  BluetoothGatt        D  registerApp() - UUID=ee9b9f74-fca7-43ed-9b82-67e362dfec87
2023-10-04 09:42:27.601  7438-7909  BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-04 09:42:28.099  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-04 09:42:28.101  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:28.101  7438-7909  DfuBaseService       I  Connected to GATT server
2023-10-04 09:42:28.104  7438-7909  BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:28.105  7438-7909  DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-04 09:42:28.585  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:28.789  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-04 09:42:28.925  7438-7909  BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-04 09:42:28.926  7438-7909  DfuBaseService       I  Services discovered
2023-10-04 09:42:28.950  7438-7951  DfuImpl              I  Reading DFU version number...
2023-10-04 09:42:28.969  7438-7951  DfuImpl              I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2023-10-04 09:42:28.972  7438-7951  DfuImpl              W  Legacy DFU bootloader found
2023-10-04 09:42:28.972  7438-7951  DfuImpl              I  Enabling notifications...
2023-10-04 09:42:28.973  7438-7951  BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-04 09:42:28.993  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:29.017  7438-7951  DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-04 09:42:29.062  7438-7951  DfuImpl              I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-04 09:42:29.499  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
2023-10-04 09:42:33.506  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=8 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:33.506  7438-7909  DfuBaseService       W  Target device disconnected with status: 8
2023-10-04 09:42:33.507  7438-7951  DfuBaseService       E  Unable to write Op Code: device disconnected
2023-10-04 09:42:33.507  7438-7951  DfuBaseService       I  Cleaning up...
2023-10-04 09:42:33.508  7438-7951  BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:33.512  7438-7951  BluetoothGatt        D  close()
2023-10-04 09:42:33.512  7438-7951  BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-04 09:42:33.516  7438-7951  DfuBaseService       I  Restarting the service (1 /3)
2023-10-04 09:42:33.523  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2023-10-04 09:42:33.548  7438-7951  DfuBaseService       I  Starting DFU service in foreground
2023-10-04 09:42:33.590  7438-7951  DfuBaseService       I  Connecting to the device...
2023-10-04 09:42:33.592  7438-7951  BluetoothGatt        D  connect() - device: XX:XX:XX:XX:XX:XX, auto: false
2023-10-04 09:42:33.592  7438-7951  BluetoothGatt        D  registerApp()
2023-10-04 09:42:33.592  7438-7951  BluetoothGatt        D  registerApp() - UUID=42e2e631-6050-4ac8-bb53-d9b632e457e0
2023-10-04 09:42:33.603  7438-7909  BluetoothGatt        D  onClientRegistered() - status=0 clientIf=8
2023-10-04 09:42:35.367  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2023-10-04 09:42:35.373  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=0 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:35.374  7438-7909  DfuBaseService       I  Connected to GATT server
2023-10-04 09:42:35.384  7438-7909  BluetoothGatt        D  discoverServices() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:35.386  7438-7909  DfuBaseService       I  Attempting to start service discovery... succeed
2023-10-04 09:42:35.792  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=6 latency=0 timeout=500 status=0
2023-10-04 09:42:36.359  7438-7909  BluetoothGatt        D  onSearchComplete() = Device=XX:XX:XX:XX:XX:XX Status=0
2023-10-04 09:42:36.360  7438-7909  DfuBaseService       I  Services discovered
2023-10-04 09:42:36.377  7438-7951  DfuImpl              I  Reading DFU version number...
2023-10-04 09:42:36.400  7438-7951  DfuImpl              I  Version number read: 0.1 -> Application with Legacy buttonless update from SDK 7.0 or newer
2023-10-04 09:42:36.405  7438-7951  DfuImpl              W  Application with legacy buttonless update found
2023-10-04 09:42:36.405  7438-7951  DfuImpl              I  Enabling notifications...
2023-10-04 09:42:36.407  7438-7951  BluetoothGatt        D  setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
2023-10-04 09:42:36.442  7438-7909  BluetoothGatt        D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=39 latency=0 timeout=500 status=0
2023-10-04 09:42:36.493  7438-7951  DfuImpl              I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-04 09:42:36.690  7438-7909  BluetoothGatt        D  onClientConnectionState() - status=19 clientIf=8 device=XX:XX:XX:XX:XX:XX
2023-10-04 09:42:36.690  7438-7909  DfuBaseService       W  Target device disconnected with status: 19
2023-10-04 09:42:36.691  7438-7951  DfuImpl              I  Device disconnected
2023-10-04 09:42:36.693  7438-7951  BluetoothGatt        D  refresh() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:36.695  7438-7951  DfuBaseService       I  Refreshing result: true
2023-10-04 09:42:36.695  7438-7951  DfuBaseService       I  Cleaning up...
2023-10-04 09:42:36.695  7438-7951  BluetoothGatt        D  cancelOpen() - device: XX:XX:XX:XX:XX:XX
2023-10-04 09:42:36.696  7438-7951  BluetoothGatt        D  close()
2023-10-04 09:42:36.697  7438-7951  BluetoothGatt        D  unregisterApp() - mClientIf=8
2023-10-04 09:42:36.698  7438-7951  DfuImpl              I  Restarting to bootloader mode
2023-10-04 09:42:36.703  7438-7438  DfuBaseService       I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED
philips77 commented 1 year ago

Hmm.. I see that 1.11 spends almost 7 seconds erasing the secondary slot:

2023-10-03 14:12:50.746 I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2023-10-03 14:12:50.804 I  Sending image size array to DFU Packet (0b, 0b, 57684b)
// 6.5 seconds pass
2023-10-03 14:12:57.329 I  Sending the Initialize DFU Parameters START (Op Code = 2, Value = 0)
2023-10-03 14:12:57.373 I  Sending 14 bytes of init packet
2023-10-03 14:12:57.373 I  Sending init packet (Value = FF-FF-DD-DD-FF-FF-FF-FF-01-00-64-00-DF-26)
2023-10-03 14:12:57.382 I  Sending the Initialize DFU Parameters COMPLETE (Op Code = 2, Value = 1)

but 2.3.0 gets a disconnection after just 4:

2023-10-04 09:42:21.344  I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-04 09:42:21.781  D  onConnectionUpdated() - Device=EA:47:BA:46:6D:AB interval=18 latency=0 timeout=400 status=0
// disconnection after 4 seconds
2023-10-04 09:42:25.786  D  onClientConnectionState() - status=8 clientIf=8 device=EA:47:BA:46:6D:AB
Rem193 commented 1 year ago

Still have the issue with some mobiles with the latest app DFU 2.3.1

DFU, 2023-10-25
phone: Redmi 9C
os version: Android 10
bluetooth version: Bluetooth 5.0

Device (XX:XX:XX:XX:FB:B0)
V   13:56:31.834    [DFU] DFU service started
V   13:56:31.848    [DFU] Opening file...
W   13:56:32.167    [DFU] Firmware file opened successfully
V   13:56:32.176    [DFU] Connecting to DFU target...
D   13:56:32.184    [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D   13:56:32.820    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
W   13:56:32.832    [DFU] Connected to XX:XX:XX:XX:FB:B0
V   13:56:32.841    [DFU] Discovering services...
D   13:56:32.849    [DFU] gatt.discoverServices()
W   13:56:33.805    [DFU] Services discovered
V   13:56:33.814    [DFU] Reading DFU version number...
D   13:56:33.823    [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
W   13:56:33.831    [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 01-00
A   13:56:33.842    [DFU] Version number read: 0.1
W   13:56:33.852    [DFU] Application with buttonless update found
V   13:56:33.860    [DFU] Jumping to the DFU Bootloader...
V   13:56:33.870    [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D   13:56:33.880    [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D   13:56:33.889    [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
W   13:56:33.904    [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123
V   13:56:33.919    [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A   13:56:33.936    [DFU] Notifications enabled
V   13:56:33.952    [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
D   13:56:33.957    [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
A   13:56:33.963    [DFU] Jump to bootloader sent (Op Code = 1, Upload Mode = 4)
V   13:56:33.968    [DFU] Disconnecting...
D   13:56:33.974    [DFU] gatt.disconnect()
W   13:56:33.979    [DFU] Disconnected
D   13:56:33.984    [DFU] gatt.refresh() (hidden)
D   13:56:33.996    [DFU] gatt.disconnect()
D   13:56:34.004    [DFU] gatt.close()
V   13:56:34.013    [DFU] Scanning for the DFU Bootloader... (timeout 2000 ms)
D   13:56:34.025    [DFU] wait(1000)
D   13:56:34.031    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
W   13:56:35.094    [DFU] DFU Bootloader found with address XX:XX:XX:XX:FB:B0
V   13:56:35.130    [DFU] DFU service started
W   13:56:35.142    [DFU] Firmware file opened successfully
V   13:56:35.151    [DFU] Connecting to DFU target...
D   13:56:35.157    [DFU] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferredPhy = LE_1M | LE_2M)
D   13:56:35.396    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
W   13:56:35.428    [DFU] Connected to XX:XX:XX:XX:FB:B0
V   13:56:35.450    [DFU] Discovering services...
D   13:56:35.464    [DFU] gatt.discoverServices()
W   13:56:36.220    [DFU] Services discovered
V   13:56:36.237    [DFU] Reading DFU version number...
D   13:56:36.250    [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)
W   13:56:36.263    [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 06-00
A   13:56:36.274    [DFU] Version number read: 0.6
V   13:56:36.285    [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D   13:56:36.298    [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D   13:56:36.310    [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
W   13:56:36.325    [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123
V   13:56:36.338    [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
A   13:56:36.351    [DFU] Notifications enabled
V   13:56:36.359    [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
D   13:56:36.368    [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
W   13:56:36.375    [DFU] Data written to 00001531-1212-efde-1523-785feabcd123
A   13:56:36.384    [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)
V   13:56:36.397    [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-54-E1-00-00
D   13:56:36.405    [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
W   13:56:36.415    [DFU] Data written to 00001532-1212-efde-1523-785feabcd123
A   13:56:36.425    [DFU] Firmware image size sent (0b, 0b, 57684b)
E   13:56:40.830    [DFU] Device has disconnected
D   13:56:40.849    [DFU] gatt.disconnect()
D   13:56:40.863    [DFU] gatt.close()
D   13:56:40.897    [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
philips77 commented 1 year ago

This, actually, indeed may be due to the remote not sending any packets while it erases the slot. Depending on Supervision Timeout in Connection Parameters the Central will disconnect if nothing is received. ST used to be very long, like 20 sec, not it's around 4-5 seconds, but may vary on different phones.

Have a look at the log I pasted before:

2023-10-04 09:42:21.344  I  Sending image size array to DFU Packet (0b, 0b, 57684b)
2023-10-04 09:42:21.781  D  onConnectionUpdated() - Device=EA:47:BA:46:6D:AB interval=18 latency=0 timeout=400 status=0
// disconnection after 4 seconds
2023-10-04 09:42:25.786  D  onClientConnectionState() - status=8 clientIf=8 device=EA:47:BA:46:6D:AB

The Supervision Timeout was set to 400, which translates to 4 seconds. And exactly after 4 seconds the connection is terminated.

If it is possible to modify the fw to request longer connection interval, that would help. Or, we can add a Connection Priority request from Android just before sending the sizes. Starting from Android 8+ Android requests 5 seconds Supervision Timeout, but seems like you need almost 7.

I wonder why 1.11 works...

philips77 commented 1 year ago

The logs from 1.11 you pasted above also have 4 seconds Supervision Timeout:

2023-10-03 14:12:48.483 18024-18454 BluetoothGatt     D  onConnectionUpdated() - Device=XX:XX:XX:XX:XX:XX interval=18 latency=0 timeout=400 status=0
[...]
2023-10-03 14:12:50.804 18024-18554 DfuImpl           I  Sending image size array to DFU Packet (0b, 0b, 57684b)
// 6.5 seconds
2023-10-03 14:12:57.329 18024-18554 DfuImpl           I  Sending the Initialize DFU Parameters START (Op Code = 2, Value = 0)
philips77 commented 1 year ago

Perhaps it's not the Supervision Timeout, after all.

Rem193 commented 3 months ago

I tried on an other phone (samsung a15) with the latest version (2.5.0) of DFU lib but I still have an issue with the latest one and I notice that with an old version (2.1.0) the update works

I tested both versions on the same phone, same application I only changed the used version of the dfu library. I also tested with the latest nRF Device Firmware Update app from the play store, the FW update doesn't work too.

DFU Bootloader version:

Device information:

With Android DFU lib 2.5.0 (not working)

no.nordicsemi.android:dfu:2.5.0

2024-08-19 14:49:54.071  DfuBaseService  I  DFU service created. Version: 2.5.0
2024-08-19 14:49:54.100  DfuBaseService  I  Starting DFU service in foreground
2024-08-19 14:49:54.121  DfuBaseService  I  Connecting to the device...
2024-08-19 14:49:54.409  DfuBaseService  I  Connected to GATT server
2024-08-19 14:49:54.415  DfuBaseService  I  Attempting to start service discovery... succeed
2024-08-19 14:49:54.419  DfuBaseService  I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2024-08-19 14:49:55.182  DfuBaseService  I  Services discovered
2024-08-19 14:49:55.190  DfuImpl         I  Reading DFU version number...
2024-08-19 14:49:55.214  DfuImpl         I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2024-08-19 14:49:55.215  DfuImpl         W  Legacy DFU bootloader found
2024-08-19 14:49:55.215  DfuImpl         I  Requesting MTU = 517
2024-08-19 14:49:55.260  DfuImpl         I  MTU changed to: 23
2024-08-19 14:49:55.261  DfuImpl         I  Enabling notifications...
2024-08-19 14:49:55.319  DfuImpl         I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2024-08-19 14:49:55.365  DfuImpl         I  Sending image size array to DFU Packet (0b, 0b, 58628b)
2024-08-19 14:50:00.133  DfuBaseService  W  Target device disconnected with status: 8
2024-08-19 14:50:00.134  DfuBaseService  E  Unable to write Op Code: device disconnected
2024-08-19 14:50:00.135  DfuBaseService  I  Cleaning up...
2024-08-19 14:50:00.145  DfuBaseService  I  Action received: android.bluetooth.device.action.ACL_DISCONNECTED

With Android DFU lib 2.1.0 (working)

no.nordicsemi.android:dfu:2.1.0

2024-08-19 14:52:50.627  DfuBaseService  I  Starting DFU service in foreground
2024-08-19 14:52:52.638  DfuBaseService  I  Connecting to the device...
2024-08-19 14:52:52.901  DfuBaseService  I  Connected to GATT server
2024-08-19 14:52:52.906  DfuBaseService  I  Attempting to start service discovery... succeed
2024-08-19 14:52:53.291  DfuBaseService  I  Action received: android.bluetooth.device.action.ACL_CONNECTED
2024-08-19 14:52:53.642  DfuBaseService  I  Services discovered
2024-08-19 14:52:54.670  DfuImpl         I  Reading DFU version number...
2024-08-19 14:52:54.739  DfuImpl         I  Version number read: 0.6 -> Bootloader from SDK 8.0 or newer. Bond sharing supported
2024-08-19 14:52:54.742  DfuImpl         W  Legacy DFU bootloader found
2024-08-19 14:52:54.742  DfuImpl         I  Requesting MTU = 517
2024-08-19 14:52:54.788  DfuImpl         I  MTU changed to: 23
2024-08-19 14:52:55.791  DfuImpl         I  Enabling notifications...
2024-08-19 14:52:56.840  DfuImpl         I  Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2024-08-19 14:52:56.901  DfuImpl         I  Sending image size array to DFU Packet (0b, 0b, 58628b)
2024-08-19 14:53:03.427  DfuImpl         I  Sending the Initialize DFU Parameters START (Op Code = 2, Value = 0)
2024-08-19 14:53:03.467  DfuImpl         I  Sending 14 bytes of init packet
2024-08-19 14:53:03.467  DfuImpl         I  Sending init packet (Value = FF-FF-DD-DD-FF-FF-FF-FF-01-00-64-00-8F-27)
2024-08-19 14:53:03.477  DfuImpl         I  Sending the Initialize DFU Parameters COMPLETE (Op Code = 2, Value = 1)
2024-08-19 14:53:03.540  DfuImpl         I  Sending the number of packets before notifications (Op Code = 8, Value = 12)
2024-08-19 14:53:03.602  DfuImpl         I  Sending Receive Firmware Image request (Op Code = 3)
2024-08-19 14:53:03.671  DfuImpl         I  Uploading firmware...

How I initialize the DfuServiceInitiator

        // Kick off DFU
        final DfuServiceInitiator starter = new DfuServiceInitiator(targetedBleAddress)
                .setDeviceName(bluetoothManager.getAdapter().getRemoteDevice(name)
                .setNumberOfRetries(DFU_NUMBER_OF_RETRIES)
                .setForceDfu(true)
                .setPacketsReceiptNotificationsEnabled(true)
                .setPacketsReceiptNotificationsValue(PACKETS_RECEIPT_NOTIFICATIONS_VALUE)
                .setKeepBond(keepBond);
philips77 commented 4 weeks ago

Hi, I don't know how library version may cause a timeout in BLE communication. I'm about to release a new version (2.7.0), please give it a spin.