Dfu Error "Unable to write Op Code 3 (error 133)"

[Roland B]

Hi,

I have a custom board with nRF52840/SDK 16/Softdevice 7.3.0 using Secure Dfu Bootloader. On my Android device I use Nordic Dfu Library. I have tried all available Dfu lib versions from 1.11.0 to 2.0.2.
I've had Dfu up and running for a few months and it has been working fine for most Android devices I have tested so far. However I just recently bought a Samsung Galaxy Tab A8/Android 11 and the Dfu does not work on this device returning the error 'Unable to write Op Code 3 (error 133)'. Below I will show logs from Android Studio logcat and also from my Peripheral custom board for case 1 (Samsung Galaxy Tab A8/Android 11 ) where Dfu fails and case 2 (Samsung Galaxy S20 FE/Android 12) where Dfu succeeds. I also provide the relevant app code section I use for Dfu. In the app code I have tried different settings, for example setting the PRN value to 1 and increasing the 'preparDataObjectDelay' up to 400.
I am grateful for any tip.

Case 1: Ble Client Samsung TAB A8/Android 11: -------------------------------------------------------------------------------------------------------------

2022-05-23 13:38:23.964 25812-27662/com.prisma.ui I/DfuImpl: Enabling notifications...
2022-05-23 13:38:23.965 25812-27662/com.prisma.ui D/BluetoothGatt: setCharacteristicNotification() - uuid: 8ec90001-f315-4f60-9fb8-838830daea50 enable: true
2022-05-23 13:38:24.995 25812-27662/com.prisma.ui I/DfuImpl: Setting object to Command (Op Code = 6, Type = 1)
2022-05-23 13:38:25.056 25812-27662/com.prisma.ui I/DfuImpl: Command object info received (Max size = 512, Offset = 0, CRC = 00000000)
2022-05-23 13:38:25.062 25812-27662/com.prisma.ui I/DfuImpl: Sending the number of packets before notifications (Op Code = 2, Value = 0)
2022-05-23 13:38:25.093 25812-27662/com.prisma.ui I/DfuImpl: Creating Init packet object (Op Code = 1, Type = 1, Size = 141)
2022-05-23 13:38:25.123 25812-27662/com.prisma.ui I/DfuImpl: Sending 141 bytes of init packet...
2022-05-23 13:38:25.126 25812-27662/com.prisma.ui I/DfuImpl: Sending init packet (Value = 12-8A-01-0A-44-08-01-12-40-08-01-10-34-1A-02-A3-02-20-00-28-00-30-00-38-BC-F0-11-42-24-08-03-12-20-13-5B-83-CD-0F-EC-D5-26-36-5C-AE-0D-5D-71-E8-D5-BD-1B-AD-5E-F0-3C-0D-32-FA-32-07-6F-C0-C4-C5-DC-48-00-52-04-08-01-12-00-10-00-1A-40-00-37-1B-3B-A3-38-02-AA-65-BA-15-04-1A-13-86-C5-F7-2D-D6-87-A9-8E-7C-42-B1-A1-0B-C6-A1-8F-0D-6F-46-89-82-94-9D-17-11-57-4D-37-B9-01-1F-A3-B2-22-55-BA-98-D5-B0-58-01-9C-FD-3A-64-41-29-AA-3F-47)
2022-05-23 13:38:25.138 25812-27662/com.prisma.ui I/DfuImpl: Sending Calculate Checksum command (Op Code = 3)
2022-05-23 13:38:31.124 25812-27285/com.prisma.ui E/DfuImpl: Characteristic write error: 133
2022-05-23 13:38:31.125 25812-27285/com.prisma.ui D/BluetoothGatt: onClientConnectionState() - status=8 clientIf=10 device=C6:5D:74:1E:7D:29
2022-05-23 13:38:31.128 25812-27662/com.prisma.ui E/DfuBaseService: Unable to write Op Code 3 (error 133)
2022-05-23 13:38:31.133 25812-25812/com.prisma.ui D/BleFileTransferActivity: ----- FTBA  DfuProgress->onDeviceDisconnecting
2022-05-23 13:38:31.147 25812-25812/com.prisma.ui I/DfuBaseService: Action received: android.bluetooth.device.action.ACL_DISCONNECTED
2022-05-23 13:38:31.153 25812-27285/com.prisma.ui W/DfuBaseService: Target device disconnected with status: 8
2022-05-23 13:38:31.159 25812-27662/com.prisma.ui I/DfuBaseService: Disconnecting from the device...
2022-05-23 13:38:31.159 25812-27662/com.prisma.ui D/BluetoothGatt: cancelOpen() - device: C6:5D:74:1E:7D:29
2022-05-23 13:38:31.175 25812-27662/com.prisma.ui D/BluetoothGatt: refresh() - device: C6:5D:74:1E:7D:29


