write_cmd_tx_queue count wraps around when counting amount of queued writes and decreasing the count on tx complete event

[mk2]

Hi,

I´m using nrf52840 with softdevice S132 and set ble_gattc_conn_cfg_t::write_cmd_tx_queue_size to larger than 1. I´m count number of queued writes by increasing a counter each time I receive NRF_SUCCESS back from sd_ble_gattc_write and decerasing the counter on BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event with p_ble_evt->evt.gattc_evt.params.write_cmd_tx_complete.count.

But it happens sometimes that the counter wraps around on the negative side so that it becomes 255 or 254. How is this possible?

This must mean that BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event was fired before actually increasing the counter at some point.

The counter is not used any where else, and is set to 0 when connection is established.

I have measured that the amount of times I manage to queue write with NRF_SUCCESS is equal to number of BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE events.

[Einar Thorsrud]

Hi,

Which SDK and SoftDevice version are you using?

But it happens sometimes that the counter wraps around on the negative side so that it becomes 255 or 254. How is this possible?

This seems odd. Do you by any chance use multiple connections, and if so could it be that you count for BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE for another connection as well? (just a shot in the dark).

I have measured that the amount of times I manage to queue write with NRF_SUCCESS is equal to number of BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE events.

So this means that you get a BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE for every successful call to sd_ble_gattc_write(), so if p_ble_evt->evt.gattc_evt.params.write_cmd_tx_complete.count always was 1, this would be correct? But sometimes it is more than 1?

[mk2]

SDK version is 15.2 and softdevice is S132.

Einar Thorsrud said:

This seems odd. Do you by any chance use multiple connections, and if so could it be that you count for BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE for another connection as well? (just a shot in the dark).

I have only 1 connection.

Einar Thorsrud said:

So this means that you get a BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE for every successful call to sd_ble_gattc_write(), so if p_ble_evt->evt.gattc_evt.params.write_cmd_tx_complete.count always was 1, this would be correct? But sometimes it is more than 1?

The write_cmd_tx_complete.count is always 1. I was no precise in my description, I measured the counts of BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE by accumulating the counter with p_ble_evt->evt.gattc_evt.params.write_cmd_tx_complete.count. And the total amount of completed tx writes are exactly same as total amount of queued writes.

The only explanation I can come up with is that the BLE_GATTC_EVT_WRITE_CMD_TX_COMPLETE event was issued before incrementing counter after receiving NRF_SUCCESS at some point which is very weird.

[Einar Thorsrud]

Hi,

I suspect you are seeing a ghost, caused by a race condition in your application (just an assumption, since I don't know the details of your test). It could happen if, for instance, you do it like this:

Thread 1 does:

• sd_ble_gattc_write()
• print counter
• increment counter
• print counter
• ...

Thread 2 (event handler) has higher priority and decrements the counter. Then you could get an instance where it decrements the counter before the first print in thread 1.

[mk2]

Well Thread 1 acutally looks like:

* sd_ble_gattc_write()

* increment counter

* print counter

I did also suspect possibility of race condition, so I did try having a counter incrementing for each event handler call, and then decrementing the queue counter in main loop instead for each event handler count. In this way I would avoid the delayed increment due to race condition, but it didn`t help.

[Einar Thorsrud]

Strange... I discussed with the SoftDevice team and we do not see any other explanation than that there is some kind of race condition in the application, but I am not able to explain it after your latest change.