Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Trying to do a Firmware-Update, but nothing is written. #202

Open
lsh-silpion opened this issue Nov 7, 2024 · 51 comments
Open

Trying to do a Firmware-Update, but nothing is written. #202

lsh-silpion opened this issue Nov 7, 2024 · 51 comments
Labels
question Further information is requested

Comments

@lsh-silpion
Copy link

lsh-silpion commented Nov 7, 2024

Hi,

I am trying to implement a Firmware-Update capability for a custom device employing the Nordic 5340 chip, in a Jetpack-Compose Android app.

For that purpose I use the following dependency:

    // nordic update manager
    implementation("no.nordicsemi.android:mcumgr-ble:2.2.2")

and this Kotlin code:

val updateButtonLabelMutableStateFlow = MutableStateFlow("")

fun setUpdateButtonLabel(value: String) {
    updateButtonLabelMutableStateFlow.value = value
}

val updateButtonEnabledMutableStateFlow = MutableStateFlow(false)

fun setUpdateButtonEnabled(value: Boolean) {
    updateButtonEnabledMutableStateFlow.value = value
}

…

fun onUpdateButtonClicked(context: Context, bluetoothDevice: BluetoothDevice, mainViewModel: MainViewModel) {
    val bluetoothDeviceAddress = bluetoothDevice.address

    val firmwareFile = mainViewModel.getFirmwareFile()
    if (firmwareFile.exists()) {

        val transport: McuMgrTransport = McuMgrBleTransport(context, bluetoothDevice)

        val dfuCallback = object : FirmwareUpgradeCallback<FirmwareUpgradeManager.State> {
            override fun onUpgradeStarted(controller: FirmwareUpgradeController?) {
                Timber.d("onUpgradeStarted(): controller: $controller")

                setUpdateButtonLabel(context.getString(R.string.update_starting))
                setUpdateButtonEnabled(false)
            }

            override fun onUpgradeCompleted() {
                Timber.d("onUpgradeCompleted()")

                // reconnect to device after reboot
                mainViewModel.onConnect(bluetoothDeviceAddress)

                setUpdateButtonLabel(context.getString(R.string.update_complete))
            }

            override fun onUploadProgressChanged(bytesSent: Int, imageSize: Int, timestamp: Long) {
                Timber.d("onUploadProgressChanged(): bytesSent: $bytesSent, imageSize: $imageSize, timestamp: $timestamp")

                setUpdateButtonLabel("${bytesSent / (imageSize / 100)} %")
            }

            override fun onUpgradeCanceled(state: FirmwareUpgradeManager.State?) {
                Timber.d("onUpgradeCanceled(): state: $state")

                setUpdateButtonLabel(context.getString(R.string.update_canceled))
            }

            override fun onUpgradeFailed(
                state: FirmwareUpgradeManager.State?,
                error: McuMgrException?
            ) {
                Timber.d("onUpgradeFailed(): state: $state, error: $error")

                setUpdateButtonLabel(context.getString(R.string.update_failed))
            }

            override fun onStateChanged(
                previousState: FirmwareUpgradeManager.State?,
                newState: FirmwareUpgradeManager.State?
            ) {
                Timber.d("onStateChanged(): previousState: $previousState, newState: $newState")

                if (previousState == FirmwareUpgradeManager.State.VALIDATE && newState == FirmwareUpgradeManager.State.RESET) {
                    setUpdateButtonLabel(context.getString(R.string.rebooting))
                }

            }
        }

        val dfuManager = FirmwareUpgradeManager(transport, dfuCallback)
        val dfuManagerSettings = FirmwareUpgradeManager.Settings.Builder()
            .setEstimatedSwapTime(10_000)
            .setEraseAppSettings(false)
            .setWindowCapacity(10)
            .setMemoryAlignment(4)
            .build()

        val imageSet = ZipPackage(firmwareFile.readBytes()).binaries

        dfuManager.setMode(FirmwareUpgradeManager.Mode.TEST_AND_CONFIRM)

        try {
            dfuManager.start(imageSet, dfuManagerSettings)
        } catch (e: Exception) {
            Timber.e(e)
        }
    } else {
        Timber.e("firmwareFile: $firmwareFile doesn't exist")
    }
}

the code does something, but it is not updating the firmware. We also have an iOS app for that purpose (using your iOSMcuManagerLibrary) and this is working with the same firmware file. It also takes quite a time longer than the stuff the "no.nordicsemi.android:mcumgr-ble:2.2.1" is doing, it finishes way to fast on Android. Also, the callback function onUploadProgressChanged seems never to be called, here is a log output (filtered for those callback functions):

2024-11-07 12:18:32.749 26433-26433 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@75ee5ab
2024-11-07 12:18:34.162 26433-26433 FirmwareUp...teChanged:          D  onStateChanged(): previousState: VALIDATE, newState: RESET
2024-11-07 12:18:35.092 26433-26433 FirmwareUp...Completed:          D  onUpgradeCompleted()

Am I missing something? Did I omit something important in my code?

Kind regards,

Lars

@lsh-silpion lsh-silpion changed the title Firmware-Update not working, nothing is written Trying to do a Firmware-Update, but nothing is written. Nov 15, 2024
@philips77
Copy link
Member

Hello,
You are using nRF5340, which has 2 cores - app core and net core. I assume, you're only trying to update the app core.
Why? You're using TEST_AND_CONFIRM mode, which doesn't work with the net core (its fw cannot be reverted, so doesn't allow "test"). If you have both binaries, change the mode to TEST_ONLY.

Also, nothing gets uploaded. Why?
The firmware that is currently running on your device has the same hash as the one you're trying to send. The validate state sends image list command and checks what's on the device. Then it compares returned hashes with those from the given binary/zip and - if hashes match - reports success. In nRF Connect Device Manager load the ZIP/bin file in Image tab / Basic and note printed hashes. Then, switch to Advanced and tap Read button to get the images. Compare the returned hashes with the previous ones. If that's not the case, please paste here the logs (either from LogCat from your app, from nRF Connect Device Manager app, or from nRF Logger app when using nRFCDM to do the DFU).

Try modifying anything (e.g. a version number) in the firmware or signing process to generate firmware with different hashes and try updating.

@philips77 philips77 added the question Further information is requested label Nov 15, 2024
@lsh-silpion
Copy link
Author

Hello, You are using nRF5340, which has 2 cores - app core and net core. I assume, you're only trying to update the app core. Why? You're using TEST_AND_CONFIRM mode, which doesn't work with the net core (its fw cannot be reverted, so doesn't allow "test"). If you have both binaries, change the mode to TEST_ONLY.

Yes, I am trying to update just the app core with my above code. Is it better to use TEST_ONLY in that case too?

Also, nothing gets uploaded. Why? The firmware that is currently running on your device has the same hash as the one you're trying to send. The validate state sends image list command and checks what's on the device. Then it compares returned hashes with those from the given binary/zip and - if hashes match - reports success. In nRF Connect Device Manager load the ZIP/bin file in Image tab / Basic and note printed hashes. Then, switch to Advanced and tap Read button to get the images. Compare the returned hashes with the previous ones. If that's not the case, please paste here the logs (either from LogCat from your app, from nRF Connect Device Manager app, or from nRF Logger app when using nRFCDM to do the DFU).

Well, I also got the upload working with the example app (nRF Connect Device Manager) but not with my code. We need the code in our app to be working since we don't want to deliver nRF Connect Device Manager to our customers. So what I am missing in my code?

Try modifying anything (e.g. a version number) in the firmware or signing process to generate firmware with different hashes and try updating.

I'll try this and report back.

Thanks again for your help!

@philips77
Copy link
Member

Is it better to use TEST_ONLY in that case too?

Sorry, I meant CONFIRM_ONLY. My mistake. Then the lib won't try to reconnect to the device to send confirm command, but it will do this in the first connection and report success after the device reboots + "estimated swap time".

@lsh-silpion
Copy link
Author

Is it better to use TEST_ONLY in that case too?

Sorry, I meant CONFIRM_ONLY. My mistake. Then the lib won't try to reconnect to the device to send confirm command, but it will do this in the first connection and report success after the device reboots + "estimated swap time".

I tried both and none worked in my code.

On the other hand I just realized that the nRF Connect Device Manager app only allows me to downgrade the firmware, from 0.3.4+0 down to 0.3.1+0, but not the other way around.

@lsh-silpion
Copy link
Author

Please let me know, if you need some additional information!

@philips77
Copy link
Member

Could you share the logs from LogCat?

@lsh-silpion
Copy link
Author

Could you share the logs from LogCat?

Which logCat? That of my app or the one from the nRF Connect Device Manager app?

@philips77
Copy link
Member

From your app, as it's not working. I may compare it with logs from nRFCDM.

@lsh-silpion
Copy link
Author

This should be the relevant section from LogCat:

2024-11-18 13:06:59.836 11915-11915 BluetoothAdapter                 D  STATE_ON
2024-11-18 13:06:59.837 11915-11915 BluetoothGatt                    D  connect() - device: EB:A3:43:8E:4B:5D, auto: false
2024-11-18 13:06:59.837 11915-11915 BluetoothAdapter                 D  isSecureModeEnabled
2024-11-18 13:06:59.838 11915-11915 BluetoothGatt                    D  registerApp()
2024-11-18 13:06:59.838 11915-11915 BluetoothGatt                    D  registerApp() - UUID=0d1dacf8-7130-4da2-b904-bdc34cc0828a
2024-11-18 13:06:59.842 11915-12002 BluetoothGatt                    D  onClientRegistered() - status=0 clientIf=16
2024-11-18 13:06:59.854 11915-11915 ViewRootImpl                     I  updatePointerIcon pointerType = 1000, calling pid = 11915
2024-11-18 13:06:59.854 11915-11915 InputManager                     D  setPointerIconType iconId = 1000, callingPid = 11915
2024-11-18 13:06:59.861 11915-12002 BluetoothGatt                    D  onClientConnectionState() - status=0 clientIf=16 device=EB:A3:43:8E:4B:5D
2024-11-18 13:06:59.876 11915-11915 Choreographer                    I  Skipped 1382 frames!  The application may be doing too much work on its main thread.
2024-11-18 13:06:59.884 11915-11915 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@b83d366
2024-11-18 13:07:00.192 11915-12149 BluetoothGatt                    D  discoverServices() - device: EB:A3:43:8E:4B:5D
2024-11-18 13:07:00.226 11915-12002 BluetoothGatt                    D  onSearchComplete() = Device=EB:A3:43:8E:4B:5D Status=0
2024-11-18 13:07:00.303 11915-11915 BluetoothGatt                    D  configureMTU() - device: EB:A3:43:8E:4B:5D mtu: 498
2024-11-18 13:07:00.394 11915-12002 BluetoothGatt                    D  onConfigureMTU() - Device=EB:A3:43:8E:4B:5D mtu=498 status=0
2024-11-18 13:07:00.401 11915-11915 BluetoothGatt                    D  setCharacteristicNotification() - uuid: da2e7828-fbce-4e01-ae9e-261174997c48 enable: true
2024-11-18 13:07:00.702 11915-12002 BleGatt.kt...icChanged:          D  characteristic changed: 1,0,0,6,0,0,-1,6,-65,98,114,99,8,-1
2024-11-18 13:07:00.708 11915-12002 DeviceChar...ification:          D  fromNotify: [B@34586fd
2024-11-18 13:07:00.719 11915-12002 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:07:00.720 11915-12002 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[1, 0, 0, 6, 0, 0, -1, 6, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-18 13:07:00.814 11915-11915 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+0
2024-11-18 13:07:00.817 11915-11915 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-18 13:07:00.940 11915-11927 er.cubo.androi                   I  Background concurrent copying GC freed 46218(3460KB) AllocSpace objects, 17(2188KB) LOS objects, 50% free, 6083KB/11MB, paused 191us total 154.081ms
2024-11-18 13:07:00.952 11915-11929 System                           W  A resource failed to call end. 
2024-11-18 13:07:00.957 11915-11929 System                           W  A resource failed to call end. 
2024-11-18 13:07:00.962 11915-12002 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,6,0,0,0,8,-65,98,114,99,8,-1
2024-11-18 13:07:00.965 11915-11929 System                           W  A resource failed to call end. 
2024-11-18 13:07:00.967 11915-12002 DeviceChar...ification:          D  fromNotify: [B@4aea643
2024-11-18 13:07:00.976 11915-12002 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:07:00.976 11915-12002 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, 6, 0, 0, 0, 8, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-18 13:07:01.186 11915-11915 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+0
2024-11-18 13:07:01.187 11915-11915 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-18 13:07:01.381 11915-12002 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,-12,0,1,1,0,-65,102,105,109,97,103,101,115,-97,-65,100,115,108,111,116,0,103,118,101,114,115,105,111,110,101,48,46,51,46,50,100,104,97,115,104,88,32,-90,63,-13,-75,-43,-94,-48,67,-56,34,45,68,-42,79,49,-78,48,-102,125,116,-102,-49,-47,50,-28,-91,-75,-87,-102,8,-19,-71,104,98,111,111,116,97,98,108,101,-11,103,112,101,110,100,105,110,103,-12,105,99,111,110,102,105,114,109,101,100,-11,102,97,99,116,105,118,101,-11,105,112,101,114,109,97,110,101,110,116,-12,-1,-65,100,115,108,111,116,1,103,118,101,114,115,105,111,110,101,48,46,51,46,52,100,104,97,115,104,88,32,33,-106,46,32,104,29,-15,-90,19,117,121,-7,18,19,-57,-96,38,-55,-116,50,-74,0,-34,-3,91,-77,10,4,-56,19,25,-112,104,98,111,111,116,97,98,108,101,-11,103,112,101,110,100,105,110,103,-12,105,99,111,110,102,105,114,109,101,100,-12,102,97,99,116,105,118,101,-12,105,112,101,114,109,97,110,101,110,116,-12,-1,-1,107,115,112,108,105,116,83,116,97,116,117,115,0,-1
2024-11-18 13:07:01.382 11915-12002 DeviceChar...ification:          D  fromNotify: [B@390f611
2024-11-18 13:07:01.385 11915-12002 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:07:01.386 11915-12002 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, -12, 0, 1, 1, 0, -65, 102, 105, 109, 97, 103, 101, 115, -97, -65, 100, 115, 108, 111, 116, 0, 103, 118, 101, 114, 115, 105, 111, 110, 101, 48, 46, 51, 46, 50, 100, 104, 97, 115, 104, 88, 32, -90, 63, -13, -75, -43, -94, -48, 67, -56, 34, 45, 68, -42, 79, 49, -78, 48, -102, 125, 116, -102, -49, -47, 50, -28, -91, -75, -87, -102, 8, -19, -71, 104, 98, 111, 111, 116, 97, 98, 108, 101, -11, 103, 112, 101, 110, 100, 105, 110, 103, -12, 105, 99, 111, 110, 102, 105, 114, 109, 101, 100, -11, 102, 97, 99, 116, 105, 118, 101, -11, 105, 112, 101, 114, 109, 97, 110, 101, 110, 116, -12, -1, -65, 100, 115, 108, 111, 116, 1, 103, 118, 101, 114, 115, 105, 111, 110, 101, 48, 46, 51, 46, 52, 100, 104, 97, 115, 104, 88, 32, 33, -106, 46, 32, 104, 29, -15, -90, 19, 117, 121, -7, 18, 19, -57, -96, 38, -55, -116, 50, -74, 0, -34, -3, 91, -77, 10, 4, -56, 19, 25, -112, 104, 98, 111, 111, 116, 97, 98, 108, 101, -11, 103, 112, 101, 110, 100, 105, 110, 103, -12, 105, 99, 111, 110, 102, 105, 114, 109, 101, 100, -12, 102, 97, 99, 116, 105, 118, 101, -12, 105, 112, 101, 114, 109, 97, 110, 101, 110, 116, -12, -1, -1, 107, 115, 112, 108, 105, 116, 83, 116, 97, 116, 117, 115, 0, -1], notificationBytes=null)])]
2024-11-18 13:07:01.478 11915-11915 FirmwareUp...Completed:          D  onUpgradeCompleted()
2024-11-18 13:07:01.478 11915-11915 ScanViewMo...onConnect:          D  onConnect

