Characteristic write error (257) on Chrome OS

[soramisono]

Dear Nordic Semiconductor,

DFU update is failed because of "Characteristic write error: 257". It happened just after DFU update was started. Running environment is followings:

Running on: ASUS Chromebook tablet CT100 (Chrome OS 80.0.3987.158 (Official Build) 32bit) DFU library version: 1.10.1 Target device SOC: Nordic nRF52840

It also could repeat on DFU function of nRF Toolbox APP on Chromebook.

The debug log of my APP is:

I/DFU: Please wait...
I/DFU: startDFU started.
W/libEGL: EGLNativeWindowType 0xd7d2b808 disconnect failed
I/DfuBaseService: DFU service created. Version: 1.10.1
W/DfuBaseService: Foreground service disabled. Android Oreo or newer may kill a background service few moments after user closes the application.
    Consider enabling foreground service using DfuServiceInitiator#setForeground(boolean)
I/DfuBaseService: Connecting to the device...
D/BluetoothGatt: connect() - device: CF:5F:DE:9D:08:D1, auto: false
    registerApp()
D/BluetoothGatt: registerApp() - UUID=657cd030-d317-42ee-9e22-c933f2beacf8
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=2
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=2 device=CF:5F:DE:9D:08:D1
I/DfuBaseService: Connected to GATT server
D/BluetoothGatt: discoverServices() - device: CF:5F:DE:9D:08:D1
I/DfuBaseService: Attempting to start service discovery... succeed
D/BluetoothGatt: onSearchComplete() = Device=CF:5F:DE:9D:08:D1 Status=0
I/DfuBaseService: Services discovered
W/DfuImpl: Secure DFU bootloader found
I/DFU: Starting...
I/DfuImpl: Requesting MTU = 517
D/BluetoothGatt: configureMTU() - device: CF:5F:DE:9D:08:D1 mtu: 517
D/BluetoothGatt: onConfigureMTU() - Device=CF:5F:DE:9D:08:D1 mtu=517 status=0
I/DfuImpl: MTU changed to: 517
I/DfuImpl: Enabling notifications...
D/BluetoothGatt: setCharacteristicNotification() - uuid: 8ec90001-f315-4f60-9fb8-838830daea50 enable: true
I/DfuImpl: Setting object to Command (Op Code = 6, Type = 1)
I/DfuImpl: Command object info received (Max size = 256, Offset = 0, CRC = 00000000)
I/DfuImpl: Sending the number of packets before notifications (Op Code = 2, Value = 0)
I/DfuImpl: Creating Init packet object (Op Code = 1, Type = 1, Size = 135)
I/DfuImpl: Sending 135 bytes of init packet...
I/DfuImpl: Sending init packet (Value = 12-84-01-0A-3E-08-01-12-3A-08-01-10-34-1A-02-A9-01-20-00-28-00-30-00-38-A8-B6-11-42-24-08-03-12-20-20-53-50-10-9C-97-E1-F8-1B-B4-65-C1-7E-32-62-19-57-CD-E2-BF-14-10-82-9D-7C-44-23-88-67-05-36-89-48-00-10-00-1A-40-09-2D-21-5D-0D-8F-F6-84-98-A2-84-0C-1F-5E-26-77-FA-7D-C8-9C-4C-96-21-D5-1F-3E-09-15-97-ED-82-99-8D-55-AE-FB-F3-53-28-71-E4-00-3A-3D-3C-4F-66-73-05-63-1A-ED-06-EF-F7-58-BD-AB-61-95-B4-35-22-AC)
I/DfuImpl: Sending Calculate Checksum command (Op Code = 3)
I/DfuImpl: Checksum received (Offset = 135, CRC = 50B64E6E)
    Executing init packet (Op Code = 4)
I/DfuImpl: Sending the number of packets before notifications (Op Code = 2, Value = 12)
I/DfuImpl: Setting object to Data (Op Code = 6, Type = 2)
I/DfuImpl: Data object info received (Max size = 4096, Offset = 0, CRC = 00000000)
I/DfuImpl: Creating Data object (Op Code = 1, Type = 2, Size = 4096) (1/70)
D/DecorView[]: Cannot get the activity to get CaptionConfiguration.
I/DfuImpl: Uploading firmware...
E/DfuImpl: Characteristic write error: 257
E/DfuBaseService: Uploading Firmware Image failed (error 257)
I/DfuBaseService: Disconnecting from the device...
D/BluetoothGatt: cancelOpen() - device: CF:5F:DE:9D:08:D1
D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
I/DFU: Disconnecting...
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=2 device=CF:5F:DE:9D:08:D1
I/DfuBaseService: Disconnected from GATT server
W/.greenonpremiu: Accessing hidden method Landroid/bluetooth/BluetoothGatt;->refresh()Z (light greylist, reflection)
D/BluetoothGatt: refresh() - device: CF:5F:DE:9D:08:D1
I/DfuBaseService: Refreshing result: true
    Cleaning up...

