NRF52840 USB CDC Serial is missing first character when SOF = 2 and QUEUE_EN = 0 only

[OPCODE]

Hi,

The following code has been working fine since it was taken from the examples (NRF52840).

#include <stdint.h>
#include <string.h>
#include "nordic_common.h"
#include "nrf.h"
// #include "ble_hci.h"
// #include "ble_advdata.h"
// #include "ble_advertising.h"
// #include "ble_conn_params.h"
#include "nrf_sdh.h"
#include "nrf_sdh_soc.h"
#include "nrf_sdh_ble.h"
// #include "nrf_ble_gatt.h"
#include "app_timer.h"
// #include "ble_nus.h"
#include "app_uart.h"
#include "app_util_platform.h"
//#include "bsp_btn_ble.h"

// #include "nrf_log.h"
// #include "nrf_log_ctrl.h"
// #include "nrf_log_default_backends.h"

#include "nrf_drv_usbd.h"
#include "nrf_drv_clock.h"
#include "nrf_gpio.h"
#include "nrf_delay.h"
#include "nrf_drv_power.h"

#include "app_error.h"
#include "app_util.h"
#include "app_usbd_core.h"
#include "app_usbd.h"
#include "app_usbd_string_desc.h"
#include "app_usbd_cdc_acm.h"
#include "app_usbd_serial_num.h"


//#define LED_BLE_NUS_CONN (BSP_BOARD_LED_0)
//#define LED_BLE_NUS_RX   (BSP_BOARD_LED_1)
//#define LED_CDC_ACM_CONN (BSP_BOARD_LED_2)
//#define LED_CDC_ACM_RX   (BSP_BOARD_LED_3)

#define RECV_BUF_LEN 256

//#define ENDLINE_STRING "\r\n"



// BLE DEFINES START
#define APP_BLE_CONN_CFG_TAG            1                                           /**< A tag identifying the SoftDevice BLE configuration. */

#define APP_FEATURE_NOT_SUPPORTED       BLE_GATT_STATUS_ATTERR_APP_BEGIN + 2        /**< Reply when unsupported features are requested. */


#define DEAD_BEEF                       0xDEADBEEF                                  /**< Value used as error code on stack dump. Can be used to identify stack location on stack unwind. */


uint32_t buffer_available_idx = 0;


//#define LED_1          NRF_GPIO_PIN_MAP(0,13)
//#define LED_2          NRF_GPIO_PIN_MAP(0,14)


void assert_nrf_callback(uint16_t line_num, const uint8_t * p_file_name)
{
    app_error_handler(DEAD_BEEF, line_num, p_file_name);
}


// USB DEFINES START
static void cdc_acm_user_ev_handler(app_usbd_class_inst_t const * p_inst,
                                    app_usbd_cdc_acm_user_event_t event);

#define CDC_ACM_COMM_INTERFACE  0
#define CDC_ACM_COMM_EPIN       NRF_DRV_USBD_EPIN2

#define CDC_ACM_DATA_INTERFACE  1
#define CDC_ACM_DATA_EPIN       NRF_DRV_USBD_EPIN1
#define CDC_ACM_DATA_EPOUT      NRF_DRV_USBD_EPOUT1

static char m_cdc_data_array[RECV_BUF_LEN] = {0};

/** @brief CDC_ACM class instance */
APP_USBD_CDC_ACM_GLOBAL_DEF(m_app_cdc_acm,
                            cdc_acm_user_ev_handler,
                            CDC_ACM_COMM_INTERFACE,
                            CDC_ACM_DATA_INTERFACE,
                            CDC_ACM_COMM_EPIN,
                            CDC_ACM_DATA_EPIN,
                            CDC_ACM_DATA_EPOUT,
                            APP_USBD_CDC_COMM_PROTOCOL_AT_V250);

// USB DEFINES END
// USB CODE START
static bool m_usb_connected = false;