@lsh-silpion
Copy link
Author

From your app, as it's not working. I may compare it with logs from nRFCDM.

Btw. the nRF Connect Device Manager app currently allows me only to downgrade the firmware, for upgrading I currently use our iOS-App.

@philips77
Copy link
Member

You may use

/**
* Allows to enable low-level logging. If enabled, all BLE events will be logged.
*
* @param enabled true to enable logging, false to disable (default).
*/
public void setLoggingEnabled(boolean enabled) {
mLoggingEnabled = enabled;
}
to enable transport logs.

When using nRF Connect Device Manager you may also see the runtime logs in nRF Logger app, if you have it installed.

@philips77
Copy link
Member

OK, so based on your logs from ^ here's what you get in response:

{ 
  "images": 
     [ 
        { 
           "slot": 0, 
           "version": "0.3.2", 
           "hash": 0xA63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9,
           "bootable": true, 
           "pending": false, 
           "confirmed": true, 
           "active": true, 
           "permanent": false
        }, 
        {
           "slot": 1, 
           "version": "0.3.4", 
           "hash": 0x21962E20681DF1A6137579F91213C7A026C98C32B600DEFD5BB30A04C8131990,
           "bootable": true, 
           "pending": false, 
           "confirmed": false, 
           "active": false, 
           "permanent": false
        }
    ], 
  "splitStatus": 0
}

It seems, like the fw has been successfully uploaded (it's in secondary slot (1)) and the library should send Confirm request at that moment (assuming CONFIRM_ONLY).
Try going to nRF Connect Device Manager -> Image tab -> Advanced -> Image Control pane -> tap READ and CONFIRM.

Will it show the "perding" and "permanent" flags as true? If so, tap RESET button at the bottom to restart the device. It should make the swap.

@lsh-silpion
Copy link
Author

Here is the LogCat from my app with

        val transport = McuMgrBleTransport(context, bluetoothDevice)
        transport.setLoggingEnabled(true)
2024-11-18 13:52:34.632 16943-16943 BluetoothAdapter                 D  STATE_ON
2024-11-18 13:52:34.634 16943-16943 BluetoothGatt                    D  connect() - device: EB:A3:43:8E:4B:5D, auto: false
2024-11-18 13:52:34.634 16943-16943 BluetoothAdapter                 D  isSecureModeEnabled
2024-11-18 13:52:34.635 16943-16943 BluetoothGatt                    D  registerApp()
2024-11-18 13:52:34.635 16943-16943 BluetoothGatt                    D  registerApp() - UUID=908f827a-1582-458f-92ee-ebf09ef89168
2024-11-18 13:52:34.638 16943-16973 BluetoothGatt                    D  onClientRegistered() - status=0 clientIf=16
2024-11-18 13:52:34.642 16943-16943 ViewRootImpl                     I  updatePointerIcon pointerType = 1000, calling pid = 16943
2024-11-18 13:52:34.643 16943-16943 InputManager                     D  setPointerIconType iconId = 1000, callingPid = 16943
2024-11-18 13:52:34.659 16943-16973 BluetoothGatt                    D  onClientConnectionState() - status=0 clientIf=16 device=EB:A3:43:8E:4B:5D
2024-11-18 13:52:34.670 16943-16943 Choreographer                    I  Skipped 1635 frames!  The application may be doing too much work on its main thread.
2024-11-18 13:52:34.677 16943-16943 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@b41e6e
2024-11-18 13:52:34.984 16943-17921 BluetoothGatt                    D  discoverServices() - device: EB:A3:43:8E:4B:5D
2024-11-18 13:52:35.014 16943-16973 BluetoothGatt                    D  onSearchComplete() = Device=EB:A3:43:8E:4B:5D Status=0
2024-11-18 13:52:35.098 16943-16943 BluetoothGatt                    D  configureMTU() - device: EB:A3:43:8E:4B:5D mtu: 498
2024-11-18 13:52:35.167 16943-16973 BluetoothGatt                    D  onConfigureMTU() - Device=EB:A3:43:8E:4B:5D mtu=498 status=0
2024-11-18 13:52:35.174 16943-16943 BluetoothGatt                    D  setCharacteristicNotification() - uuid: da2e7828-fbce-4e01-ae9e-261174997c48 enable: true
2024-11-18 13:52:35.475 16943-16973 BleGatt.kt...icChanged:          D  characteristic changed: 1,0,0,6,0,0,-1,6,-65,98,114,99,8,-1
2024-11-18 13:52:35.485 16943-16973 DeviceChar...ification:          D  fromNotify: [B@86c73a5
2024-11-18 13:52:35.500 16943-16973 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:52:35.500 16943-16973 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[1, 0, 0, 6, 0, 0, -1, 6, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-18 13:52:35.641 16943-16943 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+1
2024-11-18 13:52:35.642 16943-16943 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-18 13:52:35.752 16943-16973 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,6,0,0,0,8,-65,98,114,99,8,-1
2024-11-18 13:52:35.756 16943-16973 DeviceChar...ification:          D  fromNotify: [B@fb4ab07
2024-11-18 13:52:35.772 16943-16973 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:52:35.772 16943-16973 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, 6, 0, 0, 0, 8, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-18 13:52:35.966 16943-16943 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+1
2024-11-18 13:52:35.968 16943-16943 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-18 13:52:36.024 16943-16966 System                           W  A resource failed to call end. 
2024-11-18 13:52:36.027 16943-16966 chatty                           I  uid=10371() FinalizerDaemon identical 1 line
2024-11-18 13:52:36.028 16943-16966 System                           W  A resource failed to call end. 
2024-11-18 13:52:36.180 16943-16973 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,-12,0,1,1,0,-65,102,105,109,97,103,101,115,-97,-65,100,115,108,111,116,0,103,118,101,114,115,105,111,110,101,48,46,51,46,50,100,104,97,115,104,88,32,-90,63,-13,-75,-43,-94,-48,67,-56,34,45,68,-42,79,49,-78,48,-102,125,116,-102,-49,-47,50,-28,-91,-75,-87,-102,8,-19,-71,104,98,111,111,116,97,98,108,101,-11,103,112,101,110,100,105,110,103,-12,105,99,111,110,102,105,114,109,101,100,-11,102,97,99,116,105,118,101,-11,105,112,101,114,109,97,110,101,110,116,-12,-1,-65,100,115,108,111,116,1,103,118,101,114,115,105,111,110,101,48,46,51,46,52,100,104,97,115,104,88,32,33,-106,46,32,104,29,-15,-90,19,117,121,-7,18,19,-57,-96,38,-55,-116,50,-74,0,-34,-3,91,-77,10,4,-56,19,25,-112,104,98,111,111,116,97,98,108,101,-11,103,112,101,110,100,105,110,103,-12,105,99,111,110,102,105,114,109,101,100,-12,102,97,99,116,105,118,101,-12,105,112,101,114,109,97,110,101,110,116,-12,-1,-1,107,115,112,108,105,116,83,116,97,116,117,115,0,-1
2024-11-18 13:52:36.182 16943-16973 DeviceChar...ification:          D  fromNotify: [B@b0d1a2c
2024-11-18 13:52:36.185 16943-16973 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-18 13:52:36.185 16943-16973 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, -12, 0, 1, 1, 0, -65, 102, 105, 109, 97, 103, 101, 115, -97, -65, 100, 115, 108, 111, 116, 0, 103, 118, 101, 114, 115, 105, 111, 110, 101, 48, 46, 51, 46, 50, 100, 104, 97, 115, 104, 88, 32, -90, 63, -13, -75, -43, -94, -48, 67, -56, 34, 45, 68, -42, 79, 49, -78, 48, -102, 125, 116, -102, -49, -47, 50, -28, -91, -75, -87, -102, 8, -19, -71, 104, 98, 111, 111, 116, 97, 98, 108, 101, -11, 103, 112, 101, 110, 100, 105, 110, 103, -12, 105, 99, 111, 110, 102, 105, 114, 109, 101, 100, -11, 102, 97, 99, 116, 105, 118, 101, -11, 105, 112, 101, 114, 109, 97, 110, 101, 110, 116, -12, -1, -65, 100, 115, 108, 111, 116, 1, 103, 118, 101, 114, 115, 105, 111, 110, 101, 48, 46, 51, 46, 52, 100, 104, 97, 115, 104, 88, 32, 33, -106, 46, 32, 104, 29, -15, -90, 19, 117, 121, -7, 18, 19, -57, -96, 38, -55, -116, 50, -74, 0, -34, -3, 91, -77, 10, 4, -56, 19, 25, -112, 104, 98, 111, 111, 116, 97, 98, 108, 101, -11, 103, 112, 101, 110, 100, 105, 110, 103, -12, 105, 99, 111, 110, 102, 105, 114, 109, 101, 100, -12, 102, 97, 99, 116, 105, 118, 101, -12, 105, 112, 101, 114, 109, 97, 110, 101, 110, 116, -12, -1, -1, 107, 115, 112, 108, 105, 116, 83, 116, 97, 116, 117, 115, 0, -1], notificationBytes=null)])]
2024-11-18 13:52:36.267 16943-16943 FirmwareUp...Completed:          D  onUpgradeCompleted()
2024-11-18 13:52:36.267 16943-16943 ScanViewMo...onConnect:          D  onConnect

@lsh-silpion
Copy link
Author

