Hi Simon, On 5 September 2017 at 19:40, Simon Ratner <[email protected]> wrote:
> Just found this thread, which has come up a couple of times before (I think > that's what you were referring to last time we spoke, Will?) > https://www.mail-archive.com/[email protected]/msg02454.html AFAIK it is not valid anymore as Nimble now exchange features first as well. After that Nimble takes decision to send LL_LENGTH_REQ or not. I believe Andrzej fixed that some time ago. > > Could this be related, in a sense that the peer is sending some stray > rejection frame that is causing connection to not be established? I do see > this with both Android and iOS, for what it's worth (and both iOS10 and > iOS11). What would be an easy way for me to confirm? > > > On Tue, Sep 5, 2017 at 10:34 AM, Simon Ratner <[email protected]> wrote: > > > Indeed that would be an improvement in error reporting :) > PR is in place for that. With this we will be sure if connection is established or not in your scenario. Note that this is how BLE works. Master sends LE Create Connection on Advertising event and assumes connection is created. In this point of time host gets Connection Complete Event according to BT spec. However, for the reasons Will described, it might happen that peer will not answer on any of the first 6 connection events. In this case connection is considered as dropped and Disconnect Complete Event will come with "Connection failed to be established" goes to host > However i am not convinced this is what i am seeing here - see my other > > response. > > > > On Tue, Sep 5, 2017 at 10:28 AM, Łukasz Rymanowski < > > [email protected]> wrote: > > > >> Hi > >> > >> On 5 September 2017 at 19:08, will sanfilippo <[email protected]> wrote: > >> > >> > I do not think this is really an answer but it is the best I can do > >> > without more information. > >> > > >> > When a device initially “connects” the state of the connection is not > >> > considered established until a data frame is received from the other > >> device > >> > in the connection. The initial supervision timeout is 6 connection > >> > intervals and is not based on the supervision timeout. That is why you > >> see > >> > the disconnect in 6 connection intervals. > >> > >> > >> Actually I had plan some time ago to fix the error code on such event, > >> because in this case we should use CONNECTION FAILED TO BE ESTABLISHED > >> 0x3e > >> Will put it on my todo list :) > >> > >> > >> > So either the connect request from the master to the peripheral was > not > >> > received by the peripheral or it was received but no further data > >> packets > >> > were transferred and that is why the connection dropped. > >> > > >> > What version of code are you using? When I did the anchor point/last > rxd > >> > cputime math I see the difference between the two is 301889. This > >> implies > >> > to me that cputime is counting at 1 MHz and not at 32.768kHz. Which > also > >> > implies that you are not using the latest code. > >> > > >> > NOTE: I would expect this to happen occasionally, and more > occasionally > >> if > >> > there are alot of devices transmitting in close proximity or if the > two > >> > devices connecting dont have a great RF link. > >> > > >> > > >> Łukasz > >> > >> > >> > > On Sep 4, 2017, at 5:50 PM, Simon Ratner <[email protected]> wrote: > >> > > > >> > > Hi devs, > >> > > > >> > > I am tracking a nimble issue (on nrf52) that seems to surface > >> > > intermittently - a supervision timeout when i am not expecting one. > >> Below > >> > > is a section of the log, nimble is the master here and as you can > see, > >> > the > >> > > time between connection being established and the tmo error is > ~260ms: > >> > > > >> > > 007734 [ts=60421848ssb, mod=4 level=1] GAP procedure initiated: > >> connect; > >> > > peer_addr_type=1 peer_addr=73:a0:1a:2e:b1:df scan_itvl=16 > >> scan_window=16 > >> > > itvl_min=24 itvl_max=40 latency=1 supervision_timeout=512 > >> min_ce_len=16 > >> > > max_ce_len=768 own_addr_ty > >> > > 007760 [ts=60624960ssb, mod=64 level=1] peer: connected; > >> conn_handle=14 > >> > > status=0 addr=73:a0:1a:2e:b1:df > >> > > 007763 [ts=60648396ssb, mod=4 level=1] GATT procedure initiated: > >> exchange > >> > > mtu > >> > > 007765 [ts=60664020ssb, mod=4 level=1] GATT procedure initiated: > >> discover > >> > > service by uuid; uuid=.. > >> > > 007793 *** ble_ll_conn.c:2160 *** cputime=61336489 > >> anchor_point=61386140 > >> > > last_rxd_pdu_cputime=61084251 tmo=300000 > >> > > 007795 [ts=60898380ssb, mod=64 level=1] peer: updated; > conn_handle=14 > >> > > status=520 itvl=40 latency=1 tmo=512 > >> > > 007800 [ts=60937440ssb, mod=64 level=1] peer: disconnected; > >> > conn_handle=14 > >> > > reason=520 > >> > > > >> > > > >> > > The line marked with *** is in `ble_ll_conn_event_end`, just before > it > >> > > reports `BLE_ERR_CONN_SPVN_TMO`. The time of last PDU seems to match > >> the > >> > > time when I see the "connected" host event (line #7760), and the > >> anchor > >> > > point is presumably the time of the next scheduled conn event. What > I > >> > > thought was interesting is that the tmo value is 300ms, i.e. > >> > > conn_itvl(50ms) * 6 rather than the supervision timeout. The > >> connection > >> > sm > >> > > is in `BLE_LL_CONN_STATE_CREATED` state, and not > >> > > `BLE_LL_CONN_STATE_ESTABLISHED` as I would've expected, having > >> already > >> > > received the "connected" event from the host. > >> > > > >> > > Any ideas what could be going on here? > >> > > > >> > > cheers, > >> > > simon > >> > > >> > > >> > > > > >