/** @brief User event handler @ref app_usbd_cdc_acm_user_ev_handler_t */
static void cdc_acm_user_ev_handler(app_usbd_class_inst_t const * p_inst,
                                    app_usbd_cdc_acm_user_event_t event)
{
    //app_usbd_cdc_acm_t const * p_cdc_acm = app_usbd_cdc_acm_class_get(p_inst);

    switch (event)
    {
        case APP_USBD_CDC_ACM_USER_EVT_PORT_OPEN:
        {
            /*Set up the first transfer*/
            ret_code_t ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, m_cdc_data_array, 1); // necessary it seems
            break;
        }

        case APP_USBD_CDC_ACM_USER_EVT_PORT_CLOSE:
            //NRF_LOG_INFO("CDC ACM port closed");
            //nrf_gpio_pin_write(LED_1,1);
            break;

        case APP_USBD_CDC_ACM_USER_EVT_TX_DONE:
            app_usbd_cdc_acm_read_any(&m_app_cdc_acm, m_cdc_data_array, 1);

            break;

        case APP_USBD_CDC_ACM_USER_EVT_RX_DONE:
        {
            ret_code_t ret;

            do{
                    ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_cdc_data_array[buffer_available_idx++], 1);  
            }while (ret == NRF_SUCCESS);

            break;
        }
        default:
            break;
    }
}

static void usbd_user_ev_handler(app_usbd_event_type_t event)
{
    switch (event)
    {
        case APP_USBD_EVT_DRV_SUSPEND:
            break;

        case APP_USBD_EVT_DRV_RESUME:
            break;

        case APP_USBD_EVT_STARTED:
            break;

        case APP_USBD_EVT_STOPPED:
            app_usbd_disable();
            break;

        case APP_USBD_EVT_POWER_DETECTED:
            //NRF_LOG_INFO("USB power detected");

            if (!nrf_drv_usbd_is_enabled())
            {
                app_usbd_enable();
            }
            break;

        case APP_USBD_EVT_POWER_REMOVED:
        {

            m_usb_connected = false;
            app_usbd_stop();
        }
            break;

        case APP_USBD_EVT_POWER_READY:
        {

            m_usb_connected = true;
            app_usbd_start();
        }
            break;

        default:
            break;
    }
}


void usb_cdc_write123(char *str, uint16_t len){
    ret_code_t ret = app_usbd_cdc_acm_write(&m_app_cdc_acm, str,len);
}

void INIT_usb_cdc(){
            
    ret_code_t ret;
    static const app_usbd_config_t usbd_config = {
        .ev_state_proc = usbd_user_ev_handler
    };


    app_usbd_serial_num_generate();

    ret = nrf_drv_clock_init();
    APP_ERROR_CHECK(ret);

    //NRF_LOG_INFO("USBD BLE UART example started.");

    ret = app_usbd_init(&usbd_config);
    APP_ERROR_CHECK(ret);

    app_usbd_class_inst_t const * class_cdc_acm = app_usbd_cdc_acm_class_inst_get(&m_app_cdc_acm);
    ret = app_usbd_class_append(class_cdc_acm);
    APP_ERROR_CHECK(ret);


            // SOFT DEVICE SHIAT
            ret_code_t err_code;
            err_code = nrf_sdh_enable_request();
            APP_ERROR_CHECK(err_code);
            // Configure the BLE stack using the default settings.
            // Fetch the start address of the application RAM.
            uint32_t ram_start = 0;
            err_code = nrf_sdh_ble_default_cfg_set(APP_BLE_CONN_CFG_TAG, &ram_start);
            APP_ERROR_CHECK(err_code);

            // Enable BLE stack.
            err_code = nrf_sdh_ble_enable(&ram_start);
            APP_ERROR_CHECK(err_code);

    ret = app_usbd_power_events_enable();
    APP_ERROR_CHECK(ret);
}

uint32_t usb_cdc_available(){
    return buffer_available_idx;
}

uint8_t usb_cdc_read(){
        char temp_buf[RECV_BUF_LEN] = {0};
        uint8_t bytey = m_cdc_data_array[0]; // if empty it will be \0
        memcpy(temp_buf, (m_cdc_data_array+1), RECV_BUF_LEN-1);
        memcpy(m_cdc_data_array, temp_buf, RECV_BUF_LEN);
        if (buffer_available_idx > 0)
            buffer_available_idx--;
        if (buffer_available_idx == 0)
            memset(m_cdc_data_array, 0, RECV_BUF_LEN);
        return bytey;
}

