* Unknown Connection Identifier
@ 2015-11-23 14:43 François Beaufort
2015-11-23 17:43 ` Marcel Holtmann
0 siblings, 1 reply; 16+ messages in thread
From: François Beaufort @ 2015-11-23 14:43 UTC (permalink / raw)
To: linux-bluetooth
Hello everyone!
Would you know why I get a "Status: Unknown Connection Identifier
(0x02)" error while trying to connect to a BLE device, causing a
"Connect failed" message. However sometimes, as you can read below, it
is still able to connect to it.
Bluetooth monitor ver 5.35
...
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
[hci0] 15:36:33.367332
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:33.368113
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 15:36:33.368139
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:33.369111
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15:36:37.636180
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Data length: 31
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Company: Anhui Huami Information Technology Co., Ltd. (343)
Data: 0093590469cb1080738d253d87117136f902880f109deb42
RSSI: -60 dBm (0xc4)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 15:36:37.636249
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:37.637121
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25
[hci0] 15:36:37.637198
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
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] 15:36:37.638083
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
[hci0] 15:36:39.643232
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:39.644088
LE Create Connection Cancel (0x08|0x000e) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 15:36:39.646071
LE Connection Complete (0x01)
Status: Unknown Connection Identifier (0x02)
Handle: 32
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Connection interval: 67.50 msec (0x0036)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
[hci0] 15:36:39.663306
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:39.664082
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 15:36:39.664181
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:39.665078
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15:36:40.647148
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Data length: 31
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Company: Anhui Huami Information Technology Co., Ltd. (343)
Data: 0093590469cb1080738d253d87117136f902880f109deb42
RSSI: -61 dBm (0xc3)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 15:36:40.647275
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:40.648077
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25
[hci0] 15:36:40.648195
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
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] 15:36:40.649074
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 15:36:42.154146
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 32
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Connection interval: 67.50 msec (0x0036)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
[hci0] 15:36:42.154539
Handle: 32
@ Device Connected: 88:0F:10:9D:EB:42 (1) flags 0x0000
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-23 14:43 Unknown Connection Identifier François Beaufort
@ 2015-11-23 17:43 ` Marcel Holtmann
2015-11-23 18:23 ` Szymon Janc
0 siblings, 1 reply; 16+ messages in thread
From: Marcel Holtmann @ 2015-11-23 17:43 UTC (permalink / raw)
To: François Beaufort; +Cc: linux-bluetooth
Hi Francois,
> Would you know why I get a "Status: Unknown Connection Identifier
> (0x02)" error while trying to connect to a BLE device, causing a
> "Connect failed" message. However sometimes, as you can read below, it
> is still able to connect to it.
>
> Bluetooth monitor ver 5.35
> ...
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> [hci0] 15:36:33.367332
> Type: Passive (0x00)
> Interval: 60.000 msec (0x0060)
> Window: 30.000 msec (0x0030)
> Own address type: Public (0x00)
> Filter policy: Ignore not in white list (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:33.368113
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> [hci0] 15:36:33.368139
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:33.369111
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15:36:37.636180
> LE Advertising Report (0x02)
> Num reports: 1
> Event type: Connectable undirected - ADV_IND (0x00)
> Address type: Public (0x00)
> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> Data length: 31
> Flags: 0x06
> LE General Discoverable Mode
> BR/EDR Not Supported
> Company: Anhui Huami Information Technology Co., Ltd. (343)
> Data: 0093590469cb1080738d253d87117136f902880f109deb42
> RSSI: -60 dBm (0xc4)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> [hci0] 15:36:37.636249
> Scanning: Disabled (0x00)
> Filter duplicates: Disabled (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:37.637121
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> [hci0] 15:36:37.637198
> Scan interval: 60.000 msec (0x0060)
> Scan window: 30.000 msec (0x0030)
> Filter policy: White list is not used (0x00)
> Peer address type: Public (0x00)
> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> 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] 15:36:37.638083
> LE Create Connection (0x08|0x000d) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
> [hci0] 15:36:39.643232
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15:36:39.644088
> LE Create Connection Cancel (0x08|0x000e) ncmd 1
> Status: Success (0x00)
here you are cancelling the connection attempt.
>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 15:36:39.646071
> LE Connection Complete (0x01)
> Status: Unknown Connection Identifier (0x02)
And this results in a connect complete with the this error. It actually says the create connection cancel has been successful.
I think the real question is why we are ending up with the create connection cancel in the first place. Only 2 seconds after the connection attempt.
> Handle: 32
> Role: Master (0x00)
> Peer address type: Public (0x00)
> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> Connection interval: 67.50 msec (0x0036)
> Connection latency: 0.00 msec (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x00
> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
This mgmt message might also be bug. It depends on what triggered the connection and the cancel action, but in general we are not tracking the state correctly as it seems. The message will not hurt, but I think it should not be here in the first place.
How are you triggering the connection?
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-23 17:43 ` Marcel Holtmann
@ 2015-11-23 18:23 ` Szymon Janc
2015-11-24 9:24 ` François Beaufort
0 siblings, 1 reply; 16+ messages in thread
From: Szymon Janc @ 2015-11-23 18:23 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: François Beaufort, linux-bluetooth
Hi,
On Monday 23 November 2015 18:43:11 Marcel Holtmann wrote:
> Hi Francois,
>
> > Would you know why I get a "Status: Unknown Connection Identifier
> > (0x02)" error while trying to connect to a BLE device, causing a
> > "Connect failed" message. However sometimes, as you can read below, it
> > is still able to connect to it.
> >
> > Bluetooth monitor ver 5.35
> > ...
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> > [hci0] 15:36:33.367332
> >
> > Type: Passive (0x00)
> > Interval: 60.000 msec (0x0060)
> > Window: 30.000 msec (0x0030)
> > Own address type: Public (0x00)
> > Filter policy: Ignore not in white list (0x01)
> >>
> >> HCI Event: Command Complete (0x0e) plen 4
> >> [hci0] 15:36:33.368113>>
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> >
> > Status: Success (0x00)
> >
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > [hci0] 15:36:33.368139
> >
> > Scanning: Enabled (0x01)
> > Filter duplicates: Enabled (0x01)
> >>
> >> HCI Event: Command Complete (0x0e) plen 4
> >> [hci0] 15:36:33.369111>>
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> >
> > Status: Success (0x00)
> >>
> >> HCI Event: LE Meta Event (0x3e) plen 43
> >> [hci0] 15:36:37.636180>>
> > LE Advertising Report (0x02)
> >
> > Num reports: 1
> > Event type: Connectable undirected - ADV_IND (0x00)
> > Address type: Public (0x00)
> > Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > Data length: 31
> > Flags: 0x06
> >
> > LE General Discoverable Mode
> > BR/EDR Not Supported
> >
> > Company: Anhui Huami Information Technology Co., Ltd. (343)
> >
> > Data: 0093590469cb1080738d253d87117136f902880f109deb42
> >
> > RSSI: -60 dBm (0xc4)
> >
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > [hci0] 15:36:37.636249
> >
> > Scanning: Disabled (0x00)
> > Filter duplicates: Disabled (0x00)
> >>
> >> HCI Event: Command Complete (0x0e) plen 4
> >> [hci0] 15:36:37.637121>>
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> >
> > Status: Success (0x00)
> >
> > < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> > [hci0] 15:36:37.637198
> >
> > Scan interval: 60.000 msec (0x0060)
> > Scan window: 30.000 msec (0x0030)
> > Filter policy: White list is not used (0x00)
> > Peer address type: Public (0x00)
> > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > 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] 15:36:37.638083>>
> > LE Create Connection (0x08|0x000d) ncmd 1
> >
> > Status: Success (0x00)
> >
> > < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
> > [hci0] 15:36:39.643232
> >
> >> HCI Event: Command Complete (0x0e) plen 4
> >> [hci0] 15:36:39.644088>>
> > LE Create Connection Cancel (0x08|0x000e) ncmd 1
> >
> > Status: Success (0x00)
>
> here you are cancelling the connection attempt.
>
> >> HCI Event: LE Meta Event (0x3e) plen 19
> >> [hci0] 15:36:39.646071>>
> > LE Connection Complete (0x01)
> >
> > Status: Unknown Connection Identifier (0x02)
>
> And this results in a connect complete with the this error. It actually says
> the create connection cancel has been successful.
>
> I think the real question is why we are ending up with the create connection
> cancel in the first place. Only 2 seconds after the connection attempt.
This is to not block other devices from connecting if pending connection takes
too long (we can't have more than 1 pending connection).
> > Handle: 32
> > Role: Master (0x00)
> > Peer address type: Public (0x00)
> > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > Connection interval: 67.50 msec (0x0036)
> > Connection latency: 0.00 msec (0x0000)
> > Supervision timeout: 420 msec (0x002a)
> > Master clock accuracy: 0x00
> >
> > @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>
> This mgmt message might also be bug. It depends on what triggered the
> connection and the cancel action, but in general we are not tracking the
> state correctly as it seems. The message will not hurt, but I think it
> should not be here in the first place.
>
> How are you triggering the connection?
>
> Regards
>
> Marcel
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth"
> in the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
--
pozdrawiam
Szymon Janc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-23 18:23 ` Szymon Janc
@ 2015-11-24 9:24 ` François Beaufort
2015-11-24 11:00 ` Marcel Holtmann
0 siblings, 1 reply; 16+ messages in thread
From: François Beaufort @ 2015-11-24 9:24 UTC (permalink / raw)
To: Szymon Janc, Marcel Holtmann; +Cc: linux-bluetooth
Thanks both of you for your input.
Here are my 100% reproducible steps:
- Restart bluetoothd to start fresh
- Remove cached device (remove 88:0F:10:9D:EB:42)
- Run basic scan (scan on)
- Wait for the device to pop up in results and stop scan (scan off)
- Try to connect to it (connect 88:0F:10:9D:EB:42)
As you can read below I now have 2 "LE Connection Complete (0x01)" events.
Bluetooth monitor ver 5.35
= New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
[hci0] 0.624321
< HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
[hci0] 11.038826
Address type: Public (0x00)
Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.040084
LE Add Device To White List (0x08|0x0011) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
[hci0] 11.040125
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.041085
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 11.041134
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.042084
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15.668141
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Data length: 31
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Company: Anhui Huami Information Technology Co., Ltd. (343)
Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
RSSI: -59 dBm (0xc5)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 15.668289
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15.669062
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25
[hci0] 15.669171
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
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] 15.670065
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
[hci0] 17.670566
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
LE Create Connection Cancel (0x08|0x000e) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
LE Connection Complete (0x01)
Status: Unknown Connection Identifier (0x02)
Handle: 32
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Connection interval: 67.50 msec (0x0036)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
[hci0] 17.687564
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.689036
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 17.689118
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.690036
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 18.672125
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Data length: 31
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
Company: Anhui Huami Information Technology Co., Ltd. (343)
Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
RSSI: -62 dBm (0xc2)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
[hci0] 18.672266
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 18.673040
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25
[hci0] 18.673161
Scan interval: 60.000 msec (0x0060)
Scan window: 30.000 msec (0x0030)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
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] 18.674040
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
[hci0] 20.678576
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 20.680062
LE Create Connection Cancel (0x08|0x000e) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 20.682048
LE Connection Complete (0x01)
Status: Unknown Connection Identifier (0x02)
Handle: 32
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
Connection interval: 67.50 msec (0x0036)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
@ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
On Mon, Nov 23, 2015 at 7:23 PM Szymon Janc <szymon.janc@codecoup.pl> wrote:
>
> Hi,
>
> On Monday 23 November 2015 18:43:11 Marcel Holtmann wrote:
> > Hi Francois,
> >
> > > Would you know why I get a "Status: Unknown Connection Identifier
> > > (0x02)" error while trying to connect to a BLE device, causing a
> > > "Connect failed" message. However sometimes, as you can read below, it
> > > is still able to connect to it.
> > >
> > > Bluetooth monitor ver 5.35
> > > ...
> > > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> > > [hci0] 15:36:33.367332
> > >
> > > Type: Passive (0x00)
> > > Interval: 60.000 msec (0x0060)
> > > Window: 30.000 msec (0x0030)
> > > Own address type: Public (0x00)
> > > Filter policy: Ignore not in white list (0x01)
> > >>
> > >> HCI Event: Command Complete (0x0e) plen 4
> > >> [hci0] 15:36:33.368113>>
> > > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > >
> > > Status: Success (0x00)
> > >
> > > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > > [hci0] 15:36:33.368139
> > >
> > > Scanning: Enabled (0x01)
> > > Filter duplicates: Enabled (0x01)
> > >>
> > >> HCI Event: Command Complete (0x0e) plen 4
> > >> [hci0] 15:36:33.369111>>
> > > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > >
> > > Status: Success (0x00)
> > >>
> > >> HCI Event: LE Meta Event (0x3e) plen 43
> > >> [hci0] 15:36:37.636180>>
> > > LE Advertising Report (0x02)
> > >
> > > Num reports: 1
> > > Event type: Connectable undirected - ADV_IND (0x00)
> > > Address type: Public (0x00)
> > > Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > > Data length: 31
> > > Flags: 0x06
> > >
> > > LE General Discoverable Mode
> > > BR/EDR Not Supported
> > >
> > > Company: Anhui Huami Information Technology Co., Ltd. (343)
> > >
> > > Data: 0093590469cb1080738d253d87117136f902880f109deb42
> > >
> > > RSSI: -60 dBm (0xc4)
> > >
> > > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > > [hci0] 15:36:37.636249
> > >
> > > Scanning: Disabled (0x00)
> > > Filter duplicates: Disabled (0x00)
> > >>
> > >> HCI Event: Command Complete (0x0e) plen 4
> > >> [hci0] 15:36:37.637121>>
> > > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > >
> > > Status: Success (0x00)
> > >
> > > < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> > > [hci0] 15:36:37.637198
> > >
> > > Scan interval: 60.000 msec (0x0060)
> > > Scan window: 30.000 msec (0x0030)
> > > Filter policy: White list is not used (0x00)
> > > Peer address type: Public (0x00)
> > > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > > 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] 15:36:37.638083>>
> > > LE Create Connection (0x08|0x000d) ncmd 1
> > >
> > > Status: Success (0x00)
> > >
> > > < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
> > > [hci0] 15:36:39.643232
> > >
> > >> HCI Event: Command Complete (0x0e) plen 4
> > >> [hci0] 15:36:39.644088>>
> > > LE Create Connection Cancel (0x08|0x000e) ncmd 1
> > >
> > > Status: Success (0x00)
> >
> > here you are cancelling the connection attempt.
> >
> > >> HCI Event: LE Meta Event (0x3e) plen 19
> > >> [hci0] 15:36:39.646071>>
> > > LE Connection Complete (0x01)
> > >
> > > Status: Unknown Connection Identifier (0x02)
> >
> > And this results in a connect complete with the this error. It actually says
> > the create connection cancel has been successful.
> >
> > I think the real question is why we are ending up with the create connection
> > cancel in the first place. Only 2 seconds after the connection attempt.
>
> This is to not block other devices from connecting if pending connection takes
> too long (we can't have more than 1 pending connection).
>
> > > Handle: 32
> > > Role: Master (0x00)
> > > Peer address type: Public (0x00)
> > > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > > Connection interval: 67.50 msec (0x0036)
> > > Connection latency: 0.00 msec (0x0000)
> > > Supervision timeout: 420 msec (0x002a)
> > > Master clock accuracy: 0x00
> > >
> > > @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
> >
> > This mgmt message might also be bug. It depends on what triggered the
> > connection and the cancel action, but in general we are not tracking the
> > state correctly as it seems. The message will not hurt, but I think it
> > should not be here in the first place.
> >
> > How are you triggering the connection?
> >
> > Regards
> >
> > Marcel
> >
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-bluetooth"
> > in the body of a message to majordomo@vger.kernel.org
> > More majordomo info at http://vger.kernel.org/majordomo-info.html
>
> --
> pozdrawiam
> Szymon Janc
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-24 9:24 ` François Beaufort
@ 2015-11-24 11:00 ` Marcel Holtmann
2015-11-24 12:05 ` François Beaufort
` (3 more replies)
0 siblings, 4 replies; 16+ messages in thread
From: Marcel Holtmann @ 2015-11-24 11:00 UTC (permalink / raw)
To: François Beaufort; +Cc: Szymon Janc, linux-bluetooth
Hi Francois,
> Thanks both of you for your input.
>
> Here are my 100% reproducible steps:
> - Restart bluetoothd to start fresh
> - Remove cached device (remove 88:0F:10:9D:EB:42)
> - Run basic scan (scan on)
> - Wait for the device to pop up in results and stop scan (scan off)
> - Try to connect to it (connect 88:0F:10:9D:EB:42)
>
> As you can read below I now have 2 "LE Connection Complete (0x01)" events.
>
> Bluetooth monitor ver 5.35
> = New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
> [hci0] 0.624321
> < HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
> [hci0] 11.038826
> Address type: Public (0x00)
> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.040084
> LE Add Device To White List (0x08|0x0011) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> [hci0] 11.040125
> Type: Passive (0x00)
> Interval: 60.000 msec (0x0060)
> Window: 30.000 msec (0x0030)
> Own address type: Public (0x00)
> Filter policy: Ignore not in white list (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.041085
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> [hci0] 11.041134
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.042084
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15.668141
> LE Advertising Report (0x02)
> Num reports: 1
> Event type: Connectable undirected - ADV_IND (0x00)
> Address type: Public (0x00)
> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> Data length: 31
> Flags: 0x06
> LE General Discoverable Mode
> BR/EDR Not Supported
> Company: Anhui Huami Information Technology Co., Ltd. (343)
> Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
> RSSI: -59 dBm (0xc5)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> [hci0] 15.668289
> Scanning: Disabled (0x00)
> Filter duplicates: Disabled (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15.669062
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> [hci0] 15.669171
> Scan interval: 60.000 msec (0x0060)
> Scan window: 30.000 msec (0x0030)
we might should have the LE Create Connection scan with a full duty cycle here. So it does not miss any advertising PDUs.
> Filter policy: White list is not used (0x00)
> Peer address type: Public (0x00)
> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> 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] 15.670065
> LE Create Connection (0x08|0x000d) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
> [hci0] 17.670566
And I think we need to increase the timeout to something like 4-5 seconds before we give up and try the next device that might have been found.
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
> LE Create Connection Cancel (0x08|0x000e) ncmd 1
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
> LE Connection Complete (0x01)
> Status: Unknown Connection Identifier (0x02)
> Handle: 32
> Role: Master (0x00)
> Peer address type: Public (0x00)
> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> Connection interval: 67.50 msec (0x0036)
> Connection latency: 0.00 msec (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x00
> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
This one still needs to be fixed. It is a bug. The implementation is too naive. The unknown connection identifier is actually the success case for LE Create Connection Cancel command. And since we keep trying until the connection timeout hits, this is not an error at this point.
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-24 11:00 ` Marcel Holtmann
@ 2015-11-24 12:05 ` François Beaufort
2015-11-30 7:43 ` François Beaufort
` (2 subsequent siblings)
3 siblings, 0 replies; 16+ messages in thread
From: François Beaufort @ 2015-11-24 12:05 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: Szymon Janc, linux-bluetooth
On Tue, Nov 24, 2015 at 12:00 PM, Marcel Holtmann <marcel@holtmann.org> wro=
te:
> Hi Francois,
>
>> Thanks both of you for your input.
>>
>> Here are my 100% reproducible steps:
>> - Restart bluetoothd to start fresh
>> - Remove cached device (remove 88:0F:10:9D:EB:42)
>> - Run basic scan (scan on)
>> - Wait for the device to pop up in results and stop scan (scan off)
>> - Try to connect to it (connect 88:0F:10:9D:EB:42)
>>
>> As you can read below I now have 2 "LE Connection Complete (0x01)" event=
s.
>>
>> Bluetooth monitor ver 5.35
>> =3D New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
>> [hci0] 0.624321
>> < HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
>> [hci0] 11.038826
>> Address type: Public (0x00)
>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.040084
>> LE Add Device To White List (0x08|0x0011) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>> [hci0] 11.040125
>> Type: Passive (0x00)
>> Interval: 60.000 msec (0x0060)
>> Window: 30.000 msec (0x0030)
>> Own address type: Public (0x00)
>> Filter policy: Ignore not in white list (0x01)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.041085
>> LE Set Scan Parameters (0x08|0x000b) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> [hci0] 11.041134
>> Scanning: Enabled (0x01)
>> Filter duplicates: Enabled (0x01)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.042084
>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>> Status: Success (0x00)
>>> HCI Event: LE Meta Event (0x3e) plen 43 =
[hci0] 15.668141
>> LE Advertising Report (0x02)
>> Num reports: 1
>> Event type: Connectable undirected - ADV_IND (0x00)
>> Address type: Public (0x00)
>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> Data length: 31
>> Flags: 0x06
>> LE General Discoverable Mode
>> BR/EDR Not Supported
>> Company: Anhui Huami Information Technology Co., Ltd. (343)
>> Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
>> RSSI: -59 dBm (0xc5)
>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> [hci0] 15.668289
>> Scanning: Disabled (0x00)
>> Filter duplicates: Disabled (0x00)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 15.669062
>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>> [hci0] 15.669171
>> Scan interval: 60.000 msec (0x0060)
>> Scan window: 30.000 msec (0x0030)
>
> we might should have the LE Create Connection scan with a full duty cycle=
here. So it does not miss any advertising PDUs.
>
>> Filter policy: White list is not used (0x00)
>> Peer address type: Public (0x00)
>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> 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] 15.670065
>> LE Create Connection (0x08|0x000d) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
>> [hci0] 17.670566
>
> And I think we need to increase the timeout to something like 4-5 seconds=
before we give up and try the next device that might have been found.
>
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 17.672048
>> LE Create Connection Cancel (0x08|0x000e) ncmd 1
>> Status: Success (0x00)
>>> HCI Event: LE Meta Event (0x3e) plen 19 =
[hci0] 17.674036
>> LE Connection Complete (0x01)
>> Status: Unknown Connection Identifier (0x02)
>> Handle: 32
>> Role: Master (0x00)
>> Peer address type: Public (0x00)
>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> Connection interval: 67.50 msec (0x0036)
>> Connection latency: 0.00 msec (0x0000)
>> Supervision timeout: 420 msec (0x002a)
>> Master clock accuracy: 0x00
>> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>
> This one still needs to be fixed. It is a bug. The implementation is too =
naive. The unknown connection identifier is actually the success case for L=
E Create Connection Cancel command. And since we keep trying until the conn=
ection timeout hits, this is not an error at this point.
Where should I file that bug so that I can keep track of it?
>
> Regards
>
> Marcel
>
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-24 11:00 ` Marcel Holtmann
2015-11-24 12:05 ` François Beaufort
@ 2015-11-30 7:43 ` François Beaufort
2015-11-30 7:44 ` François Beaufort
2015-12-01 8:41 ` Johan Hedberg
3 siblings, 0 replies; 16+ messages in thread
From: François Beaufort @ 2015-11-30 7:43 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: Szymon Janc, linux-bluetooth
[-- Attachment #1: Type: text/plain, Size: 5307 bytes --]
On Tue, Nov 24, 2015 at 12:00 PM, Marcel Holtmann <marcel@holtmann.org>
wrote:
> Hi Francois,
>
> > Thanks both of you for your input.
> >
> > Here are my 100% reproducible steps:
> > - Restart bluetoothd to start fresh
> > - Remove cached device (remove 88:0F:10:9D:EB:42)
> > - Run basic scan (scan on)
> > - Wait for the device to pop up in results and stop scan (scan off)
> > - Try to connect to it (connect 88:0F:10:9D:EB:42)
> >
> > As you can read below I now have 2 "LE Connection Complete (0x01)"
> events.
> >
> > Bluetooth monitor ver 5.35
> > = New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
> > [hci0] 0.624321
> > < HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
> > [hci0] 11.038826
> > Address type: Public (0x00)
> > Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> >> HCI Event: Command Complete (0x0e) plen 4
> [hci0] 11.040084
> > LE Add Device To White List (0x08|0x0011) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
> > [hci0] 11.040125
> > Type: Passive (0x00)
> > Interval: 60.000 msec (0x0060)
> > Window: 30.000 msec (0x0030)
> > Own address type: Public (0x00)
> > Filter policy: Ignore not in white list (0x01)
> >> HCI Event: Command Complete (0x0e) plen 4
> [hci0] 11.041085
> > LE Set Scan Parameters (0x08|0x000b) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > [hci0] 11.041134
> > Scanning: Enabled (0x01)
> > Filter duplicates: Enabled (0x01)
> >> HCI Event: Command Complete (0x0e) plen 4
> [hci0] 11.042084
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > Status: Success (0x00)
> >> HCI Event: LE Meta Event (0x3e) plen 43
> [hci0] 15.668141
> > LE Advertising Report (0x02)
> > Num reports: 1
> > Event type: Connectable undirected - ADV_IND (0x00)
> > Address type: Public (0x00)
> > Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > Data length: 31
> > Flags: 0x06
> > LE General Discoverable Mode
> > BR/EDR Not Supported
> > Company: Anhui Huami Information Technology Co., Ltd. (343)
> > Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
> > RSSI: -59 dBm (0xc5)
> > < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
> > [hci0] 15.668289
> > Scanning: Disabled (0x00)
> > Filter duplicates: Disabled (0x00)
> >> HCI Event: Command Complete (0x0e) plen 4
> [hci0] 15.669062
> > LE Set Scan Enable (0x08|0x000c) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> > [hci0] 15.669171
> > Scan interval: 60.000 msec (0x0060)
> > Scan window: 30.000 msec (0x0030)
>
> we might should have the LE Create Connection scan with a full duty cycle
> here. So it does not miss any advertising PDUs.
>
Is this something the Linux Bluetooth team is going to address?
>
> > Filter policy: White list is not used (0x00)
> > Peer address type: Public (0x00)
> > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > 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] 15.670065
> > LE Create Connection (0x08|0x000d) ncmd 1
> > Status: Success (0x00)
> > < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
> > [hci0] 17.670566
>
> And I think we need to increase the timeout to something like 4-5 seconds
> before we give up and try the next device that might have been found.
>
>
For my own curiosity, how does does perform Android Bluetooth stack when
creating a LE connection?
Does it hardcode a 4-5 seconds timeout or does it use other heuristics?
> >> HCI Event: Command Complete (0x0e) plen 4
> [hci0] 17.672048
> > LE Create Connection Cancel (0x08|0x000e) ncmd 1
> > Status: Success (0x00)
> >> HCI Event: LE Meta Event (0x3e) plen 19
> [hci0] 17.674036
> > LE Connection Complete (0x01)
> > Status: Unknown Connection Identifier (0x02)
> > Handle: 32
> > Role: Master (0x00)
> > Peer address type: Public (0x00)
> > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > Connection interval: 67.50 msec (0x0036)
> > Connection latency: 0.00 msec (0x0000)
> > Supervision timeout: 420 msec (0x002a)
> > Master clock accuracy: 0x00
> > @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>
> This one still needs to be fixed. It is a bug. The implementation is too
> naive. The unknown connection identifier is actually the success case for
> LE Create Connection Cancel command. And since we keep trying until the
> connection timeout hits, this is not an error at this point.
>
> Regards
>
> Marcel
>
>
[-- Attachment #2: Type: text/html, Size: 7414 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-24 11:00 ` Marcel Holtmann
2015-11-24 12:05 ` François Beaufort
2015-11-30 7:43 ` François Beaufort
@ 2015-11-30 7:44 ` François Beaufort
2015-11-30 10:51 ` Johan Hedberg
2015-11-30 17:55 ` Marcel Holtmann
2015-12-01 8:41 ` Johan Hedberg
3 siblings, 2 replies; 16+ messages in thread
From: François Beaufort @ 2015-11-30 7:44 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: Szymon Janc, linux-bluetooth
On Tue, Nov 24, 2015 at 12:00 PM, Marcel Holtmann <marcel@holtmann.org> wro=
te:
> Hi Francois,
>
>> Thanks both of you for your input.
>>
>> Here are my 100% reproducible steps:
>> - Restart bluetoothd to start fresh
>> - Remove cached device (remove 88:0F:10:9D:EB:42)
>> - Run basic scan (scan on)
>> - Wait for the device to pop up in results and stop scan (scan off)
>> - Try to connect to it (connect 88:0F:10:9D:EB:42)
>>
>> As you can read below I now have 2 "LE Connection Complete (0x01)" event=
s.
>>
>> Bluetooth monitor ver 5.35
>> =3D New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
>> [hci0] 0.624321
>> < HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
>> [hci0] 11.038826
>> Address type: Public (0x00)
>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.040084
>> LE Add Device To White List (0x08|0x0011) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>> [hci0] 11.040125
>> Type: Passive (0x00)
>> Interval: 60.000 msec (0x0060)
>> Window: 30.000 msec (0x0030)
>> Own address type: Public (0x00)
>> Filter policy: Ignore not in white list (0x01)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.041085
>> LE Set Scan Parameters (0x08|0x000b) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> [hci0] 11.041134
>> Scanning: Enabled (0x01)
>> Filter duplicates: Enabled (0x01)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 11.042084
>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>> Status: Success (0x00)
>>> HCI Event: LE Meta Event (0x3e) plen 43 =
[hci0] 15.668141
>> LE Advertising Report (0x02)
>> Num reports: 1
>> Event type: Connectable undirected - ADV_IND (0x00)
>> Address type: Public (0x00)
>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> Data length: 31
>> Flags: 0x06
>> LE General Discoverable Mode
>> BR/EDR Not Supported
>> Company: Anhui Huami Information Technology Co., Ltd. (343)
>> Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
>> RSSI: -59 dBm (0xc5)
>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>> [hci0] 15.668289
>> Scanning: Disabled (0x00)
>> Filter duplicates: Disabled (0x00)
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 15.669062
>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>> [hci0] 15.669171
>> Scan interval: 60.000 msec (0x0060)
>> Scan window: 30.000 msec (0x0030)
>
> we might should have the LE Create Connection scan with a full duty cycle=
here. So it does not miss any advertising PDUs.
Is this something the Linux Bluetooth team is going to address?
>
>> Filter policy: White list is not used (0x00)
>> Peer address type: Public (0x00)
>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> 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] 15.670065
>> LE Create Connection (0x08|0x000d) ncmd 1
>> Status: Success (0x00)
>> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
>> [hci0] 17.670566
>
> And I think we need to increase the timeout to something like 4-5 seconds=
before we give up and try the next device that might have been found.
>
For my own curiosity, how does does perform Android Bluetooth stack
when creating a LE connection?
Does it hardcode a 4-5 seconds timeout or does it use other heuristics?
>>> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 17.672048
>> LE Create Connection Cancel (0x08|0x000e) ncmd 1
>> Status: Success (0x00)
>>> HCI Event: LE Meta Event (0x3e) plen 19 =
[hci0] 17.674036
>> LE Connection Complete (0x01)
>> Status: Unknown Connection Identifier (0x02)
>> Handle: 32
>> Role: Master (0x00)
>> Peer address type: Public (0x00)
>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>> Connection interval: 67.50 msec (0x0036)
>> Connection latency: 0.00 msec (0x0000)
>> Supervision timeout: 420 msec (0x002a)
>> Master clock accuracy: 0x00
>> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>
> This one still needs to be fixed. It is a bug. The implementation is too =
naive. The unknown connection identifier is actually the success case for L=
E Create Connection Cancel command. And since we keep trying until the conn=
ection timeout hits, this is not an error at this point.
>
> Regards
>
> Marcel
>
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-30 7:44 ` François Beaufort
@ 2015-11-30 10:51 ` Johan Hedberg
2015-11-30 22:20 ` Vinicius Costa Gomes
2015-11-30 17:55 ` Marcel Holtmann
1 sibling, 1 reply; 16+ messages in thread
From: Johan Hedberg @ 2015-11-30 10:51 UTC (permalink / raw)
To: François Beaufort; +Cc: Marcel Holtmann, Szymon Janc, linux-bluetooth
Hi François,
On Mon, Nov 30, 2015, François Beaufort wrote:
> >> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
> >> [hci0] 15.669171
> >> Scan interval: 60.000 msec (0x0060)
> >> Scan window: 30.000 msec (0x0030)
> >
> > we might should have the LE Create Connection scan with a full duty
> > cycle here. So it does not miss any advertising PDUs.
>
> Is this something the Linux Bluetooth team is going to address?
I think this alone might fix the issue you're seeing. Could you please
try the patch I just sent and see if it solves the issue for you:
Bluetooth: Use continuous scanning when creating LE connections
Johan
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-30 7:44 ` François Beaufort
2015-11-30 10:51 ` Johan Hedberg
@ 2015-11-30 17:55 ` Marcel Holtmann
1 sibling, 0 replies; 16+ messages in thread
From: Marcel Holtmann @ 2015-11-30 17:55 UTC (permalink / raw)
To: François Beaufort; +Cc: Szymon Janc, linux-bluetooth
Hi Francois,
>>> Thanks both of you for your input.
>>>
>>> Here are my 100% reproducible steps:
>>> - Restart bluetoothd to start fresh
>>> - Remove cached device (remove 88:0F:10:9D:EB:42)
>>> - Run basic scan (scan on)
>>> - Wait for the device to pop up in results and stop scan (scan off)
>>> - Try to connect to it (connect 88:0F:10:9D:EB:42)
>>>
>>> As you can read below I now have 2 "LE Connection Complete (0x01)" events.
>>>
>>> Bluetooth monitor ver 5.35
>>> = New Index: A4:17:31:78:A6:04 (BR/EDR,USB,hci0)
>>> [hci0] 0.624321
>>> < HCI Command: LE Add Device To White List (0x08|0x0011) plen 7
>>> [hci0] 11.038826
>>> Address type: Public (0x00)
>>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.040084
>>> LE Add Device To White List (0x08|0x0011) ncmd 1
>>> Status: Success (0x00)
>>> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7
>>> [hci0] 11.040125
>>> Type: Passive (0x00)
>>> Interval: 60.000 msec (0x0060)
>>> Window: 30.000 msec (0x0030)
>>> Own address type: Public (0x00)
>>> Filter policy: Ignore not in white list (0x01)
>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.041085
>>> LE Set Scan Parameters (0x08|0x000b) ncmd 1
>>> Status: Success (0x00)
>>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>> [hci0] 11.041134
>>> Scanning: Enabled (0x01)
>>> Filter duplicates: Enabled (0x01)
>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 11.042084
>>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>>> Status: Success (0x00)
>>>> HCI Event: LE Meta Event (0x3e) plen 43 [hci0] 15.668141
>>> LE Advertising Report (0x02)
>>> Num reports: 1
>>> Event type: Connectable undirected - ADV_IND (0x00)
>>> Address type: Public (0x00)
>>> Address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>> Data length: 31
>>> Flags: 0x06
>>> LE General Discoverable Mode
>>> BR/EDR Not Supported
>>> Company: Anhui Huami Information Technology Co., Ltd. (343)
>>> Data: 00f70b676930f4c909f4a5acd792a299ff02880f109deb42
>>> RSSI: -59 dBm (0xc5)
>>> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2
>>> [hci0] 15.668289
>>> Scanning: Disabled (0x00)
>>> Filter duplicates: Disabled (0x00)
>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 15.669062
>>> LE Set Scan Enable (0x08|0x000c) ncmd 1
>>> Status: Success (0x00)
>>> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>>> [hci0] 15.669171
>>> Scan interval: 60.000 msec (0x0060)
>>> Scan window: 30.000 msec (0x0030)
>>
>> we might should have the LE Create Connection scan with a full duty cycle here. So it does not miss any advertising PDUs.
>
> Is this something the Linux Bluetooth team is going to address?
yes we are addressing this. Also the mgmt event with the connection failed error needs to be suppressed. While a connection attempt might still be aborted, it is not an error. It is really just lets scan one more time and try again.
>>> Filter policy: White list is not used (0x00)
>>> Peer address type: Public (0x00)
>>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>> 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] 15.670065
>>> LE Create Connection (0x08|0x000d) ncmd 1
>>> Status: Success (0x00)
>>> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0
>>> [hci0] 17.670566
>>
>> And I think we need to increase the timeout to something like 4-5 seconds before we give up and try the next device that might have been found.
>>
>
> For my own curiosity, how does does perform Android Bluetooth stack
> when creating a LE connection?
> Does it hardcode a 4-5 seconds timeout or does it use other heuristics?
I honestly do not know what Android picks as default values. Easy to find out though, just enable tracing and grab the btsnoop file via adb. You can read it with btmon btw.
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-30 10:51 ` Johan Hedberg
@ 2015-11-30 22:20 ` Vinicius Costa Gomes
2015-11-30 22:31 ` Marcel Holtmann
0 siblings, 1 reply; 16+ messages in thread
From: Vinicius Costa Gomes @ 2015-11-30 22:20 UTC (permalink / raw)
To: Johan Hedberg, François Beaufort
Cc: Marcel Holtmann, Szymon Janc, linux-bluetooth
Hi Johan,
Johan Hedberg <johan.hedberg@gmail.com> writes:
> Hi Fran=C3=A7ois,
>
> On Mon, Nov 30, 2015, Fran=C3=A7ois Beaufort wrote:
>> >> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>> >> [hci0] 15.669171
>> >> Scan interval: 60.000 msec (0x0060)
>> >> Scan window: 30.000 msec (0x0030)
>> >
>> > we might should have the LE Create Connection scan with a full duty
>> > cycle here. So it does not miss any advertising PDUs.
>>
>> Is this something the Linux Bluetooth team is going to address?
>
> I think this alone might fix the issue you're seeing. Could you please
> try the patch I just sent and see if it solves the issue for you:
>
> Bluetooth: Use continuous scanning when creating LE connections
I ended up with the same problem using the 4.3 kernel.
The patch seems to solve the issue, and could perhaps be submitted to
-stable.
I gave it a few tries trying to connect to a Parrot Flower Power, and
got into a situation that may indicate a possible race condition:
(this line: '< HCI Command: LE Create Connection Cancel... ')
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 =
[hci0] 20.602345
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 20.603330
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 =
[hci0] 20.603348
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 20.604339
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 36 =
[hci0] 21.508266
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Public (0x00)
Address: A0:14:3D:08:B5:36 (PARROT SA)
Data length: 24
Flags: 0x06
LE General Discoverable Mode
BR/EDR Not Supported
128-bit Service UUIDs (partial): 1 entry
39e1fa00-84a8-11e2-afba-0002a5d5c51b
RSSI: -59 dBm (0xc5)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 =
[hci0] 21.508332
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 21.510342
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25 =
[hci0] 21.510396
Scan interval: 60.000 msec (0x0060)
Scan window: 60.000 msec (0x0060)
Filter policy: White list is not used (0x00)
Peer address type: Public (0x00)
Peer address: A0:14:3D:08:B5:36 (PARROT SA)
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] 21.512248
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0 =
[hci0] 23.512098
> HCI Event: LE Meta Event (0x3e) plen 19 =
[hci0] 23.514370
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 64
Role: Master (0x00)
Peer address type: Public (0x00)
Peer address: A0:14:3D:08:B5:36 (PARROT SA)
Connection interval: 67.50 msec (0x0036)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x05
@ Device Connected: A0:14:3D:08:B5:36 (1) flags 0x0000
02 01 06 11 06 1b c5 d5 a5 02 00 ba af e2 11 a8 ................
84 00 fa e1 39 02 ff 03 ....9...
> HCI Event: Command Complete (0x0e) plen 4 =
[hci0] 23.519286
LE Create Connection Cancel (0x08|0x000e) ncmd 1
Status: Command Disallowed (0x0c)
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2 =
[hci0] 23.519347
Handle: 64
> HCI Event: Command Status (0x0f) plen 4 =
[hci0] 23.520302
LE Read Remote Used Features (0x08|0x0016) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 12 =
[hci0] 23.632256
LE Read Remote Used Features (0x04)
Status: Success (0x00)
Handle: 64
Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
LE Encryption
< ACL Data TX: Handle 64 flags 0x00 dlen 11 =
[hci0] 23.632361
SMP: Pairing Request (0x01) len 6
IO capability: NoInputNoOutput (0x03)
OOB data: Authentication data not present (0x00)
Authentication requirement: Bonding, No MITM, SC, No Keypresses (0x=
09)
Max encryption key size: 16
Initiator key distribution: EncKey Sign LinkKey (0x0d)
Responder key distribution: EncKey IdKey Sign LinkKey (0x0f)
>
> Johan
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth=
" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
Cheers,
--
Vinicius
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-30 22:20 ` Vinicius Costa Gomes
@ 2015-11-30 22:31 ` Marcel Holtmann
0 siblings, 0 replies; 16+ messages in thread
From: Marcel Holtmann @ 2015-11-30 22:31 UTC (permalink / raw)
To: Vinicius Costa Gomes
Cc: Johan Hedberg, François Beaufort, Szymon Janc, linux-bluetooth
Hi Vinicius,
>>>>> < HCI Command: LE Create Connection (0x08|0x000d) plen 25
>>>>> [hci0] 15.669171
>>>>> Scan interval: 60.000 msec (0x0060)
>>>>> Scan window: 30.000 msec (0x0030)
>>>>
>>>> we might should have the LE Create Connection scan with a full duty
>>>> cycle here. So it does not miss any advertising PDUs.
>>>
>>> Is this something the Linux Bluetooth team is going to address?
>>
>> I think this alone might fix the issue you're seeing. Could you please
>> try the patch I just sent and see if it solves the issue for you:
>>
>> Bluetooth: Use continuous scanning when creating LE connections
>
> I ended up with the same problem using the 4.3 kernel.
>
> The patch seems to solve the issue, and could perhaps be submitted to
> -stable.
>
> I gave it a few tries trying to connect to a Parrot Flower Power, and
> got into a situation that may indicate a possible race condition:
>
> (this line: '< HCI Command: LE Create Connection Cancel... ')
>
> < HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 20.602345
> Type: Passive (0x00)
> Interval: 60.000 msec (0x0060)
> Window: 30.000 msec (0x0030)
> Own address type: Public (0x00)
> Filter policy: Ignore not in white list (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 20.603330
> LE Set Scan Parameters (0x08|0x000b) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 20.603348
> Scanning: Enabled (0x01)
> Filter duplicates: Enabled (0x01)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 20.604339
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 36 [hci0] 21.508266
> LE Advertising Report (0x02)
> Num reports: 1
> Event type: Connectable undirected - ADV_IND (0x00)
> Address type: Public (0x00)
> Address: A0:14:3D:08:B5:36 (PARROT SA)
> Data length: 24
> Flags: 0x06
> LE General Discoverable Mode
> BR/EDR Not Supported
> 128-bit Service UUIDs (partial): 1 entry
> 39e1fa00-84a8-11e2-afba-0002a5d5c51b
> RSSI: -59 dBm (0xc5)
> < HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 21.508332
> Scanning: Disabled (0x00)
> Filter duplicates: Disabled (0x00)
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 21.510342
> LE Set Scan Enable (0x08|0x000c) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection (0x08|0x000d) plen 25 [hci0] 21.510396
> Scan interval: 60.000 msec (0x0060)
> Scan window: 60.000 msec (0x0060)
> Filter policy: White list is not used (0x00)
> Peer address type: Public (0x00)
> Peer address: A0:14:3D:08:B5:36 (PARROT SA)
> 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] 21.512248
> LE Create Connection (0x08|0x000d) ncmd 1
> Status: Success (0x00)
> < HCI Command: LE Create Connection Cancel (0x08|0x000e) plen 0 [hci0] 23.512098
>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 23.514370
> LE Connection Complete (0x01)
> Status: Success (0x00)
> Handle: 64
> Role: Master (0x00)
> Peer address type: Public (0x00)
> Peer address: A0:14:3D:08:B5:36 (PARROT SA)
> Connection interval: 67.50 msec (0x0036)
> Connection latency: 0.00 msec (0x0000)
> Supervision timeout: 420 msec (0x002a)
> Master clock accuracy: 0x05
> @ Device Connected: A0:14:3D:08:B5:36 (1) flags 0x0000
> 02 01 06 11 06 1b c5 d5 a5 02 00 ba af e2 11 a8 ................
> 84 00 fa e1 39 02 ff 03 ....9...
>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 23.519286
> LE Create Connection Cancel (0x08|0x000e) ncmd 1
> Status: Command Disallowed (0x0c)
I assume you means this one. The LE Connection Complete event arrives before the LE Create Connection Cancel actually completes.
Actually I do not think this is a race condition, it is just something with the nature on how LE connection are established (remember there is no CONN_RSP, just a CONN_REQ). It is just to catch this one since I think we need to be able to handle this one correctly.
If I remember the specification correctly, then you can only cancel a LE Create Connection that has not yet received its first data packet. Once the first data packet has arrived, then the connection has been established. Meaning the cancel operation either cancels the scanning or has to wait for the timeout of CONN_REQ. If you actually get a data packet, then it can not do anything anymore. Hence we have the Command Disallowed error here. Now only sending Disconnect will work.
It would be great if we have l2cap-tester or mgmt-tester test cases that simulate this behavior and also the other one where the LE Create Connection requires more than 2 seconds. Ensuring that we handle these correctly is important.
> < HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2 [hci0] 23.519347
> Handle: 64
>> HCI Event: Command Status (0x0f) plen 4 [hci0] 23.520302
> LE Read Remote Used Features (0x08|0x0016) ncmd 1
> Status: Success (0x00)
>> HCI Event: LE Meta Event (0x3e) plen 12 [hci0] 23.632256
> LE Read Remote Used Features (0x04)
> Status: Success (0x00)
> Handle: 64
> Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
> LE Encryption
> < ACL Data TX: Handle 64 flags 0x00 dlen 11 [hci0] 23.632361
> SMP: Pairing Request (0x01) len 6
> IO capability: NoInputNoOutput (0x03)
> OOB data: Authentication data not present (0x00)
> Authentication requirement: Bonding, No MITM, SC, No Keypresses (0x09)
> Max encryption key size: 16
> Initiator key distribution: EncKey Sign LinkKey (0x0d)
> Responder key distribution: EncKey IdKey Sign LinkKey (0x0f)
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-11-24 11:00 ` Marcel Holtmann
` (2 preceding siblings ...)
2015-11-30 7:44 ` François Beaufort
@ 2015-12-01 8:41 ` Johan Hedberg
2015-12-02 7:37 ` Marcel Holtmann
3 siblings, 1 reply; 16+ messages in thread
From: Johan Hedberg @ 2015-12-01 8:41 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: François Beaufort, Szymon Janc, linux-bluetooth
Hi Marcel,
On Tue, Nov 24, 2015, Marcel Holtmann wrote:
> >> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
> > LE Create Connection Cancel (0x08|0x000e) ncmd 1
> > Status: Success (0x00)
> >> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
> > LE Connection Complete (0x01)
> > Status: Unknown Connection Identifier (0x02)
> > Handle: 32
> > Role: Master (0x00)
> > Peer address type: Public (0x00)
> > Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> > Connection interval: 67.50 msec (0x0036)
> > Connection latency: 0.00 msec (0x0000)
> > Supervision timeout: 420 msec (0x002a)
> > Master clock accuracy: 0x00
> > @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>
> This one still needs to be fixed. It is a bug. The implementation is
> too naive. The unknown connection identifier is actually the success
> case for LE Create Connection Cancel command. And since we keep trying
> until the connection timeout hits, this is not an error at this point.
I think we need to differentiate between explicit connection requests
(L2CAP socket connect()) and Add Device based connections. For the
former we probably do want the Connect Failed since that's consistent
with the behavior you see when operating the L2CAP socket. For the
latter where we just go back to trying again, so the event doesn't
really describe what's going on.
Johan
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-12-01 8:41 ` Johan Hedberg
@ 2015-12-02 7:37 ` Marcel Holtmann
2015-12-02 8:52 ` Johan Hedberg
0 siblings, 1 reply; 16+ messages in thread
From: Marcel Holtmann @ 2015-12-02 7:37 UTC (permalink / raw)
To: Johan Hedberg; +Cc: François Beaufort, Szymon Janc, linux-bluetooth
Hi Johan,
>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
>>> LE Create Connection Cancel (0x08|0x000e) ncmd 1
>>> Status: Success (0x00)
>>>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
>>> LE Connection Complete (0x01)
>>> Status: Unknown Connection Identifier (0x02)
>>> Handle: 32
>>> Role: Master (0x00)
>>> Peer address type: Public (0x00)
>>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>> Connection interval: 67.50 msec (0x0036)
>>> Connection latency: 0.00 msec (0x0000)
>>> Supervision timeout: 420 msec (0x002a)
>>> Master clock accuracy: 0x00
>>> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>>
>> This one still needs to be fixed. It is a bug. The implementation is
>> too naive. The unknown connection identifier is actually the success
>> case for LE Create Connection Cancel command. And since we keep trying
>> until the connection timeout hits, this is not an error at this point.
>
> I think we need to differentiate between explicit connection requests
> (L2CAP socket connect()) and Add Device based connections. For the
> former we probably do want the Connect Failed since that's consistent
> with the behavior you see when operating the L2CAP socket. For the
> latter where we just go back to trying again, so the event doesn't
> really describe what's going on.
are you sure about that. I think we need to define when we want the mgmt connect failed event to show up. Does it make sense that it shows up for connection attempts that are not initiated by mgmt?
I mean, what is the benefit of a connection failed event if you can not tell that something actually tried to connect in the first. So if you try to connect via L2CAP, we are just getting a failure and do not know what triggered it. How is that helpful?
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-12-02 7:37 ` Marcel Holtmann
@ 2015-12-02 8:52 ` Johan Hedberg
2015-12-02 17:54 ` Marcel Holtmann
0 siblings, 1 reply; 16+ messages in thread
From: Johan Hedberg @ 2015-12-02 8:52 UTC (permalink / raw)
To: Marcel Holtmann; +Cc: François Beaufort, Szymon Janc, linux-bluetooth
Hi Marcel,
On Tue, Dec 01, 2015, Marcel Holtmann wrote:
> >>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
> >>> LE Create Connection Cancel (0x08|0x000e) ncmd 1
> >>> Status: Success (0x00)
> >>>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
> >>> LE Connection Complete (0x01)
> >>> Status: Unknown Connection Identifier (0x02)
> >>> Handle: 32
> >>> Role: Master (0x00)
> >>> Peer address type: Public (0x00)
> >>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
> >>> Connection interval: 67.50 msec (0x0036)
> >>> Connection latency: 0.00 msec (0x0000)
> >>> Supervision timeout: 420 msec (0x002a)
> >>> Master clock accuracy: 0x00
> >>> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
> >>
> >> This one still needs to be fixed. It is a bug. The implementation is
> >> too naive. The unknown connection identifier is actually the success
> >> case for LE Create Connection Cancel command. And since we keep trying
> >> until the connection timeout hits, this is not an error at this point.
> >
> > I think we need to differentiate between explicit connection requests
> > (L2CAP socket connect()) and Add Device based connections. For the
> > former we probably do want the Connect Failed since that's consistent
> > with the behavior you see when operating the L2CAP socket. For the
> > latter where we just go back to trying again, so the event doesn't
> > really describe what's going on.
>
> are you sure about that. I think we need to define when we want the
> mgmt connect failed event to show up. Does it make sense that it shows
> up for connection attempts that are not initiated by mgmt?
>
> I mean, what is the benefit of a connection failed event if you can
> not tell that something actually tried to connect in the first. So if
> you try to connect via L2CAP, we are just getting a failure and do not
> know what triggered it. How is that helpful?
I could think of at least one case: a device uses security mode 3 and we
connect to it via L2CAP. This triggers a PIN Code Request event, however
before we answer it the remote side cancels the connection/pairing
triggering a connect complete with failure status. In this case
bluetoothd should notify the agent to stop requesting for the PIN. Quite
a far stretched scenario (and I might even be wrong about it) but I
wouldn't be so quick to dismiss this event for non-mgmt actions.
Johan
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Unknown Connection Identifier
2015-12-02 8:52 ` Johan Hedberg
@ 2015-12-02 17:54 ` Marcel Holtmann
0 siblings, 0 replies; 16+ messages in thread
From: Marcel Holtmann @ 2015-12-02 17:54 UTC (permalink / raw)
To: Johan Hedberg; +Cc: François Beaufort, Szymon Janc, linux-bluetooth
Hi Johan,
>>>>>> HCI Event: Command Complete (0x0e) plen 4 [hci0] 17.672048
>>>>> LE Create Connection Cancel (0x08|0x000e) ncmd 1
>>>>> Status: Success (0x00)
>>>>>> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 17.674036
>>>>> LE Connection Complete (0x01)
>>>>> Status: Unknown Connection Identifier (0x02)
>>>>> Handle: 32
>>>>> Role: Master (0x00)
>>>>> Peer address type: Public (0x00)
>>>>> Peer address: 88:0F:10:9D:EB:42 (OUI 88-0F-10)
>>>>> Connection interval: 67.50 msec (0x0036)
>>>>> Connection latency: 0.00 msec (0x0000)
>>>>> Supervision timeout: 420 msec (0x002a)
>>>>> Master clock accuracy: 0x00
>>>>> @ Connect Failed: 88:0F:10:9D:EB:42 (1) status 0x02
>>>>
>>>> This one still needs to be fixed. It is a bug. The implementation is
>>>> too naive. The unknown connection identifier is actually the success
>>>> case for LE Create Connection Cancel command. And since we keep trying
>>>> until the connection timeout hits, this is not an error at this point.
>>>
>>> I think we need to differentiate between explicit connection requests
>>> (L2CAP socket connect()) and Add Device based connections. For the
>>> former we probably do want the Connect Failed since that's consistent
>>> with the behavior you see when operating the L2CAP socket. For the
>>> latter where we just go back to trying again, so the event doesn't
>>> really describe what's going on.
>>
>> are you sure about that. I think we need to define when we want the
>> mgmt connect failed event to show up. Does it make sense that it shows
>> up for connection attempts that are not initiated by mgmt?
>>
>> I mean, what is the benefit of a connection failed event if you can
>> not tell that something actually tried to connect in the first. So if
>> you try to connect via L2CAP, we are just getting a failure and do not
>> know what triggered it. How is that helpful?
>
> I could think of at least one case: a device uses security mode 3 and we
> connect to it via L2CAP. This triggers a PIN Code Request event, however
> before we answer it the remote side cancels the connection/pairing
> triggering a connect complete with failure status. In this case
> bluetoothd should notify the agent to stop requesting for the PIN. Quite
> a far stretched scenario (and I might even be wrong about it) but I
> wouldn't be so quick to dismiss this event for non-mgmt actions.
actually I agree, everything involved with mgmt and pairing should cause this error. However has that really anything to do with L2CAP? It is more like we only send it if something happens on HCI side of things that are no related to any higher layers.
Btw. I am fine with applying your initial patch with the updated comment. It is improving the situation no matter what, but we might want to double check if not sending this event with nobody being able to react on it.
Regards
Marcel
^ permalink raw reply [flat|nested] 16+ messages in thread
end of thread, other threads:[~2015-12-02 17:54 UTC | newest]
Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-11-23 14:43 Unknown Connection Identifier François Beaufort
2015-11-23 17:43 ` Marcel Holtmann
2015-11-23 18:23 ` Szymon Janc
2015-11-24 9:24 ` François Beaufort
2015-11-24 11:00 ` Marcel Holtmann
2015-11-24 12:05 ` François Beaufort
2015-11-30 7:43 ` François Beaufort
2015-11-30 7:44 ` François Beaufort
2015-11-30 10:51 ` Johan Hedberg
2015-11-30 22:20 ` Vinicius Costa Gomes
2015-11-30 22:31 ` Marcel Holtmann
2015-11-30 17:55 ` Marcel Holtmann
2015-12-01 8:41 ` Johan Hedberg
2015-12-02 7:37 ` Marcel Holtmann
2015-12-02 8:52 ` Johan Hedberg
2015-12-02 17:54 ` Marcel Holtmann
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.