It seems, like the fw has been successfully uploaded (it's in secondary slot (1)) and the library should send Confirm request at that moment (assuming CONFIRM_ONLY). Try going to nRF Connect Device Manager -> Image tab -> Advanced -> Image Control pane -> tap READ and CONFIRM.

Will it show the "perding" and "permanent" flags as true? If so, tap RESET button at the bottom to restart the device. It should make the swap.

Tried that with the nRF CDM and got a Connection timed out error.

Here is the LogCat of nRF CDM:

2024-11-18 14:06:20.294 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:20.296 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527
2024-11-18 14:06:20.936 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 0
2024-11-18 14:06:20.941 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:20.942 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527
2024-11-18 14:06:20.943 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 1
2024-11-18 14:06:21.072 20527-20527 Dialog                  no....droid.nrfconnectdevicemanager  D  mIsSamsungBasicInteraction = false, isMetaDataInActivity = false
2024-11-18 14:06:21.086 20527-20527 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  I  [INFO] isPopOver = false
2024-11-18 14:06:21.086 20527-20527 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  I  updateCaptionType >> DecorView@9409e7[], isFloating: true, isApplication: true, hasWindowDecorCaption: false, hasWindowControllerCallback: false
2024-11-18 14:06:21.086 20527-20527 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  D  setCaptionType = 0, DecorView = DecorView@9409e7[]
2024-11-18 14:06:21.136 20527-20527 ScrollView              no....droid.nrfconnectdevicemanager  D  initGoToTop
2024-11-18 14:06:21.185 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  setView = com.android.internal.policy.DecorView@9409e7 TM=true MM=false
2024-11-18 14:06:21.280 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  Relayout returned: old=(0,72,1080,2076) new=(27,529,1053,1619) req=(1026,1090)0 dur=14 res=0x7 s={true 519380463616} ch=true
2024-11-18 14:06:21.282 20527-20574 mali_winsys             no....droid.nrfconnectdevicemanager  I  new_window_surface() [1098x1162] return: 0x3000
2024-11-18 14:06:21.327 20527-20527 ScrollView              no....droid.nrfconnectdevicemanager  D   onsize change changed 
2024-11-18 14:06:21.330 20527-20527 DecorView               no....droid.nrfconnectdevicemanager  E  mWindow.mActivityCurrentConfig is null
2024-11-18 14:06:21.359 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 1 1
2024-11-18 14:06:21.457 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 0 1
2024-11-18 14:06:21.458 20527-20527 InputMethodManager      no....droid.nrfconnectdevicemanager  D  prepareNavigationBarInfo() DecorView@610c89c[MainActivity]
2024-11-18 14:06:21.458 20527-20527 InputMethodManager      no....droid.nrfconnectdevicemanager  D  getNavigationBarColor() -1773582
2024-11-18 14:06:21.526 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_RESIZED: frame=(27,529,1053,1619) ci=(0,0,0,0) vi=(0,0,0,0) or=1
2024-11-18 14:06:21.571 20527-20527 DecorView               no....droid.nrfconnectdevicemanager  E  mWindow.mActivityCurrentConfig is null
2024-11-18 14:06:25.469 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20527
2024-11-18 14:06:25.473 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20527
2024-11-18 14:06:25.569 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:25.571 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527
2024-11-18 14:06:26.977 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 0
2024-11-18 14:06:26.985 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:26.987 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527
2024-11-18 14:06:29.555 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 1
2024-11-18 14:06:29.588 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:29.591 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527
2024-11-18 14:06:29.685 20527-20527 BluetoothAdapter        no....droid.nrfconnectdevicemanager  D  STATE_ON
2024-11-18 14:06:29.719 20527-20527 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  connect() - device: EB:A3:43:8E:4B:5D, auto: false
2024-11-18 14:06:29.719 20527-20527 BluetoothAdapter        no....droid.nrfconnectdevicemanager  D  isSecureModeEnabled
2024-11-18 14:06:29.722 20527-20527 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  registerApp()
2024-11-18 14:06:29.724 20527-20527 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  registerApp() - UUID=6425f747-f34f-41ac-8741-1956c1e827fa
2024-11-18 14:06:29.740 20527-20595 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onClientRegistered() - status=0 clientIf=16
2024-11-18 14:06:29.783 20527-20574 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() in
2024-11-18 14:06:29.788 20527-20574 mali_winsys             no....droid.nrfconnectdevicemanager  I  delete_surface() [1098x1162] return
2024-11-18 14:06:29.788 20527-20574 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() out
2024-11-18 14:06:29.789   512-562   BufferQueueProducer     pid-512                              E  [no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity$_20527#1] disconnect: not connected (req=1)
2024-11-18 14:06:29.789 20527-20574 libEGL                  no....droid.nrfconnectdevicemanager  W  EGLNativeWindowType 0x78dc1e5a10 disconnect failed
2024-11-18 14:06:29.789 20527-20574 OpenGLRenderer          no....droid.nrfconnectdevicemanager  D  endAllActiveAnimators on 0x78eda17200 (RippleDrawable) with handle 0x794be91c40
2024-11-18 14:06:29.790 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  dispatchDetachedFromWindow
2024-11-18 14:06:29.795 20527-20527 InputTransport          no....droid.nrfconnectdevicemanager  D  Input channel destroyed: '1747cc3', fd=84
2024-11-18 14:06:29.801   967-3037  InputDispatcher         pid-967                              E  Window handle Window{1747cc3 u0 no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity} has no registered input channel
2024-11-18 14:06:29.931 20527-20527 InputMethodManager      no....droid.nrfconnectdevicemanager  D  prepareNavigationBarInfo() DecorView@610c89c[MainActivity]
2024-11-18 14:06:29.931 20527-20527 InputMethodManager      no....droid.nrfconnectdevicemanager  D  getNavigationBarColor() -1773582
2024-11-18 14:06:29.951   967-1047  WindowManager           pid-967                              E  win=Window{1747cc3 u0 no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity EXITING} destroySurfaces: appStopped=false win.mWindowRemovalAllowed=true win.mRemoveOnExit=true win.mViewVisibility=0 caller=com.android.server.wm.AppWindowToken.destroySurfaces:1249 com.android.server.wm.AppWindowToken.destroySurfaces:1230 com.android.server.wm.WindowState.onExitAnimationDone:5189 com.android.server.wm.WindowStateAnimator.onAnimationFinished:320 com.android.server.wm.WindowState.onAnimationFinished:5630 com.android.server.wm.-$$Lambda$yVRF8YoeNdTa8GR1wDStVsHu8xM.run:2 com.android.server.wm.SurfaceAnimator.lambda$getFinishedCallback$0$SurfaceAnimator:100 
2024-11-18 14:06:29.994 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20527
2024-11-18 14:06:29.994 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20527
2024-11-18 14:06:30.001 20527-20527 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 1 1
2024-11-18 14:06:30.001 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  E  sendUserActionEvent() mView returned.
2024-11-18 14:06:30.471 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onClientConnectionState() - status=0 clientIf=16 device=EB:A3:43:8E:4B:5D
2024-11-18 14:06:30.794 20527-20721 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  discoverServices() - device: EB:A3:43:8E:4B:5D
2024-11-18 14:06:30.898 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=6 latency=0 timeout=500 status=0
2024-11-18 14:06:30.964 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onPhyUpdate() - status=0 address=EB:A3:43:8E:4B:5D txPhy=2 rxPhy=2
2024-11-18 14:06:31.371 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onSearchComplete() = Device=EB:A3:43:8E:4B:5D Status=0
2024-11-18 14:06:31.411 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=39 latency=0 timeout=500 status=0
2024-11-18 14:06:31.489 20527-20600 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  configureMTU() - device: EB:A3:43:8E:4B:5D mtu: 498
2024-11-18 14:06:31.557 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConfigureMTU() - Device=EB:A3:43:8E:4B:5D mtu=498 status=0
2024-11-18 14:06:31.559 20527-20600 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  setCharacteristicNotification() - uuid: da2e7828-fbce-4e01-ae9e-261174997c48 enable: true
2024-11-18 14:06:31.862 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onPhyRead() - status=0 address=EB:A3:43:8E:4B:5D txPhy=2 rxPhy=2
2024-11-18 14:06:31.873 20527-20600 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  requestConnectionPriority() - params: 1
2024-11-18 14:06:32.197 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=12 latency=0 timeout=500 status=0
2024-11-18 14:06:35.440 20527-20549 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=39 latency=0 timeout=42 status=0
2024-11-18 14:06:49.043 20527-20527 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20527
2024-11-18 14:06:49.046 20527-20527 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20527

Hope that helps …

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 18, 2024

In BASIC-Mode inside the nRF CDM I get this:

14:11:39.798  V  Starting DFU, mode: CONFIRM_ONLY
14:11:40.050  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 4, Command: 8) CBOR {}
14:11:40.054  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:11:40.140  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=12 latency=0 timeout=500 status=0
14:11:40.143  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-04-08-BF-62-72-63-08-FF
14:11:40.145  I  Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
14:11:40.166  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 4, Command: 8) CBOR {"rc":8}
14:11:40.274  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 5, Command: 0) CBOR {}
14:11:40.278  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:11:40.313  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F4-00-01-05-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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-F4-66-61-63-74-69-76-65-F4-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
14:11:40.329  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 5, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
14:11:40.449  V  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
14:11:40.453  V  Moving from state VALIDATE to state CONFIRM
14:11:40.482  I  Sending (57 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 49, Group: 1, Seq: 6, Command: 0) CBOR {"confirm":true,"hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA="}
14:11:40.494  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:11:40.526  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 0B-00-00-F4-00-01-06-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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
14:11:40.536  I  Received Header (Version: 1, Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 6, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":true}],"splitStatus":0}
14:11:40.675  V  Confirm response: {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":true}],"splitStatus":0}
14:11:40.676  V  Moving from state CONFIRM to state RESET
14:11:40.695  I  Sending (9 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 1, Group: 0, Seq: 7, Command: 5) CBOR {}
14:11:40.700  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:11:40.725  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 0B-00-00-02-00-00-07-05-BF-FF
14:11:40.730  I  Received Header (Version: 1, Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 7, Command: 5) CBOR {}
14:11:40.793  V  Reset request success. Waiting for disconnect...
14:11:45.969  D  onClientConnectionState() - status=8 clientIf=16 device=EB:A3:43:8E:4B:5D
14:11:45.997  W  Error: (0x8): GATT CONN TIMEOUT
14:11:46.000  I  Disconnected
14:11:46.016  D  close()
14:11:46.028  D  unregisterApp() - mClientIf=16
14:11:46.046  I  Device disconnected
14:11:46.047  V  Waiting remaining 4746 ms for the swap operation to complete
14:11:50.801  I  Upgrade complete

@philips77
Copy link
Member

Here is the LogCat from my app with

   val transport = McuMgrBleTransport(context, bluetoothDevice)
   transport.setLoggingEnabled(true)

I think you need to add dependency to slf4j-simple in your project, instead of slf4j-noop. The McuMgrBleTransport is logging using LSF4J and seems like the logs are discarded.

@philips77
Copy link
Member

philips77 commented Nov 18, 2024

In BASIC mode you're getting:

{
   "images": [ 
    {
      "slot":0,
      "version":"0.3.2",
      "hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=",
      "bootable":true,
      "pending":false,
      "confirmed":true,
      "active":true,
      "permanent":false
    }, 
    {
      "slot":1,
      "version":"0.3.4",
      "hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=",
      "bootable":true,
      "pending":true,
      "confirmed":false,
      "active":false,
      "permanent":true
    }
  ],
  "splitStatus":0
}

Which would indicate, that the 0.3.4 will be set as active after the reset. This is a good response.

As you see, the 2nd image was marked as "pending" (will be swapped) and "permanent" con't be reverted after second reset. After the device reboots and starts advertising you should read 0.3.4 in slot 0 with "active" flag on.

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 18, 2024

The firmware downgrade works in nRF CDM:

14:24:19.382  V  Starting DFU, mode: CONFIRM_ONLY
14:24:22.888  I  Connected to EB:A3:43:8E:4B:5D
14:24:23.285  I  Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
14:24:23.362  I  PHY updated (TX: LE 2M, RX: LE 2M)
14:24:23.752  I  Services discovered
14:24:23.867  I  Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 5000ms)
14:24:23.957  I  MTU changed to: 498
14:24:24.154  I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
14:24:24.155  I  Notifications enabled
14:24:24.167  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:24.250  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
14:24:24.260  I  Wait for value changed complete
14:24:24.348  I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
14:24:24.350  I  PHY read (TX: LE 2M, RX: LE 2M)
14:24:24.374  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
14:24:24.564  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:24.590  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 1, Command: 6) CBOR {}
14:24:24.598  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:24.642  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
14:24:24.654  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
14:24:24.692  D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=12 latency=0 timeout=500 status=0
14:24:24.832  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-01-06-BF-62-72-63-08-FF
14:24:24.833  I  Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
14:24:24.841  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
14:24:24.853  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 2, Command: 0) CBOR {}
14:24:24.934  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:24.944  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F4-00-01-02-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-F4-66-61-63-74-69-76-65-F4-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
14:24:24.967 I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
14:24:24.974  I  Sending (19 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 11, Group: 0, Seq: 3, Command: 7) CBOR {"format":"sv"}
14:24:25.099  V  Validation response: {"images":[{"slot":0,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
14:24:25.102  V  Moving from state VALIDATE to state CONFIRM
14:24:25.116  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:25.118  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-03-07-BF-62-72-63-08-FF
14:24:25.125  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 3, Command: 7) CBOR {"rc":8}
14:24:25.134  I  Sending (57 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 49, Group: 1, Seq: 4, Command: 0) CBOR {"confirm":true,"hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk="}
14:24:25.202  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:25.209  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 0B-00-00-F4-00-01-04-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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
14:24:25.224  I  Received Header (Version: 1, Op: 3, Flags: 0, Len: 244, Group: 1, Seq: 4, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":true}],"splitStatus":0}
14:24:25.230  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 5, Command: 8) CBOR {}
14:24:25.338  V  Confirm response: {"images":[{"slot":0,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":true,"confirmed":false,"active":false,"permanent":true}],"splitStatus":0}
14:24:25.339  V  Moving from state CONFIRM to state RESET
14:24:25.346  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:25.348  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-05-08-BF-62-72-63-08-FF
14:24:25.355  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 5, Command: 8) CBOR {"rc":8}
14:24:25.361  I  Sending (9 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 1, Group: 0, Seq: 6, Command: 5) CBOR {}
14:24:25.443  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:24:25.446  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 0B-00-00-02-00-00-06-05-BF-FF
14:24:25.451  I  Received Header (Version: 1, Op: 3, Flags: 0, Len: 2, Group: 0, Seq: 6, Command: 5) CBOR {}
14:24:25.509  V  Reset request success. Waiting for disconnect...
14:24:30.635  D  onClientConnectionState() - status=8 clientIf=16 device=EB:A3:43:8E:4B:5D
14:24:30.654  W  Error: (0x8): GATT CONN TIMEOUT
14:24:30.656  I  Disconnected
14:24:30.662  D  close()
14:24:30.688  I  Device disconnected
14:24:30.689  V  Waiting remaining 4821 ms for the swap operation to complete
14:24:35.518  I  Upgrade complete

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 18, 2024

Here is the LogCat from my app with

   val transport = McuMgrBleTransport(context, bluetoothDevice)
   transport.setLoggingEnabled(true)

I think you need to add dependency to slf4j-simple in your project, instead of slf4j-noop. The McuMgrBleTransport is logging using LSF4J and seems like the logs are discarded.

Did that and now got the following:

14:28:44.489  W  [main] Connected to EB:A3:43:8E:4B:5D
14:28:44.826  W  [main] Services discovered
14:28:44.998  W  [main] MTU changed to: 498
14:28:45.195  W  [main] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
14:28:45.198  W  [main] Notifications enabled
14:28:45.221  W  [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:28:45.297  W  [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
14:28:45.329  W  [main] Wait for value changed complete
14:28:45.451  W  [main] Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
14:28:45.503  D  latestFirmwareVersionString: 0.3.4+1
14:28:45.504  D  CUBOx.firmwareVersionString: 0.3.1+0
14:28:45.519  W  [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
14:28:45.525  W  [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:28:45.582  W  [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
14:28:45.600  W  [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
14:28:45.786  W  [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
14:28:45.815  W  [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
14:28:45.881  W  [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F4-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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-F4-66-61-63-74-69-76-65-F4-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
14:28:45.906  W  [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 244, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4","hash":"IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
14:28:46.030  D  onUpgradeCompleted()

@philips77
Copy link
Member

Here's what you have before downgrade:

{
    "images": [
        {
            "version": "0.3.4",
            "hash": "IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=",
            "bootable": true,
            "pending": false,
            "confirmed": true,
            "active": true,
            "slot": 0,
            "permanent": false
        },
        {
            "slot": 1,
            "version": "0.3.2",
            "hash": "pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=",
            "bootable": true,
            "active": false,
            "confirmed": false,
            "pending": false,
            "permanent": false
        }
    ],
    "splitStatus": 0
}

and after sending confirm request:

{
    "images": [
        {
            "slot": 0,
            "version": "0.3.4",
            "hash": "IZYuIGgd8aYTdXn5EhPHoCbJjDK2AN79W7MKBMgTGZA=",
            "bootable": true,
            "pending": false,
            "confirmed": true,
            "active": true,
            "permanent": false
        },
        {
            "slot": 1,
            "version": "0.3.2",
            "hash": "pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=",
            "bootable": true,
            "pending": true,
            "confirmed": false,
            "active": false,
            "permanent": true
        }
    ],
    "splitStatus": 0
}

This is the same as #202 (comment), where you upgrade (only version and hash are swapped). IMO both up and downgrade should work.

@philips77
Copy link
Member

Based on you latest comment I deduct, that from your app you're trying to send 0.3.2, not 0.3.4. It checks that the hash of the "active" slot 0 is the same as in the binary and reports success, no action needed.

@lsh-silpion
Copy link
Author

Based on you latest comment I deduct, that from your app you're trying to send 0.3.2, not 0.3.4. It checks that the hash of the "active" slot 0 is the same as in the binary and reports success, no action needed.

Now I am baffled. I am pretty sure I am uploading 0.3.4 Is there any way to confirm this?

@philips77
Copy link
Member

philips77 commented Nov 18, 2024

You may open the file that you're sending from your app in nRF CDM and compare hashes.
On BASIC view it will show the hash after the file is selected. Then, open ADVANCED, and tap READ to list the firmware which is already on the device. Check out hashes for each version and compare with the selected file.
Just make supre you're using exactly the file that your app is trying to send.

In your app you may also print the hash of the binaries from the ZIP file or teh BIN, depending on what you are sending.
If you create ImageTarget object, it has hash property.

Also, I believe you're not using the latest version of this library, which is 2.2.2.

@lsh-silpion
Copy link
Author

Our Firmware developer tells me right now that it is required for our appliance to work to write to slot0, not slot1, to make the firmware work. How do I force a write to slot0?

Thanks again,

Lars

@philips77
Copy link
Member

Hmm.. the standard way of upgrading is by sending the image to slot 1 (secondary), then confirming them (sending confirm command with the right hash) and reseting the board (sending reset command). This will cause McuBoot to swap images, so the new one lands in slot 0 and is set as active. And I believe this is exactly the same as the iOS app is doing.

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 18, 2024

Here is the LogCat with the hash of the image I am going to upload (produced by the following code):

val imageSet = ZipPackage(firmwareFile.readBytes()).binaries

Timber.d("imageSet.images[0].image.hash: ${imageSet.images[0].image.hash.toHex()}")

dfuManager.setMode(FirmwareUpgradeManager.Mode.CONFIRM_ONLY)

try {
   dfuManager.start(imageSet, dfuManagerSettings)
} catch (e: Exception) {
   Timber.e(e)
}
D imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
W [main] Services discovered
W [main] MTU changed to: 498
W [main] Data written to descr.00002902-0000-1000-8000-00805f9b34fb
W [main] Notifications enabled
W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value:(0x)01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
W [main] Wait for value changed complete
W [main] Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
W [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value:(0x)09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
W [main] Sending (9bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value:(0x)09-00-00-F4-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-30-2E-33-2E-34-64-68-61-73-68-58-20-21-96-2E-20-68-1D-F1-A6-13-75-79-F9-12-13-C7-A0-26-C9-8C-32-B6-00-DE-FD-5B-B3-0A-04-C8-13-19-90-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-F4-66-61-63-74-69-76-65-F4-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
W [main] Received: Header (Version:1, Op:1, Flags:0, Len: 244, Group:1, Seq:1, Command:0) CBOR:
      {
          "images": [
              {
                  "active": true,
                  "bootable": true,
                  "confirmed": true,
                  "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
                  "pending": false,
                  "permanent": false,
                  "slot": 0,
                  "version": "0.3.2"
              },
              {
                  "active": false,
                  "bootable": true,
                  "confirmed": false,
                  "hash": "21962E20681DF1A6137579F91213C7A026C98C32B600DEFD5BB30A04C8131990",
                  "pending": false,
                  "permanent": false,
                  "slot": 1,
                  "version": "0.3.4"
              }
          ],
          "splitStatus": 0
      }
D onUpgradeCompleted()

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 18, 2024

Btw. ZipPackage is derived from https://github.com/NordicSemiconductor/Android-nRF-Connect-Device-Manager/blob/main/sample/src/main/java/io/runtime/mcumgr/sample/utils/ZipPackage.java and has been adapted a bit (to provide getManifestFileVersion() which we need to compare the downloaded version of our firmware to the one on the device):

ZipPackage.java
package io.runtime.mcumgr.sample.utils;

import androidx.annotation.Keep;
import androidx.annotation.NonNull;

import com.google.gson.Gson;
import com.google.gson.GsonBuilder;

import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.File;
import java.io.IOException;
import java.io.InputStreamReader;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.Map;
import java.util.zip.ZipEntry;
import java.util.zip.ZipInputStream;

import io.runtime.mcumgr.dfu.mcuboot.model.ImageSet;
import io.runtime.mcumgr.dfu.mcuboot.model.TargetImage;
import io.runtime.mcumgr.dfu.suit.model.CacheImageSet;
import io.runtime.mcumgr.exception.McuMgrException;
import timber.log.Timber;

public final class ZipPackage {
	private static final String MANIFEST = "manifest.json";

	@SuppressWarnings({"unused", "MismatchedReadAndWriteOfArray"})
	@Keep
	private static class Manifest {
		private int formatVersion;
		private File[] files;

		@Keep
		private static class File {
			/**
			 * The file type. Expected vales are: "application", "bin", "suit-envelope".
			 */
			private String type;
			/**
			 * The name of the image file.
			 */
			private String file;
			/**
			 * The version of the image file.
			 */
			private String version_MCUBOOT;
			/**
			 * The size of the image file in bytes. This is declared size and does not have to
			 * be equal to the actual file size.
			 */
			private int size;
			/**
			 * Image index is used for multi-core devices. Index 0 is the main core (app core),
			 * index 1 is secondary core (net core), etc.
			 * <p>
			 * For single-core devices this is not present in the manifest file and defaults to 0.
			 */
			private int imageIndex = 0;
			/**
			 * The slot number where the image is to be sent. By default images are sent to the
			 * secondary slot and then swapped to the primary slot after the image is confirmed
			 * and the device is reset.
			 * <p>
			 * However, if the device supports Direct XIP feature it is possible to run an app
			 * from a secondary slot. The image has to be compiled for this slot. A ZIP package
			 * can contain images for both slots. Only the one targeting the available one will
			 * be sent.
			 * @since NCS v 2.5, nRF Connect Device Manager 1.8.
			 */
			private int slot = 0; // FIXME MARC: 0 works!, was TargetImage.SLOT_SECONDARY;
			/**
			 * The target partition ID. This parameter is valid for files with type `cache`.
			 */
			private int partition = 0;
		}
	}

	private Manifest manifest;
	private final Map<String, byte[]> entries = new HashMap<>();

	public ArrayList<String> getManifestFileVersion() {
		ArrayList<String> versions = new ArrayList<>(manifest.files.length);
		for (Manifest.File file : manifest.files) {
			versions.add(file.version_MCUBOOT);
		}
		return versions;
	}

	public ZipPackage(@NonNull final byte[] data) throws IOException {
		ZipEntry ze;

		// Unzip the file and look for the manifest.json.
		final ZipInputStream zis = new ZipInputStream(new ByteArrayInputStream(data));
		while ((ze = zis.getNextEntry()) != null) {
			if (ze.isDirectory())
				throw new IOException("Invalid ZIP");

			final String name = validateFilename(ze.getName(), ".");

			if (name.equals(MANIFEST)) {
				final Gson gson = new GsonBuilder().create();
				manifest = gson.fromJson(new InputStreamReader(zis), Manifest.class);
			} else if (name.endsWith(".bin") || name.endsWith(".suit")) {
				final byte[] content = getData(zis);
				entries.put(name, content);
			} else {
				Timber.w("Unsupported file found: %s", name);
			}
		}
	}

	public ImageSet getBinaries() throws IOException, McuMgrException {
		final ImageSet binaries = new ImageSet();

		// Search for images.
		for (final Manifest.File file: manifest.files) {
			final String name = file.file;
			final byte[] content = entries.get(name);
			if (content == null)
				throw new IOException("File not found: " + name);

			binaries.add(new TargetImage(file.imageIndex, file.slot, content));
		}
		return binaries;
	}

	/**
	 * Returns the SUIT envelope.
	 * <p>
	 * This is valid only for SUIT updates using SUIT manager.
	 * @return The SUIT envelope, or null if not present in the ZIP.
	 */
	public byte[] getSuitEnvelope() {
		// First, search for an entry of type "suit-envelope".
		for (final Manifest.File file: manifest.files) {
			if (file.type.equals("suit-envelope")) {
                return entries.get(file.file);
			}
		}
		// If not found, search for a file with the ".suit" extension.
		for (final Manifest.File file: manifest.files) {
			if (file.file.endsWith(".suit")) {
				return entries.get(file.file);
			}
		}
		// Not found.
		return null;
	}

	/**
	 * Raw cache images are sent to the device together with the SUIT envelope before starting the
	 * update process. The cache images are stored in the cache partitions.
	 *
	 * @return The cache images, or null if not present in the ZIP.
	 * @throws IOException if at least one of the cache images is missing.
	 */
	public CacheImageSet getCacheBinaries() throws IOException {
		final CacheImageSet cache = new CacheImageSet();

		// Search for images.
		for (final Manifest.File file: manifest.files) {
			if (file.type.equals("cache")) {
				final String name = file.file;
				final byte[] content = entries.get(name);
				if (content == null)
					throw new IOException("File not found: " + name);

				cache.add(file.partition, content);
			}
		}
		if (cache.getImages().isEmpty())
			return null;
		return cache;
	}

	public byte[] getResource(@NonNull final String name) {
		return entries.get(name);
	}

	private byte[] getData(@NonNull ZipInputStream zis) throws IOException {
		final byte[] buffer = new byte[1024];

		// Read file content to byte array
		final ByteArrayOutputStream os = new ByteArrayOutputStream();
		int count;
		while ((count = zis.read(buffer)) != -1) {
			os.write(buffer, 0, count);
		}
		return os.toByteArray();
	}

	/**
	 * Validates the path (not the content) of the zip file to prevent path traversal issues.
	 *
	 * <p> When unzipping an archive, always validate the compressed files' paths and reject any path
	 * that has a path traversal (such as ../..). Simply looking for .. characters in the compressed
	 * file's path may not be enough to prevent path traversal issues. The code validates the name of
	 * the entry before extracting the entry. If the name is invalid, the entire extraction is aborted.
	 * <p>
	 *
	 * @param filename The path to the file.
	 * @param intendedDir The intended directory where the zip should be.
	 * @return The validated path to the file.
	 * @throws java.io.IOException Thrown in case of path traversal issues.
	 */
	@SuppressWarnings("SameParameterValue")
	private String validateFilename(@NonNull final String filename,
									@NonNull final String intendedDir)
			throws IOException {
		File f = new File(filename);
		String canonicalPath = f.getCanonicalPath();

		File iD = new File(intendedDir);
		String canonicalID = iD.getCanonicalPath();

		if (canonicalPath.startsWith(canonicalID)) {
			return canonicalPath.substring(1); // remove leading "/"
		} else {
			throw new IllegalStateException("File is outside extraction target directory.");
		}
	}

}

@philips77
Copy link
Member

Good morning,
I filtered (and clarified) the last logs you posted, and it got me baffled. Seems like the validation assumes that the hashes are equal, while they are not. Let me check the code and come back to you.

@philips77
Copy link
Member

I went through the code and cannot find the reason. Could you go to the Validate class and add logs all over the place and check why nothing gets uploaded? The only reason I see is that the hash has been found, so something is clearly not right. Either you print a different hash, then is later use in the library, or I have no idea what. Try debugging what happens after the lib gets "image list" response and how it enqueues tasks.

@lsh-silpion
Copy link
Author

I went through the code and cannot find the reason. Could you go to the Validate class and add logs all over the place and check why nothing gets uploaded? The only reason I see is that the hash has been found, so something is clearly not right. Either you print a different hash, then is later use in the library, or I have no idea what. Try debugging what happens after the lib gets "image list" response and how it enqueues tasks.

Which Validate class are you talking about? If you meant the io.runtime.mcumgr.dfu.mcuboot.task.Validate class I sadly can't change it since it comes right out of the Gradle dependency no.nordicsemi.android:mcumgr-core:2.2.2@aar which our app is using.

@philips77
Copy link
Member

You could clone the repo to StudioProjects and add the library as a module just like here:
https://github.com/NordicSemiconductor/Android-DFU-Library/blob/0c559244b34ebd27a4f51f045c067b965f918b73/settings.gradle.kts#L36-L38
You'll be able to modify the source of the library and debug it.

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 20, 2024

You could clone the repo to StudioProjects and add the library as a module just like here: https://github.com/NordicSemiconductor/Android-DFU-Library/blob/0c559244b34ebd27a4f51f045c067b965f918b73/settings.gradle.kts#L36-L38 You'll be able to modify the source of the library and debug it.

I did this and I have some new output for you:

15:26:35.033 D imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
15:26:35.401 D imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
15:26:35.475 D onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@869bff2
15:26:35.477 W [main] Connected to EB:A3:43:8E:4B:5D
15:26:35.479 D onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@4aea643
15:26:35.513 W [main] Connected to EB:A3:43:8E:4B:5D
15:26:35.789 W [main] Services discovered
15:26:35.827 W [main] Services discovered
15:26:36.206 W [main] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
15:26:36.209 W [main] Notifications enabled
15:26:36.306 W [main] Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
15:26:36.309 W [main] Notifications enabled
15:26:36.322 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.325 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.404 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
15:26:36.419 W [main] Wait for value changed complete
15:26:36.424 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
15:26:36.431 W [main] Wait for value changed complete
15:26:36.435 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
15:26:36.438 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
15:26:36.507 W [main] Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
15:26:36.528 W [main] Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
15:26:36.570 W [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
15:26:36.580 W [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
15:26:36.585 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.589 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.644 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
15:26:36.651 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
15:26:36.652 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
15:26:36.658 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
15:26:36.858 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
15:26:36.858 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
15:26:36.897 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
15:26:36.902 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
15:26:36.905 W [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
15:26:36.909 W [main] Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
15:26:36.910 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.911 W [main] Data written to da2e7828-fbce-4e01-ae9e-261174997c48
15:26:36.993 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
15:26:37.010 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
15:26:37.046 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
15:26:37.070 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        },
        {
            "active": false,
            "bootable": true,
            "confirmed": false,
            "hash": "4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715",
            "pending": false,
            "permanent": false,
            "slot": 1,
            "version": "0.3.4.1"
        }
    ],
    "splitStatus": 0
}
15:26:37.080 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
15:26:37.090 W [main] Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
15:26:37.201 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
15:26:37.281 W [main] Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        },
        {
            "active": false,
            "bootable": true,
            "confirmed": false,
            "hash": "4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715",
            "pending": false,
            "permanent": false,
            "slot": 1,
            "version": "0.3.4.1"
        }
    ],
    "splitStatus": 0
}
15:26:37.297 D latestFirmwareVersionString: 0.3.4+1
15:26:37.298 D CUBOx.kt:D  CUBOx.firmwareVersionString: 0.3.1+0
15:26:37.304 D onUpgradeCompleted()

I hope this was helpful!

I also created #209 for you as a reference, you can close the PR later on, I don't expect it to be merged.

Kind regards,

Lars

@philips77
Copy link
Member

Seems like you stared 2 DFU operations at once? Everything seems duplicated.

I also don't know why the last notifications are repeated 4 times, where only 2 requests were made.

@philips77
Copy link
Member

philips77 commented Nov 21, 2024

Also, your logs don't contain the newly added logs.
Could you perhaps use this binding: https://github.com/nomis/slf4j-android instead of slf4j-simple?

In nRFCDM we're using implementation 'uk.kulikov:slf4j2-timber:1.2' which adds Timber bindings. If you're using Timber, it's enough to add this and plant a debug tree.

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 21, 2024

Also, your logs don't contain the newly added logs. Could you perhaps use this binding: https://github.com/nomis/slf4j-android instead of slf4j-simple?

In nRFCDM we're using implementation 'uk.kulikov:slf4j2-timber:1.2' which adds Timber bindings. If you're using Timber, it's enough to add this and plant a debug tree.

Did so and got this:

12:04:48.491 FirmwareUp...onClicked:          D  imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
12:04:48.730 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@9409e7
12:04:48.731 McuMgrBleTransport               I  Connected to EB:A3:43:8E:4B:5D
12:04:49.052 McuMgrBleTransport               I  Services discovered
12:04:49.178 McuMgrBleTransport               I  MTU changed to: 498
12:04:49.378 McuMgrBleTransport               I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
12:04:49.381 McuMgrBleTransport               I  Notifications enabled
12:04:49.394 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:49.476 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
12:04:49.498 McuMgrBleTransport               I  Wait for value changed complete
12:04:49.624 McuMgrBleTransport               I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
12:04:49.667 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
12:04:49.672 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:49.818 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
12:04:49.840 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
12:04:50.107 Validate                         D  onError: Mcu Mgr Error: 8
12:04:50.108 Validate                         D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@c7b6f89, noSwap: false, allowRevert: true
12:04:50.128 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
12:04:50.133 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:50.215 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
12:04:50.245 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
12:04:50.379 Validate                         D  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        },
        {
            "active": false,
            "bootable": true,
            "confirmed": false,
            "hash": "SxlnO9M20PrXi70s1Ymz9ULbbtuVNlCwWviJH/vQ9xU=",
            "pending": false,
            "permanent": false,
            "slot": 1,
            "version": "0.3.4.1"
        }
    ],
    "splitStatus": 0
}
12:04:50.380 Validate                         D  image: TargetImage@c9cfba8
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1, slot.slot == image.slot
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1, slot.active, skip and continue …
12:04:50.381 Validate                         D  slot: ImageSlot@ff25e66
12:04:50.381 Validate                         D  slot: ImageSlot@ff25e66, slot.hash equals mcuMgrImage.getHash(): 4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
12:04:50.381 Validate                         D  skipping …
12:04:50.381 Validate                         D  cacheImages: null
12:04:50.382 FirmwareUp...Completed:          D  onUpgradeCompleted()

Also, your nRF CDM app I checked which images are currently on our device and got this:

image

@philips77
Copy link
Member

philips77 commented Nov 21, 2024

OK, I found the issue.
It's here:

private int slot = 0; // FIXME MARC: 0 works!, was TargetImage.SLOT_SECONDARY;

(see #202 (comment) -> expand ZipPackage)

By modifying that this image is skipped, as an active image is found on that slot, therefore nothing can be send there.
Your image should target SLOT_SECONDARY, as it is sent there. It will later be swapped to the primary by McuBoot, but from the lib's perspective it's irrelevant.

@lsh-silpion
Copy link
Author

OK, I found the issue. It's here:

private int slot = 0; // FIXME MARC: 0 works!, was TargetImage.SLOT_SECONDARY;

By modifying that this image is skipped, as an active image is found on that slot, therefore nothing can be send there. Your image should target SLOT_SECONDARY, as it is sent there. It will later be swapped to the primary by McuBoot, but from the lib's perspective it's irrelevant.

That was a change done by my boss, I've already asked him why he did this. Reverting the change seems to make it work, thanks again!

@philips77
Copy link
Member

Log analisis

You tries to send this image:

12:04:48.491 FirmwareUp...onClicked:          D  imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715

Connection part (boring...):

12:04:48.730 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@9409e7
12:04:48.731 McuMgrBleTransport               I  Connected to EB:A3:43:8E:4B:5D
12:04:49.052 McuMgrBleTransport               I  Services discovered
12:04:49.178 McuMgrBleTransport               I  MTU changed to: 498
12:04:49.378 McuMgrBleTransport               I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
12:04:49.381 McuMgrBleTransport               I  Notifications enabled

Checking bootloader mode, which are not supported (assuming McuBoot):

12:04:49.394 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:49.476 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
12:04:49.498 McuMgrBleTransport               I  Wait for value changed complete
12:04:49.624 McuMgrBleTransport               I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
12:04:49.667 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
12:04:49.672 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:49.818 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
12:04:49.840 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
12:04:50.107 Validate                         D  onError: Mcu Mgr Error: 8

Validating what's on the device:

12:04:50.108 Validate                         D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@c7b6f89, noSwap: false, allowRevert: true
12:04:50.128 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
12:04:50.133 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:04:50.215 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-F6-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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-67-30-2E-33-2E-34-2E-31-64-68-61-73-68-58-20-4B-19-67-3B-D3-36-D0-FA-D7-8B-BD-2C-D5-89-B3-F5-42-DB-6E-DB-95-36-50-B0-5A-F8-89-1F-FB-D0-F7-15-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-F4-66-61-63-74-69-76-65-F4-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
12:04:50.245 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 246, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}
12:04:50.379 Validate                         D  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false},{"slot":1,"version":"0.3.4.1","hash":"4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715","bootable":true,"pending":false,"confirmed":false,"active":false,"permanent":false}],"splitStatus":0}

An image with the same hash was found on the secondary slot:

{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        },
        {
            "active": false,
            "bootable": true,
            "confirmed": false,
            "hash": "4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715",
            "pending": false,
            "permanent": false,
            "slot": 1,
            "version": "0.3.4.1"
        }
    ],
    "splitStatus": 0
}

Now magic happens:

// One image is to be updated:
12:04:50.380 Validate                         D  image: TargetImage@c9cfba8
// Iterate over available slots, first:
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1
// We found the slot matching the image target slot number:
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1, slot.slot == image.slot
// However, it's active... we can't upload this image :(
12:04:50.380 Validate                         D  slot: ImageSlot@f7486c1, slot.active, skip and continue …
// Let's check another slot:
12:04:50.381 Validate                         D  slot: ImageSlot@ff25e66
// The slot already contains this image, no upload will be required:
12:04:50.381 Validate                         D  slot: ImageSlot@ff25e66, slot.hash equals mcuMgrImage.getHash(): 4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
// However, as the slot contains an active image, we must skip it. Direct XIP feature allows to have 2 images of the same app, compiled for different slots.
12:04:50.381 Validate                         D  skipping …
12:04:50.381 Validate                         D  cacheImages: null
// There was no tasks added to the performer, report success.
12:04:50.382 FirmwareUp...Completed:          D  onUpgradeCompleted() <- as nothing more is to be done, report success

@philips77
Copy link
Member

I understand why the change was made. The image was compiled against the primary slot. However, from the library point of view, as it sends it to the secondary slot, the target slot should be SLOT_SECONDARY.

If you'd be using Direct XIP feature, there it actually makes sense. A ZIP file may contain 2 binaries of the same app, compiled for the primary and secondary slot. The library chooses the one which slot isn't active and uploads only this one.

@philips77
Copy link
Member

May I know in which case changing the slot to SLOT_PRIMARY made it work? What was the intention of the change?

@lsh-silpion
Copy link
Author

May I know in which case changing the slot to SLOT_PRIMARY made it work? What was the intention of the change?

My boss said he always got a timeout for slot 1 so he changed it to slot 0.

@philips77
Copy link
Member

If possible, could you paste logs from such timeout? I wonder what's the root cause.

@lsh-silpion
Copy link
Author

If possible, could you paste logs from such timeout? I wonder what's the root cause.

My boss had a brilliant idea: erase the inactive slot and try again. I did so and now I am also getting the timeout:

2024-11-22 11:54:08.501 16169-16169 FirmwareUp...onClicked:          D  imageSet.images[0].image.hash: 0x4B19673BD336D0FAD78BBD2CD589B3F542DB6EDB953650B05AF8891FFBD0F715
2024-11-22 11:54:08.662 16169-16169 BluetoothAdapter                 D  STATE_ON
2024-11-22 11:54:08.663 16169-16169 BluetoothGatt                    D  connect() - device: EB:A3:43:8E:4B:5D, auto: false
2024-11-22 11:54:08.663 16169-16169 BluetoothAdapter                 D  isSecureModeEnabled
2024-11-22 11:54:08.664 16169-16169 BluetoothGatt                    D  registerApp()
2024-11-22 11:54:08.664 16169-16169 BluetoothGatt                    D  registerApp() - UUID=e3643b72-0ff8-474c-b399-2e6af7819477
2024-11-22 11:54:08.666 16169-16276 BluetoothGatt                    D  onClientRegistered() - status=0 clientIf=16
2024-11-22 11:54:08.681 16169-16276 BluetoothGatt                    D  onClientConnectionState() - status=0 clientIf=16 device=EB:A3:43:8E:4B:5D
2024-11-22 11:54:08.688 16169-16169 FirmwareUp...deStarted:          D  onUpgradeStarted(): controller: io.runtime.mcumgr.dfu.mcuboot.FirmwareUpgradeManager@a29b800
2024-11-22 11:54:08.689 16169-16169 McuMgrBleTransport               I  Connected to EB:A3:43:8E:4B:5D
2024-11-22 11:54:08.994 16169-16325 BluetoothGatt                    D  discoverServices() - device: EB:A3:43:8E:4B:5D
2024-11-22 11:54:09.005 16169-16276 BluetoothGatt                    D  onSearchComplete() = Device=EB:A3:43:8E:4B:5D Status=0
2024-11-22 11:54:09.007 16169-16169 McuMgrBleTransport               I  Services discovered
2024-11-22 11:54:09.039 16169-16169 BluetoothGatt                    D  configureMTU() - device: EB:A3:43:8E:4B:5D mtu: 498
2024-11-22 11:54:09.128 16169-16276 BluetoothGatt                    D  onConfigureMTU() - Device=EB:A3:43:8E:4B:5D mtu=498 status=0
2024-11-22 11:54:09.130 16169-16169 McuMgrBleTransport               I  MTU changed to: 498
2024-11-22 11:54:09.132 16169-16169 BluetoothGatt                    D  setCharacteristicNotification() - uuid: da2e7828-fbce-4e01-ae9e-261174997c48 enable: true
2024-11-22 11:54:09.333 16169-16169 McuMgrBleTransport               I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
2024-11-22 11:54:09.336 16169-16169 McuMgrBleTransport               I  Notifications enabled
2024-11-22 11:54:09.360 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:54:09.436 16169-16169 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
2024-11-22 11:54:09.441 16169-16276 BleGatt.kt...icChanged:          D  characteristic changed: 1,0,0,6,0,0,-1,6,-65,98,114,99,8,-1
2024-11-22 11:54:09.448 16169-16276 DeviceChar...ification:          D  fromNotify: [B@1a33fdf
2024-11-22 11:54:09.468 16169-16169 McuMgrBleTransport               I  Wait for value changed complete
2024-11-22 11:54:09.474 16169-16276 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-22 11:54:09.475 16169-16276 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[1, 0, 0, 6, 0, 0, -1, 6, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-22 11:54:09.592 16169-16169 McuMgrBleTransport               I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
2024-11-22 11:54:09.630 16169-16169 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+1
2024-11-22 11:54:09.632 16169-16169 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-22 11:54:09.647 16169-16169 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
2024-11-22 11:54:09.651 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:54:09.667 16169-16183 System                           W  A resource failed to call end. 
2024-11-22 11:54:09.668 16169-16183 chatty                           I  uid=10371() FinalizerDaemon identical 1 line
2024-11-22 11:54:09.668 16169-16183 System                           W  A resource failed to call end. 
2024-11-22 11:54:09.718 16169-16169 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
2024-11-22 11:54:09.724 16169-16276 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,6,0,0,0,8,-65,98,114,99,8,-1
2024-11-22 11:54:09.733 16169-16276 DeviceChar...ification:          D  fromNotify: [B@5410571
2024-11-22 11:54:09.735 16169-16169 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
2024-11-22 11:54:09.747 16169-16276 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-22 11:54:09.748 16169-16276 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, 6, 0, 0, 0, 8, -65, 98, 114, 99, 8, -1], notificationBytes=null)])]
2024-11-22 11:54:09.898 16169-16169 Validate                         D  onError: Mcu Mgr Error: 8
2024-11-22 11:54:09.899 16169-16169 Validate                         D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@6b08253, noSwap: false, allowRevert: true
2024-11-22 11:54:09.934 16169-16169 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+1
2024-11-22 11:54:09.935 16169-16169 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-22 11:54:09.943 16169-16169 McuMgrBleTransport               I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 1, Command: 0) CBOR {}
2024-11-22 11:54:09.948 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:54:10.033 16169-16169 McuMgrBleTransport               I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-86-00-01-01-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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
2024-11-22 11:54:10.075 16169-16169 McuMgrBleTransport               I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 1, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
2024-11-22 11:54:10.099 16169-16276 BleGatt.kt...icChanged:          D  characteristic changed: 9,0,0,-122,0,1,1,0,-65,102,105,109,97,103,101,115,-97,-65,100,115,108,111,116,0,103,118,101,114,115,105,111,110,101,48,46,51,46,50,100,104,97,115,104,88,32,-90,63,-13,-75,-43,-94,-48,67,-56,34,45,68,-42,79,49,-78,48,-102,125,116,-102,-49,-47,50,-28,-91,-75,-87,-102,8,-19,-71,104,98,111,111,116,97,98,108,101,-11,103,112,101,110,100,105,110,103,-12,105,99,111,110,102,105,114,109,101,100,-11,102,97,99,116,105,118,101,-11,105,112,101,114,109,97,110,101,110,116,-12,-1,-1,107,115,112,108,105,116,83,116,97,116,117,115,0,-1
2024-11-22 11:54:10.106 16169-16276 DeviceChar...ification:          D  fromNotify: [B@b6f0af
2024-11-22 11:54:10.109 16169-16276 ParseNotif...26:invoke:          D  newList: [DeviceService(uuid=00001801-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a05-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_INDICATE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a05-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_INDICATE, readBytes=null)], canRead=false, canWrite=false, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=00002b29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ, PROPERTY_WRITE], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=true, readBytes=[0], notificationBytes=null), DeviceCharacteristics(uuid=00002b2a-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[73, 48, -103, -126, 68, 57, -22, 85, 14, -54, 62, -40, -42, 32, -109, 88], notificationBytes=null)]), DeviceService(uuid=00001800-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a00-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 85, 66, 79, 116, 105, 108, 105, 116, 121, 32, 66, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a01-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[0, 0], notificationBytes=null), DeviceCharacteristics(uuid=00002a04-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[24, 0, 40, 0, 0, 0, 42, 0], notificationBytes=null)]), DeviceService(uuid=0000180f-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a19-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null), DeviceDescriptor(uuid=00002904-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=00002a19-0000-1000-8000-00805f9b34fb, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[100], notificationBytes=null)]), DeviceService(uuid=0000180a-0000-1000-8000-00805f9b34fb, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=00002a24-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[67, 117, 98, 111, 120], notificationBytes=null), DeviceCharacteristics(uuid=00002a29-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[83, 105, 108, 112, 105, 111, 110], notificationBytes=null), DeviceCharacteristics(uuid=00002a25-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[], notificationBytes=null), DeviceCharacteristics(uuid=00002a26-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=nu
2024-11-22 11:54:10.109 16169-16276 ParseNotif...26:invoke:          D  ll, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[48, 46, 51, 46, 49, 43, 48], notificationBytes=null), DeviceCharacteristics(uuid=00002a27-0000-1000-8000-00805f9b34fb, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[], canRead=true, canWrite=false, readBytes=[82, 101, 118, 46, 48], notificationBytes=null)]), DeviceService(uuid=6e400001-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400003-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[1, 0, 0, 0], notificationBytes=null), DeviceCharacteristics(uuid=6e400002-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_WRITE, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[], canRead=false, canWrite=true, readBytes=null, notificationBytes=null), DeviceCharacteristics(uuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_READ], writeTypes=[WRITE_TYPE_DEFAULT], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=6e400004-b5a3-f393-e0a9-e50e24dcca9e, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=true, canWrite=false, readBytes=[0, 0, 0, 0], notificationBytes=null)]), DeviceService(uuid=8d53dc1d-1db7-4cd3-868b-8a527460aa84, name=Mfr Service, characteristics=[DeviceCharacteristics(uuid=da2e7828-fbce-4e01-ae9e-261174997c48, name=Mfr Characteristic, descriptor=null, permissions=0, properties=[PROPERTY_NOTIFY, PROPERTY_WRITE_NO_RESPONSE], writeTypes=[WRITE_TYPE_NO_RESPONSE], descriptors=[DeviceDescriptor(uuid=00002902-0000-1000-8000-00805f9b34fb, name=Unknown, charUuid=da2e7828-fbce-4e01-ae9e-261174997c48, permissions=[], notificationProperty=PROPERTY_NOTIFY, readBytes=null)], canRead=false, canWrite=true, readBytes=[9, 0, 0, -122, 0, 1, 1, 0, -65, 102, 105, 109, 97, 103, 101, 115, -97, -65, 100, 115, 108, 111, 116, 0, 103, 118, 101, 114, 115, 105, 111, 110, 101, 48, 46, 51, 46, 50, 100, 104, 97, 115, 104, 88, 32, -90, 63, -13, -75, -43, -94, -48, 67, -56, 34, 45, 68, -42, 79, 49, -78, 48, -102, 125, 116, -102, -49, -47, 50, -28, -91, -75, -87, -102, 8, -19, -71, 104, 98, 111, 111, 116, 97, 98, 108, 101, -11, 103, 112, 101, 110, 100, 105, 110, 103, -12, 105, 99, 111, 110, 102, 105, 114, 109, 101, 100, -11, 102, 97, 99, 116, 105, 118, 101, -11, 105, 112, 101, 114, 109, 97, 110, 101, 110, 116, -12, -1, -1, 107, 115, 112, 108, 105, 116, 83, 116, 97, 116, 117, 115, 0, -1], notificationBytes=null)])]
2024-11-22 11:54:10.214 16169-16169 Validate                         D  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
2024-11-22 11:54:10.214 16169-16169 Validate                         D  image: io.runtime.mcumgr.dfu.mcuboot.model.TargetImage@a0be8cb
2024-11-22 11:54:10.214 16169-16169 Validate                         D  slot: io.runtime.mcumgr.response.img.McuMgrImageStateResponse$ImageSlot@228a8
2024-11-22 11:54:10.214 16169-16169 Validate                         D  !found
2024-11-22 11:54:10.215 16169-16169 Validate                         D  mode: CONFIRM_ONLY
2024-11-22 11:54:10.215 16169-16169 Validate                         D  cacheImages: null
2024-11-22 11:54:10.219 16169-16169 FirmwareUp...teChanged:          D  onStateChanged(): previousState: VALIDATE, newState: UPLOAD
2024-11-22 11:54:10.261 16169-16169 MainViewMo...reVersion:          D  latestFirmwareVersionString: 0.3.4+1
2024-11-22 11:54:10.262 16169-16169 CUBOx.kt:3...reVersion:          D  CUBOx.firmwareVersionString: 0.3.1+0
2024-11-22 11:54:10.379 16169-16169 McuMgrBleTransport               I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 2, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAAUHIDAAAAAAAAAwQAAQAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":226535,"sha":"dVghnV5VLH7zLOXr9/tWKbs0snCX5iHH6VsLnYWDa4c=","off":0}
2024-11-22 11:54:10.388 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:54:50.380 16169-16298 Uploader                         W  A notification for chunk with offset=0 was lost, current offset: 0
2024-11-22 11:54:50.382 16169-16298 Uploader                         W  Uploader write failure for chunk with offset=0: Transaction 2 timed out without receiving a response
2024-11-22 11:54:50.483 16169-16169 McuMgrBleTransport               I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 3, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAAUHIDAAAAAAAAAwQAAQAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":226535,"sha":"dVghnV5VLH7zLOXr9/tWKbs0snCX5iHH6VsLnYWDa4c=","off":0}
2024-11-22 11:54:50.494 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:55:30.457 16169-16297 Uploader                         W  A notification for chunk with offset=0 was lost, current offset: 0
2024-11-22 11:55:30.459 16169-16297 Uploader                         W  Uploader write failure for chunk with offset=0: Transaction 3 timed out without receiving a response
2024-11-22 11:55:30.566 16169-16169 McuMgrBleTransport               I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 4, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAAUHIDAAAAAAAAAwQAAQAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":226535,"sha":"dVghnV5VLH7zLOXr9/tWKbs0snCX5iHH6VsLnYWDa4c=","off":0}
2024-11-22 11:55:30.580 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:56:10.537 16169-16297 Uploader                         W  A notification for chunk with offset=0 was lost, current offset: 0
2024-11-22 11:56:10.538 16169-16297 Uploader                         W  Uploader write failure for chunk with offset=0: Transaction 4 timed out without receiving a response
2024-11-22 11:56:10.640 16169-16169 McuMgrBleTransport               I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 5, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAAUHIDAAAAAAAAAwQAAQAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":226535,"sha":"dVghnV5VLH7zLOXr9/tWKbs0snCX5iHH6VsLnYWDa4c=","off":0}
2024-11-22 11:56:10.650 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:56:50.615 16169-16297 Uploader                         W  A notification for chunk with offset=0 was lost, current offset: 0
2024-11-22 11:56:50.617 16169-16297 Uploader                         W  Uploader write failure for chunk with offset=0: Transaction 5 timed out without receiving a response
2024-11-22 11:56:50.729 16169-16169 McuMgrBleTransport               I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 6, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAAUHIDAAAAAAAAAwQAAQAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":226535,"sha":"dVghnV5VLH7zLOXr9/tWKbs0snCX5iHH6VsLnYWDa4c=","off":0}
2024-11-22 11:56:50.741 16169-16169 McuMgrBleTransport               I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-22 11:57:30.698 16169-16298 Uploader                         W  A notification for chunk with offset=0 was lost, current offset: 0
2024-11-22 11:57:30.700 16169-16298 Uploader                         W  Uploader write failure for chunk with offset=0: Transaction 6 timed out without receiving a response
2024-11-22 11:57:30.717 16169-16297 Uploader                         E  Upload failed: Transaction 6 timed out without receiving a response
2024-11-22 11:57:30.722 16169-16169 FirmwareUp...adeFailed:          D  onUpgradeFailed(): state: UPLOAD, error: Transaction 6 timed out without receiving a response

