search

NordicSemiconductor / Android-DFU-Library

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

Device bricked after retry #131

Closed ABouretz closed 6 years ago

ABouretz commented 6 years ago

Since the introduction of "firstRun", the firmware inputStream is not recreated in case of error and service restarting. We are using the LegacyDFU on our oldest devices with .bin firmware for application update. With the new behaviour, we experimented an error when sending firmware to device with some Samsung smartphones : Response received (Op Code = 3, Status = 6) Device returned error after sending file (error 6): OPERATION FAILED

This is not the problem since the library handles it, closing connection and restarting the service but in the second attempt, the inputStream is not reinitiated.

If the inputStream (AssetInputStream) has been partially read, the .available() that is used to calculate the image size in bytes in the init of the service will return the size of the file minus the bytes already read. The firmware size validation is based on this value, so the transfer is validated with a wrong size and the transmitted file is corrupted resulting in a bricked device.

philips77 commented 6 years ago

Hi, could you post here logs from the DFU process? Also, I don't think the library restarts the service automatically in case of such error.

ABouretz commented 6 years ago 
E/BLE DFU: Level : 1 , Message : [DFU] DFU service started
    Level : 1 , Message : [DFU] Opening file...
E/BLE DFU: Level : 5 , Message : [DFU] Firmware file opened successfully
    Level : 1 , Message : [DFU] Connecting to DFU target...
E/BLE DFU: Level : 0 , Message : [DFU] gatt = device.connectGatt(autoConnect = false)
D/BluetoothGatt: connect() - device: C8:B9:61:03:C5:6B, auto: false
D/BluetoothAdapter: isSecureModeEnabled
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=7d51500d-9bf7-47c4-91cc-2e5494ecbbe0
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=8
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
E/BLE DFU: Level : 5 , Message : [DFU] Connected to C8:B9:61:03:C5:6B
E/BLE DFU: Level : 1 , Message : [DFU] Discovering services...
E/BLE DFU: Level : 0 , Message : [DFU] gatt.discoverServices()
D/BluetoothGatt: discoverServices() - device: C8:B9:61:03:C5:6B
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onSearchComplete() = Device=C8:B9:61:03:C5:6B Status=0
E/BLE DFU: Level : 5 , Message : [DFU] Services discovered
E/BLE DFU: Level : 0 , Message : [DFU] wait(1000)
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
E/BLE DFU: Level : 10 , Message : [DFU] DFU Version characteristic not found
E/BLE DFU: Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 1 , Message : [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D/BluetoothGatt: setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
E/BLE DFU: Level : 0 , Message : [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
E/BLE DFU: Level : 1 , Message : [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 10 , Message : [DFU] Notifications enabled
    Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-B8-FE-00-00
E/BLE DFU: Level : 10 , Message : [DFU] Firmware image size sent (0b, 0b, 65208b)
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-03
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 1 Status = 3)
E/BLE DFU: Level : 15 , Message : [DFU] DFU target does not support DFU v.2
E/BLE DFU: Level : 1 , Message : [DFU] Switching to DFU v.1
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : [DFU] DFU Start sent (Op Code = 1)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): B8-FE-00-00
E/BLE DFU: Level : 10 , Message : [DFU] Firmware image size sent (65208 bytes)
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-01
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 1, Status = 1)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 08-0A-00
E/BLE DFU: Level : 10 , Message : [DFU] Packet Receipt Notif Req (Op Code = 8) sent (Value = 10)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 03
E/BLE DFU: Level : 10 , Message : [DFU] Receive Firmware Image request sent
E/BLE DFU: Level : 10 , Message : [DFU] Uploading firmware...
E/BLE DFU: Level : 1 , Message : [DFU] Sending firmware to characteristic 00001532-1212-efde-1523-785feabcd123...
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-03-06
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 3, Status = 6)
E/DfuImpl: Device returned error after sending file (error 6): OPERATION FAILED
E/BLE DFU: Level : 20 , Message : [DFU] Remote DFU error: OPERATION FAILED
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 10 , Message : [DFU] Reset request sent
    Level : 1 , Message : [DFU] Disconnecting...
