USBD issue after bluetooth is connected once

[Vishnu Pradeep]

Our application stores sensor data in flash and sends the data on request via USB. But if the device is connected to Bluetooth once then it is having issues in USB data transfer. Device receives 21 bytes in place of 20 bytes. Receiving same packet twice even if the host doesn't send. But everything works normal if we power cycle the device.

We wrote application over usbd_ble_uart_pca10056_s140 example. 

Thanks,

Vishnu 

[Vishnu Pradeep]

This is my initialization sequence

    timers_init();
    ret_code_t err_code = nrf_drv_clock_init();                        //Initialize the clock source specified in the nrf_drv_config.h file, i.e. the CLOCK_CONFIG_LF_SRC constant
    APP_ERROR_CHECK(err_code);
    nrf_drv_clock_lfclk_request(NULL);
   //Initialize RTC instance
   nrf_drv_rtc_config_t config = NRF_DRV_RTC_DEFAULT_CONFIG;
   config.prescaler = 4095;
   err_code = nrf_drv_rtc_init(&rtc, &config, rtc_handler);
   APP_ERROR_CHECK(err_code);

   err_code = nrf_drv_rtc_cc_set(&rtc, 0, RTC_CC_VALUE, true); //Set RTC compare value to trigger interrupt. Configure the interrupt frequency by adjust RTC_CC_VALUE and RTC_FREQUENCY constant in top of main.c
   APP_ERROR_CHECK(err_code);

   //Power on RTC instance
   nrf_drv_rtc_enable(&rtc);
/* Register first to receive an event when initialization is complete. */
    (void) fds_register(fds_evt_handler);

    msg("Initializing fds...");

    ret_code_t rc = fds_init();
    APP_ERROR_CHECK(rc);

    /* Wait for fds to initialize. */
    wait_for_fds_ready();
    get_fds_stat();
     static const app_usbd_config_t usbd_config = {
      .ev_state_proc = usbd_user_ev_handler};

  app_usbd_serial_num_generate();
  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 = app_usbd_power_events_enable();
  APP_ERROR_CHECK(ret);

Edit: Yes it is behaving the same with example code. Power on the device -> connect Bluetooth -> disconnect -> send data via USB, 21 bytes.
If I power cycle and send data without connecting the Bluetooth, receives 20 bytes

[Karl Ylvisaker]

Hello again Vishnu,

Vishnu Pradeep said:

This is my initialization sequence

This does not tell me much, unfortunately. I can only say that your app_usbd initialization looks all right to me.

Karl Ylvisaker said:

Is there any error messages being generated / outputted to your logger module?
Please make sure that DEBUG is defined in your preprocessor defines, as shown in the included image.

Please confirm whether you have done this, and what you are seeing.
What does the logger output when you establish the first connection? Is there any error message generated when the unexpected byte is sent?

Vishnu Pradeep said:

Edit: Yes it is behaving the same with example code. Power on the device -> connect Bluetooth -> disconnect -> send data via USB, 21 bytes.
If I power cycle and send data without connecting the Bluetooth, receives 20 bytes

Could you tell me specifically which data is being sent here? What is the contents of the unexpected byte? 

Best regards,
Karl

[Vishnu Pradeep]

Karl Ylvisaker said:

Please confirm whether you have done this, and what you are seeing.

yes, I've added DEBUG. Not seeing any error message generated as such in debug log. 

Karl Ylvisaker said:

Is there any error message generated when the unexpected byte is sent?

No. 

Karl Ylvisaker said:

Could you tell me specifically which data is being sent here? What is the contents of the unexpected byte? 

I was sending 20 bytes. BRK0000000000000000Z. But received 21 bytes with 0x0D at the end. This is not happening if we are sending data via USB after power cycle and not connecting to Bluetooth. If the device gets connected to Bluetooth once after power on, USB data transfer is having some unexpected behaviors. If we don't connect to Bluetooth and start USB data transfer after power up, it works fine.

Actually we are sending data to android phone over OTG. Whenever the device is connected to any nRF uart app even on a different phone, this issue happens.

[Karl Ylvisaker]

Hello,

Vishnu Pradeep said:

yes, I've added DEBUG. Not seeing any error message generated as such in debug log.

Thank you for verifying this.

Vishnu Pradeep said:

I was sending 20 bytes. BRK0000000000000000Z. But received 21 bytes with 0x0D at the end.

It seems a Carriage Return character is appended to the end of your message. 
Which function are you using to output this message? Could you show me the code snippets in which it is outputted.

Could you check for me if you have defined NRF_FPRINTF_FLAG_AUTOMATIC_CR_ON_LF_ENABLED 1 in your sdk_config file?
This will automatically append CR for each Line Feed character. 

Vishnu Pradeep said:

This is not happening if we are sending data via USB after power cycle and not connecting to Bluetooth. If the device gets connected to Bluetooth once after power on, USB data transfer is having some unexpected behaviors. If we don't connect to Bluetooth and start USB data transfer after power up, it works fine.

Is the appended CR character what you are referring to when you say unexpected behaviors, or are you observing other unexpected behavior as well?
It sounds strange that this only happens when connected to BLE, or if you have not power cycled the device. Perhaps this is related to your call to nrf_drv_clock_lfclk_request, which is superseded when the SoftDevice is enabled.
Could you attempt to send the same test string with and without enabling the SoftDevice?