void SVC_usb_cdc(){
        // removed since we are using the interrupt method now
        // //while (app_usbd_event_queue_process())
        // //{
        //     /* Nothing to do */
        // //}
}

We wanted to remove the  app_usbd_event_queue_process() so we enabled these 2 options in the sdk_config.h (config file was also from the example)

APP_USBD_CONFIG_EVENT_QUEUE_ENABLE = 0
APP_USBD_CONFIG_SOF_HANDLING_MODE = 2

We now have 2 issues with the above code:

- One appeared immediately after turning ON the interrupt mode 2 and queue = 0. The first character was being lost on any size transmission. We tried many solutions but no result. The first received character always gets eaten. 

- The second issue is that some characters are being lost on more frequent, repetitive prints. We are happy to do more analysis for the second issue. We hope we can start by fixing issue 1.

Finally should we want to return back to using app_usbd_event_queue_process() if there is no solution, what are the implications when we want to go to sleep? Can we get awaken by a USB event and then service the queue? Any caveats? Is the interrupt way with no queue, better? 

Thanks!

[Jørgen Holmefjord]

Hi,

I tried to reproduce this behavior by modifying the configs in the app_usbd_cdc_acm example in the SDK, but I'm not able to reproduce it. Maybe I missed something else required to reproduce this?

Could you share the full project that can be used to reproduce the issue?

Best regards,
Jørgen

[OPCODE]

Thanks for looking at it Jorgen. I have spent some hours today trimming the code down to the minimum where the bug occurs. 

The code just enumerates a CDC serial and should echo back whatever is typed. Please see the attached zip!

Setup details:

Compiler: gcc-arm-none-eabi-9-2019-q4-major-x86_64-linux

SDK version: nRF5_SDK_17.0.0_9d13099

Softdevice version: s140_nrf52_7.0.1_softdevice.hex

Let me know what you find!

usbd_cdc_acm2.zip

www.dropbox.com/.../usbd_cdc_acm2.zip

[Jørgen Holmefjord]

Unfortunately this example does not enumerate as a serial device on my setup, it only shows up as a generic USB device with a warning triangle in Windows Device manager. I was able to resolve this by modifying the VID/PID configs in sdk_config.h. Maybe this could also have been resolved by manually installing drivers, etc.

When connecting the serial terminal, I only see >> printed in most cases when I send strings. How are you testing this? Which serial terminal are you using? What is the input and output that you get?

[OPCODE]

Hi Jorgen,

Thanks for your reply. When I made this example, I had the same issue. When I sent characters down the terminal I also get >> and sometimes I get the characters minus the first. But sometimes I don't get any response. 

Looking at the code do you see any issue? Basically I am looking for a barebones interrupt CDC example with SD (no cli, no logging, no bsp, no uart) that can echo back characters so I can build on top of it. I cant run the examples as they have BSP/uart in them that might turn on and off random mosfets on our PCB. When I modify the examples to remove the bsp and uart things, I basically end up with the example I sent you, which looks like a pretty logic CDC interrupt based CDC example, but I have no idea why it doesnt work.

Regarding the terminal, I use many different ones like coolterm, minicom, custom one, and they all show the same behaviour.

Thanks!

[Jørgen Holmefjord]

Hi,

I spent some time looking into your example today. I think I found the root cause of all issues, but I do not have a good solution for all:

1. Initially, the first missing character is caused by how you call app_usbd_cdc_acm_read(). This function will only provide a buffer to the USBD library, which will be filled when data is coming in over USB. When the port is opened, you provide the first byte of the buffer as the initial buffer to the library. When the first byte is received, you provide the same byte of the buffer to the library (since buffer_available_idx is 0). You can resolve this by also incrementing buffer_available_idx in APP_USBD_CDC_ACM_USER_EVT_PORT_OPEN, and wait until buffer_available_idx > 1 before writing back the data in main().
2. When you write back the data in main(), you do not check the return codes of the calls to app_usbd_cdc_acm_write(). This function will return an error if another write operation is ongoing. You need to wait for the APP_USBD_CDC_ACM_USER_EVT_TX_DONE event before starting a new transfer. You can resolve this by setting a flag in the event handler and wait for this before starting the next transfer.
3. When you are done writing the data back, you reset buffer_available_idx to 0, but you do still have 1 byte buffer passed to the library from the latest call to app_usbd_cdc_acm_read(). When you send the second string from the terminal, the first byte will be store at the last buffer_available_idx, while subsequent bytes will be stored from 0 and upwards. This will possibly overwrite the first byte (if the string is longer than the previous). I cannot see any API to cancel a buffer, so this issue I do not have a good solution to at the moment.
4. One final issue is that the USB running at interrupt may preempt the execution of the main loop while writing the data. If data is received between the second call to app_usbd_cdc_acm_write and the reset of the buffer_available_idx variable, you may also lose these bytes.

Attaching my main.c which works apart from the missing first byte of second and subsequent strings:

#include <stdint.h>
#include <string.h>
#include "nordic_common.h"
#include "nrf.h"
#include "nrfx.h"

#include "nrf_sdh.h"
#include "nrf_sdh_soc.h"
#include "nrf_sdh_ble.h"
// #include "nrf_ble_gatt.h"
#include "app_timer.h"
// #include "ble_nus.h"
#include "app_uart.h"
#include "app_util_platform.h"

#include "nrf_drv_usbd.h"
#include "nrf_drv_clock.h"
#include "nrf_gpio.h"
#include "nrf_delay.h"
#include "nrf_drv_power.h"

#include "app_error.h"
#include "app_util.h"
#include "app_usbd_core.h"
#include "app_usbd.h"
#include "app_usbd_string_desc.h"
#include "app_usbd_cdc_acm.h"
#include "app_usbd_serial_num.h"

#define RECV_BUF_LEN 256
static char m_cdc_data_array[RECV_BUF_LEN] = {0};
volatile uint32_t buffer_available_idx = 0;
static bool m_usb_connected = false;
static bool usbd_tx_done = true;

// USB DEFINES START
static void cdc_acm_user_ev_handler(app_usbd_class_inst_t const * p_inst,
                                    app_usbd_cdc_acm_user_event_t event);
#define CDC_ACM_COMM_INTERFACE  0
#define CDC_ACM_COMM_EPIN       NRF_DRV_USBD_EPIN2
#define CDC_ACM_DATA_INTERFACE  1
#define CDC_ACM_DATA_EPIN       NRF_DRV_USBD_EPIN1
#define CDC_ACM_DATA_EPOUT      NRF_DRV_USBD_EPOUT1

/** @brief CDC_ACM class instance */
APP_USBD_CDC_ACM_GLOBAL_DEF(m_app_cdc_acm,
                            cdc_acm_user_ev_handler,
                            CDC_ACM_COMM_INTERFACE,
                            CDC_ACM_DATA_INTERFACE,
                            CDC_ACM_COMM_EPIN,
                            CDC_ACM_DATA_EPIN,
                            CDC_ACM_DATA_EPOUT,
                            APP_USBD_CDC_COMM_PROTOCOL_AT_V250);


