BLE Throughput and Timing Issues

[blue_dew]

Hello, 

I am trying to create an application on the nRF5340 which samples data at 16kHz and packages + sends it over BLE. This requires a BLE throughput ~1Mbps, which I can get very easily when trying to throughput example application, but I can not achieve when communicating with my desktop application and a single nRF5340dk. My nRF53 chip is acting as the peripheral and sends  a notification using bt_gatt_notify() after a "sample_buf" is filled and packaged. I have ensured that my peripheral negotiates a connection interval of 7.5ms, the MTU size is increased, and I have increased the number of L2CAP buffers by settings the following configs:

# bluetooth 
CONFIG_BT_GATT_CLIENT=y
CONFIG_BT_PHY_UPDATE=y
CONFIG_BT=y
CONFIG_BT_RPMSG=y
CONFIG_BT_PERIPHERAL=y
CONFIG_BT_DEVICE_NAME="LiteBEST" 
CONFIG_BT_P1_SECURITY_ENABLED=y
CONFIG_BT_USER_PHY_UPDATE=y
CONFIG_BT_BUF_ACL_RX_SIZE=502
CONFIG_BT_L2CAP_TX_BUF_COUNT=20
CONFIG_BT_L2CAP_TX_MTU=498
CONFIG_BT_L2CAP_DYNAMIC_CHANNEL=y
CONFIG_BT_CONN_TX_MAX=20
CONFIG_BT_BUF_ACL_TX_COUNT=20
CONFIG_BT_BUF_ACL_TX_SIZE=502
CONFIG_BT_PERIPHERAL_PREF_MIN_INT=6
CONFIG_BT_PERIPHERAL_PREF_MAX_INT=6
#CONFIG_BT_PERIPHERAL_PREF_LATENCY=0
#CONFIG_BT_ATT_PREPARE_COUNT=4
#CONFIG_BT_PERIPHERAL_PREF_TIMEOUT=400
CONFIG_BT_GAP_AUTO_UPDATE_CONN_PARAMS=y
CONFIG_BT_CTLR_PHY_2M=y
CONFIG_BT_AUTO_PHY_UPDATE=n

# adding addtional BLE things from random nordic dev form posts
CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_SMP=y
CONFIG_BT_ATT_PREPARE_COUNT=5
CONFIG_BT_CTLR_RX_BUFFERS=18
CONFIG_BT_CTLR_DATA_LENGTH_MAX=251
CONFIG_HEAP_MEM_POOL_SIZE=2048
#CONFIG_BT_CONN_TX_MAX=20
#CONFIG_BT_L2CAP_TX_BUF_COUNT=20
#CONFIG_BT_L2CAP_DYNAMIC_CHANNEL=y

# ads131m04
CONFIG_SPI=y
CONFIG_ABC=y
CONFIG_ABC_TRIGGER=y
CONFIG_ABC_TRIGGER_THREAD_PRIO=0
CONFIG_NRFX_SPIM4=y
CONFIG_ABC_SENSOR_LOG_LEVEL=0
CONFIG_ABC_SAMPLE_COUNT=20
CONFIG_ABC_FRAME_SIZE_BYTES=3

# LED stuff
CONFIG_LED_STRIP=y
CONFIG_LED_STRIP_LOG_LEVEL_DBG=y
CONFIG_WS2812_STRIP=y

# fuel gauge stuff
CONFIG_FUEL_GAUGE=y

# remove SWO from J-TAG
CONFIG_NRF_TRACE_PORT=n

# log stuff
CONFIG_LOG=y
CONFIG_SENSOR=y

# over clocking stuff
CONFIG_NRFX_CLOCK=y

# optimization stuff
CONFIG_SPEED_OPTIMIZATIONS=y
CONFIG_SIZE_OPTIMIZATIONS=y
#CONFIG_NO_OPTIMIZATIONS=y
CONFIG_MAIN_STACK_SIZE=4096

# gpio stuff
CONFIG_GPIO_NRFX=y
CONFIG_NRFX_TIMER0=y
CONFIG_NRFX_GPIOTE=y

# prototype stuff
CONFIG_RTT_CONSOLE=y
CONFIG_PRINTK=y
CONFIG_USE_SEGGER_RTT=y
CONFIG_LOG_BACKEND_RTT=y 
CONFIG_STDOUT_CONSOLE=y
CONFIG_CLOCK_CONTROL=y
CONFIG_SOC_HFXO_CAP_INTERNAL=y
CONFIG_SOC_HFXO_CAP_INT_VALUE_X2=27
CONFIG_LOG_MODE_MINIMAL=n
CONFIG_LOG_MODE_DEFERRED=y

The child image config is attached below:

#CONFIG_BT_LL_SOFTDEVICE=y
CONFIG_BT=y
CONFIG_BT_HCI_RAW=y
CONFIG_BT_HCI_RAW_RESERVE=1
CONFIG_BT_MAX_CONN=16
#CONFIG_BT_HCI=y
#CONFIG_BT_CTLR_ADVANCED_FEATURES=y

CONFIG_BT_CTLR_SDC_MAX_CONN_EVENT_LEN_DEFAULT=4000000
#CONFIG_BT_CTLR_DATA_LENGTH_MAX=251
#CONFIG_BT_CTLR_TX_BUFFER_SIZE=251
CONFIG_BT_BUF_ACL_RX_SIZE=502
CONFIG_BT_BUF_ACL_TX_SIZE=502
#CONFIG_BT_CTLR_RX_BUFFERS=10
#CONFIG_BT_CTLR_TX_BUFFERS=10

