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,

The system I'm working with communicates like a command line interface using UART over BLE. Since it's designed so that each command and response ends in \r I can just buffer up the entire message coming over BLE then forward it over UART when I get the \r. I made two buffers to make sure that while UART is going out, I can still receive BLE and buffer it up. I moved all of this into the main loop and out of the ble_nus_c_evt_handler() function. What I do in the interrupt is strncat the incoming string to one of my buffers then let the main loop know I got something to check for \r.

BUT! I first tried just moving everything out of the interrupt and forward the incoming BLE bytes as they come in. This still didn't work flawlessly. Here's what I did and I believe I found a bug in the example code: I created multiple buffers to load the incoming BLE bytes in. When one buffer got bytes, the main loop would send it out right away using ble_nus_chars_received_uart_print(). I would let the interrupt know (just a global boolean) that it should use the other buffer for new reception. I was still seeing dropped or unexpected characters.

After digging I found that app_uart_put() called in ble_nus_chars_received_uart_print() cannot return NRF_ERROR_BUSY as the loop implies. It will either return NRF_SUCCESS or NRF_ERROR_NO_MEM. I changed the app_uart_put() function to return busy if NO_MEM came up. I suppose I could have just changed the BUSY check in ble_nus_chars_received_uart_print() to NO_MEM and fixed it the same way.

I think the overall solution would be to double buffer and to fix the return value to appropriately wait for the app_uart FIFO to be ready and that should do the trick.

Alex

[Karl Ylvisaker]

Hello Alex,

Thank you for detailing how you were able to resolve your issue!

However, your comment about the app_uart_put not being able to return NRF_ERROR_BUSY has me wondering, are you not using the fifo uart library (app_uart_fifo) like in the unmodified example? You are correct that the regular app_uart library's app_uart_put does not return NRF_ERROR_BUSY, but this is not the one that is used in the example.
Could you confirm whether or not this is the case?
If you have changed to using the non-fifo app_uart then I concur that this very likely is how and why characters might have been dropped.

Thank you for getting back to me with an update on this! :)

Best regards,
Karl

[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