I hope that helps you to nail down the issue!

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 22, 2024

Btw. now I can also reproduce this with your nRF CDM app:

image
12:13:58.426 BluetoothGatt            D  onClientConnectionState() - status=0 clientIf=16 device=EB:A3:43:8E:4B:5D
12:13:58.442 McuMgrBleTransport       I  Connected to EB:A3:43:8E:4B:5D
12:13:58.842 McuMgrBleTransport       I  Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
12:13:58.920 McuMgrBleTransport       I  PHY updated (TX: LE 2M, RX: LE 2M)
12:13:59.322 McuMgrBleTransport       I  Services discovered
12:13:59.419 McuMgrBleTransport       I  Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 5000ms)
12:13:59.488 McuMgrBleTransport       I  MTU changed to: 498
12:13:59.685 McuMgrBleTransport       I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
12:13:59.686 McuMgrBleTransport       I  Notifications enabled
12:13:59.693 McuMgrBleTransport       I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:13:59.782 McuMgrBleTransport       I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
12:13:59.789 McuMgrBleTransport       I  Wait for value changed complete
12:13:59.843 McuMgrBleTransport       I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
12:13:59.844 McuMgrBleTransport       I  PHY read (TX: LE 2M, RX: LE 2M)
12:13:59.862 McuMgrBleTransport       I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
12:14:00.057 McuMgrBleTransport       I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:14:00.063 McuMgrBleTransport       I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 1, Command: 6) CBOR {}
12:14:00.066 McuMgrBleTransport       I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:14:00.121 McuMgrBleTransport       I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
12:14:00.123 McuMgrBleTransport       I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-01-06-BF-62-72-63-08-FF
12:14:00.128 McuMgrBleTransport       I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
12:14:00.137 McuMgrBleTransport       I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
12:14:00.262 Validate                 D  onError: Mcu Mgr Error: 8
12:14:00.263 Validate                 D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@a4f7863, noSwap: false, allowRevert: true
12:14:00.337 McuMgrBleTransport       I  Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
12:14:00.345 McuMgrBleTransport       I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 2, Command: 0) CBOR {}
12:14:00.355 McuMgrBleTransport       I  Sending (19 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 11, Group: 0, Seq: 3, Command: 7) CBOR {"format":"sv"}
12:14:00.356 McuMgrBleTransport       I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:14:00.359 McuMgrBleTransport       I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
12:14:00.394 McuMgrBleTransport       I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-86-00-01-02-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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
12:14:00.396 McuMgrBleTransport       I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-03-07-BF-62-72-63-08-FF
12:14:00.407 McuMgrBleTransport       I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
12:14:00.412 McuMgrBleTransport       I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 3, Command: 7) CBOR {"rc":8}
12:14:00.533 Validate                 D  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
12:14:00.533 Validate                 D  image: io.runtime.mcumgr.dfu.mcuboot.model.TargetImage@b1f9778
12:14:00.534 Validate                 D  slot: io.runtime.mcumgr.response.img.McuMgrImageStateResponse$ImageSlot@b6a3e51
12:14:00.534 Validate                 D  !found
12:14:00.535 Validate                 D  mode: CONFIRM_ONLY
12:14:00.537 Validate                 D  cacheImages: null
12:14:00.540 ImageUpgradeViewModel    I  Uploading firmware...
12:14:03.367 BluetoothGatt            D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=39 latency=0 timeout=42 status=0
12:14:40.782 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:14:40.783 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 5 timed out without receiving a response
12:15:12.201 System                   W  A resource failed to call end. 
12:15:12.202 System                   W  A resource failed to call end. 
12:15:20.811 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:15:20.812 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 6 timed out without receiving a response
12:16:00.863 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:16:00.864 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 7 timed out without receiving a response
12:16:40.916 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:16:40.917 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 8 timed out without receiving a response
12:17:20.965 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:17:20.966 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 9 timed out without receiving a response
12:17:20.983 Uploader                 E  Upload failed: Transaction 9 timed out without receiving a response
12:17:20.996 ImageUpgradeViewModel    E  Upgrade failed
                                         Transaction 9 timed out without receiving a response
                                         	at io.runtime.mcumgr.ble.McuMgrBleTransport$2.onFailure(McuMgrBleTransport.java:429)
                                         	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.onFailure$lambda$2(SmpProtocolSession.kt:169)
                                         	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.$r8$lambda$_a4Sj5nhnKBR_l1QU5smoEMTDUg(Unknown Source:0)
                                         	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt$$ExternalSyntheticLambda0.run(D8$$SyntheticClass:0)
                                         	at android.os.Handler.handleCallback(Handler.java:883)
                                         	at android.os.Handler.dispatchMessage(Handler.java:100)
                                         	at android.os.Looper.loop(Looper.java:237)
                                         	at android.os.HandlerThread.run(HandlerThread.java:67)
                                         Caused by: Transaction 9 timed out without receiving a response
                                         	at io.runtime.mcumgr.ble.callback.SmpProtocolSession$writer$2$job$1.invokeSuspend(SmpProtocolSession.kt:102)
                                         	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                         	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:101)
                                         	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:589)
                                         	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:832)
                                         	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:720)
                                         	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:707)

