S110 peripheral disconnects in middle of activity

[Chris Hodapp]

I am running into some symptoms here that I'm not understanding.

My peripheral is an nRF51822 using the S110 softdevice. It implements a service which sends out notifications at regular intervals (I've tried from 1 second to 10 seconds). Connection parameters are as follows, basically taken from an example service:

#define MIN_CONN_INTERVAL MSEC_TO_UNITS(500, UNIT_1_25_MS)
#define MAX_CONN_INTERVAL MSEC_TO_UNITS(1000, UNIT_1_25_MS)
#define SLAVE_LATENCY 0
#define CONN_SUP_TIMEOUT MSEC_TO_UNITS(8000, UNIT_10_MS)

I've tested this with an S120 central, with LightBlue on an iPhone, and with gatttool from BlueZ on Linux. In all cases I have similar symptoms: The peripheral will be sending out notifications, the central will be receiving them properly, and then suddenly the peripheral will receive BLE_GAP_EVT_DISCONNECTED with a reason of 0x16 (local user termination). The disconnect happens somewhere around 30-60 seconds of the connection being established.

I observed the same behavior with indications when I used gatttool to enable them. The peripheral would be properly receiving confirmations, and then randomly I would get NRF_ERROR_BUSY when trying to send the next indication.

I also tried repeatedly reading the characteristic from LightBlue, leaving notifications disabled, and still encountered this problem.

It looks to me like 0x16 is something in the peripheral terminating the connection, but what can I do to figure out why it is doing so?

[Chris Hodapp]

A reply to my own question:

I may have addressed this issue but I still do not understand it.

The peripheral had min and max connection interval of 500 and 1000 ms, respectively. The central (S120) had min and max connection interval of 30 and 60 ms. The parameters which I read from the connection event had a connection interval of 48 (though I do not know the units).

First I changed minimum interval on the peripheral to 50 ms. This remedied the problem. The part that confuses me is that the actual connection parameters on the connection event were identical to before!

I also tried setting the central's maximum interval to 1000 ms (leaving the minimum interval on the peripheral at 500 ms). This, too, worked, and the actual connection parameters differed from before.

[Pål Håland]

Hi Chris, Do you think you could try and get a sniff trace with the help of the tool mentioned in this post? https://devzone.nordicsemi.com/index.php/ble-sniffer-recommendation

This really helps understanding what is happening. Especially if there are some events that is not handled. In the place where you pull out the events, you can try to add an assert or breakpoint in the default case (if you are using a switch on the event ID) Could be an pairing request that is not handled or and indication that is not confirmed.

[Chris Hodapp]

I don't run Windows (I'm on Linux) but I will see if there's some way I can make this sniffer or another sniffer work.

I don't think it's an unconfirmed indication. I had indications and confirmations logged on the peripheral side, and every single indication that was successfully sent out received a confirmation back; this also happens even when no indications are sent.

[Chris Hodapp]

A reply to Pål Håland above (so that I may format properly and attach things):

I am still having this problem when handling indications and confirmations with gatttool in Linux, so I used hcidump from BlueZ to get a dump of HCI commands.

Here is the dump for when using notifications:

HCI sniffer - Bluetooth packet analyzer ver 5.18
btsnoop version: 1 datalink type: 1002
2014-05-23 12:29:04.480869 < HCI Command: LE Create Connection (0x08|0x000d) plen 25
    bdaddr E5:47:90:E2:1C:E2 type 1
    interval 96 window 48 initiator_filter 0
    own_bdaddr_type 0 min_interval 40 max_interval 56
    latency 0 supervision_to 42 min_ce 0 max_ce 0
2014-05-23 12:29:04.482175 > HCI Event: Command Status (0x0f) plen 4
    LE Create Connection (0x08|0x000d) status 0x00 ncmd 1
