[
https://issues.apache.org/jira/browse/MYNEWT-526?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15896767#comment-15896767
]
Jacob commented on MYNEWT-526:
------------------------------
OK. TLDR I still think theres some bad math in here.
OK. so the output has been looking different with the recent changes to the
stack around here.
As I said above, I get error code now? 571 or 59 on top of HCI error (512)? Not
sure whats up with that, but Łukasz asked me to wireshark
I have some wireshark pcap if you like, but it shows Connection Parameter
Update Response Rejected
wireshark says requested
min interval 250 (312.5msec)
max interval 400 (500msec)
latency 1ll connection event
multiplier 600 (6sec)
Hard to tell with optimizations on, but were being thrown out of
ble_gap_validate_conn_params
here
if (params->supervision_timeout <=
(((1 + params->latency) * params->itvl_max) * 6 / 4)) {
return false;
}
(gdb) set $foo = (((1 + params->latency) * params->itvl_max) * 6 / 4)
(gdb) p $foo
$3 = 1200
(gdb) set $foo2 = params->supervision_timeout <= (((1 + params->latency) *
params->itvl_max) * 6 / 4)
(gdb) p $foo2
$4 = 1
and 600 is indeed <= 1200
can I confirm that the min is 1200?
"The Supervision_Timeout parameter shall define the link supervision timeout
for the LE link. The Supervision_Timeout in milliseconds shall be larger than (1
+ Conn_Latency) * Conn_Interval_Max * 2, where Conn_Interval_Max is given
in milliseconds. ""
were definitely mixing ms and intervals in this calculation
timeout_MS >= (1 + Conn_Latency) * Conn_Interval_Max_MS * 2
6000 >= 2 * 500 * 2
6000 >= 2000
so left should be * 10 so right should be /10
timeout >= (1 + Conn_Latency) * Conn_Interval_Max_MS * 2 /100
and Conn_Interval_Max_MS = conn_interval * 1.25
timeout >= (1 + Conn_Latency) * conn_interval * 1.25 * 2 /10
timeout >= (1 + Conn_Latency) * conn_interval / 4
600 >= (1 + 1) * 400 / 4
600 >= 200
ratios work out
so should be
if (params->supervision_timeout <=
(((1 + params->latency) * params->itvl_max) / 4)) {
return false;
}
When implemented, we do pass validation and receive the LE Connection Update
Complete before it fails again with reason 520, which is what it was failing
with when I originally reported this
5832:[ts=45562464ssb, mod=4 level=0] ble_hs_hci_evt_acl_process():
conn_handle=1 pb=2 len=16 data=0x0c 0x00 0x05 0x00 0x12 0x02 0x08 0x00 0xfa
0x00 0x90 0x01 0x01 0x00 0x58 0x02
5836:[ts=45593712ssb, mod=4 level=0] L2CAP - rxed signalling msg: 0x12 0x02
0x08 0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02
5838:[ts=45609336ssb, 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
5843:[ts=45648396ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0013
len=14
5845:[ts=45664020ssb, mod=4 level=0] 0x13 0x20 0x0e 0x01 0x00 0xfa 0x00 0x90
0x01 0x01 0x00 0x58 0x02 0x10 0x00 0x00 0x03
5846:[ts=45671832ssb, mod=4 level=0] Command Status: status=0 cmd_pkts=1
ocf=0x13 ogf=0x8
5848:[ts=45687456ssb, mod=4 level=0] host tx hci data; handle=1 length=10
5849:[ts=45695268ssb, mod=4 level=0] ble_hs_hci_acl_tx(): 0x01 0x00 0x0a 0x00
0x06 0x00 0x05 0x00 0x13 0x02 0x02 0x00 0x00 0x00
5851:[ts=45710892ssb, mod=4 level=0] Number of Completed Packets: num_handles=1
5853:[ts=45726516ssb, mod=4 level=0] handle:1 pkts:1
5896:[ts=46062496ssb, mod=4 level=0] LE Connection Update Complete. handle=1
itvl=400 latency=1 timeout=600
6664:[ts=52062496ssb, mod=4 level=0] Disconnection Complete: status=0 handle=1
reason=8
6667:[ts=52085932ssb, mod=64 level=1] disconnect; reason=520 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=400 conn_latency=1
supervision_timeout=600 encrypted=0 authenticated=0 bonded=0
I havent dug further yet, but I still think theres more bad math around timeouts
> 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)