Ble Peripheral Custom Board nRF52840, SDK 16, softdevice 7.3.0:
main: SoftDevice Firmware Id: 0x123
PR Bootloader 2022.04.06.0
Bootloader start address: 0xF1000
dfu_observer: NRF_DFU_EVT_DFU_INITIALIZED
dfu_observer: NRF_DFU_EVT_TRANSPORT_ACTIVATED
dfu_observer: NRF_DFU_EVT_DFU_STARTED
dfu_observer: NRF_DFU_EVT_TRANSPORT_DEACTIVATED

Case 2: Samsung S20 Fe/Android 12: -------------------------------------------------------------------------------------------------------------------------------------

2022-05-23 13:27:07.244 13883-14153/com.prisma.ui I/DfuImpl: Sending 141 bytes of init packet...
2022-05-23 13:27:07.248 13883-14153/com.prisma.ui I/DfuImpl: Sending init packet (Value = 12-8A-01-0A-44-08-01-12-40-08-01-10-34-1A-02-A3-02-20-00-28-00-30-00-38-BC-F0-11-42-24-08-03-12-20-13-5B-83-CD-0F-EC-D5-26-36-5C-AE-0D-5D-71-E8-D5-BD-1B-AD-5E-F0-3C-0D-32-FA-32-07-6F-C0-C4-C5-DC-48-00-52-04-08-01-12-00-10-00-1A-40-00-37-1B-3B-A3-38-02-AA-65-BA-15-04-1A-13-86-C5-F7-2D-D6-87-A9-8E-7C-42-B1-A1-0B-C6-A1-8F-0D-6F-46-89-82-94-9D-17-11-57-4D-37-B9-01-1F-A3-B2-22-55-BA-98-D5-B0-58-01-9C-FD-3A-64-41-29-AA-3F-47)
2022-05-23 13:27:07.260 13883-14153/com.prisma.ui I/DfuImpl: Sending Calculate Checksum command (Op Code = 3)
2022-05-23 13:27:07.292 13883-14153/com.prisma.ui I/DfuImpl: Checksum received (Offset = 141, CRC = 742FABE1)
2022-05-23 13:27:07.292 13883-14153/com.prisma.ui I/DfuImpl: Executing init packet (Op Code = 4)


Ble Peripheral Custom Board nRF52840, SDK 16, softdevice 7.3.0:
main: SoftDevice Firmware Id: 0x123
PR Bootloader 2022.04.06.0
Bootloader start address: 0xF1000
dfu_observer: NRF_DFU_EVT_DFU_INITIALIZED
dfu_observer: NRF_DFU_EVT_TRANSPORT_ACTIVATED
dfu_observer: NRF_DFU_EVT_DFU_STARTED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED
dfu_observer: NRF_DFU_EVT_OBJECT_RECEIVED

Dfu app code section: ------------------------------------------------------------------------------------------------------------------

    if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
      DfuServiceInitiator.createDfuNotificationChannel(this);
   }
final DfuServiceInitiator starter = new DfuServiceInitiator(device.getAddress())
      .setDeviceName(device.getName())
      .setKeepBond(true)
      .setPacketsReceiptNotificationsEnabled(true)
      .setPacketsReceiptNotificationsValue(DfuServiceInitiator.DEFAULT_PRN_VALUE);

      // If you want to have experimental buttonless DFU feature (DFU from SDK 12.x only!) supported call
      // additionally:

      starter.setUnsafeExperimentalButtonlessServiceInSecureDfuEnabled(true);
      // but be aware of this: devzone.nordicsemi.com/.../
      // and other issues related to this experimental service.

      // For DFU bootloaders from SDK 15 and 16 it may be required to add a delay before sending each
      // data packet. This delay gives the DFU target more time to perpare flash memory, causing less
      // packets being dropped and more reliable transfer. Detection of packets being lost would cause
      // automatic switch to PRN = 1, making the DFU very slow (but reliable).
      starter.setPrepareDataObjectDelay(300L);

      // Init packet is required by Bootloader/DFU from SDK 7.0+ if HEX or BIN file is given above.
      // In case of a ZIP file, the init packet (a DAT file) must be included inside the ZIP file.
      Uri mFileStreamUri = Uri.fromFile(new File(filePath));

      starter.setZip(mFileStreamUri, filePath);
      controller = starter.start(getApplicationContext(), DfuService.class);
      // You may use the controller to pause, resume or abort the DFU process.

[Roland B]

Dfu SamsungS20FESuccess_220603_1.pcapngDfu SamsungTabA8Fail_220603_1.pcapng

[Einar Thorsrud]

Hi,

I notice that there is a lot of retransmissions in the failing trace. Do you by any chance have a log from the nRF side in this case (using the debug bootloader with RTT logging)?

Other than that nothing sticks out, but I have asked our mobile developers to take a look.

Edit: Does it always fail on the failing devices, or just from time to time?

[Roland B]

Hi,

Yes, it is always failing on failing devices.

Earlier in this case I provided some log info from the nrf bootloader side for a successful dfu and a failed dfu.

From my bootloader dfu_observer() I will print out with RTT any of these events occurring:

typedef enum
{
    NRF_DFU_EVT_DFU_INITIALIZED,        /**< Starting DFU. */
    NRF_DFU_EVT_TRANSPORT_ACTIVATED,    /**< Transport activated (e.g. BLE connected, USB plugged in). */
    NRF_DFU_EVT_TRANSPORT_DEACTIVATED,  /**< Transport deactivated (e.g. BLE disconnected, USB plugged out). */
    NRF_DFU_EVT_DFU_STARTED,            /**< DFU process started. */
    NRF_DFU_EVT_OBJECT_RECEIVED,        /**< A DFU data object has been received. */
    NRF_DFU_EVT_DFU_FAILED,             /**< DFU process has failed, been interrupted, or hung. */
    NRF_DFU_EVT_DFU_COMPLETED,          /**< DFU process completed. */
    NRF_DFU_EVT_DFU_ABORTED,            /**< DFU process aborted. */
} nrf_dfu_evt_type_t;

Did you refer to any other log information? What do you mean by "the debug bootloader"?

[Einar Thorsrud]

Hi,

Ah, you are right. You don't get much information when bluetooth is disconnected, and NRF_DFU_EVT_TRANSPORT_DEACTIVATED covers everything. Can you add a bit more logging in the handling of the BLE_GAP_EVT_DISCONNECTED event in components/libraries/bootloader/ble_dfu/nrf_dfu_ble.c, specifically the disconnect reason?

Einar

[Roland B]

Hi,

This is the bootloader debug printout when trying to make a dfu on my failing Android device

nrf_dfu_ble.c->ble_event_handler()->BLE_GAP_EVT_DISCONNECTED->reason: 0x8 m_flags: 0x1

Is this the corresponding error definition?
#define BLE_HCI_CONNECTION_TIMEOUT                         0x08   /**< Connection Timeout. */

[Einar Thorsrud]

Hi,

That is interesting. Seen from the nRF, this is a supervision timeout. And the sniffer trace shows that the Android device attempts a bunch of retransmissions, before I assume that also times out (error 133 covers a lot of things, including timeout).

There is nothing here that clearly indicates what the cause of the timeout is, but a possible explanation could be clock drift. Do you have multiple of your boards to test with? If so, do they behave the same? Also, which low frequency clock source do you use, and how have you configured it? (what is the configured accuracy)? Perhaps you can share the clock configuration from your sdk_config.h? This may not be the problem, but it could be that there is an issue in the nRF and the Android devices that in sum makes the combined clock inaccuracy too much, so it is worth checking that first.

[Roland B]

Hi,

Yes, I have tested with multiple boards and it is the same behavior.

I remember now that some time ago I experienced error 133 from time to time in my application, not bootloader.
These were not related to dfu, but any ble transaction. Then I found this case:
devzone.nordicsemi.com/.../error-133-0x85-gatt-error-on-nrf52840
I made changes in my clock settings in sdk_config.h for my application.

from:
//#define NRF_SDH_CLOCK_LF_ACCURACY NRF_CLOCK_LF_ACCURACY_50_PPM
//#define NRF_SDH_CLOCK_LF_SRC NRF_CLOCK_LF_SRC_XTAL
//#define NRF_SDH_CLOCK_LF_RC_CTIV 0
//#define NRF_SDH_CLOCK_LF_RC_TEMP_CTIV 0

to:
#define NRF_SDH_CLOCK_LF_ACCURACY NRF_CLOCK_LF_ACCURACY_500_PPM
#define NRF_SDH_CLOCK_LF_SRC NRF_CLOCK_LF_SRC_RC
#define NRF_SDH_CLOCK_LF_RC_CTIV 16
#define NRF_SDH_CLOCK_LF_RC_TEMP_CTIV 2

This made a clear change to the better.

It did not occur to me then that maybe I needed to update the clock settings also for the bootloader.
But so far dfu had worked for my different Android devices.

Now I changed my clock settings in sdk_config.h for my bootloader.

from:
#define NRF_SDH_CLOCK_LF_ACCURACY 7        // 20 ppm
#define NRF_SDH_CLOCK_LF_RC_CTIV 0        
#define NRF_SDH_CLOCK_LF_SRC 1        // XTAL
#define NRF_SDH_CLOCK_LF_RC_TEMP_CTIV 0    

to:
#define NRF_SDH_CLOCK_LF_ACCURACY NRF_CLOCK_LF_ACCURACY_500_PPM
#define NRF_SDH_CLOCK_LF_SRC NRF_CLOCK_LF_SRC_RC
#define NRF_SDH_CLOCK_LF_RC_CTIV 16
#define NRF_SDH_CLOCK_LF_RC_TEMP_CTIV 2

I thought it would have solved the problem, but it did not and I got the same printout
nrf_dfu_ble.c->ble_event_handler()->BLE_GAP_EVT_DISCONNECTED->reason: 0x8 m_flags: 0x1
as before.

Do you recommend other values for these settings?


Also, I noticed that for my application I have
#define NRF_SDH_DISPATCH_MODEL NRF_SDH_DISPATCH_MODEL_POLLING
but for my bootloader I have
#define NRF_SDH_DISPATCH_MODEL 0    // <0=> NRF_SDH_DISPATCH_MODEL_INTERRUPT

Is that important?