Looking forward to resolving this issue together!

Best regards,
Karl

[Vishnu Pradeep]

Karl Ylvisaker said:

Which function are you using to output this message? Could you show me the code snippets in which it is outputted.

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);
    UNUSED_VARIABLE(ret);
    msg("CDC ACM port opened");
    break;
  }

  case APP_USBD_CDC_ACM_USER_EVT_PORT_CLOSE:
    msg("CDC ACM port closed");
    break;

  case APP_USBD_CDC_ACM_USER_EVT_TX_DONE:
    break;

  case APP_USBD_CDC_ACM_USER_EVT_RX_DONE: {
    ret_code_t ret;
    static uint8_t index = 0;
    index++;

    do {
      if ((m_cdc_data_array[index - 1] == '\n') ||
          (m_cdc_data_array[index - 1] == '\r') ||
          (index >= (m_ble_nus_max_data_len))) {
        if (index > 1) {
          msg("USB data received %dbytes", index);
          msg_hexdump(m_cdc_data_array, index);
          memcpy(usb_receive_buffer, m_cdc_data_array, index);
          usb_data_received = true;
        }
        index = 0;
        }
      
      /* Fetch data until internal buffer is empty */
      ret = app_usbd_cdc_acm_read(&m_app_cdc_acm,
          &m_cdc_data_array[index],
          1);
      if (ret == NRF_SUCCESS) {
        index++;
      }
    } while (ret == NRF_SUCCESS);

    break;
  }
  default:
    break;
  }
}

Karl Ylvisaker said:

Could you check for me if you have defined NRF_FPRINTF_FLAG_AUTOMATIC_CR_ON_LF_ENABLED 1 in your sdk_config file?

Sorry I am using SDK 15.2. I cannot find this in sdk_config file.

Karl Ylvisaker said:

Is the appended CR character what you are referring to when you say unexpected behaviors, or are you observing other unexpected behavior as well?

Well, NO. Actually 21 bytes are seen in the receive buffer. but android is sending only 20 bytes. That is the issue.

My application is, storing the sensor data to a NAND flash and sending this data to android app via USB on request. The data size will be around 200MB-512 MB. 

We are doing some packet exchange between android phone and our nRF peripheral before sending the actual data. We are seeing some unexpected packet exchange between the device if we've connected the device via Bluetooth after power up. As soon as the USB cable is plugged in, we are disconnecting Bluetooth for some reasons. After a 3 to 4 USB packets are exchanged without any issues, device is receiving a packet twice, which was supposed to receive only once. After that the communication simply stops. device tries to send data, but android is not getting anything, and feels like some error in packet send from device to android app. 
Thus we've debugged and found that if we do not connect to our device using bluetooth after power up, the USB data transfer works smoothly. We are receiving only 20 bytes when android sends 20 bytes of request.
But if we connect bluetooth at any point of time after the power up, the issue arises. 

Karl Ylvisaker said:

It sounds strange that this only happens when connected to BLE, or if you have not power cycled the device. Perhaps this is related to your call to nrf_drv_clock_lfclk_request, which is superseded when the SoftDevice is enabled.

Can I remove nrf_drv_clock_lfclk_request for our application? it is not called in usbd_ble_app_uart example code. but we are using RTC module in addition to example code.?

Karl Ylvisaker said:

Could you attempt to send the same test string with and without enabling the SoftDevice?

That will work. Because we are not connecting bluetooth, It works well if the device was not connected to bluetooth. 

Thanks & best regards,

Vishnu Pradeep

[Karl Ylvisaker]

Hello Vishnu Pradeep,

Sorry for my late reply.

Vishnu Pradeep said:

Sorry I am using SDK 15.2. I cannot find this in sdk_config file.

Vishnu Pradeep said:

Well, NO. Actually 21 bytes are seen in the receive buffer. but android is sending only 20 bytes. That is the issue.

Thank you for clarifying.

Vishnu Pradeep said:

As soon as the USB cable is plugged in, we are disconnecting Bluetooth for some reasons.

Could you make sure that the device is not in fact resetting, when you connect the USB cable?
Depending on how you have configured your POWER sources, this might be the case.

Vishnu Pradeep said:

After a 3 to 4 USB packets are exchanged without any issues, device is receiving a packet twice, which was supposed to receive only once.

Vishnu Pradeep said:

After that the communication simply stops. device tries to send data, but android is not getting anything, and feels like some error in packet send from device to android app. 

This sounds very strange indeed. Are you familiar with the nRF Sniffer tool? It would be very helpful if you could provide a trace of the BLE communication when this happens, along with a log file of the USB traffic.

Vishnu Pradeep said:

But if we connect bluetooth at any point of time after the power up, the issue arises. 

This would also be great to see happen in a sniffer trace + usb communication log. 

Vishnu Pradeep said:

Can I remove nrf_drv_clock_lfclk_request

My mistake there, it seems I misread the request, instead thinking you were requesting the HF clock. The LF clock should have nothing to do with it.

Looking forward to resolving this issue together!

Best regards,
Karl