Delay between characteristics changing and connected device getting notification of that change

[DiBosco]

Hi folks,

I have a system basically working with the following setup:

#define MIN_CONN_INTERVAL               MSEC_TO_UNITS(7.5, UNIT_1_25_MS)      
#define MAX_CONN_INTERVAL               MSEC_TO_UNITS(7.5, UNIT_1_25_MS)       
#define SLAVE_LATENCY                   0      

I have a custom service with four characteristics that allow data to get from Nordic to PC (running Linux, not Windows or OSX) with handshaking in the following way:

PC Puts data in char1

Nordic gets new data and then:

Nordic writes value to char2 which tells the PC the Nordic has got the data and has enough space in its buffer for the PC to send more data. PC then pus updated version in char1 and so on...

The other two characteristics work for data being sent the other way.

Now, this works fine apart from the fact that there's a big old delay between data being put in a characteristic and the other end getting notification of that change. One problem is I don't know whether this is a delay between the Nordic picking up what the PC has changed or the PC picking up what the Nordic has changed.

I have put measurements at the PC end so I can tell that from a characteristic changed by the Nordic to tell the PC it is ready for more data it takes 140ms between updates. ie it is a round trip of 140ms, which is far too long!

Nordic writes to char2, PC updates char 1. Between the PC picking up that change in char2 and updating char1 there is less than a millisecond.

From the Nordic picking up the change in  char1 and putting a new value in char2 to twell the PC it can update char1 there is less than a millisecond.

So, there is either:

A delay in the soft device updating the characteristic after its API is called or:

A delay in the PC picking up the change in the characteristic or:

A delay in the PC from the application writing to the characteristic and it appearing "on air" or:

A delay in the soft device from picking up the change in char1 to sending it to my software running on the Nordic.

Or some combination of these. 

Are there any settings I have not tweaked that might be causing this? If so, what migt they be?

Can anyone think of anything I can do to track down exactly where the problem might be please? If I could toggle a pin on the PC when it picks up a change in char2 that might help I guess, but the days of parallel ports are long gone! ;)

Many thanks.

[tesc]

Hi,

A sniffer trace should reveal quite clearly what is going on over-the-air, and by that reveal where you get the delays. That should narrow it down enough that you can investigate the device and piece of code responsible for the delay.

Regards,
Terje

[DiBosco]

Hi,

Many thanks for the reply. How does this know, though, when a characterstic change reaches various stages

So: PC changes charactersitc. Goes out on to the air. How can this know the delay between Qt program on computer writing to the chatacteristic and that change appearing on the air?

Then how does it know how long it has taken the on air change to hit my custom hardware with the nRF on it? In terms of the hardware detecting the change, the soft machine detecting the change and it finally bubbling through to my custom app on the nRF?

Similarly going the other way, my app writes to the soft device; how on earth does the sniffer know when this has happened and what the delay is between that charcractersitc having been changed and it appearing on air, let alone how we time between writing to the soft device API and the change being detected on the PC?

I must be missing something fundamental here! Thanks. :)

[DiBosco]

Hi again,

It's taken a fair bit of time this morning to get this going. The sniffer and/or Wireshark is very flaky. I have to log out and back in again if I want to start a new sniff and the nrf dev board needs to be powered off and on.

Anyway, here is a full log, but it's even weirder than before. The first transfer starts at packet 10, this is 27 bytes long. We then get a reply from the nrf which is bizarre. Wireshark thinks it's empty, but it's not, it has two bytes in its payload which is correct.

We then get a whole massive series of 27 byte transfers. The file being transferred starts on packet 12 with FC 9F and ends with rhe 1E 01. The next bytes in the file being sent are 08 1A D5 etc exactly as is found in packet 14.

The last part of the file is in packet 26592 ending in 10 C6 BA.

Everything is clearly getting sent correctly as the new file is accepted, reprogrammed in the target and rebooted.

I'm going to put the debugger on the nrf and double check what size packets it is reading. It certainly *used* to be 240 bytes, so I con't see why it should have changed.

As far as I underatand, the master (Qt program) listens to the slave (nrf) and decides size of transfer on the size of the characteristic, so the Qt program shouldn't, AFAIK, decide to on;y sent 27 byte chunks.

Will be back with a little more info on what the nrf receives shortly!

small packet sizes.pcapng

[DiBosco]

I can confirm that when I get a read of the 240 byte characteristic, my printf in SES tells me that I receive 240 characters each and every time.

[DiBosco]

One further thing to report. If I use a different laptop which has a BT4.2 module it works really well, really fast data transfer as I'd expect. Do you know of any reason why there should be an issue with 4.2 and not 5.0?

[DiBosco]

And one final thing, FWIW. This is the pcap for the fast transfer.

fast transfer.pcapng

[tesc]

Hi,

I am really sorry for not having gotten any further with this issue for so long.

Do you see this throughput issue only from the computer that also had (potentially still has) the issues described in the thread with subject nrf52832 talks to a laptop running v4.2 BT, but not v5?

It looks like you never found the reason for that issue (other than it seemed to be with Qt), but to me it looks like a caching issue. E.g. you have previously connected to a device that had the same BLE address (most likely the same device with different firmware) and the GATT table has been cached on the pc side.

It may of course  be something else that is wrong, which also leads to slow throughput.

Note that we have to look at different levels of the BLE stack here. Characteristic size, ATT MTU size, and the Link Layer data PDU. When a characteristic is larger than the MTU size, reads and writes are segmented when reading and writing. If a packet of maximum MTU size is too big to fit in a LL data PDU, the packet is automatically segmented and sent using multiple LL packets. From the sniffer traces I see that (both for "fast transfer" and "small packet sizes") packets are fragmented in LL (e.g. PDU is small and MTU is large).

Based on the sniffer traces, it looks to me the difference may be the event length. Every connection event, packets goes back and forth between central and peripheral. Each device can stop the connection event by not transferring any more packets. This happens either when receiving an empty PDU and there is no more data to send (which means both devices have nothing to send, so no reason to continue the connection event), OR when the device decides to stop the connection events e.g. based on a locally decided timeout. From what I can tell, the last thing is what happens, i.e. on the PC side, the maximum number of packets to send each connection event is low, which means more connection events are needed to transfer the data.

Fixing the issue may involve either increasing number of packets per connection event (on the pc side), or if both sides allow longer LL data PDUs, perform a data length update.

Regards,
Terje