2014-05-23 12:29:04.508140 > HCI Event: LE Meta Event (0x3e) plen 19
    LE Connection Complete
      status 0x00 handle 64, role master
      bdaddr E5:47:90:E2:1C:E2 (Random)
2014-05-23 12:29:04.510083 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Write req (0x12)
      handle 0x0018 value  0x01 0x00
2014-05-23 12:29:04.589789 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Find By Type req (0x06)
      start 0x0001, end 0xffff, uuid 0x2800
      value 0x02 0x18
2014-05-23 12:29:04.657165 > ACL data: handle 64 flags 0x02 dlen 5
    ATT: Write resp (0x13)
2014-05-23 12:29:04.835165 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2014-05-23 12:29:05.602293 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Handle notify (0x1b)
      handle 0x0017
      value 0xe7 0x03 0x01 0x00 0x02 0x00 

(removed where the above repeats for awhile...)

2014-05-23 12:29:33.614966 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Handle notify (0x1b)
      handle 0x0017
      value 0xcb 0x03 0x01 0x00 0x02 0x00 
2014-05-23 12:29:34.763349 > HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 64 reason 0x13
    Reason: Remote User Terminated Connection

And here is the dump for indications:

HCI sniffer - Bluetooth packet analyzer ver 5.18
btsnoop version: 1 datalink type: 1002
2014-05-23 12:14:51.345168 < HCI Command: LE Create Connection (0x08|0x000d) plen 25
    bdaddr E5:47:90:E2:1C:E2 type 1
    interval 96 window 48 initiator_filter 0
    own_bdaddr_type 0 min_interval 40 max_interval 56
    latency 0 supervision_to 42 min_ce 0 max_ce 0
2014-05-23 12:14:51.346891 > HCI Event: Command Status (0x0f) plen 4
    LE Create Connection (0x08|0x000d) status 0x00 ncmd 1
2014-05-23 12:14:51.374854 > HCI Event: LE Meta Event (0x3e) plen 19
    LE Connection Complete
      status 0x00 handle 64, role master
      bdaddr E5:47:90:E2:1C:E2 (Random)
2014-05-23 12:14:51.376840 < ACL data: handle 64 flags 0x00 dlen 9
    ATT: Write req (0x12)
      handle 0x0018 value  0x02 0x00
2014-05-23 12:14:51.468253 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Find By Type req (0x06)
      start 0x0001, end 0xffff, uuid 0x2800
      value 0x02 0x18
2014-05-23 12:14:51.535628 > ACL data: handle 64 flags 0x02 dlen 5
    ATT: Write resp (0x13)
2014-05-23 12:14:51.635879 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2014-05-23 12:14:52.480757 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Handle indicate (0x1d)
2014-05-23 12:14:52.487342 < ACL data: handle 64 flags 0x00 dlen 5
    ATT: Handle CNF (0x1e)

(removed where the above three repeat - HCI Event, ACL, ACL...)

2014-05-23 12:15:19.763051 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2014-05-23 12:15:20.493434 > ACL data: handle 64 flags 0x02 dlen 13
    ATT: Handle indicate (0x1d)
2014-05-23 12:15:20.494878 < ACL data: handle 64 flags 0x00 dlen 5
    ATT: Handle CNF (0x1e)
2014-05-23 12:15:20.763057 > HCI Event: Number of Completed Packets (0x13) plen 5
    handle 64 packets 1
2014-05-23 12:15:21.641065 > HCI Event: Disconn Complete (0x05) plen 4
    status 0x00 handle 64 reason 0x13
    Reason: Remote User Terminated Connection

In both instances, I see a BLE_GATTC_EVT_TIMEOUT event on the peripheral.

The full dumps (untouched output of "hcidump -w") are attached as well.

[Pål Håland]

In both the notification log, and the indication log I noticed that the Find By Type Request does not get any response from the Linux GATT Server, Could this be the reason for the disconnect, what does the application on the S110 do when it receive the BLE_GATTC_EVT_TIMEOUT? Is that when disconnect is called?