ATT delay on BLE notification

I'm using an nRF52840 as BLE peripheral with a custom service similar to NUS to send large data. The data is send in 4k chunks via BLE notifications to an Android phone. With some phones this works pretty good, but with others I can see a weird delay at the ATT level that I can't explain. Every fourth or fifth ATT packet is delayed by about 30 ms.

The used phones are very similar (Samsung Galaxy A5 and S7 from 2016/2017; Android 8; same software and OS versions) and the nRF52840 uses nRF Connect 2.3.0 (also tested with 2.4.0 and 2.6.1). I can also replicate the same behaviour with the nRF Connect App on the Android devices. The connection details are the same in every case (MTU 23 bytes, no encryption, interval 37.5 ms, latency 0, timeout 4 s). I can't increase the MTU via DLE because of legacy devices.

The problem can be reproduced with a simple BLE service with one notify characteristic. Calling "bt_gatt_notify_cb()" 40 times, each time with 20 bytes of data sends the data correctly, but every fourth or fifth ATT packet is delayed by about 30 ms.

Is this problem known? Is there anything in general that can lead to this behaviour? Could this be a difference on the phone side? Is there a way to fix this or at least detect this on either side?

The problem can be seen in the following log. The calls to gatt_notify go through without a problem, but the actual sending, marked with att_sent, is delayed every couple of packets. E.g jumps from 01:21.569 to 01:21.604 (35 ms delay). The same timing can be seen in HCI logs on the Android side, as well as in the log of the nRF Connect App.

Note: it's not a problem, that it takes some time between calling gatt_notify and sending the ATT packet, but that there is a delay between ATT packets, although all gatt_notify calls are finished already.
[00:01:21.532,562] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.532,562] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.532,592] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.532,836] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.532,867] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.532,867] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.532,989] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,020] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,050] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,142] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,172] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,203] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,325] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,325] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,355] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,477] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,508] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,508] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,630] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,660] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,660] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,782] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,813] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,813] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.533,935] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.533,966] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.533,996] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.534,088] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.534,118] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.534,149] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.534,240] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.534,271] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.534,301] <dbg> bt_att: chan_send: code 0x1b
[00:01:21.534,423] <dbg> bt_gatt: gatt_notify: conn 0x20005068 handle 0x001f
[00:01:21.534,423] <dbg> bt_att: bt_att_chan_send: chan 0x200198a8 flags 4 code 0x1b
[00:01:21.534,454] <dbg> bt_att: chan_send: code 0x1b
...
[00:01:21.567,962] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.567,993] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.567,993] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.568,603] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.568,603] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.568,634] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.569,335] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.569,366] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.569,427] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.569,946] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.569,946] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.569,976] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.604,705] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.604,705] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.604,736] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.605,346] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.605,346] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.605,377] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.606,048] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.606,109] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.606,170] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.606,689] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.606,719] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.606,750] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.607,421] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.607,421] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.607,452] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.642,211] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.642,242] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.642,242] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.642,883] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.642,883] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.642,913] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.643,554] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.643,585] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.643,585] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.644,195] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.644,226] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.644,226] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.644,958] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.644,958] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.645,019] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
[00:01:21.679,718] <dbg> bt_att: att_sent: conn 0x20005068 chan 0x200198ac
[00:01:21.679,718] <dbg> bt_att: bt_att_sent: chan 0x200198a8
[00:01:21.679,748] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x200198a8 CID 0x0004
  • Just after posting, I think I found a possible explanation. This might just be the limit of number of packets per connection interval. It's just that one phone allows at least 50 or so packets per interval, while the "problem" phone only allows four or five. After these packets are sent, a pause is inserted until the next interval starts (about 30 ms at 37.5 ms connection interval).

    That would mean, that my only possible option would be to lower the connection interval. Or are there any options on Android side to increase the number of packets or at least detect how many packets are allowed?
  • Hi

    every fourth or fifth ATT packet is delayed by about 30 ms.

    Does this only happen on these select two phone models or do you see it on other devices as well. This sounds very much like a problem with the Android stack on the device you're using and there are a lot of BLE related issues especially in older Android devices. I can't say I have seen this issue specifically before. I would assume this is only an issue on older low-end Android devices.

    For reference I think your explanation makes sense, but I'm not aware of a way to increase the number of packets an Android device can receive per conn. interval. I would guess it's set in the stack and not configurable though.

    Best regards,

    Simon

  • Thanks for the response. This happens on multiple Android devices, at least one of which was high end at the time, and with multiple Android versions (8 and 10). Other devices from the same manufacturer and similar release date do not have these problems.

    I did some more testing and I'm now pretty sure that my explanation was right. Reducing the connection interval also reduces the delays. I just can't understand why the hardware or software stack would limit the number of packets this severely. But I guess you're right. The number probably can't be configured. I did find the Android method requestConnectionPriority(), but this seems to just reduce the connection interval. The number of packets seems to stay the same. This just leaves me with reducing the connection interval on all plattforms. Still thanks for the help.
Related