Unstable behaviour

[mmontanes]

Information
This GitHub Issue page is for reporting issues or asking questions regarding the iOS DFU library. For general DFU questions, SDK questions, etc, please check our DevZone.
Make sure you are using the latest version of the library:
Also, before creating a new issue, make sure similar issue isn't already opened in open or closed issues.

DFU Bootloader version (please complete the following information):

• SDK version: 15.2
• Bonding used: no
• Library version: 1.11.1

Device information (please complete the following information):

• Device: Motorola One Action
• OS: Android 10

Describe the bug
The library sometimes works sometimes doesn't. Success rate 2/10.

My current code:

private void launchDfuUpdate(String deviceAddress, String deviceName){
        if(Build.VERSION.SDK_INT >= Build.VERSION_CODES.O)
            DfuServiceInitiator.createDfuNotificationChannel(getMainActivity());
        final DfuServiceInitiator starter = new DfuServiceInitiator(deviceAddress)
                .setDeviceName(deviceName)
                .setKeepBond(true)
//                .setForceScanningForNewAddressInLegacyDfu(true)
                .setUnsafeExperimentalButtonlessServiceInSecureDfuEnabled(true)
                .setPrepareDataObjectDelay(400)
                .setZip(packageToInstallId);
        final DfuController dfuServiceController = starter.start(getMainActivity(), DfuService.class);
// You may use the controller to pause, resume or abort the DFU process.
}

The weirdest thing is that it doesn't matter the settings I set, the success rate keeps the same, 2/10.

I think it has something to do with the MAC address. During the successful attempts the app disconnects from the CE:18:6E:9E:8F:AD MAC address. It starts to scans for the CE:18:6E:9E:8F:AE MAC address.

When the attempt fails, the app continues scanning for the CE:18:6E:9E:8F:AD MAC.

See the logs below.

Logs
Log of a successful attempt:

15:17:14.676 I/DfuBaseService: DFU service created. Version: 1.11.1
15:17:14.692 I/DfuBaseService: Starting DFU service in foreground
15:17:14.711 I/DfuBaseService: Connecting to the device...
15:17:14.715 I/DfuBaseService: Connected to GATT server
15:17:14.716 I/DfuBaseService: Attempting to start service discovery... succeed
15:17:14.718 I/DfuBaseService: Services discovered
15:17:14.720 I/DfuImpl: Buttonless service without bond sharing found -> SDK 13 or newer
15:17:14.737 D/UpdateFragment: onProcessStarting
15:17:15.729 I/DfuImpl: Enabling indications...
15:17:15.729 D/BluetoothGatt: setCharacteristicNotification() - uuid: 8ec90003-f315-4f60-9fb8-838830daea50 enable: true
15:17:17.605 I/DfuImpl: Sending Enter Bootloader (Op Code = 1)
15:17:17.952 I/DfuImpl: Response received (Op Code = 1, Status = 1)
15:17:18.541 W/DfuBaseService: Target device disconnected with status: 19
15:17:18.549 I/DfuBaseService: Refreshing result: true
15:17:18.549 I/DfuBaseService: Cleaning up...
15:17:18.557 I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
15:17:18.561 I/DfuImpl: Restarting to bootloader mode
15:17:18.577 D/BluetoothAdapter: isLeEnabled(): ON
15:17:18.590 D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=9 mScannerId=0
15:17:20.414 D/BluetoothAdapter: isLeEnabled(): ON

15:17:20.423 I/DfuImpl: Scanning for new address finished with: CE:18:6E:9E:8F:AE

