2024-01-25 13:51:46

by Emil Lenngren

[permalink] [raw]
Subject: Wrong order of ACL Data and HCI Event packets for HCI over USB

Hi. I have a quite annoying issue on my Ubuntu 22.04 computer with an
Intel Bluetooth controller (8087:0033, Intel Wi-Fi 6E (6GHz) AX211 2x2
Bluetooth 5.2 Wireless Card).
Very often BLE connections to a particular device behaves incorrectly
(ATT timeout by remote device) because the initial ATT Exchange MTU
Request arrives to the host (BlueZ) just before the LE Enhanced
Connection Complete event arrives, and is therefore dropped. I guess
this is due to separate endpoints and therefore separate flows are
used in the HCI USB protocol, but have no idea how/if this can be
fixed?

See btmon log:

< HCI Command: LE Set Extended Advertising En.. (0x08|0x0039) plen 6
#11 [hci0] 8.102056
Extended advertising: Enabled (0x01)
Number of sets: 1 (0x01)
Entry 0
Handle: 0x01
Duration: 0 ms (0x00)
Max ext adv events: 0
> HCI Event: Command Complete (0x0e) plen 4 #12 [hci0] 8.104041
LE Set Extended Advertising Enable (0x08|0x0039) ncmd 2
Status: Success (0x00)
@ MGMT Event: Command Complete (0x0001) plen 4
{0x0001} [hci0] 8.104053
Add Extended Advertising Data (0x0055) plen 1
Status: Success (0x00)
Instance: 1
> ACL Data RX: Handle 3585 flags 0x02 dlen 7 #13 [hci0] 21.049023
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 247
> HCI Event: LE Meta Event (0x3e) plen 31 #14 [hci0] 21.049304
LE Enhanced Connection Complete (0x0a)
Status: Success (0x00)
Handle: 3585
Role: Peripheral (0x01)
Peer address type: Public (0x00)
Peer address: (removed)
Local resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
Peer resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
Connection interval: 25.00 msec (0x0014)
Connection latency: 0 (0x0000)
Supervision timeout: 700 msec (0x0046)
Central clock accuracy: 0x00
@ MGMT Event: Device Connected (0x000b) plen 13
{0x0001} [hci0] 21.049366
LE Address: (removed)
Flags: 0x00000000
Data length: 0
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
#15 [hci0] 21.049405
Handle: 3585
> HCI Event: LE Meta Event (0x3e) plen 4 #16 [hci0] 21.050229
LE Channel Selection Algorithm (0x14)
Handle: 3585
Algorithm: #2 (0x01)
> HCI Event: LE Meta Event (0x3e) plen 6 #17 [hci0] 21.051290
LE Advertising Set Terminated (0x12)
Status: Success (0x00)
Handle: 1
Connection handle: 3585
Number of completed extended advertising events: 0
> HCI Event: LE Meta Event (0x3e) plen 11 #18 [hci0] 21.052293
LE Data Length Change (0x07)
Handle: 3585
Max TX octets: 251
Max TX time: 2120
Max RX octets: 251
Max RX time: 2120
> HCI Event: Command Status (0x0f) plen 4 #19 [hci0] 21.053228
LE Read Remote Used Features (0x08|0x0016) ncmd 1
Status: Success (0x00)


2024-01-25 14:26:13

by Luiz Augusto von Dentz

[permalink] [raw]
Subject: Re: Wrong order of ACL Data and HCI Event packets for HCI over USB

Hi Emil,

