You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@mynewt.apache.org by "Jacob (JIRA)" <ji...@apache.org> on 2017/03/01 00:45:45 UTC
[jira] [Commented] (MYNEWT-526) Gap params update succeeds, but
times out immediately after
[ https://issues.apache.org/jira/browse/MYNEWT-526?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15889222#comment-15889222 ]
Jacob commented on MYNEWT-526:
------------------------------
Yes I can confirm it still disconnects. It happens every time, after about 30 seconds of being connected, presumably after attempting to update something about the connection.
Though I get a different error code now? 571 or 59 on top of HCI error (512)?
```
6518:[ts=50921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x41 0xbd 0x03
6522:[ts=50953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
6524:[ts=50968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
6526:[ts=50984312ssb, mod=64 level=1] sensor_contact=1
6527:[ts=50992124ssb, mod=64 level=1] measurement=65
6528:[ts=51000000ssb, mod=64 level=1] rr=189
6557:[ts=51226548ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=16 data=0x0c 0x00 0x05 0x00 0x12 0x0f 0x08 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02
6560:[ts=51249984ssb, mod=4 level=0] L2CAP - rxed signalling msg: 0x12 0x0f 0x08 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02
6562:[ts=51265608ssb, mod=4 level=0] host tx hci data; handle=1 length=10
6563:[ts=51273420ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00 0x0a 0x00 0x06 0x00 0x05 0x00 0x13 0x0f 0x02 0x00 0x01 0x00
6569:[ts=51320292ssb, mod=4 level=0] Number of Completed Packets: num_handles=1
6571:[ts=51335916ssb, mod=4 level=0] handle:1 pkts:1
6646:[ts=51921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3f 0xd8 0x03
6650:[ts=51953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
6652:[ts=51968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
6654:[ts=51984312ssb, mod=64 level=1] sensor_contact=1
6655:[ts=51992124ssb, mod=64 level=1] measurement=63
6656:[ts=52000000ssb, mod=64 level=1] rr=216
6774:[ts=52921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x41 0xa0 0x03
6778:[ts=52953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
6780:[ts=52968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
6782:[ts=52984312ssb, mod=64 level=1] sensor_contact=1
6783:[ts=52992124ssb, mod=64 level=1] measurement=65
6784:[ts=53000000ssb, mod=64 level=1] rr=160
6902:[ts=53921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x41 0xa9 0x03
6906:[ts=53953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
6908:[ts=53968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
6910:[ts=53984312ssb, mod=64 level=1] sensor_contact=1
6911:[ts=53992124ssb, mod=64 level=1] measurement=65
6912:[ts=54000000ssb, mod=64 level=1] rr=169
7030:[ts=54921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3f 0x00 0x04
7034:[ts=54953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7036:[ts=54968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7038:[ts=54984312ssb, mod=64 level=1] sensor_contact=1
7039:[ts=54992124ssb, mod=64 level=1] measurement=63
7040:[ts=55000000ssb, mod=64 level=1] rr=0
7158:[ts=55921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3c 0x22 0x04
7162:[ts=55953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7164:[ts=55968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7166:[ts=55984312ssb, mod=64 level=1] sensor_contact=1
7167:[ts=55992124ssb, mod=64 level=1] measurement=60
7168:[ts=56000000ssb, mod=64 level=1] rr=34
7286:[ts=56921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3e 0xd3 0x03
7290:[ts=56953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7292:[ts=56968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7294:[ts=56984312ssb, mod=64 level=1] sensor_contact=1
7295:[ts=56992124ssb, mod=64 level=1] measurement=62
7296:[ts=57000000ssb, mod=64 level=1] rr=211
7414:[ts=57921816ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3e 0xda 0x03
7418:[ts=57953064ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7420:[ts=57968688ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7422:[ts=57984312ssb, mod=64 level=1] sensor_contact=1
7423:[ts=57992124ssb, mod=64 level=1] measurement=62
7424:[ts=58000000ssb, mod=64 level=1] rr=218
7549:[ts=58976500ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3d 0x01 0x04
7552:[ts=59000000ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7554:[ts=59015624ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7556:[ts=59031248ssb, mod=64 level=1] sensor_contact=1
7557:[ts=59039060ssb, mod=64 level=1] measurement=61
7558:[ts=59046872ssb, mod=64 level=1] rr=1
7677:[ts=59976500ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x3d 0xf5 0x03
7680:[ts=60000000ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
7682:[ts=60015624ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
7684:[ts=60031248ssb, mod=64 level=1] sensor_contact=1
7685:[ts=60039060ssb, mod=64 level=1] measurement=61
7686:[ts=60046872ssb, mod=64 level=1] rr=245
7792:[ts=60874944ssb, mod=4 level=0] Disconnection Complete: status=0 handle=1 reason=59
7794:[ts=60890568ssb, mod=64 level=1] disconnect; reason=571 handle=1 our_ota_addr_type=0 our_ota_addr=0a:0a:0a:0a:0a:0a our_id_addr_type=0 our_id_addr=0a:0a:0a:0a:0a:0a peer_ota_addr_type=0 peer_ota_addr=00:22:d0:2a:e4:a3 peer_id_addr_type=0 peer_id_addr=00:22:d0:2a:e4:a3 conn_itvl=40 conn_latency=0 supervision_timeout=256 encrypted=0 authenticated=0 bonded=0
```
> Gap params update succeeds, but times out immediately after
> -----------------------------------------------------------
>
> Key: MYNEWT-526
> URL: https://issues.apache.org/jira/browse/MYNEWT-526
> Project: Mynewt
> Issue Type: Bug
> Components: Nimble
> Affects Versions: v1_0_0_beta1
> Environment: macos sierra, gcc version 5.4.1 20160919
> Reporter: Jacob
> Assignee: Łukasz Rymanowski
>
> Modification of blecent, connecting and subscribing to my polar HRM.
> My monitor (consistently) connects and subscribes and gets notifications for like 30 seconds before it does a successful gap params update, and then promptly times out.
> I havent confirmed this yet but grammar wise you do seem to be mixing terms, timeout_multiplier and supervision_timeout are separate things in the spec
> l2cap_params->timeout_multiplier = params->supervision_timeout;
> Perhaps the timeout_multiplier should be multiplied by 10ms to get the supervision_timeout?
> 3924:[ts=30656208ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
> 3926:[ts=30671832ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
> 3928:[ts=30687456ssb, mod=64 level=1] 0x16:0x00:0xee:0x02
> 3929:[ts=30695268ssb, mod=64 level=1] pkthdr_len=16; om_len=4 ble_hs_hci_evt_acl_process(): handle=1 pb=2 len=13 data=0x09 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x55 0xda 0x02 0xc9 0x02
> 4052:[ts=31656208ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
> 4054:[ts=31671832ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=6
> 4056:[ts=31687456ssb, mod=64 level=1] 0x16:0x55:0xda:0x02:0xc9:0x02
> 4057:[ts=31695268ssb, mod=64 level=1] pkthdr_len=16; om_len=6 ble_hs_hci_evt_acl_process(): handle=1 pb=2 len=16 data=0x0c 0x00 0x05 0x00 0x12 0x01 0x08 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02
> 4148:[ts=32406224ssb, mod=4 level=0] L2CAP - rxed signalling msg: 0x12 0x01 0x08 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02
> 4151:[ts=32429660ssb, mod=4 level=1] GAP procedure initiated: connection parameter update; conn_handle=1 itvl_min=250 itvl_max=400 latency=1 supervision_timeout=600 min_ce_len=16 max_ce_len
> 4156:[ts=32468720ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08 ocf=0x13 len=14
> 4158:[ts=32484344ssb, mod=4 level=0] 0x13 0x20 0x0e 0x01 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02 0x10 0x00 0x00 0x03
> 4159:[ts=32492156ssb, mod=4 level=0] Command Status: status=0 cmd_pkts=1 ocf=0x13 ogf=0x8
> 4162:[ts=32515592ssb, mod=4 level=0] host tx hci data; handle=1 length=10
> 4163:[ts=32523404ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00 0x0a 0x00 0x06 0x00 0x05 0x00 0x13 0x01 0x02 0x00 0x00 0x00
> 4171:[ts=32585900ssb, mod=4 level=0] Number of Completed Packets: num_handles=1
> 4173:[ts=32601524ssb, mod=4 level=0] handle:1 pkts:1
> 4178:[ts=32640584ssb, mod=4 level=0] ble_hs_hci_evt_acl_process(): handle=1 pb=2 len=11 data=0x07 0x00 0x04 0x00 0x1b 0x11 0x00 0x16 0x56 0xc0 0x02
> 4181:[ts=32664020ssb, mod=4 level=0] rxed att command: notify req; conn=1 handle=0x0011
> 4183:[ts=32679644ssb, mod=64 level=1] received notification; conn_handle=1 attr_handle=17 attr_len=4
> 4185:[ts=32695268ssb, mod=64 level=1] 0x16:0x56:0xc0:0x02
> 4186:[ts=32703080ssb, mod=64 level=1] pkthdr_len=16; om_len=4 LE Connection Update Complete. handle=1 itvl=400 latency=1 timeout=600
> 4978:[ts=38890568ssb, mod=4 level=0] Disconnection Complete: status=0 handle=1 reason=8
> 4980:[ts=38906192ssb, mod=64 level=1] disconnect; reason=520 handle=1 our_ota_addr_type=0 our_ota_addr=0c:0c:0c:0c:0c:0c our_id_addr_type=0 our_id_addr=0c:0c:0c:0c:0c:0c peer_ota_addr_type=0 peer_ota_addr=00:22:d0:2a:e4:a3 peer_id_addr_type=0 peer_id_addr=00:22:d0:2a:e4:a3 conn_itvl=400 conn_latency=1 supervision_timeout=600 encrypted=0 authenticated=0 bonded=0
> 4988:[ts=38968688ssb, mod=4 level=1] GAP procedure initiated: discovery; own_addr_type=0 filter_policy=0 passive=1 limited=0 filter_duplicates=1 duration=forever
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)