Firmware Upgrade "Image not valid!" only with Android (iOS version working)

Hello,

My colleague has posted this issue in Github (see https://github.com/NordicSemiconductor/Android-nRF-Connect-Device-Manager/issues/79) , but also want to post it here:

We use this library (1.4.1) in our mobile app to upgrade our BLE Device firmware (DFU, Zephyr, McuBoot). The iOS version of this library works as expected, but we have issues making this upgrade process work with the Android version. The device image used for both cases is the same.

This issue is also in the nRF Connect application (4.26.0) for Android. nRF Connect app for iOS works (2.5.3).

I have included below the code we use for iOS and Android and the messages from the BLE device during the upgrade process with the Android version. 

Could you please help? Thanks!

BLE Device Output

BLE Deviceuart:~$ *** Booting Zephyr OS version 2.3.99  ***
[00:00:00.003,601] <inf> mcuboot: Starting bootloader
[00:00:00.009,704] <inf> mcuboot: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
[00:00:00.019,561] <inf> mcuboot: Boot source: none
[00:00:00.024,932] <inf> mcuboot: Swap type: perm
[00:00:08.675,231] <err> mcuboot: Image in the secondary slot is not valid!
[00:00:09.051,116] <inf> mcuboot: Bootloader chainload address offset: 0xe000
[00:00:09.058,654] <inf> mcuboot: Jumping to the first image slot

iOS Code (Swift)

private func startDfu(_ address: String, binary: FlutterStandardTypedData, result: @escaping FlutterResult) {
    guard let uuid = UUID(uuidString: address) else {
        result(FlutterError(code: "DEVICE_ADDRESS_ERROR", message: "Device address conversion failed.", details: "Device address \(address) conversion failed"))
        return
    }

    guard let imageData = getImageData(binary: binary) else {
        result(FlutterError(code: "FIRMWARE_NOT_FOUND", message: "Binary file not valid.", details: nil))
        return
    }

    let bleTransport = McuMgrBleTransport(uuid)
    let dfuManager = FirmwareUpgradeManager(transporter: bleTransport, delegate: self)
    dfuManager.logDelegate = UIApplication.shared.delegate as? McuMgrLogDelegate
    dfuManager.estimatedSwapTime = 20.0

    do {
        try dfuManager.start(data: imageData)
    } catch {
        print("Error reading hash: \(error)")
    }
}

Android Code (Kotlin)

fun startDfu(binary: ByteArray): Unit {
    getBleDevice(address) { device ->
        val transport: McuMgrTransport = McuMgrBleTransport(context, device);
        val dfuManager = FirmwareUpgradeManager(transport, this)

        dfuManager.setEstimatedSwapTime(20000)
        dfuManager.setMode(FirmwareUpgradeManager.Mode.CONFIRM_ONLY)

        val eraseStorage = false
        val imageData = getImageData(binary)

        dfuManager.start(imageData, eraseStorage)
    }
}


  • Hi,

    Could you please paste here logs from LogCat or at least nRF Connect? When does it fail?

    If the upload is successful, but swap fails, seems like the bytes you provide to both libraries are not equal.

  • Hi  ,

    The upload finishes and takes a similar amount of time as iOS for approx 250 kB. So it is indeed before swapping that it establishes that the image is not valid. (See a log of nRF Connect below) The same image .bin file works with iOS and not for Android. So I think the android platform causes the issue, not the device that is being updated. We already tried alignments 1 and 4 in the nRF connect app.

    ```

    nRF Connect, 2022-11-16
    WAM-488D5C2 (8D:48:5C:C8:33:AF)
    V 11:57:32.451 Connecting to 8D:48:5C:C8:33:AF...
    D 11:57:32.451 gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
    D 11:57:37.316 [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    D 11:57:37.363 [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    I 11:57:37.364 Connected to 8D:48:5C:C8:33:AF
    V 11:57:37.389 Discovering services...
    D 11:57:37.389 gatt.discoverServices()
    I 11:57:37.558 PHY updated (TX: LE 2M, RX: LE 2M)
    D 11:57:39.780 [Callback] Services discovered with status: 0
    I 11:57:39.780 Services discovered
    V 11:57:39.813 Generic Attribute (0x1801)
    - Service Changed [I] (0x2A05)
       Client Characteristic Configuration (0x2902)
    - Client Supported Features [R W] (0x2B29)
    - Database Hash [R] (0x2B2A)
    Generic Access (0x1800)
    - Device Name [R W] (0x2A00)
    - Appearance [R] (0x2A01)
    - Peripheral Preferred Connection Parameters [R] (0x2A04)
    Device Information (0x180A)
    - Model Number String [R] (0x2A24)
    - Manufacturer Name String [R] (0x2A29)
    - Firmware Revision String [R] (0x2A26)
    Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
    - TX Characteristic [N] (6e400003-b5a3-f393-e0a9-e50e24dcca9e)
       Client Characteristic Configuration (0x2902)
    - RX Characteristic [W WNR] (6e400002-b5a3-f393-e0a9-e50e24dcca9e)
    SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
    - SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
       Client Characteristic Configuration (0x2902)
    D 11:57:39.813 gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
    D 11:57:39.816 gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
    I 11:57:42.417 Connection parameters updated (interval: 50.0ms, latency: 0, timeout: 420ms)
    I 11:57:42.849 Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    V 11:58:08.188 [McuMgr] Connecting...
    D 11:58:08.203 [McuMgr] gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
    D 11:58:08.268 [McuMgr] [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
    I 11:58:08.284 [McuMgr] Connected to 8D:48:5C:C8:33:AF
    D 11:58:08.297 [McuMgr] wait(300)
    V 11:58:08.614 [McuMgr] Discovering services...
    D 11:58:08.640 [McuMgr] gatt.discoverServices()
    I 11:58:08.678 [McuMgr] Services discovered
    V 11:58:08.699 [McuMgr] Primary service found
    V 11:58:08.720 [McuMgr] Requesting new MTU...
    D 11:58:08.737 [McuMgr] gatt.requestMtu(498)
    I 11:58:08.884 [McuMgr] MTU changed to: 498
    D 11:58:08.911 [McuMgr] gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
    V 11:58:08.935 [McuMgr] Enabling notifications for da2e7828-fbce-4e01-ae9e-261174997c48
    D 11:58:08.960 [McuMgr] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)
    I 11:58:09.059 [McuMgr] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
    I 11:58:09.079 [McuMgr] Notifications enabled
    V 11:58:09.094 [McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D 11:58:09.110 [McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I 11:58:09.128 [McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-01-00-00-FF-06-A0
    I 11:58:09.192 [McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
    A 11:58:09.211 [McuMgr] Received Header (Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
    W 11:58:09.226 [McuMgr] Error: NOT_SUPPORTED (8)
    A 11:58:09.246 [McuMgr] Sending (10 bytes) Header (Op: 0, Flags: 0, Len: 2, Group: 1, Seq: 0, Command: 0) CBOR {}
    V 11:58:09.260 [McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D 11:58:09.275 [McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I 11:58:09.334 [McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 00-00-00-02-00-01-00-00-BF-FF
    I 11:58:09.464 [McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-86-00-01-00-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-32-2E-31-2E-31-64-68-61-73-68-58-20-BA-3C-5A-C9-D5-CE-C7-19-FC-CE-65-A0-19-84-7F-02-69-5C-DE-61-3C-7A-40-A3-FD-7F-5C-7E-7C-3B-24-A2-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75-73-00-FF
    A 11:58:09.482 [McuMgr] Received Header (Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 0, Command: 0) CBOR {"images":[{"slot":0,"version":"2.1.1","hash":"ujxaydXOxxn8zmWgGYR/Amlc3mE8ekCj/X9cfnw7JKI=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
    V 11:58:09.518 [McuMgr] Uploading firmware...
    A 12:00:12.582 [McuMgr] 282032 bytes sent in 122848 ms (2.30 kB/s)
    A 12:00:12.631 [McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 63, Seq: 97, Command: 0) CBOR {}
    V 12:00:12.649 [McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D 12:00:12.664 [McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I 12:00:12.681 [McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-3F-61-00-BF-FF
    I 12:00:12.769 [McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-06-00-3F-61-00-BF-62-72-63-08-FF
    A 12:00:12.785 [McuMgr] Received Header (Op: 3, Flags: 0, Len: 6, Group: 63, Seq: 97, Command: 0) CBOR {"rc":8}
    W 12:00:12.802 [McuMgr] Error: NOT_SUPPORTED (8)
    V 12:00:12.832 [McuMgr] New state: CONFIRM
    A 12:00:12.851 [McuMgr] Sending (58 bytes) Header (Op: 2, Flags: 0, Len: 50, Group: 1, Seq: 98, Command: 0) CBOR {"confirm":true,"hash":"SfetEDgosd8P1vcy4NTSRjg/eQUDt8WoJkFooA7vIFA="}
    V 12:00:12.865 [McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D 12:00:12.881 [McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I 12:00:12.914 [McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-32-00-01-62-00-BF-67-63-6F-6E-66-69-72-6D-F5-64-68-61-73-68-58-20-49-F7-AD-10-38-28-B1-DF-0F-D6-F7-32-E0-D4-D2-46-38-3F-79-05-03-B7-C5-A8-26-41-68-A0-0E-EF-20-50-FF
    I 12:00:13.173 [McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-F4-00-01-62-00-BF-66-69-6D-61-67-65-73-9F-BF-64-73-6C-6F-74-00-67-76-65-72-73-69-6F-6E-65-32-2E-31-2E-31-64-68-61-73-68-58-20-BA-3C-5A-C9-D5-CE-C7-19-FC-CE-65-A0-19-84-7F-02-69-5C-DE-61-3C-7A-40-A3-FD-7F-5C-7E-7C-3B-24-A2-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F4-69-63-6F-6E-66-69-72-6D-65-64-F5-66-61-63-74-69-76-65-F5-69-70-65-72-6D-61-6E-65-6E-74-F4-FF-BF-64-73-6C-6F-74-01-67-76-65-72-73-69-6F-6E-65-33-2E-30-2E-31-64-68-61-73-68-58-20-49-F7-AD-10-38-28-B1-DF-0F-D6-F7-32-E0-D4-D2-46-38-3F-79-05-03-B7-C5-A8-26-41-68-A0-0E-EF-20-50-68-62-6F-6F-74-61-62-6C-65-F5-67-70-65-6E-64-69-6E-67-F5-69-63-6F-6E-66-69-72-6D-65-64-F4-66-61-63-74-69-76-65-F4-69-70-65-72-6D-61-6E-65-6E-74-F5-FF-FF-6B-73-70-6C-69-74-53-74-61-74-75-73-00-FF
    A 12:00:13.207 [McuMgr] Received Header (Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 98, Command: 0) CBOR {"images":[{"slot":0,"version":"2.1.1","hash":"ujxaydXOxxn8zmWgGYR/Amlc3mE8ekCj/X9cfnw7JKI=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"3.0.1","hash":"SfetEDgosd8P1vcy4NTSRjg/eQUDt8WoJkFooA7vIFA=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":true}],"splitStatus":0}
    V 12:00:13.255 [McuMgr] New state: RESET
    A 12:00:13.283 [McuMgr] Sending (10 bytes) Header (Op: 2, Flags: 0, Len: 2, Group: 0, Seq: 99, Command: 5) CBOR {}
    V 12:00:13.308 [McuMgr] Writing characteristic da2e7828-fbce-4e01-ae9e-261174997c48 (WRITE COMMAND)
    D 12:00:13.331 [McuMgr] gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
    I 12:00:13.374 [McuMgr] Data written to da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 02-00-00-02-00-00-63-05-BF-FF
    I 12:00:13.505 [McuMgr] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 03-00-00-02-00-00-63-05-BF-FF
    A 12:00:13.521 [McuMgr] Received Header (Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 99, Command: 5) CBOR {}
    D 12:00:18.648 [Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
    E 12:00:18.651 Error 8 (0x8): GATT CONN TIMEOUT
    I 12:00:18.651 Disconnected
    D 12:00:18.700 [McuMgr] [Callback] Connection state changed with status: 8 and new state: 0 (DISCONNECTED)
    W 12:00:18.723 [McuMgr] Error: (0x8): GATT CONN TIMEOUT
    I 12:00:18.765 [McuMgr] Disconnected
    D 12:00:18.786 [McuMgr] gatt.close()
    D 12:00:18.818 [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
    D 12:00:43.555 gatt.close()
    D 12:00:43.565 wait(200)
    V 12:00:43.767 Connecting to 8D:48:5C:C8:33:AF...
    D 12:00:43.767 gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)
    D 12:00:47.754 [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED
    D 12:00:47.784 [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)
    I 12:00:47.784 Connected to 8D:48:5C:C8:33:AF
    V 12:00:47.829 Discovering services...
    D 12:00:47.829 gatt.discoverServices()
    I 12:00:47.998 PHY updated (TX: LE 2M, RX: LE 2M)
    D 12:00:50.405 [Callback] Services discovered with status: 0
    I 12:00:50.405 Services discovered
    V 12:00:50.434 Generic Attribute (0x1801)
    - Service Changed [I] (0x2A05)
       Client Characteristic Configuration (0x2902)
    - Client Supported Features [R W] (0x2B29)
    - Database Hash [R] (0x2B2A)
    Generic Access (0x1800)
    - Device Name [R W] (0x2A00)
    - Appearance [R] (0x2A01)
    - Peripheral Preferred Connection Parameters [R] (0x2A04)
    Device Information (0x180A)
    - Model Number String [R] (0x2A24)
    - Manufacturer Name String [R] (0x2A29)
    - Firmware Revision String [R] (0x2A26)
    Nordic UART Service (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
    - TX Characteristic [N] (6e400003-b5a3-f393-e0a9-e50e24dcca9e)
       Client Characteristic Configuration (0x2902)
    - RX Characteristic [W WNR] (6e400002-b5a3-f393-e0a9-e50e24dcca9e)
    SMP Service (8d53dc1d-1db7-4cd3-868b-8a527460aa84)
    - SMP Characteristic [N WNR] (da2e7828-fbce-4e01-ae9e-261174997c48)
       Client Characteristic Configuration (0x2902)
    D 12:00:50.434 gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
    D 12:00:50.437 gatt.setCharacteristicNotification(6e400003-b5a3-f393-e0a9-e50e24dcca9e, true)
    I 12:00:52.903 Connection parameters updated (interval: 50.0ms, latency: 0, timeout: 420ms)
    I 12:00:53.337 Connection parameters updated (interval: 45.0ms, latency: 0, timeout: 5000ms)
    D 12:10:08.054 [Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)
    E 12:10:08.054 Error 8 (0x8): GATT CONN TIMEOUT
    I 12:10:08.054 Disconnected
    D 12:10:08.126 [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED
    ```

  • The upload seems successful, indeed.

    "permanent" flag of the image in slot 1 was set to true and the device has reset.

    Please check if number of bytes sent is exactly the same as on iOS. The only reason for a failure I can see is that the binaries are different. If you're unpacking it from a zip file, verify implementation. Your may also check if the hash of the images sent is the same on both platforms.

    Few hints:

    You may disable erasing app storage, as this seems not supported by the device.

    You're getting upload speed 2.3 kB/s, that's very slow. In NCS 2.0 we were able to reach 30+ kB/s on modern phones. Mostly by setting connection parameters and using 4 MCU mgr buffers.

  • Thanks for your reply. And thanks for the tips.

    Note that loading the same bin file on iOS nRF connect works, but not on Android nRF connect. So not sure how it can be the image that is wrong. Are there large differences between the features of the nRF connect app iOs compared to Android? 

    For our own implementation, we use 99% of the same code and 100% of the same image, and also their iOS is working Android is not.

    Will try disabling erasing coming Monday.

  • That's very weird. nRF Connect for iOS and Android open the file the same way, and send the whole thing.

    One other thing. In iOS, in your voice, you don't seem to set the upload mode to Confirm Only. Are you sure this node is chosen like in Android version? This is the proper mode, and it should work, but I'm just trying to figure out and possible differences. Could you log a hash and size of the file after sending from iOS and Android no and compare?

    I'll test the Android lib tomorrow. Didn't observe such issue before. 

    Also, what version of mcu manager and mcuboot do you have? From which NCS/Zephyr version? Seems like it is main branch of Zephyr, 2.3.99, right?

    Is it possible, that you have the same issue on iOS as well, and just accidentally iOS succeeds? I remember there was an issue in mcuboot at some point, that was failing to swap in some situations...

Related