On Thu, Jan 25, 2024 at 8:51 AM Emil Lenngren <[email protected]> wrote:
>
> Hi. I have a quite annoying issue on my Ubuntu 22.04 computer with an
> Intel Bluetooth controller (8087:0033, Intel Wi-Fi 6E (6GHz) AX211 2x2
> Bluetooth 5.2 Wireless Card).
> Very often BLE connections to a particular device behaves incorrectly
> (ATT timeout by remote device) because the initial ATT Exchange MTU
> Request arrives to the host (BlueZ) just before the LE Enhanced
> Connection Complete event arrives, and is therefore dropped. I guess
> this is due to separate endpoints and therefore separate flows are
> used in the HCI USB protocol, but have no idea how/if this can be
> fixed?
>
> See btmon log:
>
> < HCI Command: LE Set Extended Advertising En.. (0x08|0x0039) plen 6
> #11 [hci0] 8.102056
> Extended advertising: Enabled (0x01)
> Number of sets: 1 (0x01)
> Entry 0
> Handle: 0x01
> Duration: 0 ms (0x00)
> Max ext adv events: 0
> > HCI Event: Command Complete (0x0e) plen 4 #12 [hci0] 8.104041
> LE Set Extended Advertising Enable (0x08|0x0039) ncmd 2
> Status: Success (0x00)
> @ MGMT Event: Command Complete (0x0001) plen 4
> {0x0001} [hci0] 8.104053
> Add Extended Advertising Data (0x0055) plen 1
> Status: Success (0x00)
> Instance: 1
> > ACL Data RX: Handle 3585 flags 0x02 dlen 7 #13 [hci0] 21.049023
> ATT: Exchange MTU Request (0x02) len 2
> Client RX MTU: 247
> > HCI Event: LE Meta Event (0x3e) plen 31 #14 [hci0] 21.049304
> LE Enhanced Connection Complete (0x0a)
> Status: Success (0x00)
> Handle: 3585
> Role: Peripheral (0x01)
> Peer address type: Public (0x00)
> Peer address: (removed)
> Local resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
> Peer resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
> Connection interval: 25.00 msec (0x0014)
> Connection latency: 0 (0x0000)
> Supervision timeout: 700 msec (0x0046)
> Central clock accuracy: 0x00
> @ MGMT Event: Device Connected (0x000b) plen 13
> {0x0001} [hci0] 21.049366
> LE Address: (removed)
> Flags: 0x00000000
> Data length: 0
> < HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
> #15 [hci0] 21.049405
> Handle: 3585
> > HCI Event: LE Meta Event (0x3e) plen 4 #16 [hci0] 21.050229
> LE Channel Selection Algorithm (0x14)
> Handle: 3585
> Algorithm: #2 (0x01)
> > HCI Event: LE Meta Event (0x3e) plen 6 #17 [hci0] 21.051290
> LE Advertising Set Terminated (0x12)
> Status: Success (0x00)
> Handle: 1
> Connection handle: 3585
> Number of completed extended advertising events: 0
> > HCI Event: LE Meta Event (0x3e) plen 11 #18 [hci0] 21.052293
> LE Data Length Change (0x07)
> Handle: 3585
> Max TX octets: 251
> Max TX time: 2120
> Max RX octets: 251
> Max RX time: 2120
> > HCI Event: Command Status (0x0f) plen 4 #19 [hci0] 21.053228
> LE Read Remote Used Features (0x08|0x0016) ncmd 1
> Status: Success (0x00)

This is a design flaw in the Bluetooth Core Specification, it defines
different USB endpoints for data and events but since they don't come
with any timestamp from the controller the host has no idea about
their order. That said we do provide a workaround that can be enabled
with the use of the following config option:

config BT_HCIBTUSB_POLL_SYNC
bool "Enable USB poll_sync for Bluetooth USB devices by default"
depends on BT_HCIBTUSB
default y
help
poll_sync synchronizes the USB data and event endpoints by
prioritizing the later.

Say Y here to enable USB poll_sync for Bluetooth USB devices by
default.

--
Luiz Augusto von Dentz

2024-01-25 14:31:29

by Emil Lenngren

[permalink] [raw]
Subject: Re: Wrong order of ACL Data and HCI Event packets for HCI over USB

Hi Luiz and thanks for the quick answer!

In the meantime I modified the remote device's code to add a short
delay after connection establishment that also seems to work around
the issue.

Do you have any idea if this design flaw will be fixed in the
specification? Seems like a pretty bad one to me...

/Emil