@philips77
Copy link
Member

When you click this "expand" icon next to Firmware Upgrade - what value do you have as Number of mcumgr buffers?
As your device doesn't seem to support reassembly or pipelining, you should change the value to 1 and try again.
Upload will be slower, as now each packet send will expect a notification with acknowledgement.

To enable pipelining, compile the firmware with MCUMGR_TRANSPORT_NETBUF_COUNT set (it was renamed from MCUMGR_BUF_COUNT in Zephyr 3.3.0).

@lsh-silpion
Copy link
Author

lsh-silpion commented Nov 22, 2024

When you click this "expand" icon next to Firmware Upgrade - what value do you have as Number of mcumgr buffers? As your device doesn't seem to support reassembly or pipelining, you should change the value to 1 and try again. Upload will be slower, as now each packet send will expect a notification with acknowledgement.

To enable pipelining, compile the firmware with MCUMGR_TRANSPORT_NETBUF_COUNT set (it was renamed from MCUMGR_BUF_COUNT in Zephyr 3.3.0).

The value was set to 4, I changed it to 1 as you recommended and tried again:

image
13:20:56.713 McuMgrBleTransport     I  Connected to EB:A3:43:8E:4B:5D
13:20:57.132 McuMgrBleTransport     I  Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
13:20:57.215 McuMgrBleTransport     I  PHY updated (TX: LE 2M, RX: LE 2M)
13:20:57.648 McuMgrBleTransport     I  Services discovered
13:20:57.751 McuMgrBleTransport     I  Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 5000ms)
13:20:57.835 McuMgrBleTransport     I  MTU changed to: 498
13:20:58.033 McuMgrBleTransport     I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
13:20:58.034 McuMgrBleTransport     I  Notifications enabled
13:20:58.045 McuMgrBleTransport     I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
13:20:58.129 McuMgrBleTransport     I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
13:20:58.135 McuMgrBleTransport     I  Wait for value changed complete
13:20:58.199 McuMgrBleTransport     I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
13:20:58.201 McuMgrBleTransport     I  PHY read (TX: LE 2M, RX: LE 2M)
13:20:58.217 McuMgrBleTransport     I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
13:20:58.416 McuMgrBleTransport     I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
13:20:58.424 McuMgrBleTransport     I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 1, Command: 6) CBOR {}
13:20:58.429 McuMgrBleTransport     I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
13:20:58.469 McuMgrBleTransport     I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
13:20:58.479 McuMgrBleTransport     I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
13:20:58.521 BluetoothGatt          D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=12 latency=0 timeout=500 status=0
13:20:58.628 Validate               D  onError: Mcu Mgr Error: 8
13:20:58.628 Validate               D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@8cf4dff, noSwap: false, allowRevert: true
13:20:58.637 McuMgrBleTransport     I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-01-06-BF-62-72-63-08-FF
13:20:58.638 McuMgrBleTransport     I  Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
13:20:58.644 McuMgrBleTransport     I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
13:20:58.650 McuMgrBleTransport     I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 2, Command: 0) CBOR {}
13:20:58.720 McuMgrBleTransport     I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
13:20:58.725 McuMgrBleTransport     I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-86-00-01-02-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-30-2E-33-2E-32-64-68-61-73-68-58-20-A6-3F-F3-B5-D5-A2-D0-43-C8-22-2D-44-D6-4F-31-B2-30-9A-7D-74-9A-CF-D1-32-E4-A5-B5-A9-9A-08-ED-B9-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
13:20:58.741 McuMgrBleTransport     I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 134, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        }
    ],
    "splitStatus": 0
}
13:20:58.747 McuMgrBleTransport     I  Sending (19 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 11, Group: 0, Seq: 3, Command: 7) CBOR {"format":"sv"}
13:20:58.866 Validate               D  Validation response: {"images":[{"slot":0,"version":"0.3.2","hash":"pj/ztdWi0EPIIi1E1k8xsjCafXSaz9Ey5KW1qZoI7bk=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
{
    "images": [
        {
            "active": true,
            "bootable": true,
            "confirmed": true,
            "hash": "A63FF3B5D5A2D043C8222D44D64F31B2309A7D749ACFD132E4A5B5A99A08EDB9",
            "pending": false,
            "permanent": false,
            "slot": 0,
            "version": "0.3.2"
        }
    ],
    "splitStatus": 0
}
13:20:58.866 Validate               D  image: TargetImage@3799464
13:20:58.866 Validate               D  slot: McuMgrImageStateResponse$ImageSlot@f52d6cd
13:20:58.867 Validate               D  !found
13:20:58.868 Validate               D  mode: CONFIRM_ONLY
13:20:58.870 Validate               D  cacheImages: null
13:20:58.873 ImageUpgradeViewModel  I  Uploading firmware...
13:21:01.650 BluetoothGatt          D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=39 latency=0 timeout=42 status=0
13:21:39.052 ImageUpgradeViewModel  E  Upgrade failed
                                       Transaction 5 timed out without receiving a response
                                       	at io.runtime.mcumgr.ble.McuMgrBleTransport$2.onFailure(McuMgrBleTransport.java:429)
                                       	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.onFailure$lambda$2(SmpProtocolSession.kt:169)
                                       	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.$r8$lambda$_a4Sj5nhnKBR_l1QU5smoEMTDUg(Unknown Source:0)
                                       	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt$$ExternalSyntheticLambda0.run(D8$$SyntheticClass:0)
                                       	at android.os.Handler.handleCallback(Handler.java:883)
                                       	at android.os.Handler.dispatchMessage(Handler.java:100)
                                       	at android.os.Looper.loop(Looper.java:237)
                                       	at android.os.HandlerThread.run(HandlerThread.java:67)
                                       Caused by: Transaction 5 timed out without receiving a response
                                       	at io.runtime.mcumgr.ble.callback.SmpProtocolSession$writer$2$job$1.invokeSuspend(SmpProtocolSession.kt:102)
                                       	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                       	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:101)
                                       	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:589)
                                       	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:832)
                                       	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:720)
                                       	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:707)

