[
https://issues.apache.org/jira/browse/MYNEWT-526?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15887716#comment-15887716
]
Łukasz Rymanowski commented on MYNEWT-526:
------------------------------------------
Any updates on this? Could you also say how often it happens to you.
Nimble controller seems to also do everything good. Just did a test between two
mynewt devices and just set exact same parameters and it works just fine
[10:49:50:574] b update conn=1 itvl_min=250 itvl_max=400 latency=1 timeout=600
min_ce_len=16 max_ce_len=768␊
[10:49:50:582] ␍725826:[ts=1375548296ssb, 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␍␊
[10:49:50:619] 725831:[ts=1375587356ssb, mod=4 level=0] ble_hs_hci_cmd_send:
ogf=0x08 ocf=0x0013 len=14␍␊
[10:49:50:641] 725834:[ts=1375610792ssb, mod=4 level=0] 0x13 0x20 0x0e 0x01
0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02 0x10 0x00 0x00 0x03 ␍␊
[10:49:50:670] 725837:[ts=1375634228ssb, mod=4 level=0] Command Status:
status=0 cmd_pkts=1 ocf=0x13 ogf=0x8␍␊
[10:49:51:030] 725883:[ts=1375993580ssb, mod=4 level=0] LE Connection Update
Complete. handle=1 itvl=400 latency=1 timeout=600␍␊
[10:49:51:055] 725887:connection updated; status=0 handle=1 our_ota_addr_type=0
our_ota_addr=11:22:33:aa:bb:cc our_id_addr_type=0 our_id_addr=11:22:33:aa:bb:cc
peer_ota_addr_type=0 peer_ota_addr=00:11:00:11:00:11 peer_id_addr_type=0
peer_id_addr=00:11:00:11:00:11 conn_itvl=400 conn_latency=1
supervision_timeout=600 encrypted=0 authenticated=0 bonded=0␍
I did same with Zephyr - and in that case I did update connection while
receiving notifications and it also works just fine.
[11:01:05:385] 812202:[ts=2050360808ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:05:399] 812204:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x5f␍␊
[11:01:06:352] 812326:[ts=2051329560ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x60 ␍␊
[11:01:06:382] 812330:[ts=2051360808ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:06:399] 812332:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x60␍␊
[11:01:07:184] b update conn=1 itvl_min=250 itvl_max=400 latency=1 timeout=600
min_ce_len=16 max_ce_len=768␊
[11:01:07:193] ␍812433:[ts=2052165508ssb, 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␍␊
[11:01:07:234] 812439:[ts=2052212380ssb, mod=4 level=0] ble_hs_hci_cmd_send:
ogf=0x08 ocf=0x0013 len=14␍␊
[11:01:07:250] 812441:[ts=2052228004ssb, mod=4 level=0] 0x13 0x20 0x0e 0x01
0x00 0xfa 0x00 0x90 0x01 0x01 0x00 0x58 0x02 0x10 0x00 0x00 0x03 ␍␊
[11:01:07:276] 812444:[ts=2052251440ssb, mod=4 level=0] Command Status:
status=0 cmd_pkts=1 ocf=0x13 ogf=0x8␍␊
[11:01:07:352] 812454:[ts=2052329560ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x61 ␍␊
[11:01:07:382] 812458:[ts=2052360808ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:07:402] 812460:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x61␍␊
[11:01:07:652] 812492:[ts=2052626416ssb, mod=4 level=0] LE Connection Update
Complete. handle=1 itvl=400 latency=1 timeout=600␍␊
[11:01:07:676] 812495:connection updated; status=0 handle=1 our_ota_addr_type=0
our_ota_addr=11:22:33:aa:bb:cc our_id_addr_type=0 our_id_addr=11:22:33:aa:bb:cc
peer_ota_addr_type=1 peer_ota_addr=43:08:3f:84:f4:f6 peer_id_addr_type=1
peer_id_addr=43:08:3f:84:f4:f6 conn_itvl=400 conn_latency=1
supervision_timeout=600 encrypted=0 authenticated=0 bonded=0␍␊
[11:01:08:652] 812620:[ts=2053626416ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x62 ␍␊
[11:01:08:679] 812624:[ts=2053657664ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:08:699] 812626:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x62␍␊
[11:01:09:652] 812748:[ts=2054626416ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x63 ␍␊
[11:01:09:682] 812752:[ts=2054657664ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:09:696] 812754:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x63␍␊
[11:01:10:652] 812876:[ts=2055626416ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x64 ␍␊
[11:01:10:679] 812880:[ts=2055657664ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:10:696] 812882:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x64␍␊
[11:01:11:652] 813004:[ts=2056626416ssb, mod=4 level=0]
ble_hs_hci_evt_acl_process(): conn_handle=1 pb=2 len=9 data=0x05 0x00 0x04 0x00
0x1b 0x08 0x00 0x06 0x65 ␍␊
[11:01:11:679] 813008:[ts=2056657664ssb, mod=4 level=0] rxed att command:
notify req; conn=1 handle=0x0008␍␊
[11:01:11:697] 813010:notification rx event; attr_handle=8 indication=0 len=2
data=0x06:0x65␍␊
> 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)