Den tors 25 jan. 2024 kl 15:25 skrev Luiz Augusto von Dentz
<[email protected]>:
>
> Hi Emil,
>
> On Thu, Jan 25, 2024 at 8:51 AM Emil Lenngren <[email protected]> wrote:
> >
> > Hi. I have a quite annoying issue on my Ubuntu 22.04 computer with an
> > Intel Bluetooth controller (8087:0033, Intel Wi-Fi 6E (6GHz) AX211 2x2
> > Bluetooth 5.2 Wireless Card).
> > Very often BLE connections to a particular device behaves incorrectly
> > (ATT timeout by remote device) because the initial ATT Exchange MTU
> > Request arrives to the host (BlueZ) just before the LE Enhanced
> > Connection Complete event arrives, and is therefore dropped. I guess
> > this is due to separate endpoints and therefore separate flows are
> > used in the HCI USB protocol, but have no idea how/if this can be
> > fixed?
> >
> > See btmon log:
> >
> > < HCI Command: LE Set Extended Advertising En.. (0x08|0x0039) plen 6
> > #11 [hci0] 8.102056
> > Extended advertising: Enabled (0x01)
> > Number of sets: 1 (0x01)
> > Entry 0
> > Handle: 0x01
> > Duration: 0 ms (0x00)
> > Max ext adv events: 0
> > > HCI Event: Command Complete (0x0e) plen 4 #12 [hci0] 8.104041
> > LE Set Extended Advertising Enable (0x08|0x0039) ncmd 2
> > Status: Success (0x00)
> > @ MGMT Event: Command Complete (0x0001) plen 4
> > {0x0001} [hci0] 8.104053
> > Add Extended Advertising Data (0x0055) plen 1
> > Status: Success (0x00)
> > Instance: 1
> > > ACL Data RX: Handle 3585 flags 0x02 dlen 7 #13 [hci0] 21.049023
> > ATT: Exchange MTU Request (0x02) len 2
> > Client RX MTU: 247
> > > HCI Event: LE Meta Event (0x3e) plen 31 #14 [hci0] 21.049304
> > LE Enhanced Connection Complete (0x0a)
> > Status: Success (0x00)
> > Handle: 3585
> > Role: Peripheral (0x01)
> > Peer address type: Public (0x00)
> > Peer address: (removed)
> > Local resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
> > Peer resolvable private address: 00:00:00:00:00:00 (Non-Resolvable)
> > Connection interval: 25.00 msec (0x0014)
> > Connection latency: 0 (0x0000)
> > Supervision timeout: 700 msec (0x0046)
> > Central clock accuracy: 0x00
> > @ MGMT Event: Device Connected (0x000b) plen 13
> > {0x0001} [hci0] 21.049366
> > LE Address: (removed)
> > Flags: 0x00000000
> > Data length: 0
> > < HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2
> > #15 [hci0] 21.049405
> > Handle: 3585
> > > HCI Event: LE Meta Event (0x3e) plen 4 #16 [hci0] 21.050229
> > LE Channel Selection Algorithm (0x14)
> > Handle: 3585
> > Algorithm: #2 (0x01)
> > > HCI Event: LE Meta Event (0x3e) plen 6 #17 [hci0] 21.051290
> > LE Advertising Set Terminated (0x12)
> > Status: Success (0x00)
> > Handle: 1
> > Connection handle: 3585
> > Number of completed extended advertising events: 0
> > > HCI Event: LE Meta Event (0x3e) plen 11 #18 [hci0] 21.052293
> > LE Data Length Change (0x07)
> > Handle: 3585
> > Max TX octets: 251
> > Max TX time: 2120
> > Max RX octets: 251
> > Max RX time: 2120
> > > HCI Event: Command Status (0x0f) plen 4 #19 [hci0] 21.053228
> > LE Read Remote Used Features (0x08|0x0016) ncmd 1
> > Status: Success (0x00)
>
> This is a design flaw in the Bluetooth Core Specification, it defines
> different USB endpoints for data and events but since they don't come
> with any timestamp from the controller the host has no idea about
> their order. That said we do provide a workaround that can be enabled
> with the use of the following config option:
>
> config BT_HCIBTUSB_POLL_SYNC
> bool "Enable USB poll_sync for Bluetooth USB devices by default"
> depends on BT_HCIBTUSB
> default y
> help
> poll_sync synchronizes the USB data and event endpoints by
> prioritizing the later.
>
> Say Y here to enable USB poll_sync for Bluetooth USB devices by
> default.
>
> --
> Luiz Augusto von Dentz