nrf51 dfu via nrfToolbox or nrfConnect crashes on dfu upload Huawei p30 lite

[Robin P]

Hello!

I am having issues dfu from the huawei p30 lite. with nrf51. Tried with nrf connect and nrf toolbox.

Dfu progress stops at 2-3% when uploading.

Error Remote dfu error OPERATION_FAILED.

Gatt conn timeout.

Log bellow

nRF Connect, 2019-05-24

Pacelog (C8:3F:A7:C9:6F:34)

V 15:04:59.343 Connecting to C8:3F:A7:C9:6F:34...

D 15:04:59.343 gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)

D 15:04:59.630 [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED

D 15:04:59.658 [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)

I 15:04:59.658 Connected to C8:3F:A7:C9:6F:34

V 15:04:59.669 Discovering services...

D 15:04:59.669 gatt.discoverServices()

I 15:05:00.070 Connection parameters updated (interval: 30.0ms, latency: 0, timeout: 4000ms)

I 15:05:00.316 Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)

D 15:05:00.491 [Callback] Services discovered with status: 0

I 15:05:00.491 Services discovered

V 15:05:00.523 Generic Access (0x1800)

- Device Name [R W] (0x2A00)

- Appearance [R] (0x2A01)

- Peripheral Preferred Connection Parameters [R] (0x2A04)

Generic Attribute (0x1801)

- Service Changed [I] (0x2A05)

Client Characteristic Configuration (0x2902)

Device Firmware Update Service (00001530-1212-efde-1523-785feabcd123)

- DFU Packet [WNR] (00001532-1212-efde-1523-785feabcd123)

- DFU Control Point [N W] (00001531-1212-efde-1523-785feabcd123)

Client Characteristic Configuration (0x2902)

- DFU Version [R] (00001534-1212-efde-1523-785feabcd123)

D 15:05:00.523 gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)

I 15:05:00.554 Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 4000ms)

I 15:05:00.899 Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 4000ms)

V 15:05:22.905 [DFU] DFU service started

V 15:05:22.905 [DFU] Opening file...

I 15:05:23.230 [DFU] Firmware file opened successfully

V 15:05:23.230 [DFU] Connecting to DFU target...

D 15:05:23.231 [DFU] gatt = device.connectGatt(autoConnect = false)

I 15:05:23.243 [DFU] Connected to C8:3F:A7:C9:6F:34

V 15:05:23.243 [DFU] Discovering services...

D 15:05:23.243 [DFU] gatt.discoverServices()

I 15:05:23.250 [DFU] Services discovered

D 15:05:23.272 [DFU] wait(1000)

V 15:05:24.258 [DFU] Reading DFU version number...

D 15:05:24.259 [DFU] gatt.readCharacteristic(00001534-1212-efde-1523-785feabcd123)

I 15:05:24.406 [DFU] Read Response received from 00001534-1212-efde-1523-785feabcd123, value (0x): 08-00

A 15:05:24.406 [DFU] Version number read: 0.8

D 15:05:24.410 [DFU] wait(1000)

V 15:05:25.411 [DFU] Enabling notifications for 00001531-1212-efde-1523-785feabcd123

D 15:05:25.411 [DFU] gatt.setCharacteristicNotification(00001531-1212-efde-1523-785feabcd123, true)

D 15:05:25.417 [DFU] gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x01-00)

I 15:05:25.443 [DFU] Data written to descr.00001531-1212-efde-1523-785feabcd123, value (0x): 01-00

V 15:05:25.443 [DFU] Notifications enabled for 00001531-1212-efde-1523-785feabcd123

A 15:05:25.444 [DFU] Notifications enabled

D 15:05:25.444 [DFU] wait(1000)

V 15:05:26.491 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123

D 15:05:26.491 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)

