This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

connectivity_bridge malfunctions when BLE client disconnects and reconnects

I noticed that when a BLE client disconnects and then reconnects to the, instead of receiving all data arriving over the UART from nRF9160 to nRF52840, there is a delay of several seconds after which a huge block of 2048 bytes is sent over to the BLE client. This size matches the BRIDGE_BUF_SIZE configuration. The issue is observed on both Thingy:91 using the sample provided as part of the precompiled firmware, and also on nRF9160 DK - I ported the sample to work on it, so I observe the same behaviour on both boards. I tried changing BRIDGE_BUF_SIZE, and since I observed that internally 182 bytes are used for BLE transmission, I used that value. Now parts of the NMEA data sent from the GPS sample is randomly scrambled, resulting in 40% or NMEA packets that fail basic validation and CRC.

This attached log has been recorded from nRF9160dk, using the modified connectivity_bridge, which I adapted to run on the DK.
The GPS sample has also been modified, so send a copy of the NMEA strings to its second UART, which on the modified board links to the nRF52840 chip and is forwarded to BLE (application) and USB (this log file).

The following changes have been made:
nrf/samples/nrf9160/gps/src/main.c
static void print_nmea_data(void)
{
for (int i = 0; i < nmea_string_cnt; ++i) {
printk("%s", nmea_strings[i]);
+
+ #if CONFIG_TRACING_TEST
+ TRACING_STRING("%s", nmea_strings[i]);
+ #endif
+
+ #if CONFIG_UART_BLE
+ int uart_ble_send(char * msg, uint16_t length);
+ uart_ble_send(nmea_strings[i], strlen(nmea_strings[i]));
+ #endif
}
}

nrf/applications/connectivity_bridge.nrf9160dk/src/modules/Kconfig
BRIDGE_BUF_SIZE=182

nrf/applications/connectivity_bridge.nrf9160dk/prj.conf
CONFIG_USB_DEVICE_PRODUCT="nrf9160dk UART"

Send a copy of the data being sent to BLE over the debug UART of nRF52840. The USB on nRF9160dk connects to an OpenWRT router which acts as a mobile UART to TCP bridge and is then recorded on a computer using netcat.

nrf/applications/connectivity_bridge_g/src/modules/ble_handler.c
static void bt_send_work_handler(struct k_work *work)
{
uint16_t len;
uint8_t *buf;
int err;
bool notif_disabled = false;

do {
len = ring_buf_get_claim(&ble_tx_ring_buf, &buf, nus_max_send_len);

err = bt_gatt_nus_send(current_conn, buf, len);
if (err == -EINVAL) {
notif_disabled = true;
len = 0;
} else if (err) {
len = 0;
}

+ if (len)
+ {
+ char msg[BLE_TX_BUF_SIZE];
+ memcpy(msg, buf, len);
+ msg[len] = '\0';
+ printk("%s", msg);
+ }


err = ring_buf_get_finish(&ble_tx_ring_buf, len);
if (err) {
LOG_ERR("ring_buf_get_finish: %d", err);
break;
}
} while (len != 0 && !ring_buf_is_empty(&ble_tx_ring_buf));

if (notif_disabled) {
/* Peer has not enabled notifications: don't accumulate data */
ring_buf_reset(&ble_tx_ring_buf);
}
}

The following line is not valid:
$GPGLL,4.31375,N,02445.01620,E,1,04,100.00,312.72,M,0,,*26

Both of the following lines have a valid checksum:
* the first line contains invalid data
* the second line is valid
$GPGGA,085500.23,4208.30949,N,02444.97N,02444.9766.16,217.38,M,0,,*23
$GPGGA,085500.23,4208.30949,N,02444.97660,E,1,10,1.16,217.38,M,0,,*23

Notice how a part of the packet is missing or replaced with data, from
another packet. 40% of the packets are discarded, because they:
* do not begin with $
* do not have * in position line_length - 3
* do not have a valid checksum