15:17:20.435 I/DfuBaseService: Starting DFU service in foreground
15:17:22.469 I/DfuBaseService: Connecting to the device...
15:17:22.681 I/DfuBaseService: Connected to GATT server
15:17:22.684 I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_CONNECTED
15:17:22.686 I/DfuBaseService: Attempting to start service discovery... succeed
15:17:23.268 D/BluetoothGatt: onSearchComplete() = Device=CE:18:6E:9E:8F:AE Status=0
15:17:23.268 I/DfuBaseService: Services discovered
15:17:23.273 W/DfuImpl: Secure DFU bootloader found
15:17:24.292 I/DfuImpl: Requesting MTU = 517
15:17:24.327 I/DfuImpl: MTU changed to: 247
15:17:24.328 I/DfuImpl: Enabling notifications...
15:17:24.330 D/BluetoothGatt: setCharacteristicNotification() - uuid: 8ec90001-f315-4f60-9fb8-838830daea50 enable: true
15:17:25.402 I/DfuImpl: Setting object to Command (Op Code = 6, Type = 1)
15:17:25.439 I/DfuImpl: Command object info received (Max size = 256, Offset = 0, CRC = 00000000)
15:17:25.442 I/DfuImpl: Sending the number of packets before notifications (Op Code = 2, Value = 0)
15:17:25.485 I/DfuImpl: Creating Init packet object (Op Code = 1, Type = 1, Size = 141)
15:17:25.528 I/DfuImpl: Sending 141 bytes of init packet...
15:17:25.529 I/DfuImpl: Sending init packet (Value = 12-8A-01-0A-44-08-01-12-40-08-01-10-34-1A-02-B7-01-20-00-28-00-30-00-38-F4-F7-05-42-24-08-03-12-20-8F-80-42-51-8B-C3-A7-11-0E-D6-86-92-C3-AC-BA-CD0C-69-78-DA-C8-0E-88-CD-F6-99-BD-B3-48-00-52-04-08-01-12-00-10-00-1A-40-BC-9C-4D-D1-60-F4-7B-53-1-77-B8-54-B8-83-80-32-2B-99-5F-E9-D1-2C-32-CA-C9-B2-1E-CF-31-86-12-A4-2B-25-08-69-82-C9-FA-66-FE-0A-30-C7-B5-46-EF-73-57-62-5D-BB-90-B4-43-86-B2-20-EB-03)
15:17:25.539 I/DfuImpl: Sending Calculate Checksum command (Op Code = 3)
15:17:25.607 I/DfuImpl: Checksum received (Offset = 141, CRC = 9883ACBC)
15:17:25.607 I/DfuImpl: Executing init packet (Op Code = 4)
15:17:25.766 I/DfuImpl: Setting object to Data (Op Code = 6, Type = 2)
15:17:25.814 I/DfuImpl: Data object info received (Max size = 4096, Offset = 0, CRC = 00000000)
15:17:25.818 D/UpdateFragment: onProgressChanged
15:17:25.838 I/DfuImpl: Creating Data object (Op Code = 1, Type = 2, Size = 4096) (1/24)
15:17:26.335 I/DfuImpl: Uploading firmware...
15:17:26.417 I/DfuImpl: Sending Calculate Checksum command (Op Code = 3)
15:17:26.636 I/DfuImpl: Checksum received (Offset = 4096, CRC = 7057096C)
15:17:26.637 I/DfuImpl: Executing data object (Op Code = 4)
15:17:26.668 I/DfuImpl: Creating Data object (Op Code = 1, Type = 2, Size = 4096) (2/24)
15:17:27.112 I/DfuImpl: Uploading firmware...
[...]
15:17:44.578 I/DfuImpl: Checksum received (Offset = 97268, CRC = F7837690)
15:17:44.579 I/DfuImpl: Executing data object (Op Code = 4)
15:17:44.740 I/DfuImpl: Transfer of 97268 bytes has taken 18902 ms
15:17:45.028 W/DfuBaseService: Target device disconnected with status: 19
15:17:45.035 I/DfuBaseService: Refreshing result: true
15:17:45.035 I/DfuBaseService: Cleaning up...
15:17:45.040 I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
15:17:46.486 I/DfuBaseService: DFU service destroyed

Now, the log of the next attempt, that was a unsuccessful attempt:

15:18:53.009 I/DfuBaseService: DFU service created. Version: 1.11.1
15:18:53.014 I/DfuBaseService: Starting DFU service in foreground
15:18:53.026 I/DfuBaseService: Connecting to the device...
15:18:53.030 I/DfuBaseService: Connected to GATT server
15:18:53.031 I/DfuBaseService: Attempting to start service discovery... succeed
15:18:53.034 I/DfuBaseService: Services discovered
15:18:53.035 I/DfuImpl: Buttonless service without bond sharing found -> SDK 13 or newer
15:18:54.040 I/DfuImpl: Enabling indications...
15:18:55.882 I/DfuImpl: Sending Enter Bootloader (Op Code = 1)
15:18:56.232 I/DfuImpl: Response received (Op Code = 1, Status = 1)
15:18:56.823 W/DfuBaseService: Target device disconnected with status: 19
15:18:56.829 I/DfuBaseService: Refreshing result: true
15:18:56.829 I/DfuBaseService: Cleaning up...
15:18:56.838 I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
15:18:56.843 I/DfuImpl: Restarting to bootloader mode
15:18:56.858 D/BluetoothAdapter: isLeEnabled(): ON
15:18:56.868 D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=10 mScannerId=0
15:18:57.035 D/BluetoothAdapter: isLeEnabled(): ON

15:18:57.045 I/DfuImpl: Scanning for new address finished with: CE:18:6E:9E:8F:AD

15:18:57.059 I/DfuBaseService: Starting DFU service in foreground
15:18:59.087 I/DfuBaseService: Connecting to the device...
15:19:29.098 E/DfuBaseService: Connection state change error: 133 newState: 0
15:19:29.099 I/DfuBaseService: Connection error after: 30014 ms
15:19:29.100 E/DfuBaseService: Device not reachable. Check if the device with address CE:18:6E:9E:8F:AD is in range, is advertising and is connectable
15:19:29.100 I/DfuBaseService: Attempt: 1
15:19:29.105 I/DfuBaseService: Refreshing result: true
15:19:29.105 I/DfuBaseService: Cleaning up...
15:19:29.112 I/DfuBaseService: Restarting the service
15:19:29.124 I/DfuBaseService: Starting DFU service in foreground
15:19:31.139 I/DfuBaseService: Connecting to the device...
15:20:01.157 E/DfuBaseService: Connection state change error: 133 newState: 0
15:20:01.158 I/DfuBaseService: Connection error after: 30022 ms
15:20:01.158 E/DfuBaseService: Device not reachable. Check if the device with address CE:18:6E:9E:8F:AD is in range, is advertising and is connectable
15:20:01.159 I/DfuBaseService: Attempt: 2
15:20:01.164 I/DfuBaseService: Refreshing result: true
15:20:01.165 I/DfuBaseService: Cleaning up...
15:20:01.175 I/DfuBaseService: Restarting the service
15:20:01.186 I/DfuBaseService: Starting DFU service in foreground
15:20:03.202 I/DfuBaseService: Connecting to the device...
15:20:33.221 E/DfuBaseService: Connection state change error: 133 newState: 0
15:20:33.222 I/DfuBaseService: Connection error after: 30023 ms
15:20:33.222 E/DfuBaseService: Device not reachable. Check if the device with address CE:18:6E:9E:8F:AD is in range, is advertising and is connectable
15:20:33.222 I/DfuBaseService: Attempt: 3
15:20:33.230 I/DfuBaseService: Refreshing result: true
15:20:33.230 I/DfuBaseService: Cleaning up...
15:20:33.842 D/UpdateFragment: onError: GATT ERROR
15:20:33.842 D/UpdateFragment: GattError.parse: GATT ERROR
15:20:33.842 D/UpdateFragment: GattError.parseConnectionError: GATT ERROR
15:20:33.842 D/UpdateFragment: GattError.parseDfuRemoteError: UNKNOWN (133)
15:20:33.872 I/DfuBaseService: DFU service destroyed