It is sometimes hard to tell if they are "expected", but below are a couple of sample traces.
Based on the timestamps, I would say the first two are expected (device was slow to respond), while the last one is unexpected. In the last trace, the gatt op failed for another reason (rc=6 i.e. BLE_HS_ENOMEM... as an aside, any idea which specific resource it may have run out of?) then nothing for >2500ms, followed by a supervision timeout. In fact, now that you mention it, I have seen relays as long as 20~30sec before eventually hitting the supervision timeout - I had previously assumed it was some sort of an idle timeout triggered by the other end (a phone). ---8<--- 844456:[ts=824663680ssb, mod=4 level=1] GAP procedure initiated: connect; addr_type=1 addr=4d:ad:24:22:94:a5 scan_itvl=16 scan_window=16 itvl_min=24 itvl_max=40 latency=0 supervision_timeout=256 min_ce_len=16 max_ce_len=768 845483:[ts=825666608ssb, mod=64 level=1] gatt_cli: connection established; status=0 handle=2 peer_id_addr=4d:ad:24:22:94:a5 peer_ota_addr=4d:ad:24:22:94:a5 conn_itvl=40 conn_latency=0 supervision_timeout=256 845505:[ts=825688080ssb, mod=4 level=1] GATT procedure initiated: discover service by uuid; uuid=0304xxxx... 845789:[ts=825965264ssb, mod=64 level=2] gatt_cli: failed to read svc; conn_handle=2 status=7 845801:[ts=825976976ssb, mod=64 level=1] gatt_cli: disconnected; conn_handle=2 reason=520 ---8<--- 894919:[ts=873943792ssb, mod=4 level=1] GAP procedure initiated: connect; addr_type=1 addr=4d:ad:24:22:94:a5 scan_itvl=16 scan_window=16 itvl_min=24 itvl_max=40 latency=0 supervision_timeout=256 min_ce_len=16 max_ce_len=768 895991:[ts=874990640ssb, mod=64 level=1] gatt_cli: connection established; status=0 handle=1 peer_id_addr=4d:ad:24:22:94:a5 peer_ota_addr=4d:ad:24:22:94:a5 conn_itvl=40 conn_latency=0 supervision_timeout=256 896013:[ts=875012688ssb, mod=4 level=1] GATT procedure initiated: discover service by uuid; uuid=0304xxxx 896096:[ts=875093696ssb, mod=4 level=1] GATT procedure initiated: read by uuid; start_handle=40 end_handle=65535 uuid=0304yyyy 906398:[ts=885154208ssb, mod=64 level=2] gatt_cli: failed to read chr; conn_handle=1 status=7 906408:[ts=885163968ssb, mod=64 level=1] gatt_cli: disconnected; conn_handle=1 reason=520 ---8<--- 101152:[ts=98780800ssb, mod=4 level=1] GAP procedure initiated: connect; addr_type=1 addr=58:cc:bb:09:9e:f1 scan_itvl=16 scan_window=16 itvl_min=24 itvl_max=40 latency=0 supervision_timeout=256 min_ce_len=16 max_ce_len=768 101967:[ts=99576816ssb, mod=64 level=1] gatt_cli: connection established; status=0 handle=4 peer_id_addr=58:cc:bb:09:9e:f1 peer_ota_addr=58:cc:bb:09:9e:f1 conn_itvl=40 conn_latency=0 supervision_timeout=256 101989:[ts=99598288ssb, mod=4 level=1] GATT procedure initiated: discover service by uuid; uuid=0304xxxx 102002:[ts=99610976ssb, mod=64 level=2] gatt_cli: failed to read svc; conn_handle=4 rc=6 104643:[ts=102190320ssb, mod=64 level=1] gatt_cli: disconnected; conn_handle=4 reason=520 ---8<--- On Thu, Jun 30, 2016 at 12:45 PM, will sanfilippo <[email protected]> wrote: > Quick question: do you see supervision timeouts when you do not expect > them? If so, does this happen more/less when you are either a master or a > slave? I know this gets a bit tricky at times to “debug”, but if you are > seeing unexpected supervision timeouts do they occur very close to when the > device says it is connected (returns the connection complete event)? During > the bluetooth unplugfest we realized that the controller is not properly > returning the “connection failed to be established” error; it is returning > a supervision timeout. > > I would be interested to know if the devices are connecting, staying > connected for a while, then timing out… > > > > On Jun 30, 2016, at 12:39 PM, Simon Ratner <[email protected]> wrote: > > > > Hi devs, > > > > I've been looking at the reasons I get in BLE_GAP_EVENT_DISCONNECT to > make > > sure I cover all edge cases, and this is what I see (on an nrf51-based > > board): > > > > switch (ctxt->disconnect.reason) { > > case BLE_HS_ENOTCONN: > > /* I see this when the local host has terminated the connection. > > Feels like this should > > * be BLE_HS_HCI_ERR(BLE_ERR_CONN_TERM_LOCAL) instead, per spec. > > */ > > break; > > case BLE_HS_HCI_ERR(BLE_ERR_CONN_SPVN_TMO): > > /* Supervision timeout, I see this occasionally. */ > > break; > > case BLE_HS_HCI_ERR(BLE_ERR_REM_USER_CONN_TERM): > > case BLE_HS_HCI_ERR(BLE_ERR_RD_CONN_TERM_RESRCS): > > case BLE_HS_HCI_ERR(BLE_ERR_RD_CONN_TERM_PWROFF): > > /* Remote termination, I see the first one when remote peer > > terminates the connection. */ > > break; > > case BLE_HS_HCI_ERR(BLE_ERR_CONN_TERM_LOCAL): > > /* Local termination, I never see this one. */ > > break; > > } > > > > Local termination should not be setting reason to BLE_HS_ENOTCONN (which, > > when mapped onto the space of error codes in 4.2 vol 2 part D, ends up > > being BLE_ERR_MEM_CAPACITY, confusingly). > >