From the the remaining 60% of the packets which pass the above validation,
a few are discarded because they:
* have values out of range
* have missing or more than one . character in a float value
* have less or more characters per line of value than expected

In rare events, there are still packets that pass all validation, but
contain slightly invalid data, e.g. there could be a long spike on the map
when our application is drawing the path.

If BRIDGE_BUF_SIZE is reverted to its default value of 2048,
Once the BLE client disconnects and then reconnects, the connectivity bridge
starts working incorrectly and will send large blocks of 2048 bytes containg
multiple NMEA packets.

ble_handler.test.c is my attempt to add tracing code and investigate what
is wrong with the connectivity_bridge. It seems that the ble_handler is holding
all buffers, so the uart_handler has no space to store arriving data.
At some point the buffers are freed by BLE, but then UART sends another 2048 bytes
of data, which arrave at bt_send_work_handler(). It starts sending blocks of
nus_max_send_len=182 until the BLE driver chokes. At this point BLE transmission
stalls for a few seconds, and UART RX will drop some data. Next the process repeats.
I am sorry for not being able to provid more details, and this parragraph may not be
fully accurate, because the code is extremely hard to follow.

I need to make one very important note towards the Nordic SDK developers:
Please make things simple and reliable!
I cannot say if the above issue is due to the existing design patterns in Zephyr OS,
but I see that all design patters are extremely complex and hard to follow, even
for taks that are very simple to implement, such as read/write from UART or BLE,
I see that you write 400 lines of code for each!
Hence it comes to no surprise that such a complex code has bugs which are hard to
diagnose or resolve. For example, as part of my testing I needed to change the
gps sample for nRF9160dk, so that in addition to its normal output, it sends a copy
with only the NMEA strings to its second UART, which I routed to the nRF52840 chip to
forward over BLE. My expectation was that I can simply write the data to UART.
But instead of a one line solution, I was forced to dedicate 330 lines of code:
zephyr/boards/arm/nrf9160dk_nrf9160_g/uart_ble.c
with a lot of handling routines and thigs that should normally be handled by
the driver, and any decent operating system provides a simple to use interface.

Using Nordic SDK master

nrf
commit ecf5d334f1577cc7fca11ae7b5a7fb86f0ea757a

zephyr
commit 7d20f2ebf25991b2897b91275939f8d16d38513a

 4572.projects.7z

  • I'm sorry for the delay on this. I've had quite much to do lately, but I'm starting to catch up now. I programmed the nrf52840 with the connectivity_bridge.g.thingy91.2021-04-08.hex and the nrf9160 with the gps_thingy_2021-04-08.hex and have started the python script that monitors the USB activity (conn_bridge_readotron.py). I'll let it run for a long time and report back to you if I see any large bulks.

  • Thanks Simon!

    No problem, I can relate to that, because I often have too many tasks myself. Please leave it running for 3-4 days and let me know if it is reliable!

  • I let it run for 4-5 hours on Friday and did not see any bulks (laggy behaviour).

    The current script only show the last 40 minutes, but I will update it such that it can run and store the results for a longer time.

  • The script I got from the developer would create a .png screenshot of the graph if the length of the output data exceeded 1024 bytes, and when I ran it through the last night many screenshots was created.  However, when the laggy behaviour happened earlier, the data came out as 2048 bytes bulks (size of UART buffer). I looked through the screenshots, and it never exceeded ~1200, so I'll try to change the script such that 2040 is used as the threshold, then let it run for some time. 

  • You might want to have the code creating screenshots on a separate thread from the thread reading from the USB-UART, to avoid delays from processing.

    What about the delay between packets? I think there should be regular bursts every half a second, depending on how often the GPS sample is sending data. You might collect statistics about that too and look for anomalies. Another important factor is the timeout after which you consider there is a pause in the communication. If you make it too large, you might join multiple transmission blocks and consider them a large block of 1200 bytes, which is incorrect.

    You might also implement a simple checksum validation for the NMEA data. Optimally all lines should pass validation.

Related