2014-06-25 13:23:43

by Ryan Press

[permalink] [raw]
Subject: Fwd: LE mouse reconnect problem

Hi Luiz,

Yes it will repeat the scan every few seconds.

I paired the device in the Gnome applet. In the bluetoothctl I could
see the pair and trust messages like so:

[NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
[CHG] Device C5:8C:97:E6:9C:81 Connected: yes
[CHG] Device C5:8C:97:E6:9C:81 UUIDs:
00001800-0000-1000-8000-00805f9b34fb
00001801-0000-1000-8000-00805f9b34fb
0000180a-0000-1000-8000-00805f9b34fb
0000180f-0000-1000-8000-00805f9b34fb
00001812-0000-1000-8000-00805f9b34fb
[CHG] Device C5:8C:97:E6:9C:81 Paired: yes
[CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
[CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001

Thanks,

Ryan


On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>
> Hi Ryan,
>
> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
> > off/on.
> >
> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
> > fine, and it will continue to work until I turn the mouse off/on or
> > turn the computer off/on. Then it won't reconnect automatically. If
> > I go into bluetoothctl I can connect it again and it will then work.
> >
> > I looked at bluetoothd and it seems to be doing the LE scan with:
> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
> >
> > I look also at hcidump and I see:
> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
> > bdaddr 39:6D:E2:EC:17:37
> >> HCI Event: Command Complete (0x0e) plen 4
> > LE Set Random Address (0x08|0x0005) ncmd 1
> > status 0x00
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> > type 0x01 (active)
> > interval 11.250ms window 11.250ms
> > own address: 0x01 (Random) policy: All
> >> HCI Event: Command Complete (0x0e) plen 4
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > status 0x00
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > value 0x01 (scanning enabled)
> > filter duplicates 0x01 (enabled)
> >> HCI Event: Command Complete (0x0e) plen 4
> > LE Set Scan Enable (0x08|0x000c) ncmd 2
> > status 0x00
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > value 0x00 (scanning disabled)
> > filter duplicates 0x00 (disabled)
> >
> >
> > It doesn't seem to be finding anything? Is there something else I should try?
>
> Does it continue to scan or it scan a single time and stops, and have
> you paired or just connect?
>
>
> --
> Luiz Augusto von Dentz


2014-06-29 20:02:38

by Scott James Remnant

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

On Sun, Jun 29, 2014 at 12:56 PM, Marcel Holtmann <[email protected]> wrote:

>>> the same applies to the HP mouse btw.
>>>
>>
>> Which HP Mouse are you referring to?
>>
>> An HP Mouse I have uses general connectable advertising when it wants
>> to reconnect.
>
> it says HP Mouse Z8000. And at least the one that I have is using directed advertising for re-connection.
>

Don't have one of those, I'll grab for testing.

The one I have just describes itself as "HP BLE Mouse"

Scott
--
Scott James Remnant | Chrome OS Systems | [email protected] | Google

2014-06-29 19:56:46

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Scott,

>> the same applies to the HP mouse btw.
>>
>
> Which HP Mouse are you referring to?
>
> An HP Mouse I have uses general connectable advertising when it wants
> to reconnect.

it says HP Mouse Z8000. And at least the one that I have is using directed advertising for re-connection.

Regards

Marcel


2014-06-29 19:37:17

by Scott James Remnant

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

On Sun, Jun 29, 2014 at 12:19 PM, Marcel Holtmann <[email protected]> wrote:

> the same applies to the HP mouse btw.
>

Which HP Mouse are you referring to?

An HP Mouse I have uses general connectable advertising when it wants
to reconnect.

Scott
--
Scott James Remnant | Chrome OS Systems | [email protected] | Google

2014-06-29 19:19:13

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Scott,

>> The biggest problem here is that even if you are trying to be private and doing everything right, the mouse will broadcast your public address every time it tries to reconnect. So thank you Microsoft for forcing us to be trackable.
>>
>
> \o/
>
> (I'd had an open bug to investigate why this mouse wasn't
> reconnecting, y'all beat me to it)

the same applies to the HP mouse btw.

I have seen the same problem using the Microsoft and HP mice on OS X about a month ago, but I couldn't be bothered to investigate it. OS X also uses non-resolvable private addresses for scanning.

>> Now the biggest problem is that with 3.15 and 3.16-rcX kernels we would need to go back to using our identity address for discovery. This means active scanning and it means we are broadcasting our identity address to everybody when trying to find this mouse. I rather not do that.
>>
>
> I think we would rather just document that this mouse isn't going to
> reconnect, since you can at least use the UI to reconnect by hand.
> Switching back to active scanning on the identity address would make
> our devices trackable, which is very definitely not on our wish list.

Besides a minor issue with the GATT channel in bluetoothd on auto-reconnection, I have this nicely working now using the kernel passive background scanning. Which means we can use non-resolvable private addresses for the discovery. However the earliest kernel this goes in will be 3.17 and I still need some minor cleanups here and there to make this smooth.

What we most likely are going to do is allow discovery using identity address for 3.15 and 3.16 and then with 3.17 we are switching back to privacy for discovery.

Regards

Marcel


2014-06-29 19:03:06

by Scott James Remnant

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

On Sun, Jun 29, 2014 at 2:43 AM, Marcel Holtmann <[email protected]> wrot=
e:

> The biggest problem here is that even if you are trying to be private and=
doing everything right, the mouse will broadcast your public address every=
time it tries to reconnect. So thank you Microsoft for forcing us to be tr=
ackable.
>

\o/

(I'd had an open bug to investigate why this mouse wasn't
reconnecting, y'all beat me to it)

> Now the biggest problem is that with 3.15 and 3.16-rcX kernels we would n=
eed to go back to using our identity address for discovery. This means acti=
ve scanning and it means we are broadcasting our identity address to everyb=
ody when trying to find this mouse. I rather not do that.
>

I think we would rather just document that this mouse isn't going to
reconnect, since you can at least use the UI to reconnect by hand.
Switching back to active scanning on the identity address would make
our devices trackable, which is very definitely not on our wish list.

Scott
--=20
Scott James Remnant | Chrome OS Systems | [email protected] | Google

2014-06-29 19:01:49

by Ryan Press

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Marcel,

On Sun, Jun 29, 2014 at 10:52 AM, Marcel Holtmann <[email protected]> wro=
te:
> Hi Ryan,
>
>> I have one other question with it. When it first reconnects the mouse
>> pointer is really jerky, like it's updating really slow. Then after a
>> few seconds it is normal; in fact it is very responsive compared to my
>> old Bluetooth mouse. With Windows 8.1 it reconnects lightning fast
>> when I turn it on, and it is not jerky at first.
>>
> this is a kernel issue with not remembering the previous connection param=
eters. What you see is that we start connecting with the default values and=
then the slave (the mouse) will correct us and tell us what connection par=
ameters it needs. We accept them and actually change the LE link to use the=
se parameters. However we end up forgetting them. So every time you connect=
this procedure keeps repeating itself.
>
> I fixed this as well, but for that you will need a bluetooth-next kernel =
where I enabled the management API for passive scanning and a modified blue=
toothd that will then allow you a smooth experience. If the slave updates t=
he connection parameters we remember them for devices using auto-connection=
. So once the connection is triggered via passive scanning the values will =
be remembered.
>
> At the moment, I have one minor issue with the re-connection within bluet=
oothd and once that is fixed this should be pretty instant.


Okay, great, glad to hear that you're already on it. I'm really
looking forward to the seamless Bluetooth experience on Linux! When
everything is ready and in the master branch let me know and I will
try them out.

Thanks,
Ryan

2014-06-29 17:52:04

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Ryan,

>>>>>> It looks like Bluez is using random address and hcitool lescan is
>>>>>> using public address. I don't know why to use random or public.
>>>>>>
>>>>>> hcitool lescan:
>>>>>> own address: 0x00 (Public) policy: All
>>>>>> bluetoothd:
>>>>>> own address: 0x01 (Random) policy: All
>>>>>>
>>>>>> And the advertise address from the mouse is the same.
>>>>>>
>>>>>> hcitool:
>>>>>> bdaddr C5:8C:97:E9:9C:81 (Random)
>>>>>> bluetoothctl:
>>>>>> [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
>>>>>>
>>>>>>
>>>>>> Thanks.
>>>>>> Ryan
>>>>>
>>>>> Hi Luiz,
>>>>>
>>>>> I realized that 3.15+ kernel had the LE Privacy support, so I tried
>>>>> 3.14 and my mouse reconnects just fine. So somehow my mouse does not
>>>>> work with the new LE Privacy in the kernel.
>>>>>
>>>>> I couldn't find any way to disable this. It seems that bluetoothd
>>>>> just uses the default setting which is LE Privacy enabled. And I
>>>>> couldn't find any way in the kernel to disable it via a module option
>>>>> or sysfs. Is there some other way I can disable this?
>>>>
>>>> What the kernel does is it actually uses a non-resolvable private
>>>> address when doing active scanning. You should still be able to get
>>>> advertising indications even though you don't get scan responses (as the
>>>> remote can only choose to not send you the latter based on your
>>>> address). So it's a bit strange you just get complete silence when doing
>>>> active scanning with a non-resolvable private address.
>>>>
>>>> It'd be interesting to know whether passive scanning discovers the
>>>> device (it should). This is what we should be using, but as the kernel
>>>> interface for it is not yet ready we're reusing the Start Discovery mgmt
>>>> command which uses active instead of passive scanning.
>>>>
>>>> Btw, it would be *much* better if you used btmon instead of hcidump for
>>>> your investigation. It has much more complete decoding of all the
>>>> various commands and events. Now we have to guess part of the parameters
>>>> that you posted since hcidump doesn't show them.
>>>
>>> One part I missed: it seems the mouse is using directed advertising:
>>>
>>> 2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
>>> LE Advertising Report
>>> ADV_DIRECT_IND - Connectable directed advertising (1)
>>> bdaddr C5:8C:97:E9:9C:81 (Random)
>>> RSSI: -35
>>>
>>> It's possible that this makes your local controller filter out even the
>>> indications as they don't match the local address.
>>
>> that is pretty much the issue here. The controller will filter out any ADV_DIRECT_IND that are not directed to the own address that it is currently using. That is mainly the reason why nobody today is using direct advertising since it broken for non-resolvable and resolvable private addresses. This is the first LE device using advertising that I have seen so far.
>> In conclusion, we have one clear bug with our experimental passive scanning support. Since passive scanning is not sending SCAN_REQ, we should just scan with our current identity address (public or static random). We tried to be extra safe when doing background scanning, but we forgot to take direct advertising into account.
>
>>
>> The takeaway here is that active scanning (discovery) should be done using non-resolvable or resolvable private addresses, while passive scanning (background) should be done using identity address or resolvable private address.
>>
>> Now the biggest problem is that with 3.15 and 3.16-rcX kernels we would need to go back to using our identity address for discovery. This means active scanning and it means we are broadcasting our identity address to everybody when trying to find this mouse. I rather not do that.
>>
>> Regards
>>
>> Marcel
>>
>
> Thanks guys, especially Marcel! I have applied your patch and now the
> mouse reconnects correctly.
>
> I have one other question with it. When it first reconnects the mouse
> pointer is really jerky, like it's updating really slow. Then after a
> few seconds it is normal; in fact it is very responsive compared to my
> old Bluetooth mouse. With Windows 8.1 it reconnects lightning fast
> when I turn it on, and it is not jerky at first.
>
> Bluetooth monitor ver 5.20
> = New Index: 5C:51:4F:0F:45:9B (BR/EDR,USB,hci0) [hci0] 0.378098
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 2.291608
> Type: Active (0x01)
> Interval: 11.250 msec (0x0012)
> Window: 11.250 msec (0x0012)
> Own address type: Public (0x00)
> Filter policy: Accept all advertisement (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.292495
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 2.292569
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.293492
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> Status: Success (0x00)
> @ Discovering: 0x01 (6)
>> HCI Event: LE Meta Event (0x3e) plen 12 [hci0] 2.297493
> LE Advertising Report (0x02)
> Num reports: 1
> Event type: Connectable directed - ADV_DIRECT_IND (0x01)
> Address type: Random (0x01)
> Address: C5:8C:97:E9:9C:81 (Static)
> Data length: 0
> RSSI: -48 dBm (0xd0)
> @ Device Found: C5:8C:97:E9:9C:81 (2) rssi -48 flags 0x0000
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 2.297704
> Scanning: Disabled (0x00)
> Filter duplicates: Disabled (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.301506
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> Status: Success (0x00)
> @ Discovering: 0x00 (6)
> < HCI Command: LE Create Connection (0x08|0x000d) plen 25 [hci0] 2.302027
> Scan interval: 60.000 msec (0x0060)
> Scan window: 30.000 msec (0x0030)
> Filter policy: White list is not used (0x00)
> Peer address type: Random (0x01)
> Peer address: C5:8C:97:E9:9C:81 (Static)
> Own address type: Public (0x00)
> Min connection interval: 50.00 msec (0x0028)
> Max connection interval: 70.00 msec (0x0038)
> Connection latency: 0x0000
> Supervision timeout: 420 msec (0x002a)
> Min connection length: 0.000 msec (0x0000)
> Max connection length: 0.000 msec (0x0000)
>> HCI Event: Command Status (0x0f) plen 4 [hci0] 2.303493
> LE Create Connection (0x08|0x000d) ncmd 2
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 2.308593
> LE Connection Complete (0x01)
> Status: Success (0x00)
> Handle: 3585
> Role: Master (0x00)
> Peer address type: Random (0x01)
> Peer address: C5:8C:97:E9:9C:81 (Static)
> Connection interval: 70.00 msec (0x0038)
> Connection latency: 0.00 msec (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x00
> @ Device Connected: C5:8C:97:E9:9C:81 (2) flags 0x0000
> < HCI Command: LE Start Encryption (0x08|0x0019) plen 28 [hci0] 2.308922
> Handle: 3585
> Random number: 0x42a37f88d3b5619c
> Encrypted diversifier: 0x21e0
> Long term key: 283980ebe520609d7af359b28e996572
>> HCI Event: Command Status (0x0f) plen 4 [hci0] 2.310487
> LE Start Encryption (0x08|0x0019) ncmd 1
> Status: Success (0x00)
>> HCI Event: Encryption Change (0x08) plen 4 [hci0] 2.715586
> Status: Success (0x00)
> Handle: 3585
> Encryption: Enabled with AES-CCM (0x01)
> < ACL Data TX: Handle 3585 flags 0x00 dlen 11 [hci0] 2.715867
> ATT: Read By Type Request (0x08) len 6
> Handle range: 0x000c-0x0010
> Attribute type: Characteristic (0x2803)
>> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 2.785254
> ATT: Handle Value Notification (0x1b) len 11
> Handle: 0x0021
> Data: 001500b7ff00000000
>> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 2.785496
> Num handles: 1
> Handle: 3585
> Count: 1
>> ACL Data RX: Handle 3585 flags 0x02 dlen 20 [hci0] 2.855169
> ATT: Read By Type Response (0x09) len 15
> Attribute data length: 7
> Attribute data list: 2 entries
> Handle: 0x000d
> Value: 020e00292a
> Handle: 0x000f
> Value: 021000502a
> < ACL Data TX: Handle 3585 flags 0x00 dlen 7 [hci0] 2.855447
> ATT: Exchange MTU Request (0x02) len 2
> Client RX MTU: 672
>> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 2.925588
> Num handles: 1
> Handle: 3585
> Count: 1
>> ACL Data RX: Handle 3585 flags 0x02 dlen 7 [hci0] 2.995043
> ATT: Exchange MTU Response (0x03) len 2
> Server RX MTU: 23
> < ACL Data TX: Handle 3585 flags 0x00 dlen 7 [hci0] 2.995278
> ATT: Read Request (0x0a) len 2
> Handle: 0x0010
>> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 3.065590
> Num handles: 1
> Handle: 3585
> Count: 1
>> ACL Data RX: Handle 3585 flags 0x02 dlen 12 [hci0] 3.135107
> ATT: Read Response (0x0b) len 7
> Value: 025e04f3070100
>> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 7.405125
> LE L2CAP: Connection Parameter Update Request (0x12) ident 2 len 8
> Min interval: 6
> Max interval: 6
> Slave latency: 40
> Timeout multiplier: 300
> < ACL Data TX: Handle 3585 flags 0x00 dlen 10 [hci0] 7.405247
> LE L2CAP: Connection Parameter Update Response (0x13) ident 2 len 2
> Result: Connection Parameters accepted (0x0000)
> < HCI Command: LE Connection Update (0x08|0x0013) plen 14 [hci0] 7.405276
> Handle: 3585
> Min connection interval: 7.50 msec (0x0006)
> Max connection interval: 7.50 msec (0x0006)
> Connection latency: 0x0028
> Supervision timeout: 3000 msec (0x012c)
> Min connection length: 0.000 msec (0x0000)
> Max connection length: 0.000 msec (0x0000)
>> HCI Event: Command Status (0x0f) plen 4 [hci0] 7.407611
> LE Connection Update (0x08|0x0013) ncmd 2
> Status: Success (0x00)
>> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 7.475614
> Num handles: 1
> Handle: 3585
> Count: 1
>> HCI Event: LE Meta Event (0x3e) plen 10 [hci0] 8.035642
> LE Connection Update Complete (0x03)
> Status: Success (0x00)
> Handle: 3585
> Connection interval: 7.50 msec (0x0006)
> Connection latency: 50.00 msec (0x0028)
> Supervision timeout: 3000 msec (0x012c)
>> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.695162
> ATT: Handle Value Notification (0x1b) len 11
> Handle: 0x0021
> Data: 000000000000000000
>> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.920069
> ATT: Handle Value Notification (0x1b) len 11
> Handle: 0x0021
> Data: 000000000000000000
>> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.927662
> ATT: Handle Value Notification (0x1b) len 11
> Handle: 0x0021
> Data: 000000010000000000
>
>
> I see at first this setting:
> Min connection interval: 50.00 msec (0x0028)
> Max connection interval: 70.00 msec (0x0038)
> And later this setting:
> Min connection interval: 7.50 msec (0x0006)
> Max connection interval: 7.50 msec (0x0006)
>
> I guess this is why it's slow at first. I wonder why it just doesn't
> start out at 7.5 ms? And with the somewhat slower reconnection issue
> I believe it's due to bluetoothd not polling as quickly.

this is a kernel issue with not remembering the previous connection parameters. What you see is that we start connecting with the default values and then the slave (the mouse) will correct us and tell us what connection parameters it needs. We accept them and actually change the LE link to use these parameters. However we end up forgetting them. So every time you connect this procedure keeps repeating itself.

I fixed this as well, but for that you will need a bluetooth-next kernel where I enabled the management API for passive scanning and a modified bluetoothd that will then allow you a smooth experience. If the slave updates the connection parameters we remember them for devices using auto-connection. So once the connection is triggered via passive scanning the values will be remembered.

At the moment, I have one minor issue with the re-connection within bluetoothd and once that is fixed this should be pretty instant.

Regards

Marcel


2014-06-29 17:02:42

by Ryan Press

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Marcel,

On Sun, Jun 29, 2014 at 2:43 AM, Marcel Holtmann <[email protected]> wrot=
e:
> Hi Johan,
>
>>>>> It looks like Bluez is using random address and hcitool lescan is
>>>>> using public address. I don't know why to use random or public.
>>>>>
>>>>> hcitool lescan:
>>>>> own address: 0x00 (Public) policy: All
>>>>> bluetoothd:
>>>>> own address: 0x01 (Random) policy: All
>>>>>
>>>>> And the advertise address from the mouse is the same.
>>>>>
>>>>> hcitool:
>>>>> bdaddr C5:8C:97:E9:9C:81 (Random)
>>>>> bluetoothctl:
>>>>> [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
>>>>>
>>>>>
>>>>> Thanks.
>>>>> Ryan
>>>>
>>>> Hi Luiz,
>>>>
>>>> I realized that 3.15+ kernel had the LE Privacy support, so I tried
>>>> 3.14 and my mouse reconnects just fine. So somehow my mouse does not
>>>> work with the new LE Privacy in the kernel.
>>>>
>>>> I couldn't find any way to disable this. It seems that bluetoothd
>>>> just uses the default setting which is LE Privacy enabled. And I
>>>> couldn't find any way in the kernel to disable it via a module option
>>>> or sysfs. Is there some other way I can disable this?
>>>
>>> What the kernel does is it actually uses a non-resolvable private
>>> address when doing active scanning. You should still be able to get
>>> advertising indications even though you don't get scan responses (as th=
e
>>> remote can only choose to not send you the latter based on your
>>> address). So it's a bit strange you just get complete silence when doin=
g
>>> active scanning with a non-resolvable private address.
>>>
>>> It'd be interesting to know whether passive scanning discovers the
>>> device (it should). This is what we should be using, but as the kernel
>>> interface for it is not yet ready we're reusing the Start Discovery mgm=
t
>>> command which uses active instead of passive scanning.
>>>
>>> Btw, it would be *much* better if you used btmon instead of hcidump for
>>> your investigation. It has much more complete decoding of all the
>>> various commands and events. Now we have to guess part of the parameter=
s
>>> that you posted since hcidump doesn't show them.
>>
>> One part I missed: it seems the mouse is using directed advertising:
>>
>> 2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
>> LE Advertising Report
>> ADV_DIRECT_IND - Connectable directed advertising (1)
>> bdaddr C5:8C:97:E9:9C:81 (Random)
>> RSSI: -35
>>
>> It's possible that this makes your local controller filter out even the
>> indications as they don't match the local address.
>
> that is pretty much the issue here. The controller will filter out any AD=
V_DIRECT_IND that are not directed to the own address that it is currently =
using. That is mainly the reason why nobody today is using direct advertisi=
ng since it broken for non-resolvable and resolvable private addresses. Thi=
s is the first LE device using advertising that I have seen so far.
> In conclusion, we have one clear bug with our experimental passive scanni=
ng support. Since passive scanning is not sending SCAN_REQ, we should just =
scan with our current identity address (public or static random). We tried =
to be extra safe when doing background scanning, but we forgot to take dire=
ct advertising into account.

>
> The takeaway here is that active scanning (discovery) should be done usin=
g non-resolvable or resolvable private addresses, while passive scanning (b=
ackground) should be done using identity address or resolvable private addr=
ess.
>
> Now the biggest problem is that with 3.15 and 3.16-rcX kernels we would n=
eed to go back to using our identity address for discovery. This means acti=
ve scanning and it means we are broadcasting our identity address to everyb=
ody when trying to find this mouse. I rather not do that.
>
> Regards
>
> Marcel
>

Thanks guys, especially Marcel! I have applied your patch and now the
mouse reconnects correctly.

I have one other question with it. When it first reconnects the mouse
pointer is really jerky, like it's updating really slow. Then after a
few seconds it is normal; in fact it is very responsive compared to my
old Bluetooth mouse. With Windows 8.1 it reconnects lightning fast
when I turn it on, and it is not jerky at first.

Bluetooth monitor ver 5.20
=3D New Index: 5C:51:4F:0F:45:9B (BR/EDR,USB,hci0) [hci0] 0.=
378098
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 2.29=
1608
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Public (0x00)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.29=
2495
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 2.29=
2569
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.29=
3492
LE Set Scan Enable (0x08|0x000c) ncmd 2
Status: Success (0x00)
@ Discovering: 0x01 (6)
> HCI Event: LE Meta Event (0x3e) plen 12 [hci0] 2.29=
7493
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable directed - ADV_DIRECT_IND (0x01)
Address type: Random (0x01)
Address: C5:8C:97:E9:9C:81 (Static)
Data length: 0
RSSI: -48 dBm (0xd0)
@ Device Found: C5:8C:97:E9:9C:81 (2) rssi -48 flags 0x0000
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 2.29=
7704
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 2.30=
1506
LE Set Scan Enable (0x08|0x000c) ncmd 2
Status: Success (0x00)
@ Discovering: 0x00 (6)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25 [hci0] 2.30=
2027
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Random (0x01)
Peer address: C5:8C:97:E9:9C:81 (Static)
Own address type: Public (0x00)
Min connection interval: 50.00 msec (0x0028)
Max connection interval: 70.00 msec (0x0038)
Connection latency: 0x0000
Supervision timeout: 420 msec (0x002a)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 2.30=
3493
LE Create Connection (0x08|0x000d) ncmd 2
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 2.30=
8593
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 3585
Role: Master (0x00)
Peer address type: Random (0x01)
Peer address: C5:8C:97:E9:9C:81 (Static)
Connection interval: 70.00 msec (0x0038)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Device Connected: C5:8C:97:E9:9C:81 (2) flags 0x0000
< HCI Command: LE Start Encryption (0x08|0x0019) plen 28 [hci0] 2.30=
8922
Handle: 3585
Random number: 0x42a37f88d3b5619c
Encrypted diversifier: 0x21e0
Long term key: 283980ebe520609d7af359b28e996572
> HCI Event: Command Status (0x0f) plen 4 [hci0] 2.31=
0487
LE Start Encryption (0x08|0x0019) ncmd 1
Status: Success (0x00)
> HCI Event: Encryption Change (0x08) plen 4 [hci0] 2.71=
5586
Status: Success (0x00)
Handle: 3585
Encryption: Enabled with AES-CCM (0x01)
< ACL Data TX: Handle 3585 flags 0x00 dlen 11 [hci0] 2.71=
5867
ATT: Read By Type Request (0x08) len 6
Handle range: 0x000c-0x0010
Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 2.78=
5254
ATT: Handle Value Notification (0x1b) len 11
Handle: 0x0021
Data: 001500b7ff00000000
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 2.78=
5496
Num handles: 1
Handle: 3585
Count: 1
> ACL Data RX: Handle 3585 flags 0x02 dlen 20 [hci0] 2.85=
5169
ATT: Read By Type Response (0x09) len 15
Attribute data length: 7
Attribute data list: 2 entries
Handle: 0x000d
Value: 020e00292a
Handle: 0x000f
Value: 021000502a
< ACL Data TX: Handle 3585 flags 0x00 dlen 7 [hci0] 2.85=
5447
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 672
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 2.92=
5588
Num handles: 1
Handle: 3585
Count: 1
> ACL Data RX: Handle 3585 flags 0x02 dlen 7 [hci0] 2.99=
5043
ATT: Exchange MTU Response (0x03) len 2
Server RX MTU: 23
< ACL Data TX: Handle 3585 flags 0x00 dlen 7 [hci0] 2.99=
5278
ATT: Read Request (0x0a) len 2
Handle: 0x0010
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 3.06=
5590
Num handles: 1
Handle: 3585
Count: 1
> ACL Data RX: Handle 3585 flags 0x02 dlen 12 [hci0] 3.13=
5107
ATT: Read Response (0x0b) len 7
Value: 025e04f3070100
> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 7.40=
5125
LE L2CAP: Connection Parameter Update Request (0x12) ident 2 len 8
Min interval: 6
Max interval: 6
Slave latency: 40
Timeout multiplier: 300
< ACL Data TX: Handle 3585 flags 0x00 dlen 10 [hci0] 7.40=
5247
LE L2CAP: Connection Parameter Update Response (0x13) ident 2 len 2
Result: Connection Parameters accepted (0x0000)
< HCI Command: LE Connection Update (0x08|0x0013) plen 14 [hci0] 7.40=
5276
Handle: 3585
Min connection interval: 7.50 msec (0x0006)
Max connection interval: 7.50 msec (0x0006)
Connection latency: 0x0028
Supervision timeout: 3000 msec (0x012c)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 7.40=
7611
LE Connection Update (0x08|0x0013) ncmd 2
Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 7.47=
5614
Num handles: 1
Handle: 3585
Count: 1
> HCI Event: LE Meta Event (0x3e) plen 10 [hci0] 8.03=
5642
LE Connection Update Complete (0x03)
Status: Success (0x00)
Handle: 3585
Connection interval: 7.50 msec (0x0006)
Connection latency: 50.00 msec (0x0028)
Supervision timeout: 3000 msec (0x012c)
> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.69=
5162
ATT: Handle Value Notification (0x1b) len 11
Handle: 0x0021
Data: 000000000000000000
> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.92=
0069
ATT: Handle Value Notification (0x1b) len 11
Handle: 0x0021
Data: 000000000000000000
> ACL Data RX: Handle 3585 flags 0x02 dlen 16 [hci0] 11.92=
7662
ATT: Handle Value Notification (0x1b) len 11
Handle: 0x0021
Data: 000000010000000000


I see at first this setting:
Min connection interval: 50.00 msec (0x0028)
Max connection interval: 70.00 msec (0x0038)
And later this setting:
Min connection interval: 7.50 msec (0x0006)
Max connection interval: 7.50 msec (0x0006)

I guess this is why it's slow at first. I wonder why it just doesn't
start out at 7.5 ms? And with the somewhat slower reconnection issue
I believe it's due to bluetoothd not polling as quickly.

Thanks,
Ryan

2014-06-29 09:43:32

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Johan,

>>>> It looks like Bluez is using random address and hcitool lescan is
>>>> using public address. I don't know why to use random or public.
>>>>
>>>> hcitool lescan:
>>>> own address: 0x00 (Public) policy: All
>>>> bluetoothd:
>>>> own address: 0x01 (Random) policy: All
>>>>
>>>> And the advertise address from the mouse is the same.
>>>>
>>>> hcitool:
>>>> bdaddr C5:8C:97:E9:9C:81 (Random)
>>>> bluetoothctl:
>>>> [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
>>>>
>>>>
>>>> Thanks.
>>>> Ryan
>>>
>>> Hi Luiz,
>>>
>>> I realized that 3.15+ kernel had the LE Privacy support, so I tried
>>> 3.14 and my mouse reconnects just fine. So somehow my mouse does not
>>> work with the new LE Privacy in the kernel.
>>>
>>> I couldn't find any way to disable this. It seems that bluetoothd
>>> just uses the default setting which is LE Privacy enabled. And I
>>> couldn't find any way in the kernel to disable it via a module option
>>> or sysfs. Is there some other way I can disable this?
>>
>> What the kernel does is it actually uses a non-resolvable private
>> address when doing active scanning. You should still be able to get
>> advertising indications even though you don't get scan responses (as the
>> remote can only choose to not send you the latter based on your
>> address). So it's a bit strange you just get complete silence when doing
>> active scanning with a non-resolvable private address.
>>
>> It'd be interesting to know whether passive scanning discovers the
>> device (it should). This is what we should be using, but as the kernel
>> interface for it is not yet ready we're reusing the Start Discovery mgmt
>> command which uses active instead of passive scanning.
>>
>> Btw, it would be *much* better if you used btmon instead of hcidump for
>> your investigation. It has much more complete decoding of all the
>> various commands and events. Now we have to guess part of the parameters
>> that you posted since hcidump doesn't show them.
>
> One part I missed: it seems the mouse is using directed advertising:
>
> 2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
> LE Advertising Report
> ADV_DIRECT_IND - Connectable directed advertising (1)
> bdaddr C5:8C:97:E9:9C:81 (Random)
> RSSI: -35
>
> It's possible that this makes your local controller filter out even the
> indications as they don't match the local address.

that is pretty much the issue here. The controller will filter out any ADV_DIRECT_IND that are not directed to the own address that it is currently using. That is mainly the reason why nobody today is using direct advertising since it broken for non-resolvable and resolvable private addresses. This is the first LE device using advertising that I have seen so far.

So when the mouse is discoverable and ready for pairing with a host, you will see these:

> HCI Event: LE Meta Event (0x3e) plen 43
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: E7:AD:BC:AA:1A:3B (Static)
Data length: 31
Name (complete): Arc Touch Mouse SE
Appearance: Mouse (0x03c2)
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
16-bit Service UUIDs (complete): 1 entry
Human Interface Device (0x1812)
RSSI: -57 dBm (0xc7)
> HCI Event: LE Meta Event (0x3e) plen 12
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: E7:AD:BC:AA:1A:3B (Static)
Data length: 0
RSSI: -57 dBm (0xc7)

However once you are paired and you switch it one, you will only see these:

> HCI Event: LE Meta Event (0x3e) plen 12
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable directed - ADV_DIRECT_IND (0x01)
Address type: Random (0x01)
Address: E7:AD:BC:AA:1A:3B (Static)
Data length: 0
RSSI: -53 dBm (0xcb)

And for some reason the address also keeps changing if you pair multiple times. The 4th octet (AA) keeps changing when you are pairing the mouse again. It seems a bit like that for every pairing, the mouse generates a new static random address and might actually remember the old one. I have seen direct advertising with the old address as well. So that is an interesting behavior.

The biggest problem here is that even if you are trying to be private and doing everything right, the mouse will broadcast your public address every time it tries to reconnect. So thank you Microsoft for forcing us to be trackable.

At least when we are using resolvable private addresses, we can distribute our IRK to the mouse:

< ACL Data TX: Handle 64 flags 0x00 dlen 11
SMP: Pairing Request (0x01) len 6
IO capability: DisplayYesNo (0x01)
OOB data: Authentication data not present (0x00)
Authentication requirement: Bonding - MITM (0x05)
Max encryption key size: 16
Initiator key distribution: EncKey IdKey Sign (0x07)
Responder key distribution: EncKey IdKey Sign (0x07)
> ACL Data RX: Handle 64 flags 0x02 dlen 11
SMP: Pairing Response (0x02) len 6
IO capability: NoInputNoOutput (0x03)
OOB data: Authentication data not present (0x00)
Authentication requirement: Bonding - No MITM (0x01)
Max encryption key size: 16
Initiator key distribution: IdKey Sign (0x06)
Responder key distribution: EncKey (0x01)

< ACL Data TX: Handle 64 flags 0x00 dlen 21
SMP: Identity Information (0x08) len 16
Identity resolving key: ba0583710e172dee8e8e8eb70e15d232
< ACL Data TX: Handle 64 flags 0x00 dlen 12
SMP: Identity Address Information (0x09) len 7
Address type: Public (0x00)
Address: 00:02:A2:CC:10:04

The problem with that however is that we will still not get ADV_DIRECT_IND since the mouse will never know with resolvable private address we are using at the moment. So it might use an outdated address and then the controller will filter it out like it will filter it out with non-resolvable private addresses.

In conclusion, we have one clear bug with our experimental passive scanning support. Since passive scanning is not sending SCAN_REQ, we should just scan with our current identity address (public or static random). We tried to be extra safe when doing background scanning, but we forgot to take direct advertising into account.

The takeaway here is that active scanning (discovery) should be done using non-resolvable or resolvable private addresses, while passive scanning (background) should be done using identity address or resolvable private address.

Now the biggest problem is that with 3.15 and 3.16-rcX kernels we would need to go back to using our identity address for discovery. This means active scanning and it means we are broadcasting our identity address to everybody when trying to find this mouse. I rather not do that.

Regards

Marcel


2014-06-29 05:29:49

by Johan Hedberg

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi,

On Sun, Jun 29, 2014, Johan Hedberg wrote:
> On Sat, Jun 28, 2014, Ryan Press wrote:
> > > It looks like Bluez is using random address and hcitool lescan is
> > > using public address. I don't know why to use random or public.
> > >
> > > hcitool lescan:
> > > own address: 0x00 (Public) policy: All
> > > bluetoothd:
> > > own address: 0x01 (Random) policy: All
> > >
> > > And the advertise address from the mouse is the same.
> > >
> > > hcitool:
> > > bdaddr C5:8C:97:E9:9C:81 (Random)
> > > bluetoothctl:
> > > [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
> > >
> > >
> > > Thanks.
> > > Ryan
> >
> > Hi Luiz,
> >
> > I realized that 3.15+ kernel had the LE Privacy support, so I tried
> > 3.14 and my mouse reconnects just fine. So somehow my mouse does not
> > work with the new LE Privacy in the kernel.
> >
> > I couldn't find any way to disable this. It seems that bluetoothd
> > just uses the default setting which is LE Privacy enabled. And I
> > couldn't find any way in the kernel to disable it via a module option
> > or sysfs. Is there some other way I can disable this?
>
> What the kernel does is it actually uses a non-resolvable private
> address when doing active scanning. You should still be able to get
> advertising indications even though you don't get scan responses (as the
> remote can only choose to not send you the latter based on your
> address). So it's a bit strange you just get complete silence when doing
> active scanning with a non-resolvable private address.
>
> It'd be interesting to know whether passive scanning discovers the
> device (it should). This is what we should be using, but as the kernel
> interface for it is not yet ready we're reusing the Start Discovery mgmt
> command which uses active instead of passive scanning.
>
> Btw, it would be *much* better if you used btmon instead of hcidump for
> your investigation. It has much more complete decoding of all the
> various commands and events. Now we have to guess part of the parameters
> that you posted since hcidump doesn't show them.

One part I missed: it seems the mouse is using directed advertising:

2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
LE Advertising Report
ADV_DIRECT_IND - Connectable directed advertising (1)
bdaddr C5:8C:97:E9:9C:81 (Random)
RSSI: -35

It's possible that this makes your local controller filter out even the
indications as they don't match the local address.

Johan

2014-06-29 05:14:42

by Johan Hedberg

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Ryan,

On Sat, Jun 28, 2014, Ryan Press wrote:
> > It looks like Bluez is using random address and hcitool lescan is
> > using public address. I don't know why to use random or public.
> >
> > hcitool lescan:
> > own address: 0x00 (Public) policy: All
> > bluetoothd:
> > own address: 0x01 (Random) policy: All
> >
> > And the advertise address from the mouse is the same.
> >
> > hcitool:
> > bdaddr C5:8C:97:E9:9C:81 (Random)
> > bluetoothctl:
> > [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
> >
> >
> > Thanks.
> > Ryan
>
> Hi Luiz,
>
> I realized that 3.15+ kernel had the LE Privacy support, so I tried
> 3.14 and my mouse reconnects just fine. So somehow my mouse does not
> work with the new LE Privacy in the kernel.
>
> I couldn't find any way to disable this. It seems that bluetoothd
> just uses the default setting which is LE Privacy enabled. And I
> couldn't find any way in the kernel to disable it via a module option
> or sysfs. Is there some other way I can disable this?

What the kernel does is it actually uses a non-resolvable private
address when doing active scanning. You should still be able to get
advertising indications even though you don't get scan responses (as the
remote can only choose to not send you the latter based on your
address). So it's a bit strange you just get complete silence when doing
active scanning with a non-resolvable private address.

It'd be interesting to know whether passive scanning discovers the
device (it should). This is what we should be using, but as the kernel
interface for it is not yet ready we're reusing the Start Discovery mgmt
command which uses active instead of passive scanning.

Btw, it would be *much* better if you used btmon instead of hcidump for
your investigation. It has much more complete decoding of all the
various commands and events. Now we have to guess part of the parameters
that you posted since hcidump doesn't show them.

Johan

2014-06-29 04:51:49

by Ryan Press

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

On Sat, Jun 28, 2014 at 1:07 PM, Ryan Press <[email protected]> wrote:
> On Sat, Jun 28, 2014 at 12:22 PM, Luiz Augusto von Dentz
> <[email protected]> wrote:
>> On Sat, Jun 28, 2014 at 6:50 PM, Ryan Press <[email protected]> wrote:
>>> On Fri, Jun 27, 2014 at 1:32 AM, Luiz Augusto von Dentz
>>> <[email protected]> wrote:
>>>> Hi Ryan,
>>>>
>>>> On Wed, Jun 25, 2014 at 4:23 PM, Ryan Press <[email protected]> wrote:
>>>>> Hi Luiz,
>>>>>
>>>>> Yes it will repeat the scan every few seconds.
>>>>>
>>>>> I paired the device in the Gnome applet. In the bluetoothctl I could
>>>>> see the pair and trust messages like so:
>>>>>
>>>>> [NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
>>>>> [CHG] Device C5:8C:97:E6:9C:81 Connected: yes
>>>>> [CHG] Device C5:8C:97:E6:9C:81 UUIDs:
>>>>> 00001800-0000-1000-8000-00805f9b34fb
>>>>> 00001801-0000-1000-8000-00805f9b34fb
>>>>> 0000180a-0000-1000-8000-00805f9b34fb
>>>>> 0000180f-0000-1000-8000-00805f9b34fb
>>>>> 00001812-0000-1000-8000-00805f9b34fb
>>>>> [CHG] Device C5:8C:97:E6:9C:81 Paired: yes
>>>>> [CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
>>>>> [CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001
>>>>>
>>>>> Thanks,
>>>>>
>>>>> Ryan
>>>>>
>>>>>
>>>>> On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>>>>>>
>>>>>> Hi Ryan,
>>>>>>
>>>>>> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
>>>>>> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
>>>>>> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
>>>>>> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
>>>>>> > off/on.
>>>>>> >
>>>>>> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
>>>>>> > fine, and it will continue to work until I turn the mouse off/on or
>>>>>> > turn the computer off/on. Then it won't reconnect automatically. If
>>>>>> > I go into bluetoothctl I can connect it again and it will then work.
>>>>>> >
>>>>>> > I looked at bluetoothd and it seems to be doing the LE scan with:
>>>>>> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
>>>>>> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
>>>>>> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
>>>>>> >
>>>>>> > I look also at hcidump and I see:
>>>>>> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
>>>>>> > bdaddr 39:6D:E2:EC:17:37
>>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>>> > LE Set Random Address (0x08|0x0005) ncmd 1
>>>>>> > status 0x00
>>>>>> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>>>>>> > type 0x01 (active)
>>>>>> > interval 11.250ms window 11.250ms
>>>>>> > own address: 0x01 (Random) policy: All
>>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>>> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
>>>>>> > status 0x00
>>>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>>>> > value 0x01 (scanning enabled)
>>>>>> > filter duplicates 0x01 (enabled)
>>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>>> > LE Set Scan Enable (0x08|0x000c) ncmd 2
>>>>>> > status 0x00
>>>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>>>> > value 0x00 (scanning disabled)
>>>>>> > filter duplicates 0x00 (disabled)
>>>>>> >
>>>>>> >
>>>>>> > It doesn't seem to be finding anything? Is there something else I should try?
>>>>>>
>>>>>> Does it continue to scan or it scan a single time and stops, and have
>>>>>> you paired or just connect?
>>>>
>>>> Can you try with current master, we have applied a few patches for reconnection.
>>>>
>>>>
>>>> --
>>>> Luiz Augusto von Dentz
>>> Hi Luiz,
>>>
>>> I have compiled and install the git Bluez.
>>>
>>> It's the same as before, I can pair it and it will work, but it won't
>>> automatically reconnect. Using bluetoothctl and "connect" command I
>>> can manually reconnect.
>>>
>>
>> No top posting please. Im running out of ideas, are you sure the mouse
>> is advertising using the same address?
>
> I just tested with "hcitool lescan" and it connected okay. So I
> looked at a "hcidump" for the hcitool scan and for the Bluez scan and
> they are a bit different.
>
> Here is the one from "hcitool lescan":
>
> HCI sniffer - Bluetooth packet analyzer ver 5.20
> device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
> 2014-06-28 12:54:01.421267 < HCI Command: LE Set Scan Parameters
> (0x08|0x000b) plen 7
> type 0x01 (active)
> interval 10.000ms window 10.000ms
> own address: 0x00 (Public) policy: All
> 2014-06-28 12:54:01.422140 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> status 0x00
> 2014-06-28 12:54:01.422238 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x01 (scanning enabled)
> filter duplicates 0x01 (enabled)
> 2014-06-28 12:54:01.423144 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> status 0x00
> 2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
> LE Advertising Report
> ADV_DIRECT_IND - Connectable directed advertising (1)
> bdaddr C5:8C:97:E9:9C:81 (Random)
> RSSI: -35
> 2014-06-28 12:54:01.425333 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x00 (scanning disabled)
> filter duplicates 0x00 (disabled)
> 2014-06-28 12:54:01.429161 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> status 0x00
> 2014-06-28 12:54:01.429409 < HCI Command: LE Create Connection
> (0x08|0x000d) plen 25
> bdaddr C5:8C:97:E9:9C:81 type 1
> interval 96 window 48 initiator_filter 0
> own_bdaddr_type 0 min_interval 40 max_interval 56
> latency 0 supervision_to 42 min_ce 0 max_ce 0
> 2014-06-28 12:54:01.430157 > HCI Event: Command Status (0x0f) plen 4
> LE Create Connection (0x08|0x000d) status 0x00 ncmd 2
> 2014-06-28 12:54:01.433220 > HCI Event: LE Meta Event (0x3e) plen 19
> LE Connection Complete
> status 0x00 handle 3585, role master
> bdaddr C5:8C:97:E9:9C:81 (Random)
> 2014-06-28 12:54:01.433476 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x00 (scanning disabled)
> filter duplicates 0x01 (enabled)
> 2014-06-28 12:54:01.434141 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> status 0x0c
> Error: Command Disallowed
> 2014-06-28 12:54:01.434206 < HCI Command: LE Start Encryption
> (0x08|0x0019) plen 28
> 2014-06-28 12:54:01.435140 > HCI Event: Command Status (0x0f) plen 4
> LE Start Encryption (0x08|0x0019) status 0x00 ncmd 1
> 2014-06-28 12:54:01.848191 > HCI Event: Encrypt Change (0x08) plen 4
> status 0x00 handle 3585 encrypt 0x01
> 2014-06-28 12:54:01.848461 < ACL data: handle 3585 flags 0x00 dlen 11
> ATT: Read By Type req (0x08)
> start 0x000c, end 0x0010
> type-uuid 0x2803
> 2014-06-28 12:54:01.918203 > HCI Event: Number of Completed Packets
> (0x13) plen 5
> handle 3585 packets 1
> 2014-06-28 12:54:01.988079 > ACL data: handle 3585 flags 0x02 dlen 20
> ATT: Read By Type resp (0x09)
> length: 7
> handle 0x000d, value 0x02 0x0e 0x00 0x29 0x2a
> handle 0x000f, value 0x02 0x10 0x00 0x50 0x2a
> 2014-06-28 12:54:01.988364 < ACL data: handle 3585 flags 0x00 dlen 7
> ATT: MTU req (0x02)
> client rx mtu 672
> 2014-06-28 12:54:02.058200 > HCI Event: Number of Completed Packets
> (0x13) plen 5
> handle 3585 packets 1
> 2014-06-28 12:54:02.127941 > ACL data: handle 3585 flags 0x02 dlen 7
> ATT: MTU resp (0x03)
> server rx mtu 23
> 2014-06-28 12:54:02.128174 < ACL data: handle 3585 flags 0x00 dlen 7
> ATT: Read req (0x0a)
> handle 0x0010
> 2014-06-28 12:54:02.198204 > HCI Event: Number of Completed Packets
> (0x13) plen 5
> handle 3585 packets 1
> 2014-06-28 12:54:02.267972 > ACL data: handle 3585 flags 0x02 dlen 12
> ATT: Read resp (0x0b)
>
> And here is the one from the regular bluetoothd:
>
> HCI sniffer - Bluetooth packet analyzer ver 5.20
> device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
> 2014-06-28 12:55:30.229459 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x00 (scanning disabled)
> filter duplicates 0x00 (disabled)
> 2014-06-28 12:55:30.232444 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> status 0x00
> 2014-06-28 12:55:33.954807 < HCI Command: LE Set Random Address
> (0x08|0x0005) plen 6
> bdaddr 00:67:25:80:95:CD
> 2014-06-28 12:55:33.955419 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Random Address (0x08|0x0005) ncmd 1
> status 0x00
> 2014-06-28 12:55:33.955494 < HCI Command: LE Set Scan Parameters
> (0x08|0x000b) plen 7
> type 0x01 (active)
> interval 11.250ms window 11.250ms
> own address: 0x01 (Random) policy: All
> 2014-06-28 12:55:33.956440 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> status 0x00
> 2014-06-28 12:55:33.956509 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x01 (scanning enabled)
> filter duplicates 0x01 (enabled)
> 2014-06-28 12:55:33.957440 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> status 0x00
> 2014-06-28 12:55:44.213285 < HCI Command: LE Set Scan Enable
> (0x08|0x000c) plen 2
> value 0x00 (scanning disabled)
> filter duplicates 0x00 (disabled)
> 2014-06-28 12:55:44.215502 > HCI Event: Command Complete (0x0e) plen 4
> LE Set Scan Enable (0x08|0x000c) ncmd 2
> status 0x00
>
>
> It looks like Bluez is using random address and hcitool lescan is
> using public address. I don't know why to use random or public.
>
> hcitool lescan:
> own address: 0x00 (Public) policy: All
> bluetoothd:
> own address: 0x01 (Random) policy: All
>
> And the advertise address from the mouse is the same.
>
> hcitool:
> bdaddr C5:8C:97:E9:9C:81 (Random)
> bluetoothctl:
> [NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE
>
>
> Thanks.
> Ryan

Hi Luiz,

I realized that 3.15+ kernel had the LE Privacy support, so I tried
3.14 and my mouse reconnects just fine. So somehow my mouse does not
work with the new LE Privacy in the kernel.

I couldn't find any way to disable this. It seems that bluetoothd
just uses the default setting which is LE Privacy enabled. And I
couldn't find any way in the kernel to disable it via a module option
or sysfs. Is there some other way I can disable this?

Thanks,
Ryan

2014-06-28 20:07:12

by Ryan Press

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

On Sat, Jun 28, 2014 at 12:22 PM, Luiz Augusto von Dentz
<[email protected]> wrote:
> On Sat, Jun 28, 2014 at 6:50 PM, Ryan Press <[email protected]> wrote:
>> On Fri, Jun 27, 2014 at 1:32 AM, Luiz Augusto von Dentz
>> <[email protected]> wrote:
>>> Hi Ryan,
>>>
>>> On Wed, Jun 25, 2014 at 4:23 PM, Ryan Press <[email protected]> wrote:
>>>> Hi Luiz,
>>>>
>>>> Yes it will repeat the scan every few seconds.
>>>>
>>>> I paired the device in the Gnome applet. In the bluetoothctl I could
>>>> see the pair and trust messages like so:
>>>>
>>>> [NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
>>>> [CHG] Device C5:8C:97:E6:9C:81 Connected: yes
>>>> [CHG] Device C5:8C:97:E6:9C:81 UUIDs:
>>>> 00001800-0000-1000-8000-00805f9b34fb
>>>> 00001801-0000-1000-8000-00805f9b34fb
>>>> 0000180a-0000-1000-8000-00805f9b34fb
>>>> 0000180f-0000-1000-8000-00805f9b34fb
>>>> 00001812-0000-1000-8000-00805f9b34fb
>>>> [CHG] Device C5:8C:97:E6:9C:81 Paired: yes
>>>> [CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
>>>> [CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001
>>>>
>>>> Thanks,
>>>>
>>>> Ryan
>>>>
>>>>
>>>> On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>>>>>
>>>>> Hi Ryan,
>>>>>
>>>>> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
>>>>> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
>>>>> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
>>>>> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
>>>>> > off/on.
>>>>> >
>>>>> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
>>>>> > fine, and it will continue to work until I turn the mouse off/on or
>>>>> > turn the computer off/on. Then it won't reconnect automatically. If
>>>>> > I go into bluetoothctl I can connect it again and it will then work.
>>>>> >
>>>>> > I looked at bluetoothd and it seems to be doing the LE scan with:
>>>>> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
>>>>> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
>>>>> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
>>>>> >
>>>>> > I look also at hcidump and I see:
>>>>> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
>>>>> > bdaddr 39:6D:E2:EC:17:37
>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>> > LE Set Random Address (0x08|0x0005) ncmd 1
>>>>> > status 0x00
>>>>> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>>>>> > type 0x01 (active)
>>>>> > interval 11.250ms window 11.250ms
>>>>> > own address: 0x01 (Random) policy: All
>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
>>>>> > status 0x00
>>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>>> > value 0x01 (scanning enabled)
>>>>> > filter duplicates 0x01 (enabled)
>>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>>> > LE Set Scan Enable (0x08|0x000c) ncmd 2
>>>>> > status 0x00
>>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>>> > value 0x00 (scanning disabled)
>>>>> > filter duplicates 0x00 (disabled)
>>>>> >
>>>>> >
>>>>> > It doesn't seem to be finding anything? Is there something else I should try?
>>>>>
>>>>> Does it continue to scan or it scan a single time and stops, and have
>>>>> you paired or just connect?
>>>
>>> Can you try with current master, we have applied a few patches for reconnection.
>>>
>>>
>>> --
>>> Luiz Augusto von Dentz
>> Hi Luiz,
>>
>> I have compiled and install the git Bluez.
>>
>> It's the same as before, I can pair it and it will work, but it won't
>> automatically reconnect. Using bluetoothctl and "connect" command I
>> can manually reconnect.
>>
>
> No top posting please. Im running out of ideas, are you sure the mouse
> is advertising using the same address?

I just tested with "hcitool lescan" and it connected okay. So I
looked at a "hcidump" for the hcitool scan and for the Bluez scan and
they are a bit different.

Here is the one from "hcitool lescan":

HCI sniffer - Bluetooth packet analyzer ver 5.20
device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
2014-06-28 12:54:01.421267 < HCI Command: LE Set Scan Parameters
(0x08|0x000b) plen 7
type 0x01 (active)
interval 10.000ms window 10.000ms
own address: 0x00 (Public) policy: All
2014-06-28 12:54:01.422140 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Parameters (0x08|0x000b) ncmd 1
status 0x00
2014-06-28 12:54:01.422238 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x01 (scanning enabled)
filter duplicates 0x01 (enabled)
2014-06-28 12:54:01.423144 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2014-06-28 12:54:01.425141 > HCI Event: LE Meta Event (0x3e) plen 12
LE Advertising Report
ADV_DIRECT_IND - Connectable directed advertising (1)
bdaddr C5:8C:97:E9:9C:81 (Random)
RSSI: -35
2014-06-28 12:54:01.425333 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x00 (disabled)
2014-06-28 12:54:01.429161 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2014-06-28 12:54:01.429409 < HCI Command: LE Create Connection
(0x08|0x000d) plen 25
bdaddr C5:8C:97:E9:9C:81 type 1
interval 96 window 48 initiator_filter 0
own_bdaddr_type 0 min_interval 40 max_interval 56
latency 0 supervision_to 42 min_ce 0 max_ce 0
2014-06-28 12:54:01.430157 > HCI Event: Command Status (0x0f) plen 4
LE Create Connection (0x08|0x000d) status 0x00 ncmd 2
2014-06-28 12:54:01.433220 > HCI Event: LE Meta Event (0x3e) plen 19
LE Connection Complete
status 0x00 handle 3585, role master
bdaddr C5:8C:97:E9:9C:81 (Random)
2014-06-28 12:54:01.433476 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x01 (enabled)
2014-06-28 12:54:01.434141 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 1
status 0x0c
Error: Command Disallowed
2014-06-28 12:54:01.434206 < HCI Command: LE Start Encryption
(0x08|0x0019) plen 28
2014-06-28 12:54:01.435140 > HCI Event: Command Status (0x0f) plen 4
LE Start Encryption (0x08|0x0019) status 0x00 ncmd 1
2014-06-28 12:54:01.848191 > HCI Event: Encrypt Change (0x08) plen 4
status 0x00 handle 3585 encrypt 0x01
2014-06-28 12:54:01.848461 < ACL data: handle 3585 flags 0x00 dlen 11
ATT: Read By Type req (0x08)
start 0x000c, end 0x0010
type-uuid 0x2803
2014-06-28 12:54:01.918203 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 3585 packets 1
2014-06-28 12:54:01.988079 > ACL data: handle 3585 flags 0x02 dlen 20
ATT: Read By Type resp (0x09)
length: 7
handle 0x000d, value 0x02 0x0e 0x00 0x29 0x2a
handle 0x000f, value 0x02 0x10 0x00 0x50 0x2a
2014-06-28 12:54:01.988364 < ACL data: handle 3585 flags 0x00 dlen 7
ATT: MTU req (0x02)
client rx mtu 672
2014-06-28 12:54:02.058200 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 3585 packets 1
2014-06-28 12:54:02.127941 > ACL data: handle 3585 flags 0x02 dlen 7
ATT: MTU resp (0x03)
server rx mtu 23
2014-06-28 12:54:02.128174 < ACL data: handle 3585 flags 0x00 dlen 7
ATT: Read req (0x0a)
handle 0x0010
2014-06-28 12:54:02.198204 > HCI Event: Number of Completed Packets
(0x13) plen 5
handle 3585 packets 1
2014-06-28 12:54:02.267972 > ACL data: handle 3585 flags 0x02 dlen 12
ATT: Read resp (0x0b)

And here is the one from the regular bluetoothd:

HCI sniffer - Bluetooth packet analyzer ver 5.20
device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
2014-06-28 12:55:30.229459 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x00 (disabled)
2014-06-28 12:55:30.232444 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2014-06-28 12:55:33.954807 < HCI Command: LE Set Random Address
(0x08|0x0005) plen 6
bdaddr 00:67:25:80:95:CD
2014-06-28 12:55:33.955419 > HCI Event: Command Complete (0x0e) plen 4
LE Set Random Address (0x08|0x0005) ncmd 1
status 0x00
2014-06-28 12:55:33.955494 < HCI Command: LE Set Scan Parameters
(0x08|0x000b) plen 7
type 0x01 (active)
interval 11.250ms window 11.250ms
own address: 0x01 (Random) policy: All
2014-06-28 12:55:33.956440 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Parameters (0x08|0x000b) ncmd 1
status 0x00
2014-06-28 12:55:33.956509 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x01 (scanning enabled)
filter duplicates 0x01 (enabled)
2014-06-28 12:55:33.957440 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00
2014-06-28 12:55:44.213285 < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2
value 0x00 (scanning disabled)
filter duplicates 0x00 (disabled)
2014-06-28 12:55:44.215502 > HCI Event: Command Complete (0x0e) plen 4
LE Set Scan Enable (0x08|0x000c) ncmd 2
status 0x00


It looks like Bluez is using random address and hcitool lescan is
using public address. I don't know why to use random or public.

hcitool lescan:
own address: 0x00 (Public) policy: All
bluetoothd:
own address: 0x01 (Random) policy: All

And the advertise address from the mouse is the same.

hcitool:
bdaddr C5:8C:97:E9:9C:81 (Random)
bluetoothctl:
[NEW] Device C5:8C:97:E9:9C:81 Arc Touch Mouse SE


Thanks.
Ryan

2014-06-28 19:22:59

by Luiz Augusto von Dentz

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Ryan,

On Sat, Jun 28, 2014 at 6:50 PM, Ryan Press <[email protected]> wrote:
> Hi Luiz,
>
> I have compiled and install the git Bluez.
>
> It's the same as before, I can pair it and it will work, but it won't
> automatically reconnect. Using bluetoothctl and "connect" command I
> can manually reconnect.
>

No top posting please. Im running out of ideas, are you sure the mouse
is advertising using the same address?

>
>
> On Fri, Jun 27, 2014 at 1:32 AM, Luiz Augusto von Dentz
> <[email protected]> wrote:
>> Hi Ryan,
>>
>> On Wed, Jun 25, 2014 at 4:23 PM, Ryan Press <[email protected]> wrote:
>>> Hi Luiz,
>>>
>>> Yes it will repeat the scan every few seconds.
>>>
>>> I paired the device in the Gnome applet. In the bluetoothctl I could
>>> see the pair and trust messages like so:
>>>
>>> [NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
>>> [CHG] Device C5:8C:97:E6:9C:81 Connected: yes
>>> [CHG] Device C5:8C:97:E6:9C:81 UUIDs:
>>> 00001800-0000-1000-8000-00805f9b34fb
>>> 00001801-0000-1000-8000-00805f9b34fb
>>> 0000180a-0000-1000-8000-00805f9b34fb
>>> 0000180f-0000-1000-8000-00805f9b34fb
>>> 00001812-0000-1000-8000-00805f9b34fb
>>> [CHG] Device C5:8C:97:E6:9C:81 Paired: yes
>>> [CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
>>> [CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001
>>>
>>> Thanks,
>>>
>>> Ryan
>>>
>>>
>>> On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>>>>
>>>> Hi Ryan,
>>>>
>>>> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
>>>> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
>>>> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
>>>> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
>>>> > off/on.
>>>> >
>>>> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
>>>> > fine, and it will continue to work until I turn the mouse off/on or
>>>> > turn the computer off/on. Then it won't reconnect automatically. If
>>>> > I go into bluetoothctl I can connect it again and it will then work.
>>>> >
>>>> > I looked at bluetoothd and it seems to be doing the LE scan with:
>>>> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
>>>> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
>>>> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
>>>> >
>>>> > I look also at hcidump and I see:
>>>> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
>>>> > bdaddr 39:6D:E2:EC:17:37
>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>> > LE Set Random Address (0x08|0x0005) ncmd 1
>>>> > status 0x00
>>>> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>>>> > type 0x01 (active)
>>>> > interval 11.250ms window 11.250ms
>>>> > own address: 0x01 (Random) policy: All
>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
>>>> > status 0x00
>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>> > value 0x01 (scanning enabled)
>>>> > filter duplicates 0x01 (enabled)
>>>> >> HCI Event: Command Complete (0x0e) plen 4
>>>> > LE Set Scan Enable (0x08|0x000c) ncmd 2
>>>> > status 0x00
>>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>>> > value 0x00 (scanning disabled)
>>>> > filter duplicates 0x00 (disabled)
>>>> >
>>>> >
>>>> > It doesn't seem to be finding anything? Is there something else I should try?
>>>>
>>>> Does it continue to scan or it scan a single time and stops, and have
>>>> you paired or just connect?
>>
>> Can you try with current master, we have applied a few patches for reconnection.
>>
>>
>> --
>> Luiz Augusto von Dentz



--
Luiz Augusto von Dentz

2014-06-28 15:50:04

by Ryan Press

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Luiz,

I have compiled and install the git Bluez.

It's the same as before, I can pair it and it will work, but it won't
automatically reconnect. Using bluetoothctl and "connect" command I
can manually reconnect.

Thanks for the help.

Ryan


On Fri, Jun 27, 2014 at 1:32 AM, Luiz Augusto von Dentz
<[email protected]> wrote:
> Hi Ryan,
>
> On Wed, Jun 25, 2014 at 4:23 PM, Ryan Press <[email protected]> wrote:
>> Hi Luiz,
>>
>> Yes it will repeat the scan every few seconds.
>>
>> I paired the device in the Gnome applet. In the bluetoothctl I could
>> see the pair and trust messages like so:
>>
>> [NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
>> [CHG] Device C5:8C:97:E6:9C:81 Connected: yes
>> [CHG] Device C5:8C:97:E6:9C:81 UUIDs:
>> 00001800-0000-1000-8000-00805f9b34fb
>> 00001801-0000-1000-8000-00805f9b34fb
>> 0000180a-0000-1000-8000-00805f9b34fb
>> 0000180f-0000-1000-8000-00805f9b34fb
>> 00001812-0000-1000-8000-00805f9b34fb
>> [CHG] Device C5:8C:97:E6:9C:81 Paired: yes
>> [CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
>> [CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001
>>
>> Thanks,
>>
>> Ryan
>>
>>
>> On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>>>
>>> Hi Ryan,
>>>
>>> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
>>> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
>>> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
>>> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
>>> > off/on.
>>> >
>>> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
>>> > fine, and it will continue to work until I turn the mouse off/on or
>>> > turn the computer off/on. Then it won't reconnect automatically. If
>>> > I go into bluetoothctl I can connect it again and it will then work.
>>> >
>>> > I looked at bluetoothd and it seems to be doing the LE scan with:
>>> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
>>> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
>>> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
>>> >
>>> > I look also at hcidump and I see:
>>> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
>>> > bdaddr 39:6D:E2:EC:17:37
>>> >> HCI Event: Command Complete (0x0e) plen 4
>>> > LE Set Random Address (0x08|0x0005) ncmd 1
>>> > status 0x00
>>> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>>> > type 0x01 (active)
>>> > interval 11.250ms window 11.250ms
>>> > own address: 0x01 (Random) policy: All
>>> >> HCI Event: Command Complete (0x0e) plen 4
>>> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
>>> > status 0x00
>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>> > value 0x01 (scanning enabled)
>>> > filter duplicates 0x01 (enabled)
>>> >> HCI Event: Command Complete (0x0e) plen 4
>>> > LE Set Scan Enable (0x08|0x000c) ncmd 2
>>> > status 0x00
>>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>> > value 0x00 (scanning disabled)
>>> > filter duplicates 0x00 (disabled)
>>> >
>>> >
>>> > It doesn't seem to be finding anything? Is there something else I should try?
>>>
>>> Does it continue to scan or it scan a single time and stops, and have
>>> you paired or just connect?
>
> Can you try with current master, we have applied a few patches for reconnection.
>
>
> --
> Luiz Augusto von Dentz

2014-06-27 08:32:00

by Luiz Augusto von Dentz

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Ryan,

On Wed, Jun 25, 2014 at 4:23 PM, Ryan Press <[email protected]> wrote:
> Hi Luiz,
>
> Yes it will repeat the scan every few seconds.
>
> I paired the device in the Gnome applet. In the bluetoothctl I could
> see the pair and trust messages like so:
>
> [NEW] Device C5:8C:97:E6:9C:81 Arc Touch Mouse SE
> [CHG] Device C5:8C:97:E6:9C:81 Connected: yes
> [CHG] Device C5:8C:97:E6:9C:81 UUIDs:
> 00001800-0000-1000-8000-00805f9b34fb
> 00001801-0000-1000-8000-00805f9b34fb
> 0000180a-0000-1000-8000-00805f9b34fb
> 0000180f-0000-1000-8000-00805f9b34fb
> 00001812-0000-1000-8000-00805f9b34fb
> [CHG] Device C5:8C:97:E6:9C:81 Paired: yes
> [CHG] Device C5:8C:97:E6:9C:81 Trusted: yes
> [CHG] Device C5:8C:97:E6:9C:81 Modalias: usb:v045Ep07F3d0001
>
> Thanks,
>
> Ryan
>
>
> On Jun 25, 2014 12:08 AM, "Luiz Augusto von Dentz" <[email protected]> wrote:
>>
>> Hi Ryan,
>>
>> On Wed, Jun 25, 2014 at 5:27 AM, Ryan Press <[email protected]> wrote:
>> > I have a Microsoft Arc mouse, Surface edition. This uses Bluetooth
>> > Low Energy. Under dual boot Windows 8.1 I can connect this mouse, and
>> > it will reconnect just fine if I turn the mouse off/on or Bluetooth
>> > off/on.
>> >
>> > In Fedora rawhide I have Bluez 5.18-2. I can pair this mouse just
>> > fine, and it will continue to work until I turn the mouse off/on or
>> > turn the computer off/on. Then it won't reconnect automatically. If
>> > I go into bluetoothctl I can connect it again and it will then work.
>> >
>> > I looked at bluetoothd and it seems to be doing the LE scan with:
>> > bluetoothd[2356]: src/adapter.c:trigger_passive_scanning()
>> > bluetoothd[2356]: src/adapter.c:passive_scanning_complete() status 0x00
>> > bluetoothd[2356]: src/adapter.c:discovering_callback() hci0 type 6 discovering 1
>> >
>> > I look also at hcidump and I see:
>> > < HCI Command: LE Set Random Address (0x08|0x0005) plen 6
>> > bdaddr 39:6D:E2:EC:17:37
>> >> HCI Event: Command Complete (0x0e) plen 4
>> > LE Set Random Address (0x08|0x0005) ncmd 1
>> > status 0x00
>> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>> > type 0x01 (active)
>> > interval 11.250ms window 11.250ms
>> > own address: 0x01 (Random) policy: All
>> >> HCI Event: Command Complete (0x0e) plen 4
>> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
>> > status 0x00
>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> > value 0x01 (scanning enabled)
>> > filter duplicates 0x01 (enabled)
>> >> HCI Event: Command Complete (0x0e) plen 4
>> > LE Set Scan Enable (0x08|0x000c) ncmd 2
>> > status 0x00
>> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> > value 0x00 (scanning disabled)
>> > filter duplicates 0x00 (disabled)
>> >
>> >
>> > It doesn't seem to be finding anything? Is there something else I should try?
>>
>> Does it continue to scan or it scan a single time and stops, and have
>> you paired or just connect?

Can you try with current master, we have applied a few patches for reconnection.


--
Luiz Augusto von Dentz

2014-07-03 15:18:58

by d.eriksson

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Marcel,

Somewhat hijacking this thread as we've been working on similar issues.
In the Nordic Semi HID code they by default set 5sec for the "FIRST_CONN_PARAMS_UPDATE_DELAY". As a temporary fix we just se this to 50msec to force a quicker re-connect.

We're doing our pairing using mgmt, could there be something we do wrong on our end causing the CCCDs not being stored in our nrf51822, and/or on the linux side?

best
David

< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 134.414928
Type: Active (0x01)
Interval: 11.250 msec (0x0012)
Window: 11.250 msec (0x0012)
Own address type: Public (0x00)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 134.421589
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 134.421659
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 134.422590
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 12 [hci0] 134.424481
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable directed - ADV_DIRECT_IND (0x01)
Address type: Random (0x01)
Address: F1:4A:67:6A:B7:FF (Static)
Data length: 0
RSSI: -73 dBm (0xb7)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 134.425082
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 134.425657
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25 [hci0] 134.426180
Scan interval: 2.500 msec (0x0004)
Scan window: 2.500 msec (0x0004)
Filter policy: White list is not used (0x00)
Peer address type: Random (0x01)
Peer address: F1:4A:67:6A:B7:FF (Static)
Own address type: Public (0x00)
Min connection interval: 50.00 msec (0x0028)
Max connection interval: 70.00 msec (0x0038)
Connection latency: 0x0000
Supervision timeout: 420 msec (0x002a)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 134.426831
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 134.432082
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 1025
Role: Master (0x00)
Peer address type: Random (0x01)
Peer address: F1:4A:67:6A:B7:FF (Static)
Connection interval: 70.00 msec (0x0038)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x01
< HCI Command: LE Start Encryption (0x08|0x0019) plen 28 [hci0] 134.441984
Handle: 1025
Random number: 0x3e0636865278ea8f
Encrypted diversifier: 0x9bf8
Long term key: fd90856caeb6478e9ff9cbeea73bdd4a
> HCI Event: Command Status (0x0f) plen 4 [hci0] 134.442966
LE Start Encryption (0x08|0x0019) ncmd 1
Status: Success (0x00)
@ Discovering: 0x01 (6)
@ Device Found: F1:4A:67:6A:B7:FF (2) rssi -73 flags 0x0000
@ Discovering: 0x00 (6)
@ Device Connected: F1:4A:67:6A:B7:FF (2) flags 0x0000
> HCI Event: Encryption Change (0x08) plen 4 [hci0] 135.019652
Status: Success (0x00)
Handle: 1025
Encryption: Enabled with AES-CCM (0x01)
< ACL Data TX: Handle 1025 flags 0x00 dlen 11 [hci0] 135.021069
ATT: Read By Type Request (0x08) len 6
Handle range: 0x000c-0x0010
Attribute type: Characteristic (0x2803)
> ACL Data RX: Handle 1025 flags 0x02 dlen 20 [hci0] 135.298900
ATT: Read By Type Response (0x09) len 15
Attribute data length: 7
Attribute data list: 2 entries
Handle: 0x000d
Value: 020e00292a
Handle: 0x000f
Value: 021000502a
< ACL Data TX: Handle 1025 flags 0x00 dlen 7 [hci0] 135.299576
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 672
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 135.327848
Num handles: 1
Handle: 1025
Count: 1
> ACL Data RX: Handle 1025 flags 0x02 dlen 7 [hci0] 135.438638
ATT: Exchange MTU Response (0x03) len 2
Server RX MTU: 23
< ACL Data TX: Handle 1025 flags 0x00 dlen 7 [hci0] 135.439219
ATT: Read Request (0x0a) len 2
Handle: 0x0010
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 135.467853
Num handles: 1
Handle: 1025
Count: 1
> ACL Data RX: Handle 1025 flags 0x02 dlen 12 [hci0] 135.578881
ATT: Read Response (0x0b) len 7
Value: 02672302000100
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 135.607860
Num handles: 1
Handle: 1025
Count: 1
> ACL Data RX: Handle 1025 flags 0x02 dlen 16 [hci0] 139.499097
LE L2CAP: Connection Parameter Update Request (0x12) ident 2 len 8
Min interval: 6
Max interval: 24
Slave latency: 6
Timeout multiplier: 30
< ACL Data TX: Handle 1025 flags 0x00 dlen 10 [hci0] 139.499205
LE L2CAP: Connection Parameter Update Response (0x13) ident 2 len 2
Result: Connection Parameters accepted (0x0000)
< HCI Command: LE Connection Update (0x08|0x0013) plen 14 [hci0] 139.499244
Handle: 1025
Min connection interval: 7.50 msec (0x0006)
Max connection interval: 30.00 msec (0x0018)
Connection latency: 0x0006
Supervision timeout: 300 msec (0x001e)
Min connection length: 0.625 msec (0x0001)
Max connection length: 0.625 msec (0x0001)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 139.499818
LE Connection Update (0x08|0x0013) ncmd 1
Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 139.738212
Num handles: 1
Handle: 1025
Count: 1
> ACL Data RX: Handle 1025 flags 0x02 dlen 10 [hci0] 139.997853
ATT: Handle Value Notification (0x1b) len 5
Handle: 0x0019
Data: 012401
> HCI Event: LE Meta Event (0x3e) plen 10 [hci0] 139.999622
LE Connection Update Complete (0x03)
Status: Success (0x00)
Handle: 1025
Connection interval: 28.75 msec (0x0017)
Connection latency: 7.50 msec (0x0006)
Supervision timeout: 300 msec (0x001e)




On 29 Jun 2014, at 19:52, Marcel Holtmann <[email protected]> wrote:

> this is a kernel issue with not remembering the previous connection parameters. What you see is that we start connecting with the default values and then the slave (the mouse) will correct us and tell us what connection parameters it needs. We accept them and actually change the LE link to use these parameters. However we end up forgetting them. So every time you connect this procedure keeps repeating itself.
>
> I fixed this as well, but for that you will need a bluetooth-next kernel where I enabled the management API for passive scanning and a modified bluetoothd that will then allow you a smooth experience. If the slave updates the connection parameters we remember them for devices using auto-connection. So once the connection is triggered via passive scanning the values will be remembered.
>
> At the moment, I have one minor issue with the re-connection within bluetoothd and once that is fixed this should be pretty instant.
>
> Regards
>
> Marcel

2014-07-01 16:01:26

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Scott,

>> the same applies to the HP mouse btw.
>>
>
> Which HP Mouse are you referring to?
>
> An HP Mouse I have uses general connectable advertising when it wants
> to reconnect.

might want to check HCI Remote Version Information (via hcitool cmd) for that device. So what we found out today is that the Nordic based HID devices only do direct advertising. However my CSR based one does direct advertising first and if it times out, it falls back to undirected advertising.

Regards

Marcel


2014-07-01 09:49:48

by Marcel Holtmann

[permalink] [raw]
Subject: Re: LE mouse reconnect problem

Hi Ryan,

>>> I have one other question with it. When it first reconnects the mouse
>>> pointer is really jerky, like it's updating really slow. Then after a
>>> few seconds it is normal; in fact it is very responsive compared to my
>>> old Bluetooth mouse. With Windows 8.1 it reconnects lightning fast
>>> when I turn it on, and it is not jerky at first.
>>>
>> this is a kernel issue with not remembering the previous connection parameters. What you see is that we start connecting with the default values and then the slave (the mouse) will correct us and tell us what connection parameters it needs. We accept them and actually change the LE link to use these parameters. However we end up forgetting them. So every time you connect this procedure keeps repeating itself.
>>
>> I fixed this as well, but for that you will need a bluetooth-next kernel where I enabled the management API for passive scanning and a modified bluetoothd that will then allow you a smooth experience. If the slave updates the connection parameters we remember them for devices using auto-connection. So once the connection is triggered via passive scanning the values will be remembered.
>>
>> At the moment, I have one minor issue with the re-connection within bluetoothd and once that is fixed this should be pretty instant.
>
>
> Okay, great, glad to hear that you're already on it. I'm really
> looking forward to the seamless Bluetooth experience on Linux! When
> everything is ready and in the master branch let me know and I will
> try them out.

the current bluetooth-next tree and bluez.git should now make this work smoothly. The first connection after starting bluetoothd will still use the wrong connection parameters, but all future ones will be snappy.

Regards

Marcel