@philips77
Copy link
Member

If you have nRF Connect Device Manager running from code, could you open ObservableMcuMgrBleTransport file and add

@Override
public int getMinLogPriority() {
    return Log.DEBUG;
}

method and try again? It will log also during uploading (by default logging on upload is disabled as speed optimization).

@philips77
Copy link
Member

Also, have a look at:

12:14:00.540 ImageUpgradeViewModel    I  Uploading firmware...
12:14:03.367 BluetoothGatt            D  onConnectionUpdated() - Device=EB:A3:43:8E:4B:5D interval=39 latency=0 timeout=42 status=0
12:14:40.782 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:14:40.783 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 5 timed out without receiving a response
12:15:12.201 System                   W  A resource failed to call end. 
12:15:12.202 System                   W  A resource failed to call end. 
12:15:20.811 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:15:20.812 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 6 timed out without receiving a response
12:16:00.863 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:16:00.864 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 7 timed out without receiving a response
12:16:40.916 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:16:40.917 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 8 timed out without receiving a response
12:17:20.965 Uploader                 W  A notification for chunk with offset=0 was lost, current offset: 0
12:17:20.966 Uploader                 W  Uploader write failure for chunk with offset=0: Transaction 9 timed out without receiving a response
12:17:20.983 Uploader                 E  Upload failed: Transaction 9 timed out without receiving a response
12:17:20.996 ImageUpgradeViewModel    E  Upgrade failed

