search

NordicSemiconductor / Android-DFU-Library

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

DFU update finished but onDfuCompleted() is not called #278

Open kinber95 opened 3 years ago

kinber95 commented 3 years ago

When I connect and don't bond to my device, the dfu onDfuCompleted() callback method would not be called, but the dfu update finished successfully. But when I connect and immediately bond my device all works fine.

Edit: Okay currently its also happen when I bond before to my device, I think this error depends on the setKeepBond() method, because the Foreground Service still show uploading/disconnecting when the bonding is removed. Maybe the process get stuck.

My DfuServiceInitiator Settings - > 

tarter = new DfuServiceInitiator(bleDevice.getAddress())
                .setDeviceName(bleDevice.getName())
                .setKeepBond(false)
                .setPacketsReceiptNotificationsEnabled(true)
                .setPacketsReceiptNotificationsValue(6)
                .setZip(file.getAbsolutePath());
starter.start(getContext(), DfuService.class);

Logs

2020-11-05 13:33:57.744 24693-24693/de.haveltec.ishareit I/DfuBaseService: DFU service created. Version: 1.11.0
2020-11-05 13:33:57.802 24693-25342/de.haveltec.ishareit I/DfuBaseService: Starting DFU service in foreground
2020-11-05 13:33:57.855 24693-25342/de.haveltec.ishareit I/DfuBaseService: Connecting to the device...
2020-11-05 13:33:57.860 24693-24736/de.haveltec.ishareit I/DfuBaseService: Connected to GATT server
2020-11-05 13:33:57.861 24693-24736/de.haveltec.ishareit I/DfuBaseService: Attempting to start service discovery... succeed
2020-11-05 13:33:57.871 24693-24736/de.haveltec.ishareit I/DfuBaseService: Services discovered
2020-11-05 13:33:58.895 24693-25342/de.haveltec.ishareit I/DfuImpl: Reading DFU version number...
2020-11-05 13:33:59.116 24693-25342/de.haveltec.ishareit I/DfuImpl: Version number read: 0.1 -> Application with Legacy buttonless update from SDK 7.0 or newer
2020-11-05 13:33:59.120 24693-25342/de.haveltec.ishareit W/DfuImpl: Application with legacy buttonless update found
2020-11-05 13:33:59.121 24693-25342/de.haveltec.ishareit I/DfuImpl: Enabling notifications...
2020-11-05 13:34:01.247 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2020-11-05 13:34:05.275 24693-24736/de.haveltec.ishareit W/DfuBaseService: Target device disconnected with status: 8
2020-11-05 13:34:05.278 24693-25342/de.haveltec.ishareit I/DfuBaseService: Cleaning up...
2020-11-05 13:34:05.283 24693-25342/de.haveltec.ishareit I/DfuImpl: Starting service that will connect to the DFU bootloader
2020-11-05 13:34:05.287 24693-24693/de.haveltec.ishareit I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2020-11-05 13:34:07.341 24693-25342/de.haveltec.ishareit I/DfuBaseService: Connecting to the device...
2020-11-05 13:34:08.044 24693-24723/de.haveltec.ishareit E/DfuBaseService: Connection state change error: 133 newState: 0
2020-11-05 13:34:08.045 24693-25342/de.haveltec.ishareit I/DfuBaseService: Connection error after: 706 ms
2020-11-05 13:34:08.045 24693-25342/de.haveltec.ishareit E/DfuBaseService: An error occurred while connecting to the device:133
2020-11-05 13:34:08.048 24693-25342/de.haveltec.ishareit I/DfuBaseService: Attempt: 1
2020-11-05 13:34:08.052 24693-25342/de.haveltec.ishareit I/DfuBaseService: Refreshing result: true
2020-11-05 13:34:08.052 24693-25342/de.haveltec.ishareit I/DfuBaseService: Cleaning up...
2020-11-05 13:34:08.057 24693-25342/de.haveltec.ishareit I/DfuBaseService: Restarting the service
2020-11-05 13:34:08.068 24693-25342/de.haveltec.ishareit I/DfuBaseService: Starting DFU service in foreground
2020-11-05 13:34:10.084 24693-25342/de.haveltec.ishareit I/DfuBaseService: Connecting to the device...
2020-11-05 13:34:10.380 24693-24723/de.haveltec.ishareit I/DfuBaseService: Connected to GATT server
2020-11-05 13:34:10.384 24693-24723/de.haveltec.ishareit I/DfuBaseService: Waiting 1600 ms for a possible Service Changed indication...
2020-11-05 13:34:11.988 24693-24723/de.haveltec.ishareit I/DfuBaseService: Attempting to start service discovery... succeed
2020-11-05 13:34:11.995 24693-24724/de.haveltec.ishareit I/DfuBaseService: Services discovered
2020-11-05 13:34:13.015 24693-25342/de.haveltec.ishareit I/DfuImpl: Reading DFU version number...
2020-11-05 13:34:13.082 24693-25342/de.haveltec.ishareit I/DfuImpl: Version number read: 0.8 -> Bootloader from SDK 9.0 or newer. Signature supported
2020-11-05 13:34:13.086 24693-25342/de.haveltec.ishareit I/DfuImpl: Reading Service Changed CCCD value...
2020-11-05 13:34:13.142 24693-25342/de.haveltec.ishareit I/DfuImpl: Enabling indications...
2020-11-05 13:34:13.201 24693-25342/de.haveltec.ishareit I/DfuImpl: Service Changed indications enabled
2020-11-05 13:34:13.202 24693-25342/de.haveltec.ishareit W/DfuImpl: Legacy DFU bootloader found
2020-11-05 13:34:14.203 24693-25342/de.haveltec.ishareit I/DfuImpl: Enabling notifications...
2020-11-05 13:34:15.252 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending Start DFU command (Op Code = 1, Upload Mode = 4)
2020-11-05 13:34:15.301 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending image size array to DFU Packet (0b, 0b, 49220b)
2020-11-05 13:34:17.252 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending the Initialize DFU Parameters START (Op Code = 2, Value = 0)
2020-11-05 13:34:17.311 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending 14 bytes of init packet
2020-11-05 13:34:17.311 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending init packet (Value = FF-FF-FF-FF-FF-FF-FF-FF-01-00-80-00-7F-E9)
2020-11-05 13:34:17.317 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending the Initialize DFU Parameters COMPLETE (Op Code = 2, Value = 1)
2020-11-05 13:34:17.373 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending the number of packets before notifications (Op Code = 8, Value = 6)
2020-11-05 13:34:17.431 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending Receive Firmware Image request (Op Code = 3)
2020-11-05 13:34:17.511 24693-25342/de.haveltec.ishareit I/DfuImpl: Uploading firmware...
2020-11-05 13:34:45.181 24693-25342/de.haveltec.ishareit I/DfuImpl: Response received (Op Code = 16, Req Op Code = 3, Status = 1)
2020-11-05 13:34:45.182 24693-25342/de.haveltec.ishareit I/DfuImpl: Transfer of 49220 bytes has taken 27632 ms
2020-11-05 13:34:45.182 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending Validate request (Op Code = 4)
2020-11-05 13:34:45.301 24693-25342/de.haveltec.ishareit I/DfuImpl: Response received (Op Code = 16, Req Op Code = 4, Status = 1)
2020-11-05 13:34:45.318 24693-25342/de.haveltec.ishareit I/DfuImpl: Sending Activate and Reset request (Op Code = 5)
2020-11-05 13:34:45.428 24693-25397/de.haveltec.ishareit W/DfuBaseService: Target device disconnected with status: 19
2020-11-05 13:34:45.440 24693-25342/de.haveltec.ishareit I/DfuBaseService: Refreshing result: true
2020-11-05 13:34:45.440 24693-25342/de.haveltec.ishareit I/DfuBaseService: Cleaning up...
2020-11-05 13:34:45.449 24693-25342/de.haveltec.ishareit I/BluetoothDevice: removeBond() for device E3:F5:2D:CA:FF:4D called by pid: 24693 tid: 25342
kinber95 commented 3 years ago

Update:

So I can tell clearly what the problem occurs because of the keeBond(false) setting. When I start my dfu without a bonding, the nordic library creates a bond for me but after the dfu update finished, it has problems to remove the bonding. When I remove it manually, the onDfuCompleted() callback is called.