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