[PATCH v3] Bluetooth: btusb: Check for unexpected bytes when defragmenting HCI frames

[PATCH v3] Bluetooth: btusb: Check for unexpected bytes when defragmenting HCI frames

[Arkadiusz Bokowy]

Some Barrot based USB Bluetooth dongles erroneously send one extra
random byte for the HCI_OP_READ_LOCAL_EXT_FEATURES command. The
consequence of that is that the next HCI transfer is misaligned by one
byte causing undefined behavior. In most cases the response event for
the next command fails with random error code.

Since the HCI_OP_READ_LOCAL_EXT_FEATURES command is used during HCI
controller initialization, the initialization fails rendering the USB
dongle not usable.

> [59.464099] usb 1-1.3: new full-speed USB device number 11 using xhci_hcd
> [59.561617] usb 1-1.3: New USB device found, idVendor=33fa, idProduct=0012, bcdDevice=88.91
> [59.561642] usb 1-1.3: New USB device strings: Mfr=0, Product=2, SerialNumber=0
> [59.561656] usb 1-1.3: Product: UGREEN BT6.0 Adapter
> [61.720116] Bluetooth: hci1: command 0x1005 tx timeout
> [61.720167] Bluetooth: hci1: Opcode 0x1005 failed: -110

This patch was tested with the 33fa:0012 device. The info from the
/sys/kernel/debug/usb/devices is shown below:

T:  Bus=01 Lev=02 Prnt=02 Port=02 Cnt=01 Dev#= 12 Spd=12   MxCh= 0
D:  Ver= 2.00 Cls=e0(wlcon) Sub=01 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=33fa ProdID=0012 Rev=88.91
S:  Product=UGREEN BT6.0 Adapter
C:* #Ifs= 2 Cfg#= 1 Atr=c0 MxPwr=100mA
I:* If#= 0 Alt= 0 #EPs= 3 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=81(I) Atr=03(Int.) MxPS=  16 Ivl=1ms
E:  Ad=02(O) Atr=02(Bulk) MxPS=  64 Ivl=0ms
E:  Ad=82(I) Atr=02(Bulk) MxPS=  64 Ivl=0ms
I:* If#= 1 Alt= 0 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=   0 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=   0 Ivl=1ms
I:  If#= 1 Alt= 1 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=   9 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=   9 Ivl=1ms
I:  If#= 1 Alt= 2 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=  17 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=  17 Ivl=1ms
I:  If#= 1 Alt= 3 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=  25 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=  25 Ivl=1ms
I:  If#= 1 Alt= 4 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=  33 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=  33 Ivl=1ms
I:  If#= 1 Alt= 5 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E:  Ad=03(O) Atr=01(Isoc) MxPS=  49 Ivl=1ms
E:  Ad=83(I) Atr=01(Isoc) MxPS=  49 Ivl=1ms

Now the device is initialized properly:

> [43.329852] usb 1-1.4: new full-speed USB device number 4 using dwc_otg
> [43.446790] usb 1-1.4: New USB device found, idVendor=33fa, idProduct=0012, bcdDevice=88.91
> [43.446813] usb 1-1.4: New USB device strings: Mfr=0, Product=2, SerialNumber=0
> [43.446821] usb 1-1.4: Product: UGREEN BT6.0 Adapter
> [43.582024] Bluetooth: hci1: Unexpected continuation: 1 bytes
> [43.703025] Bluetooth: hci1: Unexpected continuation: 1 bytes
> [43.750141] Bluetooth: MGMT ver 1.23

Signed-off-by: Arkadiusz Bokowy <arkadiusz.bokowy@gmail.com>
Tested-by: Arkadiusz Bokowy <arkadiusz.bokowy@gmail.com>
---
 drivers/bluetooth/btusb.c | 17 +++++++++++++++++
 1 file changed, 17 insertions(+)

diff --git a/drivers/bluetooth/btusb.c b/drivers/bluetooth/btusb.c
index 8085fabad..eaf88dda6 100644
--- a/drivers/bluetooth/btusb.c
+++ b/drivers/bluetooth/btusb.c
@@ -66,6 +66,7 @@ static struct usb_driver btusb_driver;
 #define BTUSB_INTEL_BROKEN_INITIAL_NCMD BIT(25)
 #define BTUSB_INTEL_NO_WBS_SUPPORT	BIT(26)
 #define BTUSB_ACTIONS_SEMI		BIT(27)
