Hi Will,
Thanks for the explanation. I found it in the BluetoothCore v4.2 spec in
section 5.1.9 - Data Length Update Procedure.
I agree with your conclusion that it sounds like the controller must accept
LL_UNKNOWN_RSP but must not require it.
Thanks again this was really very helpful.
-Pritish
On Fri, Mar 17, 2017 at 11:05 AM, will sanfilippo <wi...@runtime.io> wrote:
> I can elaborate. It has been discussed at fair length on the dev list
> before but I will summarize.
>
> The issue is that our controller automatically attempts to do data length
> extension with a peer. The default configuration sets a larger receive size
> than the minimum size and this causes the controller to initiate that
> control procedure automatically (without any host intervention).
>
> We have seen that other controllers do not like it when they get a
> LL_LENGTH_REQ_PDU when they do not support the data length update
> procedure. They are supposed to send back an UNKNOWN_RSP but some do not.
> Actually, we have seen different controllers with different behavior.
>
> And re-reading the specification, it could be that I simply
> mis-interpreted it. It was my understanding that if a controller receives a
> control PDU that it does not understand it should reply with
> LL_UNKNOWN_RSP. The spec sort of hints at that in the Feature Exchange
> Procedure section, but maybe it is not required. Technically I am probably
> wrong as it says that an implementation must accept LL_UNKNOWN_RSP but does
> not say that you have to send it. I thought I had read it somewhere but
> maybe not.
>
> Anyway, we will address this issue soon enough so for now just disable
> data length extension and you should be fine.
>
> > On Mar 17, 2017, at 10:47 AM, Pritish Gandhi <prit...@aylanetworks.com>
> wrote:
> >
> > Hey Will,
> > That worked!! The blecent is staying connected to the bleprph almost
> > indefinitely now.
> >
> > Can you please elaborate on the reason: "And sure enough, I think this is
> > the same issue we have seen before. The data length update procedure is
> not
> > completing and the connection is timing out."
> >
> > Do you mean that the blecent device is trying to enable data length
> > extension with the bleprph but that is failing?
> >
> > Thanks,
> > Pritish
> >
> > On Fri, Mar 17, 2017 at 10:11 AM, will sanfilippo <wi...@runtime.io>
> wrote:
> >
> >> BTW: Lukasz did have a really good suggestion for future debugging (why
> >> didnt I think of that?) :-)
> >>
> >> A sniffer with wireshark is a really handy tool. I mentioned the
> debugger
> >> as it was something we could look at really quickly to see if it is an
> >> issue that I already know about with some controllers.
> >>
> >> And sure enough, I think this is the same issue we have seen before. The
> >> data length update procedure is not completing and the connection is
> timing
> >> out.
> >>
> >> A quick fix for now would be to disable the data length extension
> feature
> >> to see if this addresses the issue.
> >>
> >> In the syscfg.yml file in net/nimble/controller you should set
> >> BLE_LL_CFG_FEAT_DATA_LEN_EXT to 0. This should disable the controller
> >> automatically sending the data length update procedure. Hopefully this
> >> solves the problem.
> >>
> >> Will
> >>
> >>> On Mar 17, 2017, at 9:43 AM, Pritish Gandhi <prit...@aylanetworks.com>
> >> wrote:
> >>>
> >>> Hi Will,
> >>> Sorry I was mistaken, I jumbled up the issues in my own head. You are
> >>> correct in that the blecent is running on the nrf52dk and the logs I
> >>> provided are from the blecent application.
> >>>
> >>> As you requested I put the breakpoint at ble_ll_ctrl_proc_rsp_timer_cb(
> )
> >> please
> >>> see the dump below:
> >>>
> >>> *console logs:*
> >>>
> >>> 92626:[ts=723640584ssb, mod=64 level=1] Connection established
> >>>
> >>> 92627:[ts=723648396ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all services
> >>>
> >>> 92703:[ts=724242172ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all characteristics; start_handle=1 end_handle=11
> >>>
> >>> 92748:[ts=724593712ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all characteristics; start_handle=12 end_handle=15
> >>>
> >>> 92786:[ts=724890568ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all characteristics; start_handle=16 end_handle=19
> >>>
> >>> 92818:[ts=725140616ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all characteristics; start_handle=20 end_handle=32
> >>>
> >>> 92863:[ts=725492156ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all characteristics; start_handle=33 end_handle=65535
> >>>
> >>> 92927:[ts=725992124ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all descriptors; chr_val_handle=14 end_handle=15
> >>>
> >>> 92940:[ts=726093744ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all descriptors; chr_val_handle=18 end_handle=19
> >>>
> >>> 92953:[ts=726195300ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all descriptors; chr_val_handle=24 end_handle=25
> >>>
> >>> 92978:[ts=726390600ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all descriptors; chr_val_handle=29 end_handle=30
> >>>
> >>> 92991:[ts=726492156ssb, mod=4 level=1] GATT procedure initiated:
> discover
> >>> all descriptors; chr_val_handle=37 end_handle=65535
> >>>
> >>> 93004:[ts=726593712ssb, mod=64 level=3] Service discovery complete;
> >>> status=0 conn_handle=1
> >>>
> >>> 93006:[ts=726609336ssb, mod=4 level=1] GATT procedure initiated: read;
> >>> att_handle=22
> >>>
> >>> 93008:[ts=726624960ssb, mod=4 level=1] GATT procedure initiated: write;
> >>> att_handle=32 len=2
> >>>
> >>> 93011:[ts=726648396ssb, mod=4 level=1] GATT procedure initiated: write;
> >>> att_handle=30 len=2
> >>>
> >>> 93036:[ts=726843696ssb, mod=64 level=1] Read complete; status=0
> >>> conn_handle=1 attr_handle=22 value=
> >>>
> >>> 93042:[ts=726890568ssb, mod=64 level=1] Write complete; status=0
> >>> conn_handle=1 attr_handle=32
> >>>
> >>> 93049:[ts=726945252ssb, mod=64 level=1] Subscribe complete; status=0
> >>> conn_handle=1 attr_handle=30
> >>>
> >>> *gdb: (took a break point at ble_ll_ctrl_proc_rsp_timer_cb)*
> >>>
> >>> (gdb) p/x *(struct ble_ll_conn_sm *)ev->ev_arg
> >>>
> >>> $4 = {
> >>>
> >>> csmflags = {
> >>>
> >>> cfbit = {
> >>>
> >>> pkt_rxd = 0x0,
> >>>
> >>> terminate_ind_txd = 0x0,
> >>>
> >>> terminate_ind_rxd = 0x0,
> >>>
> >>> allow_slave_latency = 0x0,
> >>>
> >>> slave_set_last_anchor = 0x0,
> >>>
> >>> awaiting_host_reply = 0x0,
> >>>
> >>> send_conn_upd_event = 0x0,
> >>>
> >>> conn_update_sched = 0x0,
> >>>
> >>> host_expects_upd_event = 0x0,
> >>>
> >>> version_ind_sent = 0x1,
> >>>
> >>> rxd_version_ind = 0x1,
> >>>
> >>> chanmap_update_scheduled = 0x0,
> >>>
> >>> conn_empty_pdu_txd = 0x0,
> >>>
> >>> last_txd_md = 0x0,
> >>>
> >>> conn_req_txd = 0x1,
> >>>
> >>> send_ltk_req = 0x0,
> >>>
> >>> encrypted = 0x0,
> >>>
> >>> encrypt_chg_sent = 0x0,
> >>>
> >>> le_ping_supp = 0x1
> >>>
> >>> },
> >>>
> >>> conn_flags = 0x44600
> >>>
> >>> },
> >>>
> >>> conn_handle = 0x1,
> >>>
> >>> conn_state = 0x1,
> >>>
> >>> conn_role = 0x1,
> >>>
> >>> max_tx_octets = 0x1b,
> >>>
> >>> max_rx_octets = 0xfb,
> >>>
> >>> rem_max_tx_octets = 0x1b,
> >>>
> >>> rem_max_rx_octets = 0x1b,
> >>>
> >>> eff_max_tx_octets = 0x1b,
> >>>
> >>> eff_max_rx_octets = 0x1b,
> >>>
> >>> max_tx_time = 0x148,
> >>>
> >>> max_rx_time = 0x848,
> >>>
> >>> rem_max_tx_time = 0x148,
> >>>
> >>> rem_max_rx_time = 0x148,
> >>>
> >>> eff_max_tx_time = 0x148,
> >>>
> >>> eff_max_rx_time = 0x148,
> >>>
> >>> chanmap = {0xff, 0xff, 0xff, 0xff, 0x1f},
> >>>
> >>> req_chanmap = {0x0, 0x0, 0x0, 0x0, 0x0},
> >>>
> >>> chanmap_instant = 0x0,
> >>>
> >>> hop_inc = 0xb,
> >>>
> >>> data_chan_index = 0x5,
> >>>
> >>> unmapped_chan = 0x5,
> >>>
> >>> last_unmapped_chan = 0x1f,
> >>>
> >>> num_used_chans = 0x25,
> >>>
> >>> conn_rssi = 0xd0,
> >>>
> >>> tx_seqnum = 0x1,
> >>>
> >>> next_exp_seqnum = 0x1,
> >>>
> >>> cons_rxd_bad_crc = 0x0,
> >>>
> >>> last_rxd_sn = 0x0,
> >>>
> >>> last_rxd_hdr_byte = 0x5,
> >>>
> >>> rpa_index = 0xff,
> >>>
> >>> reject_reason = 0x0,
> >>>
> >>> host_reply_opcode = 0x0,
> >>>
> >>> master_sca = 0x4,
> >>>
> >>> tx_win_size = 0x1,
> >>>
> >>> cur_ctrl_proc = 0x8,
> >>>
> >>> disconnect_reason = 0x0,
> >>>
> >>> rxd_disconnect_reason = 0x0,
> >>>
> >>> common_features = 0x0,
> >>>
> >>> vers_nr = 0x7,
> >>>
> >>> pending_ctrl_procs = 0x100,
> >>>
> >>> event_cntr = 0x320,
> >>>
> >>> completed_pkts = 0x0,
> >>>
> >>> comp_id = 0xf,
> >>>
> >>> sub_vers_nr = 0x2209,
> >>>
> >>> auth_pyld_tmo = 0xbb8,
> >>>
> >>> access_addr = 0x14258862,
> >>>
> >>> crcinit = 0x742bf8,
> >>>
> >>> ce_end_time = 0x2d8b779d,
> >>>
> >>> terminate_timeout = 0x0,
> >>>
> >>> last_scheduled = 0x2d8aaaa6,
> >>>
> >>> conn_itvl_min = 0x18,
> >>>
> >>> conn_itvl_max = 0x28,
> >>>
> >>> conn_itvl = 0x28,
> >>>
> >>> slave_latency = 0x0,
> >>>
> >>> supervision_tmo = 0x100,
> >>>
> >>> min_ce_len = 0x10,
> >>>
> >>> max_ce_len = 0x50,
> >>>
> >>> tx_win_off = 0x0,
> >>>
> >>> anchor_point = 0x2d8b6e97,
> >>>
> >>> last_anchor_point = 0x2b290d01,
> >>>
> >>> slave_cur_tx_win_usecs = 0x0,
> >>>
> >>> slave_cur_window_widening = 0x0,
> >>>
> >>> own_addr_type = 0x0,
> >>>
> >>> peer_addr_type = 0x0,
> >>>
> >>> peer_addr = {0xaa, 0xaa, 0xaa, 0xaa, 0xaa, 0xaa},
> >>>
> >>> conn_spvn_timer = {
> >>>
> >>> bsp_timer = 0x20002ee4,
> >>>
> >>> cb_func = 0x19865,
> >>>
> >>> cb_arg = 0x20003298,
> >>>
> >>> expiry = 0x2db1bca8,
> >>>
> >>> link = {
> >>>
> >>> tqe_next = 0x0,
> >>>
> >>> tqe_prev = 0x200036a4
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> conn_spvn_ev = {
> >>>
> >>> ev_queued = 0x0,
> >>>
> >>> ev_cb = 0x1ac05,
> >>>
> >>> ev_arg = 0x20003298,
> >>>
> >>> ev_next = {
> >>>
> >>> stqe_next = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> conn_ev_end = {
> >>>
> >>> ev_queued = 0x0,
> >>>
> >>> ev_cb = 0x1a6a5,
> >>>
> >>> ev_arg = 0x20003298,
> >>>
> >>> ev_next = {
> >>>
> >>> stqe_next = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> cur_tx_pdu = 0x0,
> >>>
> >>> conn_txq = {
> >>>
> >>> stqh_first = 0x0,
> >>>
> >>> stqh_last = 0x20003358
> >>>
> >>> },
> >>>
> >>> {
> >>>
> >>> act_sle = {
> >>>
> >>> sle_next = 0x0
> >>>
> >>> },
> >>>
> >>> free_stqe = {
> >>>
> >>> stqe_next = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> ctrl_proc_rsp_timer = {
> >>>
> >>> c_ev = {
> >>>
> >>> ev_queued = 0x0,
> >>>
> >>> ev_cb = 0x1c1ed,
> >>>
> >>> ev_arg = 0x20003298,
> >>>
> >>> ev_next = {
> >>>
> >>> stqe_next = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> c_evq = 0x2000313c,
> >>>
> >>> c_ticks = 0x17dd2,
> >>>
> >>> c_next = {
> >>>
> >>> tqe_next = 0x200018e4,
> >>>
> >>> tqe_prev = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> conn_sch = {
> >>>
> >>> sched_type = 0x3,
> >>>
> >>> enqueued = 0x1,
> >>>
> >>> start_time = 0x2d8b6dd9,
> >>>
> >>> end_time = 0x2d8b779d,
> >>>
> >>> cb_arg = 0x20003298,
> >>>
> >>> sched_cb = 0x19d35,
> >>>
> >>> link = {
> >>>
> >>> tqe_next = 0x0,
> >>>
> >>> tqe_prev = 0x200036ac
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> auth_pyld_timer = {
> >>>
> >>> c_ev = {
> >>>
> >>> ev_queued = 0x0,
> >>>
> >>> ev_cb = 0x1a2d1,
> >>>
> >>> ev_arg = 0x20003298,
> >>>
> >>> ev_next = {
> >>>
> >>> stqe_next = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> c_evq = 0x2000313c,
> >>>
> >>> c_ticks = 0x0,
> >>>
> >>> c_next = {
> >>>
> >>> tqe_next = 0x0,
> >>>
> >>> tqe_prev = 0x0
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> enc_data = {
> >>>
> >>> enc_state = 0x1,
> >>>
> >>> tx_encrypted = 0x0,
> >>>
> >>> enc_div = 0x0,
> >>>
> >>> tx_pkt_cntr = 0x0,
> >>>
> >>> rx_pkt_cntr = 0x0,
> >>>
> >>> host_rand_num = 0x0,
> >>>
> >>> iv = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0},
> >>>
> >>> enc_block = {
> >>>
> >>> key = {0x0 <repeats 16 times>},
> >>>
> >>> plain_text = {0x0 <repeats 16 times>},
> >>>
> >>> cipher_text = {0x0 <repeats 16 times>}
> >>>
> >>> }
> >>>
> >>> },
> >>>
> >>> conn_param_req = {
> >>>
> >>> handle = 0x0,
> >>>
> >>> conn_itvl_min = 0x0,
> >>>
> >>> conn_itvl_max = 0x0,
> >>>
> >>> conn_latency = 0x0,
> >>>
> >>> supervision_timeout = 0x0,
> >>>
> >>> min_ce_len = 0x0,
> >>>
> >>> max_ce_len = 0x0
> >>>
> >>> },
> >>>
> >>> conn_update_req = {
> >>>
> >>> winsize = 0x0,
> >>>
> >>> winoffset = 0x0,
> >>>
> >>> interval = 0x0,
> >>>
> >>> latency = 0x0,
> >>>
> >>> timeout = 0x0,
> >>>
> >>> instant = 0x0
> >>>
> >>> },
> >>>
> >>> conn_cp = {
> >>>
> >>> interval_min = 0x0,
> >>>
> >>> interval_max = 0x0,
> >>>
> >>> latency = 0x0,
> >>>
> >>> timeout = 0x0,
> >>>
> >>> pref_periodicity = 0x0,
> >>>
> >>> ref_conn_event_cnt = 0x0,
> >>>
> >>> offset0 = 0x0,
> >>>
> >>> offset1 = 0x0,
> >>>
> >>> offset2 = 0x0,
> >>>
> >>> offset3 = 0x0,
> >>>
> >>> offset4 = 0x0,
> >>>
> >>> offset5 = 0x0
> >>>
> >>> }
> >>>
> >>> }
> >>>
> >>>
> >>> Thanks,
> >>>
> >>> Pritish
> >>>
> >>> On Thu, Mar 16, 2017 at 3:22 PM, will sanfilippo <wi...@runtime.io>
> >> wrote:
> >>>
> >>>> Maybe I read your email incorrectly, but I thought the error was
> coming
> >>>> from blecent on the nrf52dk?
> >>>>
> >>>>> On Mar 16, 2017, at 3:11 PM, Pritish Gandhi <
> prit...@aylanetworks.com>
> >>>> wrote:
> >>>>>
> >>>>> Hi Will,
> >>>>> I'm not building the controller lib for the image that runs on the
> >>>>> stm32f4Discovery board. I'm building it as a Host Only. So I build
> the
> >>>>> host, HCI, and uart transport. Broadcom's Bluetooth core is really a
> >>>>> BlackBox to me, I don't have any way to debug what's going on there
> >>>> (except
> >>>>> maybe using a BLE sniffer and seeing packets going out on the
> >> interface)
> >>>>> Thanks,
> >>>>> Pritish
> >>>>>
> >>>>> On Thu, Mar 16, 2017 at 2:48 PM, will sanfilippo <wi...@runtime.io>
> >>>> wrote:
> >>>>>
> >>>>>> I do not think there is a simple way to debug this. As Chris points
> >> out,
> >>>>>> the first problem is a LL control procedure timeout. I think I can
> >> help
> >>>>>> figure some things out there. There is a function called
> >>>>>> ble_ll_ctrl_proc_rsp_timer_cb. If you set a breakpoint at this
> >> function
> >>>> in
> >>>>>> the debugger when you get the first error you can examine the
> >> connection
> >>>>>> state machine. The parameter passed in to that function is an event
> >> and
> >>>>>> ev->ev_arg is a pointer to the connection state machine. In the
> >>>> debugger,
> >>>>>> just dump ev_arg after typecasting it to a connection state machine:
> >> p/x
> >>>>>> (struct ble_ll_conn_sm *)ev->ev_arg
> >>>>>>
> >>>>>> I presume you are OK with using gdb? I would ‘set print pretty on’
> >>>> before
> >>>>>> dumping the connection state machine. If you send me the output of
> >> that
> >>>> I
> >>>>>> might be able to help.
> >>>>>>
> >>>>>> Thanks
> >>>>>>
> >>>>>>> On Mar 16, 2017, at 2:30 PM, Christopher Collins <ch...@runtime.io
> >
> >>>>>> wrote:
> >>>>>>>
> >>>>>>> Hi Pritish,
> >>>>>>>
> >>>>>>> On Thu, Mar 16, 2017 at 01:50:12PM -0700, Pritish Gandhi wrote:
> >>>>>>>> Hi All,
> >>>>>>>> I'm trying to run blecent on an nrf52dk and am running the bleprph
> >>>>>>>> application on another BLE module (stm32f4discovery talking to a
> >>>>>> broadcom
> >>>>>>>> BLE core). Anyways, when try to run blecent it seems like I
> >>>> successfully
> >>>>>>>> connect to the peripheral and are able to discover it, however
> after
> >>>>>> that
> >>>>>>>> the connection seems to be timing out and then am never able to
> >>>> discover
> >>>>>>>> the peripheral again.
> >>>>>>>
> >>>>>>> [...]
> >>>>>>>
> >>>>>>> Hmm, that is odd, indeed. The disconnect reason codes you are
> seeing
> >>>>>>> are mapped as follows:
> >>>>>>>
> >>>>>>> 546 - LMP RESPONSE TIMEOUT / LL RESPONSE TIMEOUT
> >>>>>>> 520 - CONNECTION TIMEOUT
> >>>>>>>
> >>>>>>> I'm afraid I don't have any ideas at the moment. Could you please
> >>>>>>> clarify the setup you are using? Here is my understanding:
> >>>>>>>
> >>>>>>> Device A: blecent on nRF52dk (combined host-controller)
> >>>>>>> Device B:
> >>>>>>> * bleprph on stm32f4discovery (host-only)
> >>>>>>> * broadcom controller
> >>>>>>>
> >>>>>>> Is that correct? If so, I assume the host and controller on
> device B
> >>>>>>> communicate via UART?
> >>>>>>>
> >>>>>>> Thanks,
> >>>>>>> Chris
> >>>>>>>
> >>>>>>>>
> >>>>>>>> 1) Connected and Discovered the bleprph:
> >>>>>>>>
> >>>>>>>> 37493:[ts=292914004ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> discovery;
> >>>>>>>> own_addr_type=0 filter_policy=0 passive=1 limited=0
> >>>> filter_duplicates=1
> >>>>>>>> duration=forever
> >>>>>>>>
> >>>>>>>> 37503:[ts=292992124ssb, mod=4 level=1] GAP procedure initiated:
> >>>> connect;
> >>>>>>>> peer_addr_type=0 peer_addr=aa:aa:aa:aa:aa:aa 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 own_addr_ty
> >>>>>>>>
> >>>>>>>> 37517:[ts=293101556ssb, mod=64 level=1] Connection established
> >>>>>>>>
> >>>>>>>> 37519:[ts=293117180ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all services
> >>>>>>>>
> >>>>>>>> 37588:[ts=293656208ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all characteristics; start_handle=1 end_handle=11
> >>>>>>>>
> >>>>>>>> 37627:[ts=293960876ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all characteristics; start_handle=12 end_handle=15
> >>>>>>>>
> >>>>>>>> 37658:[ts=294203112ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all characteristics; start_handle=16 end_handle=19
> >>>>>>>>
> >>>>>>>> 37684:[ts=294406224ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all characteristics; start_handle=20 end_handle=32
> >>>>>>>>
> >>>>>>>> 37722:[ts=294703080ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all characteristics; start_handle=33 end_handle=65535
> >>>>>>>>
> >>>>>>>> 37761:[ts=295007812ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all descriptors; chr_val_handle=14 end_handle=15
> >>>>>>>>
> >>>>>>>> 37774:[ts=295109368ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all descriptors; chr_val_handle=18 end_handle=19
> >>>>>>>>
> >>>>>>>> 37786:[ts=295203112ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all descriptors; chr_val_handle=24 end_handle=25
> >>>>>>>>
> >>>>>>>> 37799:[ts=295304668ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all descriptors; chr_val_handle=29 end_handle=30
> >>>>>>>>
> >>>>>>>> 37812:[ts=295406224ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all descriptors; chr_val_handle=37 end_handle=65535
> >>>>>>>>
> >>>>>>>> 37825:[ts=295507780ssb, mod=64 level=3] Service discovery
> complete;
> >>>>>>>> status=0 conn_handle=1
> >>>>>>>>
> >>>>>>>> 2) Read/Write/Subscribe for notifications. Finally fails with
> >>>> reason=546
> >>>>>>>>
> >>>>>>>> 37827:[ts=295523404ssb, mod=4 level=1] GATT procedure initiated:
> >> read;
> >>>>>>>> att_handle=22
> >>>>>>>>
> >>>>>>>> 37829:[ts=295539028ssb, mod=4 level=1] GATT procedure initiated:
> >>>> write;
> >>>>>>>> att_handle=32 len=2
> >>>>>>>>
> >>>>>>>> 37832:[ts=295562464ssb, mod=4 level=1] GATT procedure initiated:
> >>>> write;
> >>>>>>>> att_handle=30 len=2
> >>>>>>>>
> >>>>>>>> 37851:[ts=295710892ssb, mod=64 level=1] Read complete; status=0
> >>>>>>>> conn_handle=1 attr_handle=22 value=
> >>>>>>>>
> >>>>>>>> 37857:[ts=295757764ssb, mod=64 level=1] Write complete; status=0
> >>>>>>>> conn_handle=1 attr_handle=32
> >>>>>>>>
> >>>>>>>> 37863:[ts=295804636ssb, mod=64 level=1] Subscribe complete;
> status=0
> >>>>>>>> conn_handle=1 attr_handle=30
> >>>>>>>>
> >>>>>>>> 42637:[ts=333101556ssb, mod=64 level=1] disconnect; reason=546
> >>>>>>>>
> >>>>>>>>
> >>>>>>>> 3) Once it disconnects, blecent gets stuck in this loop of trying
> to
> >>>>>>>> discover, but the discovery always fails:
> >>>>>>>>
> >>>>>>>> 42638:[ts=333109368ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> discovery;
> >>>>>>>> own_addr_type=0 filter_policy=0 passive=1 limited=0
> >>>> filter_duplicates=1
> >>>>>>>> duration=forever
> >>>>>>>>
> >>>>>>>> 42973:[ts=335726516ssb, mod=4 level=1] GAP procedure initiated:
> >>>> connect;
> >>>>>>>> peer_addr_type=0 peer_addr=aa:aa:aa:aa:aa:aa 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 own_addr_ty
> >>>>>>>>
> >>>>>>>> 42982:[ts=335796824ssb, mod=64 level=1] Connection established
> >>>>>>>>
> >>>>>>>> 42983:[ts=335804636ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all services
> >>>>>>>>
> >>>>>>>> 43020:[ts=336093744ssb, mod=64 level=3] Error: Service discovery
> >>>> failed;
> >>>>>>>> status=7 conn_handle=1
> >>>>>>>>
> >>>>>>>> 43022:[ts=336109368ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> terminate
> >>>>>>>> connection; conn_handle=1 hci_reason=19
> >>>>>>>>
> >>>>>>>> 43025:[ts=336132804ssb, mod=64 level=1] disconnect; reason=520
> >>>>>>>>
> >>>>>>>> 43027:[ts=336148428ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> discovery;
> >>>>>>>> own_addr_type=0 filter_policy=0 passive=1 limited=0
> >>>> filter_duplicates=1
> >>>>>>>> duration=forever
> >>>>>>>>
> >>>>>>>> 43038:[ts=336234360ssb, mod=4 level=1] GAP procedure initiated:
> >>>> connect;
> >>>>>>>> peer_addr_type=0 peer_addr=aa:aa:aa:aa:aa:aa 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 own_addr_ty
> >>>>>>>>
> >>>>>>>> 43046:[ts=336296856ssb, mod=64 level=1] Connection established
> >>>>>>>>
> >>>>>>>> 43047:[ts=336304668ssb, mod=4 level=1] GATT procedure initiated:
> >>>>>> discover
> >>>>>>>> all services
> >>>>>>>>
> >>>>>>>> 43084:[ts=336593712ssb, mod=64 level=3] Error: Service discovery
> >>>> failed;
> >>>>>>>> status=7 conn_handle=1
> >>>>>>>>
> >>>>>>>> 43086:[ts=336609336ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> terminate
> >>>>>>>> connection; conn_handle=1 hci_reason=19
> >>>>>>>>
> >>>>>>>> 43089:[ts=336632772ssb, mod=64 level=1] disconnect; reason=520
> >>>>>>>>
> >>>>>>>> 43091:[ts=336648396ssb, mod=4 level=1] GAP procedure initiated:
> >>>>>> discovery;
> >>>>>>>> own_addr_type=0 filter_policy=0 passive=1 limited=0
> >>>> filter_duplicates=1
> >>>>>>>> duration=forever
> >>>>>>>>
> >>>>>>>> 43101:[ts=336726516ssb, mod=4 level=1] GAP procedure initiated:
> >>>> connect;
> >>>>>>>> peer_addr_type=0 peer_addr=aa:aa:aa:aa:aa:aa 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 own_addr_ty
> >>>>>>>>
> >>>>>>>> Any ideas whats going on and how to debug this further?
> >>>>>>>> The only way to recover seems to be to reset my bleprph device.
> >>>>>>>> Appreciate the help,
> >>>>>>>> Pritish
> >>>>>>
> >>>>>>
> >>>>
> >>>>
> >>
> >>
>
>
