Missing BLE_GATTS_EVT_HVN_TX_COMPLETE events

[Mark Dale]

Our BLE peripheral uses a custom GATT service similar to the NUS (Nordic UART service) used in the SDK example app_ble_uart. The peripheral receives data on the UART peripheral (not UARTE) from an external device at 115200 baud with full hardware handshaking.

Our PDU data length is configured as 251 and our MTU size as 247.
The peripheral repeatedly calls sd_ble_gatts_hvx with a 244 byte ATT data packet but we only receive 4 BLE_GATTS_EVT_HVN_TX_COMPLETE events.

You can see on the oscilloscope screenshot below that we have called sd_ble_gatts_hvx 11 times (SD_SEND) but have only received TX_COMPLETE 4 times. We keep track of the number of notifications available to us so we no longer try to send after calling sd_ble_gatts_hvx 7 times since the last TX_COMPLETE event.

We are outputting any errors returned by the sd_ble_gatts_hvx call using a spare GPIO line (SD_SEND_ERR) and you can see that there are none.

We have tried keeping the PDU data length configured as 251 and our MTU size as 247, but calling sd_ble_gatts_hvx with 200 byte data payload instead and this has resolved the issue.

So the main question is why do we stop receiving the BLE_GATTS_EVT_HVN_TX_COMPLETE event when we use the maximum payload size?

More detailed setup information:

BLE peripheral = nrf52 dev kit (PCA10040).
BLE central = custom hardware using nrf52832.

We are using the S132 SoftDevice v 7.0.1.
We are not using the nRF SDK driver or HAL layers – we’re interfacing with the peripherals directly, but the chip header files we’re using are taken from SDK version 15.2.

BLE connection parameters:

Connection interval 7.5ms
Event length 7.5ms
Slave latency 0.
Connection supervisory timeout 1s.
Extended event length enabled.

MTU size 247
PDU data length 251
BLE notifications queue size (hvn_tx_queue_size) 7

Happy to provide more information if needed.

[Einar Thorsrud]

Hi,

There is not a one-to-one mapping between the number of Tx packets and the number of BLE_GATTS_EVT_HVN_TX_COMPLETE. This is because the event comes with a count field, which can be more than 1. I suspect that is the case here.

[Mark Dale]

Hi Einar, thanks for your response. 

We take the count into account when tracking the number of available buffers.

Here is our event handler:

__STATIC_INLINE void fnOnNotificationComplete(const uint16_t conn_handle, ble_evt_t const * p_ble_evt)
{
    ble_gatts_evt_hvn_tx_complete_t const * p_evt_complete = &p_ble_evt->evt.gatts_evt.params.hvn_tx_complete;
    guNotifyBuffersAvailable += p_evt_complete->count; // increase available buffers for notifications by the number of completed
}

And we then decrement guNotifyBuffersAvailable each time we call 'sd_ble_gatts_hvx'.

[Mark Dale]

Yes, of course. Not all of the data is received by the peer, in fact the most that I've seen it receive is 212 bytes. I have some screenshots of what's going on over the air (taken using Wireshark and the nRF sniffer) that I can send you. 
I'll also send you the code snippets you've requested. It will take me some some time to collate the information but I should get back to you later today.

[Mark Dale]

Hi again, sorry for the delay. I decided to recapture the data. On this occasion the peer received 212 bytes.

Below are the OTA packets for the lower transmission size (200 bytes). As you can see, the normal ATT packet length is 207, but sometimes the packet is split into multiple transmissions by the SoftDevice within the connection interval:

Here is the Wireshark capture for the higher transmission size (244 bytes):

Over the air it looks like there are far more transmissions than the 11 SD_SEND calls seen on the scope. It looks like the link layer sequence number is wrong?

Code snippets below:

Toggling SD_SEND:

The pin goes high for each byte sent and the SoftDevice call is within fnBleStack_SendNotification(). 
The pin is toggled irrespective of the value of err_code, which is why we scope that too.

   uint32_t i;
   for (i = 0; i < length; i++)
   {
       fnClock_Delay_us(1);
       fnGPIO_SetPin(ISP_GPIO_17);
       fnClock_Delay_us(1);
       fnGPIO_ClearPin(ISP_GPIO_17);
   }
   
   uint16_t actual = length;
   uint32_t err_code = fnBleStack_SendNotification(gstInHandles.value_handle, p_data, &actual);
   
   

Toggling SD_TX_CPLT:

__STATIC_INLINE void fnOnNotificationComplete(const uint16_t conn_handle, ble_evt_t const * p_ble_evt)
{
   ble_gatts_evt_hvn_tx_complete_t const * p_evt_complete = &p_ble_evt->evt.gatts_evt.params.hvn_tx_complete;
   
   fnGPIO_SetPin(ISP_GPIO_19);
   fnClock_Delay_us(1);
   fnGPIO_ClearPin(ISP_GPIO_19);

   guNotifyBuffersAvailable += p_evt_complete->count; // increase available buffers for notifications by the number of completed
}

Toggling SD_SEND_ERR:

I won't paste all the code for this... but effectively it's just a huge switch statement comparing the value of err_code to all the possible return codes as described by the documentation.
For each error code we toggle the pin a different number of times... e.g

   switch (err_code)
   {
   case NRF_SUCCESS:
       break;
   case BLE_ERROR_INVALID_CONN_HANDLE:
   {
       for (i = 0; i < 1; i++)
       {
           fnClock_Delay_us(1);
           fnGPIO_SetPin(ISP_GPIO_12);
           fnClock_Delay_us(1);
           fnGPIO_ClearPin(ISP_GPIO_12);
       }
   } ...

SD_SEND:

uint32_t fnBleStack_SendNotification(const uint16_t value_handle, const uint8_t * const p_data, uint16_t * p_length)
{
   if (!fnBleStack_IsConnected())
      return BLE_ERROR_INVALID_CONN_HANDLE;
      
   ble_gatts_hvx_params_t const hvx_param =
   {
      .type = BLE_GATT_HVX_NOTIFICATION,
      .handle = value_handle,
      .p_data = p_data,
      .p_len = p_length,
   };
   
   return sd_ble_gatts_hvx(ghConnection, &hvx_param);
}

[Einar Thorsrud]

Hi Mark,

It is difficult to get an overview from the screenshot of the sniffer trace. Can you upload the complete trace file?

Regarding checking the return value from sd_ble_gatts_hvx() (your fnBleStack_SendNotification()), you only show a bit of the switch-case so I don't know what happens in many cases. Do you toggle the GPIO for all error codes other than NRF_SUCCESS? Including having a default in case you missed some? I would like to ensure that there are no errors that are missed here.

[Mark Dale]

The cases covered are:

NRF_SUCCESS: (just break if we get this)
BLE_ERROR_INVALID_CONN_HANDLE:
NRF_ERROR_INVALID_STATE:
NRF_ERROR_INVALID_ADDR:
NRF_ERROR_INVALID_PARAM:
BLE_ERROR_INVALID_ATTR_HANDLE:
BLE_ERROR_GATTS_INVALID_ATTR_TYPE:
NRF_ERROR_NOT_FOUND:
NRF_ERROR_FORBIDDEN:
NRF_ERROR_DATA_SIZE:
NRF_ERROR_BUSY:
BLE_ERROR_GATTS_SYS_ATTR_MISSING:
NRF_ERROR_RESOURCES:
NRF_ERROR_TIMEOUT:

... but you're right, I've missed out the default case so I'll re-run that test in a minute and get back to you.

I've attached the Wireshark trace file for you:

/cfs-file/__key/communityserver-discussions-components-files/4/RetranmissionIssues.pcapng

[Mark Dale]

Hi Einar, I have now re-run the test with the default case and was able to re-produce the same result.
Please see below:

Associated Wireshark capture:

/cfs-file/__key/communityserver-discussions-components-files/4/RetranmissionIssues2.pcapng

[Einar Thorsrud]

Hi Mark,

I am not able to explain this. Before looking at your sniffer trace I wanted to suggest that perhaps you have an issue with interrupt priorities or similar in your application (waiting for events in a higher priority than the event, so that it is never serviced).

But looking at the sniffer trace it looks at bit odd. From #14379 and for the rest of the trace (41 seconds) there is an endless stream of retransmissions. Which is odd in itself, but even more so since it continues for this long (the GATT timeout is 30 seconds). What is the BLE master you are communicating with?

Einar

[Mark Dale]

Hi Einar,

That's a good point with respect to the GATT timeout.
Thanks for looking into this further for us.

I've attached our BLE master project for reference:
/cfs-file/__key/communityserver-discussions-components-files/4/6864.central.zip

Mark

[Einar Thorsrud]

Hi  Mark,

To be honest it is the same all over the trace. Looking at the sniffer trace there is a lot of retransmissions. So much that I don't know if the trace makes sense. Have you had your HW properly tuned? Can you test with DK's on both sides so that we know you are using proper HW?

It may be that you don't get BLE_GATTS_EVT_HVN_TX_COMPLETE events because you don't get data through. And you don't get errors from your call to sd_ble_gatts_hvx() because you stop calling git when the buffer is full (since packets are not successfully sent, even though you do get some data through).

As mentioned it would be good to test this on knowing good HW. And if that doe snot help, then It would be interesting to see all of your code.

Einar

[Mark Dale]

Hi Einar,

We are using the nRF52832 chip inside the ISP1507 SoC, so we have no radio or low-level hardware design of our own.

The central device consists of a ISP1507 connected to an FT2330XS-R USB UART bridge, with a local 3V3 PSU. There is no other circuitry.

Is this the hardware configuration you'd expect?

Is there anything in the code that looks particularly suspicious to you?

If we're not getting data through over the radio after the GATT timeout / supervisory timeout then why would the BLE link not drop (we are handling BLE_GAP_EVT_DISCONNECTED)?

Mark

[Einar Thorsrud]

Hi Mark,

Mark Dale said:

We are using the nRF52832 chip inside the ISP1507 SoC, so we have no radio or low-level hardware design of our own.

The central device consists of a ISP1507 connected to an FT2330XS-R USB UART bridge, with a local 3V3 PSU. There is no other circuitry.

I see. There should not be any problems using the ISP1507.

Mark Dale said:

Is there anything in the code that looks particularly suspicious to you?

I am having problems understanding what could be the problem here.  Would it be possible to share your complete project, so that I can get a better overview? Also, is it possible to modify it to run on the DK, so that I can test on my side (using two DK's, one for central and one for peripheral)?

Mark Dale said:

If we're not getting data through over the radio after the GATT timeout / supervisory timeout then why would the BLE link not drop (we are handling BLE_GAP_EVT_DISCONNECTED)?

You are right, you will get a disconnect if no packets make it through for the duration of the supervision timeout. And if there is only a problem on the GATT layer, you will get a timeout there as well.

Einar