+#define BTUSB_BARROT			BIT(28)
 
 static const struct usb_device_id btusb_table[] = {
 	/* Generic Bluetooth USB device */
@@ -810,6 +811,10 @@ static const struct usb_device_id quirks_table[] = {
 	{ USB_DEVICE(0x0cb5, 0xc547), .driver_info = BTUSB_REALTEK |
 						     BTUSB_WIDEBAND_SPEECH },
 
+	/* Barrot Technology Bluetooth devices */
+	{ USB_DEVICE(0x33fa, 0x0010), .driver_info = BTUSB_BARROT },
+	{ USB_DEVICE(0x33fa, 0x0012), .driver_info = BTUSB_BARROT },
+
 	/* Actions Semiconductor ATS2851 based devices */
 	{ USB_DEVICE(0x10d7, 0xb012), .driver_info = BTUSB_ACTIONS_SEMI },
 
@@ -1192,6 +1197,18 @@ static int btusb_recv_intr(struct btusb_data *data, void *buffer, int count)
 		}
 
 		if (!hci_skb_expect(skb)) {
+			/* Each chunk should correct to at least 1 or more
+			 * events so if there are still bytes left that doesn't
+			 * constitute a new event this is likely a bug in the
+			 * controller.
+			 */
+			if (count && count < HCI_EVENT_HDR_SIZE) {
+				bt_dev_warn(data->hdev,
+					"Unexpected continuation: %d bytes",
+					count);
+				count = 0;
+			}
+
 			/* Complete frame */
 			btusb_recv_event(data, skb);
 			skb = NULL;
-- 
2.47.2

Re: [PATCH v3] Bluetooth: btusb: Check for unexpected bytes when defragmenting HCI frames

[Julian]

Hi Arkadiusz,
I tested the patch with 33fa:0010. It initialized successfully and is 
working well so far.
It initially froze while scanning for more than 30 seconds, but after a 
little bit of USB Hokey-Pokey, it works better now. However, when using 
headphones, there is some choppiness in the audio during scanning, as 
if it might freeze again.

I will leave some logs in case they are helpful.

----
# cat /sys/kernel/debug/usb/devices
...
T: Bus=01 Lev=01 Prnt=01 Port=07 Cnt=01 Dev#= 4 Spd=12 MxCh= 0
D: Ver= 2.00 Cls=e0(wlcon) Sub=01 Prot=01 MxPS=64 #Cfgs= 1
P: Vendor=33fa ProdID=0010 Rev=88.91
S: Product=UGREEN BT5.4 Adapter
C:* #Ifs= 2 Cfg#= 1 Atr=c0 MxPwr=100mA
I:* If#= 0 Alt= 0 #EPs= 3 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=81(I) Atr=03(Int.) MxPS= 16 Ivl=1ms
E: Ad=02(O) Atr=02(Bulk) MxPS= 64 Ivl=0ms
E: Ad=82(I) Atr=02(Bulk) MxPS= 64 Ivl=0ms
I:* If#= 1 Alt= 0 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 0 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 0 Ivl=1ms
I: If#= 1 Alt= 1 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 9 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 9 Ivl=1ms
I: If#= 1 Alt= 2 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 17 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 17 Ivl=1ms
I: If#= 1 Alt= 3 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 25 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 25 Ivl=1ms
I: If#= 1 Alt= 4 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 33 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 33 Ivl=1ms
I: If#= 1 Alt= 5 #EPs= 2 Cls=e0(wlcon) Sub=01 Prot=01 Driver=btusb
E: Ad=03(O) Atr=01(Isoc) MxPS= 49 Ivl=1ms
E: Ad=83(I) Atr=01(Isoc) MxPS= 49 Ivl=1ms
...
----

----
# dmesg
...
[ 56.023305] usb 1-8: new full-speed USB device number 4 using xhci_hcd
[ 56.398644] usb 1-8: New USB device found, idVendor=33fa, 
idProduct=0010, bcdDevice=88.91
[ 56.398653] usb 1-8: New USB device strings: Mfr=0, Product=2, 
SerialNumber=0
[ 56.398657] usb 1-8: Product: UGREEN BT5.4 Adapter
[ 56.474345] Bluetooth: Core ver 2.22
[ 56.474375] NET: Registered PF_BLUETOOTH protocol family
[ 56.474377] Bluetooth: HCI device and connection manager initialized
[ 56.474382] Bluetooth: HCI socket layer initialized
[ 56.474386] Bluetooth: L2CAP socket layer initialized
[ 56.474391] Bluetooth: SCO socket layer initialized
[ 56.503855] usbcore: registered new interface driver btusb
[ 56.566661] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 56.566667] Bluetooth: BNEP filters: protocol multicast
[ 56.566671] Bluetooth: BNEP socket layer initialized
[ 56.639531] Bluetooth: hci0: Unexpected continuation: 1 bytes
[ 56.784552] Bluetooth: hci0: Unexpected continuation: 1 bytes
[ 56.858686] Bluetooth: MGMT ver 1.23
...
----

Dongle scan fault journal segment
----
...
sep 22 08:03:31 AHost systemd[1156]: Reached target Bluetooth.
sep 22 08:03:31 AHost systemd[1]: Started Load/Save RF Kill Switch 
Status.
sep 22 08:03:32 AHost kernel: Bluetooth: hci0: Unexpected continuation: 
1 bytes
sep 22 08:03:32 AHost kernel: Bluetooth: hci0: Unexpected continuation: 
1 bytes
sep 22 08:03:32 AHost bluetoothd[549]: Battery Provider Manager created
sep 22 08:03:32 AHost kernel: Bluetooth: MGMT ver 1.23
sep 22 08:03:32 AHost bluetoothd[549]: Endpoint registered: 
sender=:1.83 path=/MediaEndpoint/A2DPSource/ldac
...
sep 22 08:03:32 AHost bluetoothd[549]: Endpoint registered: 
sender=:1.83 path=/MediaEndpoint/A2DPSource/opus_05_duplex
sep 22 08:03:36 AHost systemd[1]: systemd-rfkill.service: Deactivated 
successfully.
sep 22 08:04:44 AHost kernel: Bluetooth: hci0: Opcode 0x2042 failed: 
-110
sep 22 08:04:44 AHost kernel: Bluetooth: hci0: command 0x2042 tx timeout
sep 22 08:04:44 AHost kernel: Bluetooth: hci0: Unable to disable 
scanning: -110
sep 22 08:04:44 AHost kernel: Bluetooth: hci0: Opcode 0x0401 failed: -12
sep 22 08:04:48 AHost kernel: Bluetooth: hci0: Controller not accepting 
commands anymore: ncmd = 0
sep 22 08:04:48 AHost kernel: Bluetooth: hci0: Injecting HCI hardware 
error event
sep 22 08:04:48 AHost kernel: Bluetooth: hci0: hardware error 0x00
sep 22 08:04:48 AHost kernel: Bluetooth: hci0: Opcode 0x0c03 failed: -12
sep 22 08:04:52 AHost kernel: Bluetooth: hci0: Controller not accepting 
commands anymore: ncmd = 0
sep 22 08:04:52 AHost kernel: Bluetooth: hci0: Injecting HCI hardware 
error event
sep 22 08:06:17 AHost kernel: Bluetooth: hci0: Opcode 0x0c03 failed: -12
sep 22 08:06:17 AHost bluetoothd[549]: Failed to set mode: No Resources 
(0x07)
sep 22 08:06:21 AHost kernel: Bluetooth: hci0: Controller not accepting 
commands anymore: ncmd = 0
sep 22 08:06:21 AHost kernel: Bluetooth: hci0: Injecting HCI hardware 
error event
sep 22 08:06:27 AHost kernel: Bluetooth: hci0: Opcode 0x0c03 failed: -12
sep 22 08:06:27 AHost bluetoothd[549]: Failed to set mode: No Resources 
(0x07)
sep 22 08:06:31 AHost kernel: Bluetooth: hci0: Controller not accepting 
commands anymore: ncmd = 0
sep 22 08:06:31 AHost kernel: Bluetooth: hci0: Injecting HCI hardware 
error event
...
----

Re: [PATCH v3] Bluetooth: btusb: Check for unexpected bytes when defragmenting HCI frames

[Arkadiusz Bokowy]

> It initially froze while scanning for more than 30 seconds, but after a
> little bit of USB Hokey-Pokey, it works better now. However, when using
> headphones, there is some choppiness in the audio during scanning, as
> if it might freeze again.

This patch is only for the dongle initialization failure. There might
be some other issues with this chip. I guess that when this patch will
land in the mainline (if it will) we might see more bug reports from
people trying to actually use it. It's rather impossible that this
chip does not have any other quirk :) However, I do not work for
Ugreen or Barrot so please do not expect that I will fix any of such
issues. Anyway I might submit patches fixing things related to my use
cases (if free time will allow).