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!

[Karl Ylvisaker]

Hello,

The code is almost unchanged from the example source.

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

What changes have you made to the example? I have never heard of any behavior similar to what you describe in the unmodified example, so my initial instinct would be to take a closer look at these changes.

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?

The phrasing of this question leaves some ambiguity. If by chunk you mean packet, then it is not guaranteed for all transfers, because big transfers might be broken into fragments by the SoftDevice - and therefore technically sent as multiple packets.
However, the (link layer of the) receiving device will not pass anything to the application layer before all the fragments are received and put together, so the receiving device's application will still receive the entire payload in a single event.
Please do not hesitate to ask if any part of this is unclear, so I may elaborate.

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.

Yes, the event containing the data received over BLE is passed to the ble_nus_chars_received_uart_print function as a whole, you can see this for yourself in the BLE event handler function of the central. However, there is no guarantee that the processing of this received data will not be interrupted by the SoftDevice that must meet a connection critical deadline - but the processing will resume at the same place it left off once the CPU is released by the SoftDevice.

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.

The BLE event handler will not interrupt itself, so in the case that the BLE event handler is not yet done processing the previously received message (which would be something to look into in and of itself, if the handler needs more than 7.5 ms to process the received data) and the SoftDevice passes a new reception event to it, then this new event will not be processed until the previous one is done.

So, in essence, it is expected that the printing out of the BLE payload on the UART might be interrupted by the SoftDevice at any time, but it will not affect the performance and/or 'loose' received characters.

To begin with, I therefore suggest that we take a look at the modifications that you have made to the example - what are they?
Please use the "Insert->Code" option when sharing code here on DevZone.
If we do not immediately see something wrong with the code, we can proceed to look into the on-air traffic using the nRF Sniffer tool, to better understand what is happening.

Best regards,
Karl

[Alex_O]

Hi Karl, thanks for helping me with this!

The only thing I changed was to send a "READY" string  in the main loop via UART to the other processor when a peripheral has been completely discovered. I added a ready boolean and set it to true in the BLE_NUS_C_EVT_DISCOVERY_COMPLETE case of  ble_nus_c_evt_handler. That's it.

After that the peripheral device and the processor connected to the central via UART talk to each other with the central device as the pass through.

So it sounds like if I use ble_nus_data_send() on the peripheral, all the data passed to that function will be available in the NUS callback on the central. Is that right?

The peripheral is sending some fairly long strings in back to back calls of ble_nus_data_send(). It looks like the central takes it and goes through this for{dowhile()} loop that fills a FIFO and starts UART transmission. I'm worried that the loop is holding up reception of the next packet.

The effect seen is that a character may be missing or a repeated character is sent along with a missing character. Something like "12346789" (missing a 5) or "123466789"  (missing a 5 and repeated 6).

I am not certain what the maximum packet size if for BLE but if I send a 128 byte string, the UART takes around 11ms at 115200baud to send it out. Is that a problem for the central code? I can foresee a compounding issue if I send a few large packets out quickly.

I have used a sniffer tool and found that the data over BLE seems right. I used a logic analyzer for the UART and that is where the errors were found.

Alex

[Karl Ylvisaker]

Hello again Alex,

Alex_O said:

thanks for helping me with this!

No problem at all, I am happy to help!

Alex_O said:

The only thing I changed was to send a "READY" string  in the main loop via UART to the other processor when a peripheral has been completely discovered. I added a ready boolean and set it to true in the BLE_NUS_C_EVT_DISCOVERY_COMPLETE case of  ble_nus_c_evt_handler. That's it.

Aha, thanks for clarifying. 

Alex_O said:

So it sounds like if I use ble_nus_data_send() on the peripheral, all the data passed to that function will be available in the NUS callback on the central. Is that right?

Yes, but again this will depend on their size and how they are packaged. 

Alex_O said:

The peripheral is sending some fairly long strings in back to back calls of ble_nus_data_send(). It looks like the central takes it and goes through this for{dowhile()} loop that fills a FIFO and starts UART transmission. I'm worried that the loop is holding up reception of the next packet.

What do you mean when you say back-to-back?
The minimal possible connection interval is 7.5 ms, are you filling the entire interval with notifications?
What are your connection parameters, and what event length are you using?

The UART processing will never impede packet reception, since the SoftDevice uses the highest priority, and takes control of the CPU whenever it needs to. You do not need to worry that the SoftDevice is being restricted - it is rather the other way around, it is therefore important to take into consideration that your application may be interrupted at any time as long as the SoftDevice is enabled and in use.

Alex_O said:

The effect seen is that a character may be missing or a repeated character is sent along with a missing character. Something like "12346789" (missing a 5) or "123466789"  (missing a 5 and repeated 6).

Strange - I think we should then move on to the sniffer trace. Could you capture a sniffer trace of the on-air BLE communication between the devices when this happens? It would be very helpful, and would make things a lot more clear.
Please be advised that you need to have selected the advertising device in the device drop down menu in WireShark before the connection starts, in order to have the sniffer follow into the connection.

Alex_O said:

I am not certain what the maximum packet size if for BLE but if I send a 128 byte string, the UART takes around 11ms at 115200baud to send it out. Is that a problem for the central code? I can foresee a compounding issue if I send a few large packets out quickly.

Yes, this is also a thing we will see in the sniffer trace. If you should attempt to queue too much data for transfer from the peripheral side, the queueing function will return a non-NRF_SUCCESS error code on the peripheral side.
What is the throughput requirement of your application? If you tell me this, we can take a look and see if we may improve on your connection parameters.
For completeness; when you call the ble_nus_data_send function, that data is infact just queued for sending by the SoftDevice - it will have to wait until the next connection event before it is actually sent.

Alex_O said:

I have used a sniffer tool and found that the data over BLE seems right. I used a logic analyzer for the UART and that is where the errors were found.

That is great! I am glad to hear that you have taken a look with the sniffer already.
Could you share this sniffer and logical analyzer traces with me as well, so I may take a look?
You could do this by using the "Insert->file" option here on DevZone.

Best regards,
Karl

[Alex_O]

Hi Karl,

I will have a response soon but I have some deliverables to meet and need to get something working and out. I did find a temporary? solution that I will describe soon.

Alex

[Karl Ylvisaker]

No problem at all Alex, we will continue whenever you have the time.  I am glad to hear that you were able to find a temporary solution.
I look forward to discussing it, so we may see if it is a viable long term fix as well!

Best regards,
Karl

[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