D/BluetoothGatt: cancelOpen() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] gatt.disconnect()
D/BluetoothGatt: onClientConnectionState() - status=8 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 5 , Message : [DFU] Disconnected
D/BluetoothGatt: refresh() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] gatt.refresh() (hidden)
E/BLE DFU: Level : 0 , Message : [DFU] gatt.close()
D/BluetoothGatt: close()
D/BluetoothGatt: unregisterApp() - mClientIf=8
E/BLE DFU: Level : 0 , Message : [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
E/BLE DFU: Level : 0 , Message : [DFU] wait(600)
D/Notification: allPendingIntents
E/BLE DFU: Level : 1 , Message : [DFU] DFU service started
    Level : 5 , Message : [DFU] Firmware file opened successfully
    Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 1 , Message : [DFU] Connecting to DFU target...
E/BLE DFU: Level : 0 , Message : [DFU] gatt = device.connectGatt(autoConnect = false)
D/BluetoothGatt: connect() - device: C8:B9:61:03:C5:6B, auto: false
D/BluetoothAdapter: isSecureModeEnabled
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=46227584-c3d3-4289-96d6-ed428fc2d617
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=8
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    Level : 5 , Message : [DFU] Connected to C8:B9:61:03:C5:6B
E/BLE DFU: Level : 1 , Message : [DFU] Discovering services...
E/BLE DFU: Level : 0 , Message : [DFU] gatt.discoverServices()
D/BluetoothGatt: discoverServices() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] gatt.discoverServices()
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onSearchComplete() = Device=C8:B9:61:03:C5:6B Status=0
E/BLE DFU: Level : 5 , Message : [DFU] Services discovered
E/BLE DFU: Level : 0 , Message : [DFU] wait(1000)
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
E/BLE DFU: Level : 10 , Message : [DFU] DFU Version characteristic not found
E/BLE DFU: Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 1 , Message : [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123
D/BluetoothGatt: setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
E/BLE DFU: Level : 0 , Message : [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
    Level : 1 , Message : [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 10 , Message : [DFU] Notifications enabled
    Level : 0 , Message : [DFU] wait(1000)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-F0-FD-00-00
E/BLE DFU: Level : 10 , Message : [DFU] Firmware image size sent (0b, 0b, 65008b)
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-03
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 1 Status = 3)
E/BLE DFU: Level : 15 , Message : [DFU] DFU target does not support DFU v.2
    Level : 1 , Message : [DFU] Switching to DFU v.1
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : [DFU] DFU Start sent (Op Code = 1)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): F0-FD-00-00
E/BLE DFU: Level : 10 , Message : [DFU] Firmware image size sent (65008 bytes)
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-01
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 1, Status = 1)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 08-0A-00
E/BLE DFU: Level : 10 , Message : [DFU] Packet Receipt Notif Req (Op Code = 8) sent (Value = 10)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 03
E/BLE DFU: Level : 10 , Message : [DFU] Receive Firmware Image request sent
E/BLE DFU: Level : 10 , Message : [DFU] Uploading firmware...
E/BLE DFU: Level : 1 , Message : [DFU] Sending firmware to characteristic 00001532-1212-efde-1523-785feabcd123...
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-03-01
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 3, Status = 1)
    Level : 10 , Message : [DFU] Upload completed in 24215 ms
    Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 04
    Level : 10 , Message : [DFU] Validate request sent