I 15:05:26.491 [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 01-04

A 15:05:26.491 [DFU] DFU Start sent (Op Code = 1, Upload Mode = 4)

V 15:05:26.491 [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123

D 15:05:26.491 [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)

I 15:05:26.491 [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): 00-00-00-00-00-00-00-00-68-C0-00-00

A 15:05:26.491 [DFU] Firmware image size sent (0b, 0b, 49256b)

I 15:05:30.213 [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-01-01

A 15:05:30.214 [DFU] Response received (Op Code = 1 Status = 1)

A 15:05:30.214 [DFU] Writing Initialize DFU Parameters...

V 15:05:30.214 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123

D 15:05:30.214 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)

I 15:05:30.241 [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 02-00

V 15:05:30.242 [DFU] Writing to characteristic 00001532-1212-efde-1523-785feabcd123

D 15:05:30.242 [DFU] gatt.writeCharacteristic(00001532-1212-efde-1523-785feabcd123)

I 15:05:30.246 [DFU] Data written to 00001532-1212-efde-1523-785feabcd123, value (0x): FF-FF-FF-FF-FF-FF-FF-FF-01-00-FE-FF-67-1A

V 15:05:30.247 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123

D 15:05:30.247 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)

I 15:05:30.301 [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 02-01

A 15:05:30.302 [DFU] Initialize DFU Parameters completed

I 15:05:30.303 [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-02-01

A 15:05:30.304 [DFU] Response received (Op Code = 2, Status = 1)

V 15:05:30.307 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123

D 15:05:30.307 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)

I 15:05:30.345 [DFU] Data written to 00001531-1212-efde-1523-785feabcd123, value (0x): 03

A 15:05:30.346 [DFU] Receive Firmware Image request sent

A 15:05:30.386 [DFU] Uploading firmware...

V 15:05:30.386 [DFU] Sending firmware to characteristic 00001532-1212-efde-1523-785feabcd123...

I 15:05:30.590 [DFU] Notification received from 00001531-1212-efde-1523-785feabcd123, value (0x): 10-03-06

A 15:05:30.591 [DFU] Response received (Op Code = 3, Status = 6)

E 15:05:30.593 [DFU] Remote DFU error: OPERATION FAILED

V 15:05:30.594 [DFU] Writing to characteristic 00001531-1212-efde-1523-785feabcd123

D 15:05:30.594 [DFU] gatt.writeCharacteristic(00001531-1212-efde-1523-785feabcd123)

D 15:05:34.637 [Callback] Connection state changed with status: 8 and new state: DISCONNECTED (0)

E 15:05:34.638 Error 8 (0x8): GATT CONN TIMEOUT

I 15:05:34.638 Disconnected

A 15:05:34.667 [DFU] Reset request sent

V 15:05:34.667 [DFU] Disconnecting...

D 15:05:34.668 [DFU] gatt.disconnect()

I 15:05:34.707 [DFU] Disconnected

D 15:05:34.707 [DFU] gatt.refresh() (hidden)

D 15:05:34.707 [DFU] gatt.close()

D 15:05:34.707 [DFU] wait(600)

D 15:05:34.707 [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED

D 15:05:34.730 [DFU] [Broadcast] Action received: android.bluetooth.device.action.ACL_DISCONNECTED

D 15:05:35.302 gatt.close()

D 15:05:35.307 wait(200)

V 15:05:35.509 Connecting to C8:3F:A7:C9:6F:34...

D 15:05:35.509 gatt = device.connectGatt(autoConnect = false, TRANSPORT_LE, preferred PHY = LE 1M)

D 15:05:35.708 [Callback] Connection state changed with status: 0 and new state: CONNECTED (2)

I 15:05:35.708 Connected to C8:3F:A7:C9:6F:34

V 15:05:35.745 Discovering services...

D 15:05:35.745 gatt.discoverServices()

D 15:05:35.756 [Broadcast] Action received: android.bluetooth.device.action.ACL_CONNECTED

I 15:05:36.175 Connection parameters updated (interval: 30.0ms, latency: 0, timeout: 4000ms)

I 15:05:36.420 Connection parameters updated (interval: 7.5ms, latency: 0, timeout: 5000ms)

D 15:05:36.620 [Callback] Services discovered with status: 0

I 15:05:36.620 Services discovered

V 15:05:36.648 Generic Access (0x1800)

- Device Name [R W] (0x2A00)

- Appearance [R] (0x2A01)

- Peripheral Preferred Connection Parameters [R] (0x2A04)

Generic Attribute (0x1801)

- Service Changed [I] (0x2A05)

Client Characteristic Configuration (0x2902)

Device Firmware Update Service (00001530-1212-efde-1523-785feabcd123)

- DFU Packet [WNR] (00001532-1212-efde-1523-785feabcd123)

- DFU Control Point [N W] (00001531-1212-efde-1523-785feabcd123)

Client Characteristic Configuration (0x2902)

- DFU Version [R] (00001534-1212-efde-1523-785feabcd123)

D 15:05:36.649 gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)

I 15:05:36.683 Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 4000ms)

I 15:05:37.014 Connection parameters updated (interval: 15.0ms, latency: 0, timeout: 4000ms)

[bjorn-spockeli]

Hi Robin, 

which SDK version and which SoftDevice version are you using? 

Checking the latest SDK that supports the nRF51 Series, which is SDK v12.3.0, I see that the bootloader code will return the NRF_DFU_RES_CODE_OPERATION_FAILED code in the prevalidation of the firmware image, i.e. if the version numbers are correct, if the signature of the firmware image is valid etc. See dfu_handle_prevalidate() in dfu_req_handling.c below.

So I would like to ask if you are using one of the sample firmware images from the SDK, i.e. one of the .zip files in examples\dfu\ble_dfu_send_hex or if you have generated your own image using nrfutil?

static nrf_dfu_res_code_t dfu_handle_prevalidate(dfu_signed_command_t const * p_command, pb_istream_t * p_stream, uint8_t * p_init_cmd, uint32_t init_cmd_len)
{
    dfu_init_command_t const *  p_init = &p_command->command.init;
    uint32_t                    err_code;
    uint32_t                    hw_version = NRF_DFU_HW_VERSION;
    uint32_t                    fw_version = 0;

    // check for init command found during decoding
    if(!p_init_cmd || !init_cmd_len)
    {
        return NRF_DFU_RES_CODE_OPERATION_FAILED;
    }

#ifndef NRF_DFU_DEBUG_VERSION
    if(p_init->has_is_debug && p_init->is_debug == true)
    {
        return NRF_DFU_RES_CODE_OPERATION_FAILED;
    }
#endif

#ifdef NRF_DFU_DEBUG_VERSION
    if (p_init->has_is_debug == false || p_init->is_debug == false)
    {
#endif
        if (p_init->has_hw_version == false)
        {
            return NRF_DFU_RES_CODE_OPERATION_FAILED;
        }

        // Check of init command HW version
        if(p_init->hw_version != hw_version)
        {
            return NRF_DFU_RES_CODE_OPERATION_FAILED;
        }

        // Precheck the SoftDevice version
        bool found_sd_ver = false;
        for(int i = 0; i < p_init->sd_req_count; i++)
        {
            if (p_init->sd_req[i] == SD_FWID_GET(MBR_SIZE))
            {
                found_sd_ver = true;
                break;
            }
        }
        if (!found_sd_ver)
        {
            return NRF_DFU_RES_CODE_OPERATION_FAILED;
        }

        // Get the fw version
        switch (p_init->type)
        {
            case DFU_FW_TYPE_APPLICATION:
                if (p_init->has_fw_version == false)
                {
                    return NRF_DFU_RES_CODE_OPERATION_FAILED;
                }
                // Get the application FW version
                fw_version = s_dfu_settings.app_version;
                break;

            case DFU_FW_TYPE_SOFTDEVICE:
                // not loaded
                break;

            case DFU_FW_TYPE_BOOTLOADER: // fall through
            case DFU_FW_TYPE_SOFTDEVICE_BOOTLOADER:
                if (p_init->has_fw_version == false)
                {
                    return NRF_DFU_RES_CODE_OPERATION_FAILED;
                }
                fw_version = s_dfu_settings.bootloader_version;
                break;

            default:
                NRF_LOG_INFO("Unknown FW update type\r\n");
                return NRF_DFU_RES_CODE_OPERATION_FAILED;
        }

        NRF_LOG_INFO("Req version: %d, Present: %d\r\n", p_init->fw_version, fw_version);

        // Check of init command FW version
        switch (p_init->type)
        {
            case DFU_FW_TYPE_APPLICATION:
                if (p_init->fw_version < fw_version)
                {
                    return NRF_DFU_RES_CODE_OPERATION_FAILED;
                }
                break;

            case DFU_FW_TYPE_BOOTLOADER:            // fall through
            case DFU_FW_TYPE_SOFTDEVICE_BOOTLOADER:
                // updating the bootloader is stricter. There must be an increase in version number
                if (p_init->fw_version <= fw_version)
                {
                    return NRF_DFU_RES_CODE_OPERATION_FAILED;
                }
                break;

            default:
                // do not care about fw_version in the case of a softdevice transfer
                break;
        }

#ifdef NRF_DFU_DEBUG_VERSION
    }
#endif

    // Check the signature
    switch (p_command->signature_type)
    {
        case DFU_SIGNATURE_TYPE_ECDSA_P256_SHA256:
            {
                // prepare the actual hash destination.
                hash_data.p_le_data = &hash[0];
                hash_data.len = sizeof(hash);

                NRF_LOG_INFO("Init command:\r\n");
                NRF_LOG_HEXDUMP_INFO(&s_dfu_settings.init_command[0], s_dfu_settings.progress.command_size);
                NRF_LOG_INFO("\r\n");

                NRF_LOG_INFO("p_Init command:\r\n");
                NRF_LOG_HEXDUMP_INFO(&p_init_cmd[0], init_cmd_len);
                NRF_LOG_INFO("\r\n");

                err_code = nrf_crypto_hash_compute(NRF_CRYPTO_HASH_ALG_SHA256, p_init_cmd, init_cmd_len, &hash_data);
                if (err_code != NRF_SUCCESS)
                {
                    return NRF_DFU_RES_CODE_OPERATION_FAILED;
                }

                // prepare the signature received over the air.
                memcpy(&sig[0], p_command->signature.bytes, p_command->signature.size);

                NRF_LOG_INFO("Signature\r\n");
                NRF_LOG_HEXDUMP_INFO(&p_command->signature.bytes[0], p_command->signature.size);
                NRF_LOG_INFO("\r\n");

                crypto_sig.p_le_data = sig;
                crypto_sig.len = p_command->signature.size;

                NRF_LOG_INFO("signature len: %d\r\n", p_command->signature.size);

                // calculate the signature
                err_code = nrf_crypto_verify(NRF_CRYPTO_CURVE_SECP256R1, &crypto_key_pk, &hash_data, &crypto_sig);
                if (err_code != NRF_SUCCESS)
                {
                    return NRF_DFU_RES_CODE_INVALID_OBJECT;
                }

                NRF_LOG_INFO("Image verified\r\n");
            }
            break;

        default:
            return NRF_DFU_RES_CODE_OPERATION_FAILED;
    }

    // Get the update size
    m_firmware_size_req = 0;

    switch (p_init->type)
    {
        case DFU_FW_TYPE_APPLICATION:
            if (p_init->has_app_size == false)
            {
                return NRF_DFU_RES_CODE_OPERATION_FAILED;
            }
            m_firmware_size_req += p_init->app_size;
            break;

        case DFU_FW_TYPE_BOOTLOADER:
            if (p_init->has_bl_size == false)
            {
                return NRF_DFU_RES_CODE_OPERATION_FAILED;
            }
            m_firmware_size_req += p_init->bl_size;
            // check that the size of the bootloader is not larger than the present one.
#if defined ( NRF51 )
            if (p_init->bl_size > BOOTLOADER_SETTINGS_ADDRESS - BOOTLOADER_START_ADDR)
#elif defined ( NRF52 )
            if (p_init->bl_size > NRF_MBR_PARAMS_PAGE_ADDRESS - BOOTLOADER_START_ADDR)
#endif
            {
                return NRF_DFU_RES_CODE_INSUFFICIENT_RESOURCES;
            }
            break;

        case DFU_FW_TYPE_SOFTDEVICE:
            if (p_init->has_sd_size == false)
            {
                return NRF_DFU_RES_CODE_OPERATION_FAILED;
            }
            m_firmware_size_req += p_init->sd_size;
            break;

        case DFU_FW_TYPE_SOFTDEVICE_BOOTLOADER:
            if (p_init->has_bl_size == false || p_init->has_sd_size == false)
            {
                return NRF_DFU_RES_CODE_OPERATION_FAILED;
            }
            m_firmware_size_req += p_init->sd_size + p_init->bl_size;
            if (p_init->sd_size == 0 || p_init->bl_size == 0)
            {
                return NRF_DFU_RES_CODE_INVALID_PARAMETER;
            }

            // check that the size of the bootloader is not larger than the present one.
#if defined ( NRF51 )
            if (p_init->bl_size > BOOTLOADER_SETTINGS_ADDRESS - BOOTLOADER_START_ADDR)
#elif defined ( NRF52 )
            if (p_init->bl_size > NRF_MBR_PARAMS_PAGE_ADDRESS - BOOTLOADER_START_ADDR)
#endif
            {
                return NRF_DFU_RES_CODE_INSUFFICIENT_RESOURCES;
            }
            break;

        default:
            NRF_LOG_INFO("Unknown FW update type\r\n");
            return NRF_DFU_RES_CODE_OPERATION_FAILED;
    }

    // SHA256 is the only supported hash
    memcpy(&hash[0], &p_init->hash.hash.bytes[0], 32);

    // Instead of checking each type with has-check, check the result of the size_req to
    // Validate its content.
    if (m_firmware_size_req == 0)
    {
        return NRF_DFU_RES_CODE_INVALID_PARAMETER;
    }

    // Find the location to place the DFU updates
    err_code = nrf_dfu_find_cache(m_firmware_size_req, false, &m_firmware_start_addr);
    if (err_code != NRF_SUCCESS)
    {
        return NRF_DFU_RES_CODE_INSUFFICIENT_RESOURCES;
    }

    NRF_LOG_INFO("Write address set to 0x%08x\r\n", m_firmware_start_addr);

    NRF_LOG_INFO("DFU prevalidate SUCCESSFUL!\r\n");

    return NRF_DFU_RES_CODE_SUCCESS;
}

[Robin P]

We have used nrfutil to generate image, and sdk version is: 11.

This works on older Android phones.

The Huawei phone is using android 9, with emui 9.0.1.

Some other tests:

Tried with dfuing another product we are working with that uses nrf52 and sdk 15.2.0, This however works to flash from the Huawei phone.

But a strange thing(Maybe not, but I have not seen it before) is that as soon as the fw upload starts, it spawns another connection in nrf connect view to DFU TARG. And at the same time the firmware upload runs in the background in the old connection.

[bjorn-spockeli]

Which version of nrfutil are you using?

[Robin P]

0.3.0

[bjorn-spockeli]

Ok, are you using one of the sample firmware images from the SDK, i.e. one of the .zip files in examples\dfu\ble_dfu_send_hex or if you have generated your own image using nrfutil?

[Robin P]

We tried debugging the bootloader, And the error we get is error code 4 NO_MEM before it throws the OPERATION_FAILED. 

However if I set request MTU in app, the DFU succeeds.