CONFIG_IPC_SERVICE=y
CONFIG_MBOX=y
CONFIG_HEAP_MEM_POOL_SIZE=4096
CONFIG_MAIN_STACK_SIZE=1024
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=1024


CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_SMP=y
CONFIG_BT_ATT_PREPARE_COUNT=5
CONFIG_BT_CTLR_RX_BUFFERS=18
#CONFIG_BT_CTLR_DATA_LENGTH_MAX=251
CONFIG_BT_CTLR_DATA_LENGTH_MAX=502
CONFIG_HEAP_MEM_POOL_SIZE=2048


# Workaround: Unable to allocate command buffer when using K_NO_WAIT since
# Host number of completed commands does not follow normal flow control.
CONFIG_BT_BUF_CMD_TX_COUNT=10

# Enable and adjust the below value as necessary
CONFIG_BT_BUF_EVT_RX_COUNT=16
CONFIG_BT_L2CAP_TX_BUF_COUNT=10
CONFIG_BT_L2CAP_TX_MTU=498

I know that some config changes need to be copied to the child but I'm not sure which ones exactly so I tried to copy most of them over. 

I begin the application by advertising on the 1M physical layer and then updating the connection parameters manually to 2M PHY after a connection is made. I know that this works because of the nRF BLE Sniffer logs (see below). 

The desktop application is receiving 2000 packets (each is 244 bytes) within 17 seconds (~200kbps) but it is expected to receive it under 4 seconds if we're actually able to get close to the expected throughput of ~1Mbps. 

litebest_blelog.pcapng

This is the BLE sniffer log I was able to collect which clearly shows the PHY layer getting updated but I am struggling to fully understand what I'm seeing. I know that the BLE link layer guarantees delivery and therefore the master must reply even though notify doesn't require a reply from the Host layer but I think there is a problem with the reply from Master (desktop app) as seen in the following snip of the above log:

Any help is greatly appreciated! 

[blue_dew]

Hey Susheel,

Thank you for the quick reply. I've learned a few new things by following the nordic dev academy lesson 3 exercise 2: 
https://academy.nordicsemi.com/courses/bluetooth-low-energy-fundamentals/lessons/lesson-3-bluetooth-le-connections/topic/blefund-lesson-3-exercise-2/

I linked my wireshark capture in the original post by using the nRF BLE sniffer I created from an nRF52840 dev kit. The capture starts with some malformed packets, but that is because I didn't have the sniffer close enough to both devices. If you scroll down, you can see the advertising restarts, and then a good connection is made. You can see in packet no. 845 that my PC (ble client, master) requests data length extension but the embedded system, nRF5340 w/ the above configs shown in the original post, replies in packet no. 856 with a max TX & RX octet of 27. 

By following the nordic dev academy lesson 3 exercise 2 I was able to initiate another data length extension request from the server side and the call to bt_conn_le_data_len_update() doesn't return an error but my own server doesn't honor its own request because when I debug and set a break point in  le_data_len_change() in the hci_core.c file the net_buf param doesn't contain the expected values for length and time which are set correctly in the bt_conn_le_data_len_update(). Its just reverting back to the default len and timing values of 27 bytes as seen in the attached wireshark capture. If you could help me understand this problem first I think I might be able to get more throughput regardless of the master repsonse times I first highlighted in the original post. 

Greatly apprciated,
Brady
---

Functions from the academy lesson 3 exercise 2 used to request and monitor data length extension requests/updates:

static void update_data_length(struct bt_conn *conn)
{
	int err;
	struct bt_conn_le_data_len_param data_len = {
		.tx_max_len = BT_GAP_DATA_LEN_MAX,
		.tx_max_time = BT_GAP_DATA_TIME_MAX,
	};
	err = bt_conn_le_data_len_update(conn, &data_len);
	if (err) {
		LOG_ERR("data_len_update failed (err %d)", err);
		return;
	}
	LOG_INF("Data length update successful");
}

void on_le_data_len_updated(struct bt_conn *conn, struct bt_conn_le_data_len_info *info)
{
    uint16_t tx_len     = info->tx_max_len;
    uint16_t tx_time    = info->tx_max_time;
    uint16_t rx_len     = info->rx_max_len;
    uint16_t rx_time    = info->rx_max_time;
    LOG_INF("Data length updated. Length %d/%d bytes, time %d/%d us", tx_len, rx_len, tx_time, rx_time);
}

BT_CONN_CB_DEFINE(conn_callbacks) = {
	.connected = connected,
	.disconnected = disconnected,
	.le_phy_updated = le_phy_updated,
	.le_param_updated = on_le_param_updated,
	.le_data_len_updated = on_le_data_len_updated,
};

---

Console output:

```
Connected
TX power level: 0
[00:00:21.158,142] <inf> app: PHY update successful
Connected as peripheral
Conn. interval is 6 units
[00:00:22.158,905] <inf> app: MTU exchange successful
[00:00:22.158,905] <inf> app: New MTU: 244 bytes
LE PHY updated: TX PHY LE 1M, RX PHY LE 1M
[00:00:22.158,996] <inf> app: Data length updated. Length 27/27 bytes, time 2120/2120 us
[00:00:22.376,495] <inf> app: Connection parameters updated: interval 15.00 ms, latency 0 intervals, timeout 9600 ms
[00:00:24.176,300] <inf> app: Connection parameters updated: interval 7.50 ms, latency 0 intervals, timeout 420 ms
```