/** @brief User event handler @ref app_usbd_cdc_acm_user_ev_handler_t */
static void cdc_acm_user_ev_handler(app_usbd_class_inst_t const * p_inst,
                                    app_usbd_cdc_acm_user_event_t event)
{
    //app_usbd_cdc_acm_t const * p_cdc_acm = app_usbd_cdc_acm_class_get(p_inst);

    switch (event)
    {
        case APP_USBD_CDC_ACM_USER_EVT_PORT_OPEN:
        {
            /*Set up the first transfer*/
            //ret_code_t ret = 
            app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_cdc_data_array[buffer_available_idx++], 1);  // necessary it seems
            break;
        }

        case APP_USBD_CDC_ACM_USER_EVT_PORT_CLOSE:
            break;

        case APP_USBD_CDC_ACM_USER_EVT_TX_DONE:
            usbd_tx_done = true;
            //app_usbd_cdc_acm_read_any(&m_app_cdc_acm, m_cdc_data_array, 1);
            //app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_cdc_data_array[0], 1);  
            break;

        case APP_USBD_CDC_ACM_USER_EVT_RX_DONE:
        {
            ret_code_t ret;

            //if (app_usbd_cdc_acm_bytes_stored(&m_app_cdc_acm) > 0){
            //ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_cdc_data_array[buffer_available_idx++], 1);
                        
            do{
                    ret = app_usbd_cdc_acm_read(&m_app_cdc_acm, &m_cdc_data_array[buffer_available_idx++], 1);  
            }while (ret == NRF_SUCCESS);
 
            break;
        }
        default:
            break;
    }
}

static void usbd_user_ev_handler(app_usbd_event_type_t event)
{
    switch (event)
    {
        case APP_USBD_EVT_DRV_SUSPEND:
            break;

        case APP_USBD_EVT_DRV_RESUME:
            break;

        case APP_USBD_EVT_STARTED:
            break;

        case APP_USBD_EVT_STOPPED:
            app_usbd_disable();
            break;

        case APP_USBD_EVT_POWER_DETECTED:
            //NRF_LOG_INFO("USB power detected");
            if (!nrf_drv_usbd_is_enabled())
            {
                app_usbd_enable();
            }
            break;

        case APP_USBD_EVT_POWER_REMOVED:
        {
            m_usb_connected = false;
            app_usbd_stop();
        }
            break;

        case APP_USBD_EVT_POWER_READY:
        {
            m_usb_connected = true;
            app_usbd_start();
        }
            break;

        default:
            break;
    }
}


void INIT_usb_cdc(){

    ret_code_t ret;
    static const app_usbd_config_t usbd_config = {
        .ev_state_proc = usbd_user_ev_handler
    };

    app_usbd_serial_num_generate();

    ret = nrf_drv_clock_init();
    APP_ERROR_CHECK(ret);

    ret = app_usbd_init(&usbd_config);
    APP_ERROR_CHECK(ret);

    app_usbd_class_inst_t const * class_cdc_acm = app_usbd_cdc_acm_class_inst_get(&m_app_cdc_acm);
    ret = app_usbd_class_append(class_cdc_acm);
    APP_ERROR_CHECK(ret);

    ret = nrf_sdh_enable_request();
    APP_ERROR_CHECK(ret);

    ret = app_usbd_power_events_enable();
    APP_ERROR_CHECK(ret);
}




int main(void){
    INIT_usb_cdc();
    ret_code_t ret;
    while(1)
    {
        if (buffer_available_idx>1){            
            while(usbd_tx_done == false);
            usbd_tx_done = false;
            ret = app_usbd_cdc_acm_write(&m_app_cdc_acm, ">> ", 3);
            if(ret == NRF_SUCCESS)
            {              
                while(usbd_tx_done == false);
                usbd_tx_done = false;

                ret = app_usbd_cdc_acm_write(&m_app_cdc_acm, m_cdc_data_array, buffer_available_idx-1);
                if(ret == NRF_SUCCESS)
                {
                    buffer_available_idx=0;
                }
            }
        }
    }
}

Best regards,
Jørgen

[OPCODE]

Thanks so much for looking at it Jorgen!

Adding a delay of 100uS or a while(flag) check, after the app_usbd_cdc_acm_write also fixes the loss of any TX data (my original issue no2). I have confirmed that with my larger codebase and this example. I dont see any loss when transmitting in bursts anymore. I think it solves the same issue as the usbd_tx_done flag does in your code above.

Regarding the missing first character during RX, I tried improving the code as per your suggestions but I cant get it to go away either. Only the first string is received well.

- Do you think its something related to the CDC APP? Shall I start poking in app_usbd_cdc_acm.c?

- Shall I try a different SDK?

I am basically a little unclear as to what I should try next. Any pointers would be welcome!