E/BLE DFU: Level : 5 , Message : [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-04-01
E/BLE DFU: Level : 10 , Message : [DFU] Response received (Op Code = 4, Status = 1)
E/BLE DFU: Level : 1 , Message : [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123
    Level : 0 , Message : [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 05
E/BLE DFU: Level : 10 , Message : [DFU] Activate and Reset request sent
D/BluetoothGatt: onClientConnectionState() - status=19 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 5 , Message : [DFU] Disconnected by the remote device
D/BluetoothGatt: refresh() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [DFU] gatt.refresh() (hidden)
D/BluetoothGatt: close()
E/BLE DFU: Level : 0 , Message : [DFU] gatt.close()
D/BluetoothGatt: unregisterApp() - mClientIf=8
E/BLE DFU: Level : 0 , Message : [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
E/BLE DFU: Level : 0 , Message : [DFU] wait(1400)
philips77 commented 6 years ago

Great. Thanks. I have few questions:

  1. What's "firstRun"?
  2. Do you start the service again after receiving error, or the lib indeed restarts on it's own?
  3. You are right, the stream should be restarted in the second attempt, no matter who starts the service.
  4. Do you know why do you get error 6 on the first attempt and not on the second?
ABouretz commented 6 years ago

  1. "firstRun" is a variable that check if the inputStream is already defined to avoid recreating it if service is restarted for any reason (which is the case here). You can find it in onHandleIntent() in DfuBaseService.java. There is a comment that explains its necessity, it's about one-time read permission.

  2. We do not restart the service ourselves, it's not easy to understand how the lib handles it but you can see in the logs that onHandleIntent() is called again and "firstRun" is false the second time. We can see that the lib send a reset request to the device before the disconnection.

  3. Yes, if the full file needs to be sent when the service restarts, the inputStream needs to be reinit.

  4. We don't know why we are getting this error, we got it on some Samsung devices and not on other manufacturers smartphones (tested on Huawei and Google Nexus 6P), it may be the Android OS version that brings new behaviours.

philips77 commented 6 years ago

Thanks. I wrote the library, but has forgotten many details since then. Thanks for all your answers, I'll dive into this now.

ABouretz commented 6 years ago

Same here, after searching in our code, I can tell we restart the service ourselves if a DfuBaseService.BROADCAST_ERROR is received by the listener, which may be the case here.

philips77 commented 6 years ago

Hi, could you try the version from branch bugfix/131? You would have to include the library as a module.

philips77 commented 6 years ago

Also, have a look at this comment: https://github.com/NordicSemiconductor/IOS-Pods-DFU-Library/blob/master/iOSDFULibrary/Classes/Implementation/LegacyDFU/Services/LegacyDFUService.swift#L235

In the iOS library, for targets running DFU from SDK 6.1 or older(?) (I guess that's one you are using), a 1 second delay was required: https://github.com/NordicSemiconductor/IOS-Pods-DFU-Library/blob/master/iOSDFULibrary/Classes/Implementation/LegacyDFU/Services/LegacyDFUService.swift#L282. I'll add it to the Android lib to this branch.

philips77 commented 6 years ago

Ok, I've added this 1 sec delay. In theory, it should work on the first try now. Could you verify? I don't remember why I've added this delay before sending Start DFU command, not after receiving a confirmation notification, but it worked for iOS, so I ported the same to Android.

ABouretz commented 6 years ago

I just tried your code and the behaviour remains the same. I get the same error 6 when sending the firmware. Since you added is.mark(is.available()) in the service init, the call to .reset() will do nothing. The firmware will be sent from where it stopped to transmit and .available() will return the remaining part and not the full file.

Besides, initIs is null in my case I had to add a null check before calling .mark(), I added the same check for is too.

In conclusion, I encountered the same error (I don't know why I get this error) and sent a corrupted file to the device.

ABouretz commented 6 years ago

I think you can remove the .mark() part and only call the .reset() method in LegacyDFU only. That way, LegacyDFU will resend the full file from the beginning but newer DFU like SecuredDFU will continue to handle service retries as before.

philips77 commented 6 years ago

Calling reset() without marking it first may cause an exception. I've fixed the embarrassing issue. Could you try again? Could you also paste the logs again? I want to see why the 1 sec delay didn't help.

philips77 commented 6 years ago

Btw, do you also use the iOS version of the library? Does it work for you?

ABouretz commented 6 years ago

I'll try it. We do not use the iOS library for LegacyDFU.

ABouretz commented 6 years ago 
E/BLE DFU: Level : 1 , Message : DFU service started
E/BLE DFU: Level : 1 , Message : Opening file...
E/BLE DFU: Level : 5 , Message : Firmware file opened successfully
E/BLE DFU: Level : 1 , Message : Connecting to DFU target...
E/BLE DFU: Level : 0 , Message : gatt = device.connectGatt(autoConnect = false)
D/BluetoothGatt: connect() - device: C8:B9:61:03:C5:6B, auto: false
D/BluetoothAdapter: isSecureModeEnabled
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=1cdce73e-b4b7-460a-8fb4-a878c0fc0875
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=8
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
E/BLE DFU: Level : 5 , Message : Connected to C8:B9:61:03:C5:6B
E/BLE DFU: Level : 1 , Message : Discovering services...
E/BLE DFU: Level : 0 , Message : gatt.discoverServices()
D/BluetoothGatt: discoverServices() - device: C8:B9:61:03:C5:6B
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onSearchComplete() = Device=C8:B9:61:03:C5:6B Status=0
E/BLE DFU: Level : 5 , Message : Services discovered
E/BLE DFU: Level : 0 , Message : wait(1000)
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
E/BLE DFU: Level : 10 , Message : DFU Version characteristic not found
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 1 , Message : Enabling notifications for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D/BluetoothGatt: setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
E/BLE DFU: Level : 0 , Message : gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
E/BLE DFU: Level : 5 , Message : Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
E/BLE DFU: Level : 1 , Message : Notifications enabled for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 10 , Message : Notifications enabled
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : DFU Start sent (Op Code = 1, Upload Mode = 4)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-B8-FE-00-00
E/BLE DFU: Level : 10 , Message : Firmware image size sent (0b, 0b, 65208b)
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-03
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 1 Status = 3)
E/BLE DFU: Level : 15 , Message : DFU target does not support DFU v.2
E/BLE DFU: Level : 1 , Message : Switching to DFU v.1
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01
E/BLE DFU: Level : 10 , Message : DFU Start sent (Op Code = 1)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): B8-FE-00-00
E/BLE DFU: Level : 10 , Message : Firmware image size sent (65208 bytes)
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-01
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 1, Status = 1)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 08-0A-00
E/BLE DFU: Level : 10 , Message : Packet Receipt Notif Req (Op Code = 8) sent (Value = 10)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 03
E/BLE DFU: Level : 10 , Message : Receive Firmware Image request sent
E/BLE DFU: Level : 10 , Message : Uploading firmware...
E/BLE DFU: Level : 1 , Message : Sending firmware to characteristic 00001532-1212-efde-1523-785feabcd123...
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-03-06
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 3, Status = 6)
E/DfuImpl: Device returned error after sending file (error 6): OPERATION FAILED
E/BLE DFU: Level : 20 , Message : Remote DFU error: OPERATION FAILED
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 10 , Message : Reset request sent
E/BLE DFU: Level : 1 , Message : Disconnecting...
D/BluetoothGatt: onClientConnectionState() - status=8 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : gatt.disconnect()
D/BluetoothGatt: cancelOpen() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
E/BLE DFU: Level : 5 , Message : Disconnected
E/BLE DFU: Level : 0 , Message : gatt.refresh() (hidden)
D/BluetoothGatt: refresh() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : gatt.close()
D/BluetoothGatt: close()
D/BluetoothGatt: unregisterApp() - mClientIf=8
E/BLE DFU: Level : 0 , Message : wait(600)
D/Notification: allPendingIntents
E/BLE DFU: Level : 1 , Message : DFU service started
    Level : 5 , Message : Firmware file opened successfully
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 1 , Message : Connecting to DFU target...
E/BLE DFU: Level : 0 , Message : gatt = device.connectGatt(autoConnect = false)
D/BluetoothGatt: connect() - device: C8:B9:61:03:C5:6B, auto: false
D/BluetoothAdapter: isSecureModeEnabled
D/BluetoothGatt: registerApp()
D/BluetoothGatt: registerApp() - UUID=a2106172-ca55-4979-ab71-d474c6d45a33
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=8
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
E/BLE DFU: Level : 5 , Message : Connected to C8:B9:61:03:C5:6B
E/BLE DFU: Level : 1 , Message : Discovering services...
    Level : 0 , Message : gatt.discoverServices()
D/BluetoothGatt: discoverServices() - device: C8:B9:61:03:C5:6B
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=6 latency=0 timeout=500 status=0
D/BluetoothGatt: onSearchComplete() = Device=C8:B9:61:03:C5:6B Status=0
E/BLE DFU: Level : 5 , Message : Services discovered
E/BLE DFU: Level : 0 , Message : wait(1000)
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
D/BluetoothGatt: onConnectionUpdated() - Device=C8:B9:61:03:C5:6B interval=12 latency=0 timeout=400 status=0
E/BLE DFU: Level : 10 , Message : DFU Version characteristic not found
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 1 , Message : Enabling notifications for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)
D/BluetoothGatt: setCharacteristicNotification() - uuid: 00001531-1212-efde-1523-785feabcd123 enable: true
E/BLE DFU: Level : 0 , Message : gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
E/BLE DFU: Level : 5 , Message : Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00
E/BLE DFU: Level : 1 , Message : Notifications enabled for 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 10 , Message : Notifications enabled
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 0 , Message : wait(1000)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04
E/BLE DFU: Level : 10 , Message : DFU Start sent (Op Code = 1, Upload Mode = 4)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-B8-FE-00-00
E/BLE DFU: Level : 10 , Message : Firmware image size sent (0b, 0b, 65208b)
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-03
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 1 Status = 3)
E/BLE DFU: Level : 15 , Message : DFU target does not support DFU v.2
E/BLE DFU: Level : 1 , Message : Switching to DFU v.1
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01
E/BLE DFU: Level : 10 , Message : DFU Start sent (Op Code = 1)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001532-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): B8-FE-00-00
E/BLE DFU: Level : 10 , Message : Firmware image size sent (65208 bytes)
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-01
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 1, Status = 1)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 08-0A-00
E/BLE DFU: Level : 10 , Message : Packet Receipt Notif Req (Op Code = 8) sent (Value = 10)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 03
E/BLE DFU: Level : 10 , Message : Receive Firmware Image request sent
E/BLE DFU: Level : 10 , Message : Uploading firmware...
E/BLE DFU: Level : 1 , Message : Sending firmware to characteristic 00001532-1212-efde-1523-785feabcd123...
I/zygote64: Do full code cache collection, code=1009KB, data=672KB
I/zygote64: After code cache collection, code=1009KB, data=593KB
I/zygote64: Do partial code cache collection, code=1009KB, data=597KB
I/zygote64: After code cache collection, code=1009KB, data=597KB
    Increasing code cache capacity to 3MB
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-03-01
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 3, Status = 1)
E/BLE DFU: Level : 10 , Message : Upload completed in 22549 ms
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 04
E/BLE DFU: Level : 10 , Message : Validate request sent
E/BLE DFU: Level : 5 , Message : Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-04-01
E/BLE DFU: Level : 10 , Message : Response received (Op Code = 4, Status = 1)
E/BLE DFU: Level : 1 , Message : Writing to characteristic 00001531-1212-efde-1523-785feabcd123
E/BLE DFU: Level : 0 , Message : gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)
E/BLE DFU: Level : 5 , Message : Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 05
E/BLE DFU: Level : 10 , Message : Activate and Reset request sent
D/BluetoothGatt: onClientConnectionState() - status=19 clientIf=8 device=C8:B9:61:03:C5:6B
E/BLE DFU: Level : 5 , Message : Disconnected by the remote device
E/BLE DFU: Level : 0 , Message : gatt.refresh() (hidden)
D/BluetoothGatt: refresh() - device: C8:B9:61:03:C5:6B
E/BLE DFU: Level : 0 , Message : gatt.close()
D/BluetoothGatt: close()
E/BLE DFU: Level : 0 , Message : [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
D/BluetoothGatt: unregisterApp() - mClientIf=8
E/BLE DFU: Level : 0 , Message : wait(1400)
ABouretz commented 6 years ago

Here you can see in the full logs that the error is still present but the file is now fully sent, so it fixed the most critical issue. I tried several times on different devices and I'm not able to brick them anymore.

philips77 commented 6 years ago

How about now with the latest commit? I moved the 1 sec delay to after you sent the file size. I guess hte old DFU bootlaoder needed some time to clear the flash before the file could be received. Next versions of the bootloader delay notification until the flash is ready.

ABouretz commented 6 years ago

I just tried with the latest commit, but the error is still here. I got the very same logs I uploaded.

philips77 commented 6 years ago

One wait(1000) should be moved a bit further, after the (0x): 10-01-01 was received. Could you confirm that?

ABouretz commented 6 years ago

Yes and/or maybe after sending the number of packets for notifications (method setNumberOfPackets). I can try it tomorrow.

ABouretz commented 6 years ago

Hi, I tested with delays between every communication with the device but the error was still here. I don't think its a timing problem since I have not been encountering this error using a Nexus 6P which is about as fast as the Samsung Galaxy S7. I don't know, it could be a Samsung's implementation of BLE stack that causes this error. Have you already encountered manufacturer specific issues ?

philips77 commented 6 years ago

Yes, some devices are "too fast" for the old bootloader to handle everything. But your case is different, add the second attempt works. My only explanation I could find is that it needs time to prepare slot, and on the second attempt it's already prepared. Hope about increasing delay to 2 seconds? In various places before uploading?

ABouretz commented 6 years ago

I did a last try increasing all delays to 3 seconds and adding same 3 seconds delay between each communication in the LegacyDFU but I got the same error... I don't think the problem comes from the speed of the device. I don't know what are the reasons this error can be triggered and returned.

philips77 commented 6 years ago

Hello again, sorry for the delay, I was sick. Did you find any solution that makes the first attempt to work? If not (but I'd really like to find the root cause and have it fixed), I'll revert the 1 sec delay and release 1.8.0 of the library. At least now it doesn't brick your device.

philips77 commented 6 years ago

Hi, managed to reproduce the issue on our side. Now I have something to test with. Let me come back to you when I find something.

ABouretz commented 6 years ago

Hi, no I haven't been able to find a way to avoid this error. Glad you could reproduce this behaviour, but I still don't understand why the error happens with some devices and not others.

philips77 commented 6 years ago

GitHub was down, and PRs and Issues didn't refresh, so I just saw your comment. I don't know if I fixed your issue, but I found a problem with DFU from SDK 6.0 or older (which is the one you are having troubles with). I already pushed 2 commits to bugfix/131 branch with a fix. Could you try it?

ABouretz commented 6 years ago

Hi, same here, I have not been notified of your comment. I'll try it asap.

ABouretz commented 6 years ago

I just tried twice and got the same error. I'll not be able to test much more for a while but thanks for your support!

philips77 commented 6 years ago

It might have not fixed your issue, but it fixed some other bug. I'll merge the PR and close the issue here. If you find something, feel free to create a new one or reopen this one.

philips77 commented 6 years ago

1.8.0 is released now.