You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mynewt.apache.org by Jan Becker <jb...@clickbar.rocks> on 2017/06/09 07:03:55 UTC

BLE connection timeout

Hey,

I've just been getting started with mynewt and build a small program
that is very similar to the bleprph example provided by you.
The board is a readbear blend v2 (based on the nRF52832 chipset) and I
have the latest development of mynewt-core installed.
However, it seems like the connection to my xperia z5 running Android
7.0 always times out after 40 seconds with reason 34
(BLE_ERR_LMP_LL_RSP_TMO).
Here is the log:

...
011403 [ts=89085932ssb, mod=4 level=0] Disconnection Complete: status=0
handle=1 reason=34
011405 [ts=89101556ssb, mod=64 level=1] connection updated; status=546
handle=1 our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a
our_id_addr_type=0 our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
011414 [ts=89171864ssb, mod=64 level=1]
011415 [ts=89179676ssb, mod=64 level=1] subscribe event; conn_handle=1
attr_handle=14 reason=2 prevn=0 curn=0 previ=1 curi=0
011418 [ts=89203112ssb, mod=64 level=1] subscribe event; conn_handle=1
attr_handle=18 reason=2 prevn=1 curn=0 previ=0 curi=0
011422 [ts=89234360ssb, mod=64 level=1] disconnect; reason=546 handle=1
our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a our_id_addr_type=0
our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
011431 [ts=89304668ssb, mod=64 level=1]
011432 [ts=89312480ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x0007 len=0
011434 [ts=89328104ssb, mod=4 level=0] 0x07 0x20 0x00
011435 [ts=89335916ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8 ocf=0x7 status=0
011438 [ts=89359352ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x0008 len=32
011440 [ts=89374976ssb, mod=4 level=0] 0x08 0x20 0x20 0x12 0x02 0x01
0x06 0x0b 0x09 0x53 0x70 0x65 0x65 0x64 0x54 0x72 0x61 0x63 0x6b 0x02
0x0a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
011445 [ts=89414036ssb, mod=4 level=0] Command complete: cmd_pkts=1
ogf=0x8 ocf=0x8 status=0
011448 [ts=89437472ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
ocf=0x0009 len=32
011450 [ts=89453096ssb, mod=4 level=0] 0x09 0x20 0x20 0x12 0x11 0x07
0x23 0x7e 0xe9 0xa8 0xf5 0xcd 0xe0 0xfc 0x8a 0x84 0x4d 0xdf 0xf7 0x3c
0x65 0xb3 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
...

Then I tried the same with my other test device, a wileyfox swift 2, and
everything was fine.
At first it seems like there is something wrong with my phone, but I
never had such issues when running Nordic's Softdevice on the board.
So, what does Softdevice do what nimble does not (or does wrong)?
Unfortunately, I don't have the resources or knowledge to further
investigate this.

What do you think might be the issue here?

Thanks,
Jan

Re: BLE connection timeout

Posted by will sanfilippo <wi...@runtime.io>.
Yes, we have seen this issue with a number of phones. Basically, the nimble controller was starting certain control procedures without first attempting to determine if the other controller supports those procedures. The spec allows for this but some controllers did not like it. There are a number of changes on the bluetooth5 branch that change how the nimble controller starts control procedures and those changes should allow compatibility with the other controllers.

> On Jun 9, 2017, at 9:46 AM, Jan Becker <jb...@clickbar.rocks> wrote:
> 
> Hey,
> 
> Thank you for the quick response.
> I went for option 1) and disabled the DATA_LEN_EXT feature, which seems
> to fix the timeout when connecting to my Z5.
> Good to hear that there is already a fix for this, I'm looking forward
> to a merge into master!
> 
> (FYI I could also reproduce the issue on a few other phones, including a
> Nexus 6P)
> 
> Jan
> 
> Am 09.06.2017 um 17:44 schrieb will sanfilippo:
>> Jan:
>> 
>> I am not 100% sure but we have seen issues with certain phones due to how the nimble stack controller starts some LL control procedures. This has been addressed in a development branch but I do not think it has been merged into the master branch yet (it will in the upcoming release).
>> 
>> I could go into more details if you like but all you probably want is a fix. There are two things you could try:
>> 
>> 1) This might be a temporary work-around: disable data length extension. You can do this by setting the following syscfg variable to 0: BLE_LL_CFG_FEAT_DATA_LEN_EXT. A simple way to do this is to go in and hack the syscfg.yml in net/nimble/controller/ and set the value to 0. If that works you can set that in your target.
>> 
>> - or -
>> 
>> 2) Get the bluetooth5 branch. I think this has the fixes in it.
>> 
>> Let us know how it goes.
>> 
>>> On Jun 9, 2017, at 12:03 AM, Jan Becker <jb...@clickbar.rocks> wrote:
>>> 
>>> Hey,
>>> 
>>> I've just been getting started with mynewt and build a small program
>>> that is very similar to the bleprph example provided by you.
>>> The board is a readbear blend v2 (based on the nRF52832 chipset) and I
>>> have the latest development of mynewt-core installed.
>>> However, it seems like the connection to my xperia z5 running Android
>>> 7.0 always times out after 40 seconds with reason 34
>>> (BLE_ERR_LMP_LL_RSP_TMO).
>>> Here is the log:
>>> 
>>> ...
>>> 011403 [ts=89085932ssb, mod=4 level=0] Disconnection Complete: status=0
>>> handle=1 reason=34
>>> 011405 [ts=89101556ssb, mod=64 level=1] connection updated; status=546
>>> handle=1 our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a
>>> our_id_addr_type=0 our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
>>> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
>>> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
>>> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
>>> 011414 [ts=89171864ssb, mod=64 level=1]
>>> 011415 [ts=89179676ssb, mod=64 level=1] subscribe event; conn_handle=1
>>> attr_handle=14 reason=2 prevn=0 curn=0 previ=1 curi=0
>>> 011418 [ts=89203112ssb, mod=64 level=1] subscribe event; conn_handle=1
>>> attr_handle=18 reason=2 prevn=1 curn=0 previ=0 curi=0
>>> 011422 [ts=89234360ssb, mod=64 level=1] disconnect; reason=546 handle=1
>>> our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a our_id_addr_type=0
>>> our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
>>> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
>>> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
>>> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
>>> 011431 [ts=89304668ssb, mod=64 level=1]
>>> 011432 [ts=89312480ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>>> ocf=0x0007 len=0
>>> 011434 [ts=89328104ssb, mod=4 level=0] 0x07 0x20 0x00
>>> 011435 [ts=89335916ssb, mod=4 level=0] Command complete: cmd_pkts=1
>>> ogf=0x8 ocf=0x7 status=0
>>> 011438 [ts=89359352ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>>> ocf=0x0008 len=32
>>> 011440 [ts=89374976ssb, mod=4 level=0] 0x08 0x20 0x20 0x12 0x02 0x01
>>> 0x06 0x0b 0x09 0x53 0x70 0x65 0x65 0x64 0x54 0x72 0x61 0x63 0x6b 0x02
>>> 0x0a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
>>> 011445 [ts=89414036ssb, mod=4 level=0] Command complete: cmd_pkts=1
>>> ogf=0x8 ocf=0x8 status=0
>>> 011448 [ts=89437472ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>>> ocf=0x0009 len=32
>>> 011450 [ts=89453096ssb, mod=4 level=0] 0x09 0x20 0x20 0x12 0x11 0x07
>>> 0x23 0x7e 0xe9 0xa8 0xf5 0xcd 0xe0 0xfc 0x8a 0x84 0x4d 0xdf 0xf7 0x3c
>>> 0x65 0xb3 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
>>> ...
>>> 
>>> Then I tried the same with my other test device, a wileyfox swift 2, and
>>> everything was fine.
>>> At first it seems like there is something wrong with my phone, but I
>>> never had such issues when running Nordic's Softdevice on the board.
>>> So, what does Softdevice do what nimble does not (or does wrong)?
>>> Unfortunately, I don't have the resources or knowledge to further
>>> investigate this.
>>> 
>>> What do you think might be the issue here?
>>> 
>>> Thanks,
>>> Jan
> 


Re: BLE connection timeout

Posted by Jan Becker <jb...@clickbar.rocks>.
Hey,

Thank you for the quick response.
I went for option 1) and disabled the DATA_LEN_EXT feature, which seems
to fix the timeout when connecting to my Z5.
Good to hear that there is already a fix for this, I'm looking forward
to a merge into master!

(FYI I could also reproduce the issue on a few other phones, including a
Nexus 6P)

Jan

Am 09.06.2017 um 17:44 schrieb will sanfilippo:
> Jan:
>
> I am not 100% sure but we have seen issues with certain phones due to how the nimble stack controller starts some LL control procedures. This has been addressed in a development branch but I do not think it has been merged into the master branch yet (it will in the upcoming release).
>
> I could go into more details if you like but all you probably want is a fix. There are two things you could try:
>
> 1) This might be a temporary work-around: disable data length extension. You can do this by setting the following syscfg variable to 0: BLE_LL_CFG_FEAT_DATA_LEN_EXT. A simple way to do this is to go in and hack the syscfg.yml in net/nimble/controller/ and set the value to 0. If that works you can set that in your target.
>
> - or -
>
> 2) Get the bluetooth5 branch. I think this has the fixes in it.
>
> Let us know how it goes.
>
>> On Jun 9, 2017, at 12:03 AM, Jan Becker <jb...@clickbar.rocks> wrote:
>>
>> Hey,
>>
>> I've just been getting started with mynewt and build a small program
>> that is very similar to the bleprph example provided by you.
>> The board is a readbear blend v2 (based on the nRF52832 chipset) and I
>> have the latest development of mynewt-core installed.
>> However, it seems like the connection to my xperia z5 running Android
>> 7.0 always times out after 40 seconds with reason 34
>> (BLE_ERR_LMP_LL_RSP_TMO).
>> Here is the log:
>>
>> ...
>> 011403 [ts=89085932ssb, mod=4 level=0] Disconnection Complete: status=0
>> handle=1 reason=34
>> 011405 [ts=89101556ssb, mod=64 level=1] connection updated; status=546
>> handle=1 our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a
>> our_id_addr_type=0 our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
>> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
>> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
>> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
>> 011414 [ts=89171864ssb, mod=64 level=1]
>> 011415 [ts=89179676ssb, mod=64 level=1] subscribe event; conn_handle=1
>> attr_handle=14 reason=2 prevn=0 curn=0 previ=1 curi=0
>> 011418 [ts=89203112ssb, mod=64 level=1] subscribe event; conn_handle=1
>> attr_handle=18 reason=2 prevn=1 curn=0 previ=0 curi=0
>> 011422 [ts=89234360ssb, mod=64 level=1] disconnect; reason=546 handle=1
>> our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a our_id_addr_type=0
>> our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
>> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
>> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
>> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
>> 011431 [ts=89304668ssb, mod=64 level=1]
>> 011432 [ts=89312480ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>> ocf=0x0007 len=0
>> 011434 [ts=89328104ssb, mod=4 level=0] 0x07 0x20 0x00
>> 011435 [ts=89335916ssb, mod=4 level=0] Command complete: cmd_pkts=1
>> ogf=0x8 ocf=0x7 status=0
>> 011438 [ts=89359352ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>> ocf=0x0008 len=32
>> 011440 [ts=89374976ssb, mod=4 level=0] 0x08 0x20 0x20 0x12 0x02 0x01
>> 0x06 0x0b 0x09 0x53 0x70 0x65 0x65 0x64 0x54 0x72 0x61 0x63 0x6b 0x02
>> 0x0a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
>> 011445 [ts=89414036ssb, mod=4 level=0] Command complete: cmd_pkts=1
>> ogf=0x8 ocf=0x8 status=0
>> 011448 [ts=89437472ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
>> ocf=0x0009 len=32
>> 011450 [ts=89453096ssb, mod=4 level=0] 0x09 0x20 0x20 0x12 0x11 0x07
>> 0x23 0x7e 0xe9 0xa8 0xf5 0xcd 0xe0 0xfc 0x8a 0x84 0x4d 0xdf 0xf7 0x3c
>> 0x65 0xb3 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
>> ...
>>
>> Then I tried the same with my other test device, a wileyfox swift 2, and
>> everything was fine.
>> At first it seems like there is something wrong with my phone, but I
>> never had such issues when running Nordic's Softdevice on the board.
>> So, what does Softdevice do what nimble does not (or does wrong)?
>> Unfortunately, I don't have the resources or knowledge to further
>> investigate this.
>>
>> What do you think might be the issue here?
>>
>> Thanks,
>> Jan


Re: BLE connection timeout

Posted by will sanfilippo <wi...@runtime.io>.
Jan:

I am not 100% sure but we have seen issues with certain phones due to how the nimble stack controller starts some LL control procedures. This has been addressed in a development branch but I do not think it has been merged into the master branch yet (it will in the upcoming release).

I could go into more details if you like but all you probably want is a fix. There are two things you could try:

1) This might be a temporary work-around: disable data length extension. You can do this by setting the following syscfg variable to 0: BLE_LL_CFG_FEAT_DATA_LEN_EXT. A simple way to do this is to go in and hack the syscfg.yml in net/nimble/controller/ and set the value to 0. If that works you can set that in your target.

- or -

2) Get the bluetooth5 branch. I think this has the fixes in it.

Let us know how it goes.

> On Jun 9, 2017, at 12:03 AM, Jan Becker <jb...@clickbar.rocks> wrote:
> 
> Hey,
> 
> I've just been getting started with mynewt and build a small program
> that is very similar to the bleprph example provided by you.
> The board is a readbear blend v2 (based on the nRF52832 chipset) and I
> have the latest development of mynewt-core installed.
> However, it seems like the connection to my xperia z5 running Android
> 7.0 always times out after 40 seconds with reason 34
> (BLE_ERR_LMP_LL_RSP_TMO).
> Here is the log:
> 
> ...
> 011403 [ts=89085932ssb, mod=4 level=0] Disconnection Complete: status=0
> handle=1 reason=34
> 011405 [ts=89101556ssb, mod=64 level=1] connection updated; status=546
> handle=1 our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a
> our_id_addr_type=0 our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
> 011414 [ts=89171864ssb, mod=64 level=1]
> 011415 [ts=89179676ssb, mod=64 level=1] subscribe event; conn_handle=1
> attr_handle=14 reason=2 prevn=0 curn=0 previ=1 curi=0
> 011418 [ts=89203112ssb, mod=64 level=1] subscribe event; conn_handle=1
> attr_handle=18 reason=2 prevn=1 curn=0 previ=0 curi=0
> 011422 [ts=89234360ssb, mod=64 level=1] disconnect; reason=546 handle=1
> our_ota_addr_type=0 our_ota_addr=c0:fa:ac:cf:fa:0a our_id_addr_type=0
> our_id_addr=c0:fa:ac:cf:fa:0a peer_ota_addr_type=1
> peer_ota_addr=72:0f:3c:e1:f5:75 peer_id_addr_type=1
> peer_id_addr=72:0f:3c:e1:f5:75 conn_itvl=39 conn_latency=0
> supervision_timeout=2000 encrypted=0 authenticated=0 bonded=0
> 011431 [ts=89304668ssb, mod=64 level=1]
> 011432 [ts=89312480ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
> ocf=0x0007 len=0
> 011434 [ts=89328104ssb, mod=4 level=0] 0x07 0x20 0x00
> 011435 [ts=89335916ssb, mod=4 level=0] Command complete: cmd_pkts=1
> ogf=0x8 ocf=0x7 status=0
> 011438 [ts=89359352ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
> ocf=0x0008 len=32
> 011440 [ts=89374976ssb, mod=4 level=0] 0x08 0x20 0x20 0x12 0x02 0x01
> 0x06 0x0b 0x09 0x53 0x70 0x65 0x65 0x64 0x54 0x72 0x61 0x63 0x6b 0x02
> 0x0a 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
> 011445 [ts=89414036ssb, mod=4 level=0] Command complete: cmd_pkts=1
> ogf=0x8 ocf=0x8 status=0
> 011448 [ts=89437472ssb, mod=4 level=0] ble_hs_hci_cmd_send: ogf=0x08
> ocf=0x0009 len=32
> 011450 [ts=89453096ssb, mod=4 level=0] 0x09 0x20 0x20 0x12 0x11 0x07
> 0x23 0x7e 0xe9 0xa8 0xf5 0xcd 0xe0 0xfc 0x8a 0x84 0x4d 0xdf 0xf7 0x3c
> 0x65 0xb3 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00 0x00
> ...
> 
> Then I tried the same with my other test device, a wileyfox swift 2, and
> everything was fine.
> At first it seems like there is something wrong with my phone, but I
> never had such issues when running Nordic's Softdevice on the board.
> So, what does Softdevice do what nimble does not (or does wrong)?
> Unfortunately, I don't have the resources or knowledge to further
> investigate this.
> 
> What do you think might be the issue here?
> 
> Thanks,
> Jan