Looks like the device doesn't respond with notifications. Library tries 5 times and gives up.

@philips77
Copy link
Member

Hello,
Do you have any updates on this?

@lsh-silpion
Copy link
Author

Hello, Do you have any updates on this?

Hi @philips77 , I am currently working on something else. I'll coming back to you once I have new results. Please be patient.

@lsh-silpion
Copy link
Author

Hi @philips77 , some news. I found some time to add that Method to ObservableMcuMgrBleTransport and run the update attempt from your nRF CDM app with that change:

2024-11-29 11:45:08.967 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:45:08.968 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:45:08.974 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() in
2024-11-29 11:45:08.976 20272-20411 mali_winsys             no....droid.nrfconnectdevicemanager  I  delete_surface() [268x145] return
2024-11-29 11:45:08.976 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() out
2024-11-29 11:45:08.976 20272-20411 libEGL                  no....droid.nrfconnectdevicemanager  W  EGLNativeWindowType 0x7941dc0710 disconnect failed
2024-11-29 11:45:08.983 20272-20272 ViewRootIm...[Kurzinfo] no....droid.nrfconnectdevicemanager  I  dispatchDetachedFromWindow
2024-11-29 11:45:08.990 20272-20272 InputTransport          no....droid.nrfconnectdevicemanager  D  Input channel destroyed: 'd88625 ', fd=84
2024-11-29 11:45:09.942 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:09.946 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:11.804 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 0
2024-11-29 11:45:11.808 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:11.809 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:18.498 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 1
2024-11-29 11:45:18.553 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:18.554 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:18.598 20272-20272 Dialog                  no....droid.nrfconnectdevicemanager  D  mIsSamsungBasicInteraction = false, isMetaDataInActivity = false
2024-11-29 11:45:18.645 20272-20272 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  I  [INFO] isPopOver = false
2024-11-29 11:45:18.646 20272-20272 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  I  updateCaptionType >> DecorView@a163b9[], isFloating: true, isApplication: true, hasWindowDecorCaption: false, hasWindowControllerCallback: false
2024-11-29 11:45:18.646 20272-20272 MultiWindowDecorSupport no....droid.nrfconnectdevicemanager  D  setCaptionType = 0, DecorView = DecorView@a163b9[]
2024-11-29 11:45:18.698 20272-20272 ScrollView              no....droid.nrfconnectdevicemanager  D  initGoToTop
2024-11-29 11:45:18.751 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  setView = com.android.internal.policy.DecorView@a163b9 TM=true MM=false
2024-11-29 11:45:18.919 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  Relayout returned: old=(0,72,1080,2076) new=(27,332,1053,1815) req=(1026,1483)0 dur=10 res=0x7 s={true 519377530880} ch=true
2024-11-29 11:45:18.921 20272-20411 mali_winsys             no....droid.nrfconnectdevicemanager  I  new_window_surface() [1098x1555] return: 0x3000
2024-11-29 11:45:18.999 20272-20272 AbsListView             no....droid.nrfconnectdevicemanager  D   in onLayout changed 
2024-11-29 11:45:19.000 20272-20272 ScrollView              no....droid.nrfconnectdevicemanager  D   onsize change changed 
2024-11-29 11:45:19.003 20272-20272 DecorView               no....droid.nrfconnectdevicemanager  E  mWindow.mActivityCurrentConfig is null
2024-11-29 11:45:19.038 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 1 1
2024-11-29 11:45:19.042 20272-20272 InputMethodManager      no....droid.nrfconnectdevicemanager  D  prepareNavigationBarInfo() DecorView@6ed22a5[MainActivity]
2024-11-29 11:45:19.043 20272-20272 InputMethodManager      no....droid.nrfconnectdevicemanager  D  getNavigationBarColor() -1773582
2024-11-29 11:45:19.125 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 0 1
2024-11-29 11:45:19.159 20272-20272 DecorView               no....droid.nrfconnectdevicemanager  E  mWindow.mActivityCurrentConfig is null
2024-11-29 11:45:19.168 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_RESIZED: frame=(27,332,1053,1815) ci=(0,0,0,0) vi=(0,0,0,0) or=1
2024-11-29 11:45:19.267 20272-20272 TooltipPopup            no....droid.nrfconnectdevicemanager  D  left inset = 0
2024-11-29 11:45:19.286 20272-20272 ViewRootIm...[Kurzinfo] no....droid.nrfconnectdevicemanager  I  setView = android.widget.LinearLayout@fd011a4 TM=true MM=false
2024-11-29 11:45:19.315 20272-20272 ViewRootIm...[Kurzinfo] no....droid.nrfconnectdevicemanager  I  Relayout returned: old=(0,72,1080,2076) new=(846,1691,1080,1836) req=(234,145)0 dur=21 res=0x7 s={true 520972152832} ch=true
2024-11-29 11:45:19.318 20272-20411 mali_winsys             no....droid.nrfconnectdevicemanager  I  new_window_surface() [234x145] return: 0x3000
2024-11-29 11:45:19.341 20272-20272 ViewRootIm...[Kurzinfo] no....droid.nrfconnectdevicemanager  I  MSG_RESIZED: frame=(846,1691,1080,1836) ci=(0,0,0,0) vi=(0,0,0,0) or=1
2024-11-29 11:45:20.087 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  D  updatePointerIcon called with position out of bounds
2024-11-29 11:45:20.094 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() in
2024-11-29 11:45:20.097 20272-20411 mali_winsys             no....droid.nrfconnectdevicemanager  I  delete_surface() [234x145] return
2024-11-29 11:45:20.098 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() out
2024-11-29 11:45:20.099 20272-20411 libEGL                  no....droid.nrfconnectdevicemanager  W  EGLNativeWindowType 0x78d0cc9590 disconnect failed
2024-11-29 11:45:20.107 20272-20272 ViewRootIm...[Kurzinfo] no....droid.nrfconnectdevicemanager  I  dispatchDetachedFromWindow
2024-11-29 11:45:20.142 20272-20272 InputTransport          no....droid.nrfconnectdevicemanager  D  Input channel destroyed: 'bda7f6c', fd=86
2024-11-29 11:45:20.146 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  D  updatePointerIcon called with position out of bounds
2024-11-29 11:45:20.166 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  D  updatePointerIcon called with position out of bounds
2024-11-29 11:45:20.187 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:45:20.192 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:45:20.290 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:20.292 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:20.335 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:45:20.336 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:45:21.194 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 0
2024-11-29 11:45:21.205 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:45:21.207 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:45:21.271 20272-20297 System                  no....droid.nrfconnectdevicemanager  W  A resource failed to call end. 
2024-11-29 11:45:21.842 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 1
2024-11-29 11:45:21.843 20272-20272 AbsListView             no....droid.nrfconnectdevicemanager  D  onTouchUp() mTouchMode : 2
2024-11-29 11:45:21.895 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:45:21.895 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:45:22.509 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:22.511 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:23.322 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 0
2024-11-29 11:45:23.327 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:45:23.329 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:45:23.334 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  ViewPostIme pointer 1
2024-11-29 11:45:23.437 20272-20272 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, LE 1M)
2024-11-29 11:45:23.438 20272-20272 BluetoothAdapter        no....droid.nrfconnectdevicemanager  D  STATE_ON
2024-11-29 11:45:23.441 20272-20272 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  connect() - device: DD:11:A7:3E:0C:16, auto: false
2024-11-29 11:45:23.442 20272-20272 BluetoothAdapter        no....droid.nrfconnectdevicemanager  D  isSecureModeEnabled
2024-11-29 11:45:23.442 20272-20272 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  registerApp()
2024-11-29 11:45:23.443 20272-20272 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  registerApp() - UUID=46322d98-477e-4efb-853d-bc33a33823e5
2024-11-29 11:45:23.448 20272-20308 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onClientRegistered() - status=0 clientIf=16
2024-11-29 11:45:23.449 20272-20272 FirmwareUp...ePerformer no....droid.nrfconnectdevicemanager  V  Starting DFU, mode: CONFIRM_ONLY
2024-11-29 11:45:23.647 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() in
2024-11-29 11:45:23.647 20272-20411 mali_winsys             no....droid.nrfconnectdevicemanager  I  delete_surface() [1098x1555] return
2024-11-29 11:45:23.647 20272-20411 mali_egl                no....droid.nrfconnectdevicemanager  I  eglDestroySurface() out
2024-11-29 11:45:23.647   512-2501  BufferQueueProducer     surfaceflinger                       E  [no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity$_20272#1] disconnect: not connected (req=1)
2024-11-29 11:45:23.648 20272-20411 libEGL                  no....droid.nrfconnectdevicemanager  W  EGLNativeWindowType 0x78d0cc7a10 disconnect failed
2024-11-29 11:45:23.648 20272-20411 OpenGLRenderer          no....droid.nrfconnectdevicemanager  D  endAllActiveAnimators on 0x794c588000 (RippleDrawable) with handle 0x794bedbb40
2024-11-29 11:45:23.648 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  dispatchDetachedFromWindow
2024-11-29 11:45:23.652 20272-20272 InputTransport          no....droid.nrfconnectdevicemanager  D  Input channel destroyed: '1afa328', fd=84
2024-11-29 11:45:23.656   967-1637  InputDispatcher         system_server                        E  Window handle Window{1afa328 u0 no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity} has no registered input channel
2024-11-29 11:45:23.772 20272-20272 ViewRootIm...nActivity] no....droid.nrfconnectdevicemanager  I  MSG_WINDOW_FOCUS_CHANGED 1 1
2024-11-29 11:45:23.773 20272-20272 InputMethodManager      no....droid.nrfconnectdevicemanager  D  prepareNavigationBarInfo() DecorView@6ed22a5[MainActivity]
2024-11-29 11:45:23.773 20272-20272 InputMethodManager      no....droid.nrfconnectdevicemanager  D  getNavigationBarColor() -1773582
2024-11-29 11:45:23.778 20272-20297 System                  no....droid.nrfconnectdevicemanager  W  A resource failed to call end. 
2024-11-29 11:45:23.807   967-1047  WindowManager           system_server                        E  win=Window{1afa328 u0 no.nordicsemi.android.nrfconnectdevicemanager/io.runtime.mcumgr.sample.MainActivity EXITING} destroySurfaces: appStopped=false win.mWindowRemovalAllowed=true win.mRemoveOnExit=true win.mViewVisibility=0 caller=com.android.server.wm.AppWindowToken.destroySurfaces:1249 com.android.server.wm.AppWindowToken.destroySurfaces:1230 com.android.server.wm.WindowState.onExitAnimationDone:5189 com.android.server.wm.WindowStateAnimator.onAnimationFinished:320 com.android.server.wm.WindowState.onAnimationFinished:5630 com.android.server.wm.-$$Lambda$yVRF8YoeNdTa8GR1wDStVsHu8xM.run:2 com.android.server.wm.SurfaceAnimator.lambda$getFinishedCallback$0$SurfaceAnimator:100 
2024-11-29 11:45:23.779 20272-20297 System                  no....droid.nrfconnectdevicemanager  W  A resource failed to call end. 
2024-11-29 11:45:23.843 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  E  sendUserActionEvent() mView returned.
2024-11-29 11:45:25.657 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onClientConnectionState() - status=0 clientIf=16 device=DD:11:A7:3E:0C:16
2024-11-29 11:45:25.678 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  [Callback] Connection state changed with status: 0 and new state: 2 (CONNECTED)
2024-11-29 11:45:25.679 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Connected to DD:11:A7:3E:0C:16
2024-11-29 11:45:25.682 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  wait(300)
2024-11-29 11:45:25.986 20272-21584 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.discoverServices()
2024-11-29 11:45:25.986 20272-21584 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  discoverServices() - device: DD:11:A7:3E:0C:16
2024-11-29 11:45:26.082 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=DD:11:A7:3E:0C:16 interval=6 latency=0 timeout=500 status=0
2024-11-29 11:45:26.085 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)
2024-11-29 11:45:26.148 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onPhyUpdate() - status=0 address=DD:11:A7:3E:0C:16 txPhy=2 rxPhy=2
2024-11-29 11:45:26.165 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  PHY updated (TX: LE 2M, RX: LE 2M)
2024-11-29 11:45:26.553 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onSearchComplete() = Device=DD:11:A7:3E:0C:16 Status=0
2024-11-29 11:45:26.555 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Services discovered
2024-11-29 11:45:26.618 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=DD:11:A7:3E:0C:16 interval=39 latency=0 timeout=500 status=0
2024-11-29 11:45:26.631 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.requestMtu(498)
2024-11-29 11:45:26.632 20272-20447 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  configureMTU() - device: DD:11:A7:3E:0C:16 mtu: 498
2024-11-29 11:45:26.633 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 5000ms)
2024-11-29 11:45:26.716 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConfigureMTU() - Device=DD:11:A7:3E:0C:16 mtu=498 status=0
2024-11-29 11:45:26.717 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  MTU changed to: 498
2024-11-29 11:45:26.719 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.setCharacteristicNotification(da2e7828-fbce-4e01-ae9e-261174997c48, true)
2024-11-29 11:45:26.720 20272-20447 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  setCharacteristicNotification() - uuid: da2e7828-fbce-4e01-ae9e-261174997c48 enable: true
2024-11-29 11:45:26.721 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  descriptor.setValue(0x01-00)
2024-11-29 11:45:26.722 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb)
2024-11-29 11:45:26.914 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to descr. 00002902-0000-1000-8000-00805f9b34fb
2024-11-29 11:45:26.915 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notifications enabled
2024-11-29 11:45:26.918 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x000000010000FF06A0)
2024-11-29 11:45:26.918 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:26.919 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:26.922 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.010 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 01-00-00-06-00-00-FF-06-BF-62-72-63-08-FF
2024-11-29 11:45:27.015 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Wait for value changed complete
2024-11-29 11:45:27.016 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.readPhy()
2024-11-29 11:45:27.019 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onPhyRead() - status=0 address=DD:11:A7:3E:0C:16 txPhy=2 rxPhy=2
2024-11-29 11:45:27.068 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 0, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 255, Command: 6) CBOR {"rc":8}
2024-11-29 11:45:27.070 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  PHY read (TX: LE 2M, RX: LE 2M)
2024-11-29 11:45:27.074 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.requestConnectionPriority(HIGH)
2024-11-29 11:45:27.074 20272-20447 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  requestConnectionPriority() - params: 1
2024-11-29 11:45:27.088 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 0, Command: 8) CBOR {}
2024-11-29 11:45:27.279 20272-21706 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0800000100000008A0)
2024-11-29 11:45:27.280 20272-21706 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:27.281 20272-21706 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:27.289 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 1, Command: 6) CBOR {}
2024-11-29 11:45:27.290 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.291 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0800000100000106A0)
2024-11-29 11:45:27.291 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:27.292 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:27.295 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.356 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-00-08-BF-62-72-63-08-FF
2024-11-29 11:45:27.359 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-01-06-BF-62-72-63-08-FF
2024-11-29 11:45:27.366 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 0, Command: 8) CBOR {"rc":8}
2024-11-29 11:45:27.377 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 1, Command: 6) CBOR {"rc":8}
2024-11-29 11:45:27.411 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=DD:11:A7:3E:0C:16 interval=12 latency=0 timeout=500 status=0
2024-11-29 11:45:27.511 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  onError: Mcu Mgr Error: 8
2024-11-29 11:45:27.512 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  validate: performer: io.runtime.mcumgr.task.TaskPerformer$TaskManagerImpl@187943c, noSwap: false, allowRevert: true
2024-11-29 11:45:27.591 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 5000ms)
2024-11-29 11:45:27.601 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 1, Seq: 2, Command: 0) CBOR {}
2024-11-29 11:45:27.603 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0800000100010200A0)
2024-11-29 11:45:27.603 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:27.605 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:27.612 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (19 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 11, Group: 0, Seq: 3, Command: 7) CBOR {"format":"sv"}
2024-11-29 11:45:27.613 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.614 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0800000B00000307A166666F726D6174627376)
2024-11-29 11:45:27.614 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:27.615 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:27.619 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.655 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-88-00-01-02-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-67-30-2E-33-2E-34-2E-34-64-68-61-73-68-58-20-F8-DF-FA-EB-E4-B8-E5-EB-3C-BE-A6-36-79-EA-EC-3C-7F-56-70-EA-40-C5-3F-CF-54-C0-9C-4A-1B-12-88-1D-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
2024-11-29 11:45:27.674 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 136, Group: 1, Seq: 2, Command: 0) CBOR {"images":[{"slot":0,"version":"0.3.4.4","hash":"+N/66+S45es8vqY2eersPH9WcOpAxT/PVMCcShsSiB0=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
2024-11-29 11:45:27.677 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-03-07-BF-62-72-63-08-FF
2024-11-29 11:45:27.686 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 3, Command: 7) CBOR {"rc":8}
2024-11-29 11:45:27.812 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  Validation response: {"images":[{"slot":0,"version":"0.3.4.4","hash":"+N/66+S45es8vqY2eersPH9WcOpAxT/PVMCcShsSiB0=","bootable":true,"pending":false,"confirmed":true,"active":true,"permanent":false}],"splitStatus":0}
2024-11-29 11:45:27.812 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  image: io.runtime.mcumgr.dfu.mcuboot.model.TargetImage@b84b87d
2024-11-29 11:45:27.813 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  slot: io.runtime.mcumgr.response.img.McuMgrImageStateResponse$ImageSlot@566d372
2024-11-29 11:45:27.813 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  !found
2024-11-29 11:45:27.814 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  mode: CONFIRM_ONLY
2024-11-29 11:45:27.816 20272-20447 Validate                no....droid.nrfconnectdevicemanager  D  cacheImages: null
2024-11-29 11:45:27.817 20272-20447 FirmwareUp...ePerformer no....droid.nrfconnectdevicemanager  V  Moving from state VALIDATE to state UPLOAD
2024-11-29 11:45:27.819 20272-20272 ImageUpgradeViewModel   no....droid.nrfconnectdevicemanager  I  Uploading firmware...
2024-11-29 11:45:27.926 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (9 bytes) Header (Version: 1, Op: 0, Flags: 0, Len: 1, Group: 0, Seq: 4, Command: 8) CBOR {}
2024-11-29 11:45:27.927 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0800000100000408A0)
2024-11-29 11:45:27.927 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:27.928 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:27.933 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:27.954 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Notification received from da2e7828-fbce-4e01-ae9e-261174997c48, value: (0x) 09-00-00-06-00-00-04-08-BF-62-72-63-08-FF
2024-11-29 11:45:27.964 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Received Header (Version: 1, Op: 1, Flags: 0, Len: 6, Group: 0, Seq: 4, Command: 8) CBOR {"rc":8}
2024-11-29 11:45:28.057 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Sending (493 bytes) Header (Version: 1, Op: 2, Flags: 0, Len: 485, Group: 1, Seq: 5, Command: 1) CBOR {"data":"PbjzlgAAAAAAAgAATG0DAAAAAAAAAwIAAAAAAAAAAAD//////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////w==","len":225250,"sha":"E26fU0JjN2TpAsVOUG9VexNUJ0SM0Kvr9oQ/sLeS40Q=","off":0}
2024-11-29 11:45:28.064 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setValue(0x0A0001E500010501A464646174615901A83DB8F39600000000000200004C6D030000000000000302000000000000000000FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF636C656E1A00036FE2637368615820136E9F5342633764E902C54E506F557B135427448CD0ABEBF6843FB0B792E344636F666600)
2024-11-29 11:45:28.064 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  characteristic.setWriteType(WRITE COMMAND)
2024-11-29 11:45:28.066 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  D  gatt.writeCharacteristic(da2e7828-fbce-4e01-ae9e-261174997c48)
2024-11-29 11:45:28.071 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Data written to da2e7828-fbce-4e01-ae9e-261174997c48
2024-11-29 11:45:30.610 20272-20449 BluetoothGatt           no....droid.nrfconnectdevicemanager  D  onConnectionUpdated() - Device=DD:11:A7:3E:0C:16 interval=39 latency=0 timeout=42 status=0
2024-11-29 11:45:30.612 20272-20447 McuMgrBleTransport      no....droid.nrfconnectdevicemanager  I  Connection parameters updated (interval: 48.75ms, latency: 0, timeout: 420ms)
2024-11-29 11:46:07.990 20272-20272 ImageUpgradeViewModel   no....droid.nrfconnectdevicemanager  E  Upgrade failed
                                                                                                    Transaction 5 timed out without receiving a response
                                                                                                    	at io.runtime.mcumgr.ble.McuMgrBleTransport$2.onFailure(McuMgrBleTransport.java:429)
                                                                                                    	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.onFailure$lambda$2(SmpProtocolSession.kt:169)
                                                                                                    	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt.$r8$lambda$_a4Sj5nhnKBR_l1QU5smoEMTDUg(Unknown Source:0)
                                                                                                    	at io.runtime.mcumgr.ble.callback.SmpProtocolSessionKt$$ExternalSyntheticLambda0.run(D8$$SyntheticClass:0)
                                                                                                    	at android.os.Handler.handleCallback(Handler.java:883)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:100)
                                                                                                    	at android.os.Looper.loop(Looper.java:237)
                                                                                                    	at android.os.HandlerThread.run(HandlerThread.java:67)
                                                                                                    Caused by: Transaction 5 timed out without receiving a response
                                                                                                    	at io.runtime.mcumgr.ble.callback.SmpProtocolSession$writer$2$job$1.invokeSuspend(SmpProtocolSession.kt:102)
                                                                                                    	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
                                                                                                    	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:101)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:589)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:832)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:720)
                                                                                                    	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:707)
2024-11-29 11:46:11.947 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:46:11.949 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:46:12.028 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:46:12.029 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272
2024-11-29 11:46:12.090 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1000, calling pid = 20272
2024-11-29 11:46:12.091 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1000, callingPid = 20272
2024-11-29 11:46:12.105 20272-20272 ViewRootImpl            no....droid.nrfconnectdevicemanager  I  updatePointerIcon pointerType = 1002, calling pid = 20272
2024-11-29 11:46:12.105 20272-20272 InputManager            no....droid.nrfconnectdevicemanager  D  setPointerIconType iconId = 1002, callingPid = 20272

If you want me to run our app please let me know!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
question Further information is requested
Projects
None yet
Development

No branches or pull requests

2 participants