ble NUS central device occasionally dropping or sending wrong characters out the UART

[Alex_O]

Hello,

I am using the ble_app_uart_c_pca10056_s140 example code (SDK v17). This is the NUS BLE central device.

The code is almost unchanged from the example source.

I am finding that characters are not being forwarded via UART from BLE as expected. A peripheral is sending strings over BLE to the Central. The Central forwards it on to another processor via UART.

The UART output occasionally drops a character or sends the wrong character. Is this expected/known behavior?

How does the Central soft device handle reception of BLE? Specifically, if the peripheral sends "1234" then "5678" is it possible that the reception on the Central side can give me "123" in one NUS callback then "45678" in another or should I expect all the serial data to be received in the same chunks they were sent out? Does the Nordic Central code that handles the UART transmission properly buffer data to ensure that incoming BLE data cannot affect the data that has previously been given to the UART?

When I observe the UART traffic, I see gaps in time between characters where I wouldn't have expected a gap, such as described above in my description of the "12345678" sequence. The gaps aren't in chunks that correspond to what was sent from the BLE Peripheral device. This makes me wonder how the soft device is notifying the application of reception, or wonder if it's not buffering it properly to send/receive over UART/BLE without stomping on each other.

Thanks!

[Alex_O]

Hi Karl, sorry for this out of place message but for some reason I can not reply to your last message. There is no button to do so.

Anyway, I'm fairly certain I'm using the fifo. ble_nus_chars_received_uart_print() which is a function in main.c from the ble_app_uart_c_pca10056_s140 example project calls app_uart_put(). In app_uart_put(), app_fifo_put() is called. App_fifo_put():

uint32_t app_fifo_put(app_fifo_t * p_fifo, uint8_t byte)
{
    if (FIFO_LENGTH() <= p_fifo->buf_size_mask)
    {
        fifo_put(p_fifo, byte);
        return NRF_SUCCESS;
    }

    return NRF_ERROR_NO_MEM;
}

There is no NRF_ERROR_BUSY return option. It's true, nrfx_uarte_tx() can return busy, but if the fifo is full, ble_nus_chars_received_uart_print() does not retry sending the same data:

static void ble_nus_chars_received_uart_print(uint8_t * p_data, uint16_t data_len)
{
    ret_code_t ret_val;
    bool checkStr = false;
    NRF_LOG_DEBUG("Receiving data.");
    NRF_LOG_HEXDUMP_DEBUG(p_data, data_len);

    for (uint32_t i = 0; i < data_len; i++)
    {
        do
        {
            ret_val = app_uart_put(p_data[i]);
            if ((ret_val != NRF_SUCCESS) && (ret_val != NRF_ERROR_BUSY))
            {
                NRF_LOG_ERROR("app_uart_put failed for index 0x%04x.", i);
                APP_ERROR_CHECK(ret_val);
            }
        } while (ret_val == NRF_ERROR_BUSY);
    }

...

}

Now I admit I never ended in an error handler that I know of and I don't have LOG error enabled but I changed the error reported to busy instead of NO_MEM and it seemed to help.

I understand that the Soft Device takes priority but is the on_hvx() function called from the soft device interrupt context? In other words, could it be that while waiting for the fifo/uart in a soft device interrupt the next interrupt is being blocked? Just curious how the callback functions for the soft device work.

[Karl Ylvisaker]

Hello Alex,

Thank you for your patience with this.

Alex_O said:

sorry for this out of place message but for some reason I can not reply to your last message. There is no button to do so.

No need to apologize at all! I've heard that this can happen sometimes, and our site engineers are looking into it, but in the meantime a workaround to it is to click on the timestamp of the comment you wish to reply to, and then the buttons should show up.

Alex_O said:

There is no NRF_ERROR_BUSY return option. It's true, nrfx_uarte_tx() can return busy, but if the fifo is full, ble_nus_chars_received_uart_print() does not retry sending the same data:

This is correct, but also as intended, since it will require a different solution when the fifo is full compared to when the uarte_tx returns busy. I would argue that there is really only the NRF_ERROR_BUSY error that it makes sense to rapidly retry the operation for. If the buffer is full, and there is no more memory to store characters then there needs to be done some other error handling other than just retrying the operation - which is why the error code then is passed to an APP_ERROR_CHECK, so that this error handling can happen.

Alex_O said:

Now I admit I never ended in an error handler that I know of and I don't have LOG error enabled but I changed the error reported to busy instead of NO_MEM and it seemed to help.

I suppose this will work as long as you are able to avoid the race condition of the FIFO being full, and the UARTE being stopped at the same time - since this will lead to an error being returned immediately by app_fifo_put, and it thus never reaching the nrf_drv_uart_tx call in app_uart_put. Does this make sense?
This is an edge case, but if you have not implemented any other error handling here you might end up in a deadlock of the UART prints. You can test this by filling your UART and stopping the transfer (simulating that it happens for whatever reason/error elsewhere), to see if it resumes when the next character arrives, I would think it does not, but I could be wrong (bear in mind that I have only seen snippets of your application code).
On that note, If this test fails I would rather recommend that you implement specific error handling for NRF_ERROR_NO_MEM, and revert your error code modification so that retired only happens when the NRF_ERROR_BUSY returns.

Furthermore, I highly recommend making use of the loggers RTT backend while developing using the UART for your application. Being able to see the logs and what is going on often saves a lot of debug time in the long run.

For future reference, please use the Insert -> Code option when sharing code here on DevZone - it increases the readability of your code tenfold :) 

Alex_O said:

I understand that the Soft Device takes priority but is the on_hvx() function called from the soft device interrupt context? In other words, could it be that while waiting for the fifo/uart in a soft device interrupt the next interrupt is being blocked? Just curious how the callback functions for the soft device work.

The default priority level of the NUS event observer is 2 (BLE_NUS_BLE_OBSERVER_PRIO), which is the highest possible application priority level, so while it does not run on the same priority as the SoftDevice, it still is close to it for all application layer purposes.
Thus the answer to your second question is no; the SoftDevice will not be blocked by any application layer task.

Best regards,
Karl