[philips77]

To be honest, we didn't try any of our apps on Chrome OS. Perhaps it's time to start doing it. 257 is described here https://developer.android.com/reference/android/bluetooth/BluetoothGatt#GATT_FAILURE but the reason of this error is unknown. You'd need to do some sniffing, or capture HCI Snoop logs.

[soramisono]

Sorry for my late reply. The error message which is set on DfuProgressListener.onError() method is "TOO MANY OPEN CONNECTIONS". Can you think of anything that might have caused it?

[soramisono]

I tried Android DFU library v1.10.2, but following errors happened.

W/DfuArchiveInputStream: Manifest not found in the ZIP. It is recommended to use a distribution file created with: https://github.com/NordicSemiconductor/pc-nrfutil/ (for Legacy DFU use version 0.5.x)
E/DfuBaseService: An exception occurred while calculating file size
    java.io.IOException: The ZIP file must contain an Application, a Soft Device and/or a Bootloader.
        at no.nordicsemi.android.dfu.internal.ArchiveInputStream.<init>(ArchiveInputStream.java:264)
        at no.nordicsemi.android.dfu.DfuBaseService.openInputStream(DfuBaseService.java:1434)
        at no.nordicsemi.android.dfu.DfuBaseService.onHandleIntent(DfuBaseService.java:1174)
        at android.app.IntentService$ServiceHandler.handleMessage(IntentService.java:76)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:193)
        at android.os.HandlerThread.run(HandlerThread.java:65)

The firmware ZIP file could be updated on Android 10 and DFU library v1.10.1. Is it necessary to remake firmware ZIP file?

[philips77]

No, there's a bug in 1.10.2, related to how ZIP files are looking for files inside. I'll fix it and release 1.10.3.

[soramisono]

Thanks for reply, I understood.

[soramisono]

I tried DFU library 1.10.3 and it works well on Android 10. But an error "DFU DEVICE DISCONNECTED" occurred on Chrome OS. The debug log is following:

I/DFU: startDFU started.
W/libEGL: EGLNativeWindowType 0xecace808 disconnect failed
I/DFU: Please wait...
I/BLE_manager: scan_le_device : false
D/BluetoothAdapter: stopLeScan()
D/BluetoothAdapter: isLeEnabled(): ON
I/Choreographer: Skipped 31 frames!  The application may be doing too much work on its main thread.
I/DfuBaseService: DFU service created. Version: 1.10.3
W/DfuBaseService: Foreground service disabled. Android Oreo or newer may kill a background service few moments after user closes the application.
    Consider enabling foreground service using DfuServiceInitiator#setForeground(boolean)
D/DecorView[]: Cannot get the activity to get CaptionConfiguration.
D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
I/DfuBaseService: Connecting to the device...
D/BluetoothGatt: connect() - device: DA:2C:3D:20:D8:85, auto: false
    registerApp()
D/BluetoothGatt: registerApp() - UUID=d1f774e6-1116-4e0e-b78e-9ec18b56bc64
D/BluetoothGatt: onClientRegistered() - status=0 clientIf=3
D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
W/libEGL: EGLNativeWindowType 0xf2bee008 disconnect failed
D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=3 device=DA:2C:3D:20:D8:85
I/DfuBaseService: Disconnected from GATT server
W/.greenonpremiu: Accessing hidden method Landroid/bluetooth/BluetoothGatt;->refresh()Z (light greylist, reflection)
D/BluetoothGatt: refresh() - device: DA:2C:3D:20:D8:85
I/DfuBaseService: Refreshing result: true
    Cleaning up...
D/BluetoothGatt: close()
    unregisterApp() - mClientIf=3
D/Update_firmware_appscr: go_message() called. msg='An error occurred.
    DFU DEVICE DISCONNECTED'.
W/libEGL: EGLNativeWindowType 0xecace808 disconnect failed
D/DecorView[]: Cannot get the activity to get CaptionConfiguration.
D/mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
I/DfuBaseService: DFU service destroyed

Please check it.

[philips77]

Does it happen every time? Did you try resetting Bluetooth?

[soramisono]

I tried several times after restarting chromebook. Every time an error "TOO MANY OPEN CONNECTIONS" occurred, it is the same situation as DFU library v1.10.1 on Chrome OS.

[soramisono]

Sorry for my very late reply. I have captured the log between Chromebook and Device by BLE sniffer.

• Master: LiteonTe_85:70:c8 (3c:91:80:85:70:c8)
• Slave: da:2c:3d:20:d8:85 (da:2c:3d:20:d8:85) NORM DFU 23456

The DFU Log begins at Packet No. 1261. After sending Exchange MTU response from Master, Two Error responses are sent from Master. Please check the attached file.

20201224_dfu_error.zip