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

DFU update failed on Samsung S8 (android 7.0.0) with Suunto Movesense #71

Closed skrabacz-michal closed 6 years ago

skrabacz-michal commented 7 years ago

On a bunch of different devices, everything works normal and fine (like Samsung S7Edge, A5, S6, Nexus5, MotoXPlay). I run tests several times with same result.

31m  FirmwareUpdateService  D  (FirmwareUpdateService.java:17) in onCreate => Start firmware update service [user=pudzian@dka.io]
pdateFirmwareSubscriber  D  (FirmwareUpdatePresenter$UpdateFirmwareSubscriber.java:197) in onNext => Update firmware done Firmware(installed=false) (is view bind=true) [user=pudzian@dka.io]
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] DFU service started [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Opening file... [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Image file opened (275492 bytes in total) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] wait(1000) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] wait(1000) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Connecting to DFU target... [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt = device.connectGatt(autoConnect = false) [user=pudzian@dka.io]
          BluetoothGatt  D  connect() - device: D7:74:2A:0C:51:E0, auto: false
       BluetoothAdapter  D  isSecureModeEnabled
          BluetoothGatt  D  registerApp()
                         D  registerApp() - UUID=d8da9eae-07d0-432c-a2b2-e3fb28cc9b7e
                         D  onClientRegistered() - status=0 clientIf=7
                         D  onClientConnectionState() - status=0 clientIf=7 device=D7:74:2A:0C:51:E0
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Connected to D7:74:2A:0C:51:E0 [user=pudzian@dka.io]
          BluetoothGatt  D  discoverServices() - device: D7:74:2A:0C:51:E0
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Discovering services... [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.discoverServices() [user=pudzian@dka.io]
          BluetoothGatt  D  onClientConnParamsChanged() - Device=D7:74:2A:0C:51:E0 interval=13 status=0
                         D  onClientConnParamsChanged() - Device=D7:74:2A:0C:51:E0 interval=6 status=0
                         D  onSearchComplete() = Device=D7:74:2A:0C:51:E0 Status=0
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Services discovered [user=pudzian@dka.io]
ogressListenerAdapter$1  D  (FirmwareUpdatePresenter$dfuProgressListenerAdapter$1.java:51) in onDeviceConnected => Dfu progress ... (is view bind=true) [user=pudzian@dka.io]
                         D  (FirmwareUpdatePresenter$dfuProgressListenerAdapter$1.java:58) in onDfuProcessStarting => Dfu progress ... (is view bind=true) [user=pudzian@dka.io]
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] wait(1000) [user=pudzian@dka.io]
          BluetoothGatt  D  onClientConnParamsChanged() - Device=D7:74:2A:0C:51:E0 interval=13 status=0
                         D  onClientConnParamsChanged() - Device=D7:74:2A:0C:51:E0 interval=13 status=0
                         D  configureMTU() - device: D7:74:2A:0C:51:E0 mtu: 517
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Requesting new MTU... [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.requestMtu(517) [user=pudzian@dka.io]
          BluetoothGatt  D  onConfigureMTU() - Device=D7:74:2A:0C:51:E0 mtu=23 status=0
                         D  setCharacteristicNotification() - uuid: 8ec90001-f315-4f60-9fb8-838830daea50 enable: true
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] MTU changed to: 23 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Enabling notifications for 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.setCharacteristicNotification(8ec90001-f315-4f60-9fb8-838830daea50, true) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data written to descr.8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 01-00 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notifications enabled for 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notifications enabled [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] wait(1000) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 06-01 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-06-01-00-01-00-00-87-00-00-00-B3-ED-83-09 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Command object info received (Max size = 256, Offset = 135, CRC = 0983EDB3) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Received CRC match Init packet [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 04 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-04-01 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Command object executed [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 06-02 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-06-01-00-10-00-00-00-10-00-00-78-23-37-4E [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data object info received (Max size = 4096, Offset = 4096, CRC = 4E372378) [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] 4096 bytes of data sent before, CRC match [user=pudzian@dka.io]
ogressListenerAdapter$1  D  (FirmwareUpdatePresenter$dfuProgressListenerAdapter$1.java:70) in onProgressChanged => Dfu progress 1... (is view bind=true) [user=pudzian@dka.io]
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Writing to characteristic 8ec90001-f315-4f60-9fb8-838830daea50 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] gatt.writeCharacteristic(8ec90001-f315-4f60-9fb8-838830daea50) [user=pudzian@dka.io]
                DfuImpl  E  Executing object failed (error 8)
          BluetoothGatt  D  cancelOpen() - device: D7:74:2A:0C:51:E0
dateActivity$onCreate$3  D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Notification received from 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-04-08 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Data written to 8ec90001-f315-4f60-9fb8-838830daea50, value (0x): 60-04-08 [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Remote DFU error: REMOTE DFU OPERATION NOT PERMITTED [user=pudzian@dka.io]
                         D  (FirmwareUpdateActivity$onCreate$3.java:39) in onLogEvent => Update firmware on device D7:74:2A:0C:51:E0:[DFU] Disconnecting... [user=pudzian@dka.io]
ogressListenerAdapter$1  D  (FirmwareUpdatePresenter$dfuProgressListenerAdapter$1.java:76) in onDeviceDisconnecting => Dfu progress ... (is view bind=true) [user=pudzian@dka.io]
philips77 commented 7 years ago

Hi, do you get the same result when you try to update the device starting from beginning, not resuming the upload? On the log you sent I see that you try to resume upload, the init packet is the same, the first page of data is the same and the library tries to execute it. For unknown reason it fails. But what if you erase the first page and start again? As the library does not allow to do this yet, you may replace the app.bin file in your zip (or just change first byte in it) and try again. This time the CRC will be different so the lib, instead of sending 0x04 (execute), will send 06-02 (create data object) which will erase the old one. You may then abort the upload (it would fail eventually as the signature check wouldn't pass), revert the first byte and try again.

skrabacz-michal commented 7 years ago

Hi, ok - i'll try it and back with the result. How can I check/verify if my package is correct? Right now I getting error Update firmware on device D7:74:2A:0C:51:E0:[DFU] Remote DFU error: REMOTE DFU INVALID OBJECT ?

philips77 commented 7 years ago

As you get this error it means it's not correct :) Do you get it just after sending init packet or whole fw? In the first case make sure it's signed with correct key, the same used in the bootloader. In the second case - you must have alerted the bin file.

ojousima commented 7 years ago

I've had reports of DFU failing on Samsung S8 and OnePlus 5 (Android 7 on both). The reports come from end users so I do not have detailed logs. The users are able to run DFU to same nRF52 device with same DFU package on Samsung S5 and ZTE Blade Android 7 on both.

Additionally S8 user reports that DFU service failures started after recent Android update. I can contact the users for more detailed reports if necessary, please give exact instructions on how to report if more details are needed.

yjwfn commented 6 years ago

I facing this problem . I fork this project, and then disable resume feature by modify source code. It is working fine.

Beremor commented 6 years ago

@yjwfn Could you please share your solution ?

yjwfn commented 6 years ago

@Beremor I found performDfu method in SecureDfuImpl first, and then you can see two methods sendInitPacket(gatt) and sendFirmware(gatt) within it. The methods will correct CRC before send package, you can make it always not equals to CRC of you package. This is not very nice solution, hope DFULibrary can add some options to disable it.

philips77 commented 6 years ago

I'll add an option to do fresh DFU in 1.8.0.

philips77 commented 6 years ago

Released in 1.8.0