linux icon indicating copy to clipboard operation
linux copied to clipboard
verified publisher icon raspberrypi

rtl8761_bu usb bluetooth download fw command failed

Open hkskoglund opened this issue 1 year ago • 36 comments

Describe the bug

Hi! I have a Trust usb stick that most of the time fails to download fw during boot on my raspberry pi 5. I have to plug/unplug it until it succeeds. From the btmon log it seems that fw loading stops after the last packet which fails to get HCI Event: Command Complete?

I have no issues with the usb stick on my laptop running fedora 40 with kernel 6.8.7-300.fc40, so maybe its related to the raspberry pi kernel?

Steps to reproduce the behaviour

dmesg --ctime --follow Plug/unplug usb stick Some times download fw fails

Device (s)

Raspberry Pi 5

System

Raspberry Pi reference 2024-03-15 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, f19ee211ddafcae300827f953d143de92a5c6624, stage4 2024/04/20 11:53:30 Copyright (c) 2012 Broadcom version d1744d21 (release) (embedded) Linux raspberrypi0 6.6.28+rpt-rpi-2712 #1 SMP PREEMPT Debian 1:6.6.28-1+rpt1 (2024-04-22) aarch64 GNU/Linux

Logs

dmesg --ctime --follow:

[Wed May 1 18:26:14 2024] usb 1-2: new full-speed USB device number 6 using xhci-hcd [Wed May 1 18:26:14 2024] usb 1-2: New USB device found, idVendor=0bda, idProduct=8771, bcdDevice= 2.00 [Wed May 1 18:26:14 2024] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [Wed May 1 18:26:14 2024] usb 1-2: Product: Bluetooth Radio [Wed May 1 18:26:14 2024] usb 1-2: Manufacturer: Realtek [Wed May 1 18:26:14 2024] usb 1-2: SerialNumber: 00E04C239987 [Wed May 1 18:26:14 2024] Bluetooth: hci3: RTL: examining hci_ver=0a hci_rev=000b lmp_ver=0a lmp_subver=8761 [Wed May 1 18:26:14 2024] Bluetooth: hci3: RTL: rom_version status=0 version=1 [Wed May 1 18:26:14 2024] Bluetooth: hci3: RTL: loading rtl_bt/rtl8761bu_fw.bin [Wed May 1 18:26:14 2024] Bluetooth: hci3: RTL: loading rtl_bt/rtl8761bu_config.bin [Wed May 1 18:26:14 2024] Bluetooth: hci3: RTL: cfg_sz 6, total sz 30210 [Wed May 1 18:26:17 2024] Bluetooth: hci3: command 0xfc20 tx timeout [Wed May 1 18:26:17 2024] Bluetooth: hci3: RTL: Failed to generate devcoredump [Wed May 1 18:26:17 2024] Bluetooth: hci3: RTL: download fw command failed (-110) [Wed May 1 18:26:18 2024] usb 1-2: USB disconnect, device number 6 [Wed May 1 18:26:18 2024] Bluetooth: hci3: RTL: RTL: Read reg16 failed (-19) [Wed May 1 18:26:29 2024] usb 1-2: new full-speed USB device number 7 using xhci-hcd [Wed May 1 18:26:29 2024] usb 1-2: New USB device found, idVendor=0bda, idProduct=8771, bcdDevice= 2.00 [Wed May 1 18:26:29 2024] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [Wed May 1 18:26:29 2024] usb 1-2: Product: Bluetooth Radio [Wed May 1 18:26:29 2024] usb 1-2: Manufacturer: Realtek [Wed May 1 18:26:29 2024] usb 1-2: SerialNumber: 00E04C239987 [Wed May 1 18:26:29 2024] Bluetooth: hci3: RTL: examining hci_ver=0a hci_rev=000b lmp_ver=0a lmp_subver=8761 [Wed May 1 18:26:29 2024] Bluetooth: hci3: RTL: rom_version status=0 version=1 [Wed May 1 18:26:29 2024] Bluetooth: hci3: RTL: loading rtl_bt/rtl8761bu_fw.bin [Wed May 1 18:26:29 2024] Bluetooth: hci3: RTL: loading rtl_bt/rtl8761bu_config.bin [Wed May 1 18:26:29 2024] Bluetooth: hci3: RTL: cfg_sz 6, total sz 30210 [Wed May 1 18:26:30 2024] Bluetooth: hci3: RTL: fw version 0xdfc6d922 [Wed May 1 18:26:30 2024] Bluetooth: MGMT ver 1.22

tail btmon-1.log of failed fw download:

< HCI Command: Vendor (0x3f|0x0020) plen 223 #245 [hci1] 6.804458 f7 68 01 44 51 02 00 40 41 06 00 64 30 08 00 b0 [email protected]... 00 66 00 59 40 0a 06 db 50 0c 06 f2 7b 10 06 8c [email protected]...{... 55 12 06 0a 28 14 06 27 01 00 f0 60 00 02 90 77 U...(..'......w f8 64 06 27 00 02 01 00 00 34 00 04 27 38 00 83 .d.'.....4..'8.. 80 00 20 11 50 01 20 00 02 02 20 00 3b 3f 20 28 .. .P. ... .;? ( 03 20 20 2c 90 02 01 20 00 40 00 00 80 42 00 00 . ,... [email protected].. 01 44 00 00 00 46 00 84 00 48 00 c0 00 4a 00 00 .D...F...H...J.. 00 4c 00 00 00 4e 00 28 00 50 00 40 cc 52 00 00 .L...N.([email protected].. 14 54 00 00 00 56 00 00 20 58 00 11 55 5a 00 00 .T...V.. X..UZ.. 80 5c 00 00 00 5e 00 05 28 0e 01 01 00 02 01 60 .\...^..(...... c0 02 01 22 c0 7c e1 64 00 02 01 20 00 30 06 26 ...".|.d... .0.& 67 34 06 7f c8 3a 06 d3 00 5a 03 45 00 42 02 bf g4...:...Z.E.B.. 05 2e 01 00 68 02 00 40 41 08 00 b0 00 02 02 47 [email protected] 99 a4 25 d5 d6 22 d9 c6 df 55 ab 23 87 00 00 ..%.."...U.#... = Close Index: 00:00:00:00:00:00 [hci1] 8.819086

same in fw download success btmon-2.log

< HCI Command: Vendor (0x3f|0x0020) plen 223 #245 [hci3] 7.428504 f7 68 01 44 51 02 00 40 41 06 00 64 30 08 00 b0 [email protected]... 00 66 00 59 40 0a 06 db 50 0c 06 f2 7b 10 06 8c [email protected]...{... 55 12 06 0a 28 14 06 27 01 00 f0 60 00 02 90 77 U...(..'......w f8 64 06 27 00 02 01 00 00 34 00 04 27 38 00 83 .d.'.....4..'8.. 80 00 20 11 50 01 20 00 02 02 20 00 3b 3f 20 28 .. .P. ... .;? ( 03 20 20 2c 90 02 01 20 00 40 00 00 80 42 00 00 . ,... [email protected].. 01 44 00 00 00 46 00 84 00 48 00 c0 00 4a 00 00 .D...F...H...J.. 00 4c 00 00 00 4e 00 28 00 50 00 40 cc 52 00 00 .L...N.([email protected].. 14 54 00 00 00 56 00 00 20 58 00 11 55 5a 00 00 .T...V.. X..UZ.. 80 5c 00 00 00 5e 00 05 28 0e 01 01 00 02 01 60 .\...^..(...... c0 02 01 22 c0 7c e1 64 00 02 01 20 00 30 06 26 ...".|.d... .0.& 67 34 06 7f c8 3a 06 d3 00 5a 03 45 00 42 02 bf g4...:...Z.E.B.. 05 2e 01 00 68 02 00 40 41 08 00 b0 00 02 02 47 [email protected] 99 a4 25 d5 d6 22 d9 c6 df 55 ab 23 87 00 00 ..%.."...U.#...

HCI Event: Command Complete (0x0e) plen 5 #246 [hci3] 7.461497 Vendor (0x3f|0x0020) ncmd 3 Status: Success (0x00) f7 .
< HCI Command: Read Local Version... (0x04|0x0001) plen 0 #247 [hci3] 7.461506 HCI Event: Command Complete (0x0e) plen 12 #248 [hci3] 7.463502 Read Local Version Information (0x04|0x0001) ncmd 2 Status: Success (0x00) HCI version: Bluetooth 5.1 (0x0a) - Revision 57286 (0xdfc6) LMP version: Bluetooth 5.1 (0x0a) - Subversion 55586 (0xd922) Manufacturer: Realtek Semiconductor Corporation (93)

Additional context

I have dtoverlay=disable-bt in /boot/firmware/config.txt and have disabled hciuart, since I dont need the internal adapter

hkskoglund avatar May 01 '24 17:05 hkskoglund

I've tried to trace down the source code responsible for downloading firmware, and found it in rtl_download_firmware https://github.com/torvalds/linux/blob/master/drivers/bluetooth/btrtl.c#L802

The function only tries 1 time to download a fragment before giving up.

/* Send download command */
		skb = __hci_cmd_sync(hdev, 0xfc20, frag_len + 1, dl_cmd,
				     HCI_INIT_TIMEOUT);
		if (IS_ERR(skb)) {
			rtl_dev_err(hdev, "download fw command failed (%ld)",
				    PTR_ERR(skb));
			ret = PTR_ERR(skb);
			goto out;
		}

In addition gemini AI/chatgpt gives :

gemini AI

The provided C code appears mostly correct for downloading firmware to an RTL Bluetooth controller. Here's a breakdown with some explanations and potential improvements:

Functionality:

  • The code downloads firmware in fragments to the Bluetooth controller identified by hdev.
  • It iterates through the firmware data (data) in chunks of RTL_FRAG_LEN and sends them using HCI commands.
  • After successful download, it reads the local firmware version using another HCI command.

Strengths:

  • The code uses kernel memory allocation (kmalloc) for the download command structure.
  • It checks for errors during command sending and data length verification.
  • It logs debugging and informational messages using appropriate functions.

Potential Improvements:

  • Error Handling: Consider adding checks for dl_cmd allocation failures beyond just checking the return value. You can use a similar approach for skb allocations.
  • Loop Termination: The loop condition i < frag_num might be susceptible to overflow if frag_num is very large. Consider using a loop that iterates until all data is sent (data + frag_len > data).
  • Resource Management: Move the kfree(dl_cmd); outside the loop to ensure it's always freed even in error cases.
  • Clarity: Adding comments within the loop to explain the purpose of setting dl_cmd->index and handling the last fragment could improve code readability.

Uncertainties:

  • The code relies on undefined types like struct rtl_download_cmd and struct rtl_download_response. Without knowing their definitions, it's impossible to fully verify their usage.
  • The functions rtl_dev_dbg, rtl_dev_err, rtl_dev_info, and btrtl_read_local_version are assumed to be specific to the RTL Bluetooth driver and are not part of the standard Linux kernel API.

Overall:

The code seems like a reasonable implementation for downloading firmware to an RTL Bluetooth controller. However, for a complete review, the missing type definitions and specific driver functionalities would need to be analyzed. The suggested improvements can further enhance the code's robustness and readability.

chatgpt:

The code you provided appears to be a function for downloading firmware to a Realtek Bluetooth device. Here's a quick analysis:

  1. Memory Allocation: The function allocates memory for a struct rtl_download_cmd using kmalloc. This allocation is later freed using kfree.

  2. Looping through Fragments: The function loops through the firmware data in fragments of size RTL_FRAG_LEN. It constructs a struct rtl_download_cmd for each fragment and sends it using __hci_cmd_sync. The loop also handles the case when the last fragment might be smaller than RTL_FRAG_LEN.

  3. Error Handling: The function properly handles errors by returning appropriate error codes and freeing allocated resources (skb, dl_cmd) before returning.

  4. Verification: It verifies the length of the response received after sending the download command and also reads the local version information after downloading the firmware.

  5. Correctness: The code appears logically correct, assuming RTL_FRAG_LEN is defined and rtl_dev_dbg, rtl_dev_err, and rtl_dev_info are properly implemented for debugging and logging.

However, I noticed a couple of potential issues or areas for improvement:

  • Data Copying: Inside the loop, memcpy(dl_cmd->data, data, frag_len); appears to copy the same data (data) into dl_cmd->data in each iteration. It seems like it should copy a portion of data corresponding to the current fragment. You might need to adjust the starting position in data for each fragment.

  • Unused Variables: The skb variable is declared twice inside the loop. You can remove the declaration inside the loop since it's already declared outside.

  • Error Handling in Fragment Loop: In the fragment loop, if an error occurs during sending the download command (__hci_cmd_sync), the loop will break out early with an error code, but it's not clearing resources allocated before the error occurred (e.g., previously allocated skb). You should make sure to free resources properly before exiting the function.

Overall, the code seems structurally sound, but you might need to verify the details of the firmware download process and adjust the data copying logic accordingly.

hkskoglund avatar May 02 '24 07:05 hkskoglund

hi hkskoglund,

i have the same issue with several aliexpress rtl8761bu dongles on the pi5, plug/unplug until firmware loads and then everything is fine. strange thing is that my pi4's dont have this problem at all. same raspberry pi os, all rpi-updated to 6.6.30 to be sure. overclocking doesn't seem to matter much. pi's are in flirc cases so external bluetooth is pretty much essential.

just thought this might be helpful in tracking down the issue.

sninaber avatar May 04 '24 12:05 sninaber

Same exact issue here.

djholt avatar May 23 '24 05:05 djholt

the latest firmware (https://github.com/raspberrypi/firmware/commit/5c83250276c4fa9d79a93ebc5a739a5ab6a4d6a7) seems to show some improvement on the pi5, sometimes rtl_bt/rtl8761bu now even loads succesfully at boot (about 30-40% succes rate). could this be related to this change: https://github.com/raspberrypi/linux/pull/6171 ?

pi4 still loads the driver without problems, also with the same rpi-update.

sninaber avatar May 23 '24 07:05 sninaber

@sninaber I saw this same improvement just after my comment above. I updated firmware and also enabled usb_max_current_enable=1 at the same time, so I wasn't sure which change helped.

But, still not good reliability. As a workaround, I can repeatedly power cycle USB power using uhubctl until the hci interface comes up successfully, but this isn't ideal. Have you found any way to reload the driver/module or device from software? Or, have you found any alternative Bluetooth chip that plays nicely on Pi 5?

Thanks for the help!

djholt avatar May 23 '24 14:05 djholt

i have tried to modprobe, hcitool, rfkill and bluetoothctl (bluez) to no avail. i have some older bluetooth dongles that work with pi5 and some newer that don't have linux drivers yet. but i can't really recommend any for the pi5 as long as we don't know what causes the issue. let's see if this patch ( https://github.com/raspberrypi/linux/commit/0a19b5256303d2f35be9272832b01a170c9a039b ) for the next firmware release solves the timeout.

sninaber avatar May 23 '24 20:05 sninaber

Same exact issue here.

Thanks for providing a comprehensive bug report. It's very useful.

i have tried to modprobe, hcitool, rfkill and bluetoothctl (bluez) to no avail. i have some older bluetooth dongles that work with pi5 and some newer that don't have linux drivers yet. but i can't really recommend any for the pi5 as long as we don't know what causes the issue. let's see if this patch ( 0a19b52 ) for the next firmware release solves the timeout.

Why would it? You've got a USB device, and the patch there only concerns a SoC:PCIe link.

the latest firmware (raspberrypi/firmware@5c83250) seems to show some improvement on the pi5, sometimes rtl_bt/rtl8761bu now even loads succesfully at boot (about 30-40% succes rate). could this be related to this change: #6171 ?

pi4 still loads the driver without problems, also with the same rpi-update.

This is interesting. Can you iterate through rpi-update versions before and after this date and see which lead to the improvement? Commit list here: https://github.com/raspberrypi/firmware/commits/master/

P33M avatar May 23 '24 20:05 P33M

Thanks for providing a comprehensive bug report. It's very useful.

Whoa—uncalled for. I had no differentiating information to contribute at the time, but I'm following and interested. Thanks for the support through this issue.

djholt avatar May 23 '24 20:05 djholt

Can you iterate through rpi-update versions

Okay. The problem started occurring in e632362—looks like 6.6.16 introduced the issue. I don't experience the issue whatsoever in 6.1.77.

djholt avatar May 23 '24 22:05 djholt

ok that was fast i was still typing my reply.. thank for looking in to this!

sninaber avatar May 23 '24 22:05 sninaber

Okay. The problem started occurring in e632362—looks like 6.6.16 introduced the issue. I don't experience the issue whatsoever in 6.1.77.

i couldn't find this commit, did you mean revert back to https://github.com/raspberrypi/firmware/commit/e7590adb503bd6bc59e598f00e73bbae834d0d81 to check?

Why would it? You've got a USB device, and the patch there only concerns a SoC:PCIe link.

my guess would be that on the pi5, RP1 is also connected to pcie, which among others holds the usb controller. (see latency considerations: https://datasheets.raspberrypi.com/rp1/rp1-peripherals.pdf ). so any pcie issues would affect RP1 devices.

sninaber avatar May 24 '24 07:05 sninaber

I was reverting using rpi-update, so I referenced the commits from rpi-firmware instead: https://github.com/raspberrypi/rpi-firmware/commits/master/

So, for example, the issue didn't manifest after reverting all the way back to 5fc4f64 (kernel 6.1.77):

sudo rpi-update 5fc4f643d2e9c5aa972828705a902d184527ae3f

djholt avatar May 24 '24 08:05 djholt

That's a clue that it might be an upstream issue (compounded by whatever's different on Pi 5[1]). Does a Pi 4 exhibit the same when updated to either version?

Note that running rpi-update on a Pi 4/5 will also update the bootloader, which has slightly changed XHCI behaviour over time. rpi-update won't downgrade it afterwards, so that should keep the same version for both 6.1 and 6.6.

There's certainly scope for a regression given the commit logs...

$ git log --oneline  rpi-6.1.y..rpi-6.6.y btrtl.c
9ee252868787 Bluetooth: btrtl: Ignore error return for hci_devcd_register()
bd003fb338af Bluetooth: btrtl: Load FW v2 otherwise FW v1 for RTL8852C
9e14606d8f38 Bluetooth: msft: Extended monitor tracking by address filter
6b42f04e2417 Bluetooth: btrtl: Correct the length of the HCI command for drop fw
044014ce85a1 Bluetooth: btrtl: Add Realtek devcoredump support
bb23f07cb639 Bluetooth: btrtl: Add missing MODULE_FIRMWARE declarations
7948fe1c92d9 Bluetooth: btrtl: Add the support for RTL8851B
9a24ce5e29b1 Bluetooth: btrtl: Firmware format v2 support
253cf30e8d3d Bluetooth: btrtl: check for NULL in btrtl_set_quirks()
c0123cb6c4c7 Bluetooth: btrtl: add support for the RTL8723CS
10c9e0104e3b Bluetooth: hci_h5: btrtl: Add support for RTL8821CS
fe4b71b59ed5 Bluetooth: btrtl: Add support for RTL8852BS
a479e71322ce Bluetooth: btusb: Ignore zero length of USB packets on ALT 6 for specific chip

[1] On Pi 5, the device is directly connected to a root port. On Pi 1-4, all full-speed devices are accessed though at least one hub.

P33M avatar May 24 '24 09:05 P33M

sudo rpi-update 5fc4f643d2e9c5aa972828705a902d184527ae3f

must admit i expected the problem te have existed on the pi5 all along, but can confirm this completely resolves the issue, so my compliments to how quickly you found this. still, looking at the upstream changes to rtl, generic or specifically rtl8761bu, it doesn't really explain why the pi5 sometimes fails to load the firmware while others (including pi4) don't. i have tried different usb hubs on the pi5 (powered and nonpowered) which doesn't make a difference. can't comment on XHCI or the binary files in e632362 where the problem started, so i'm quite useless from here on..

firmware update today https://github.com/raspberrypi/firmware/commit/f31d28d61e048c9d918874be8e7ebbc30db90617 improves a bit further (about 80% succes loading rtl firmware), but still fails sometimes.

sninaber avatar May 24 '24 14:05 sninaber

i thought about what @p33m said earlier about xhci and the bootloader, so i wanted to see if the otg port behaved in the same way. so i added dtoverlay=dwc2,dr_mode=host to config.txt and connected the bluetooth adapter to the otg port.

IMG_20240607_124435

this solves the problem and recognises the adapter without problems, at boot or multiple unplug/plug. does this help in any way in finding the cause?

is the firmware for RP1 also held in eeprom? if so downgrading to kernel 6.1.77 would not change this. @p33m: i can send you one of these adapters if that helps.

sninaber avatar Jun 07 '24 11:06 sninaber

Thanks for the suggestion @sninaber - I ran into this problem running Home Assistant, and had had to revert the kernel version to keep using the dongles on USBA ports. Using the OSB OTG port in host mode, so far, is working fine on kernel 6.6.28

dbrb2 avatar Jun 09 '24 14:06 dbrb2

I'm insufficiently convinced this isn't a regression between Pi 4 and Pi 5 host controller hardware. @sninaber can you email info < at > raspberrypi.com to start a discussion about getting one of these shipped here?

P33M avatar Jun 17 '24 09:06 P33M

https://github.com/raspberrypi/linux/issues/5046#issuecomment-2167137559 may be related

buganini avatar Jul 04 '24 16:07 buganini

Apologies for the lag in response - I've received your BT adapter and had a first pass at reproducing your issue - which I can't. It's worked correctly for me 10/10 times.

As a point of reference, can you re-run rpi-update as 6.6 has moved on several upstream revisions since then?

P33M avatar Jul 23 '24 10:07 P33M

interesting! no problem, thanks for taking time trying to reproduce. so far no issues in linux and firmware seem related, so impact seems low and we may have to close this issue for now.

i just tried flashing a fresh sdcard for Pi5 with 64bit Pi-OS networkinstall, full-upgrade and rpi-update. offical keyboard, mouse and powersupply. for me with both 4k/16k kernels the problem remains intermittent (20-30% succes) with all rtl8761 dongles directly attached.

so that only leaves the pi5 units which are probably initial revisions. will look into replacing them after summer recess.

/proc/cpuinfo Revision : d04170 Serial : e2fa4c6734b38595 Model : Raspberry Pi 5 Model B Rev 1.0

uname -a Linux raspberrypi 6.6.40-v8+ #1784 SMP PREEMPT Tue Jul 16 13:53:31 BST 2024 aarch64 GNU/Linux

last working firmware: af3ab905d42829d4ce860f19a0e049c3bcdbe35f (feb 8 2024).

sninaber avatar Jul 24 '24 09:07 sninaber

Do you have any other USB devices simultaneously plugged in, and if so what are they? (lsusb -v)

P33M avatar Jul 24 '24 10:07 P33M

I've tried sudo rpi-update to 6.6.40 and the issue still persist

I then tried the sudo rpi-update 5fc4f643d2e9c5aa972828705a902d184527ae3f (6.1.77) and have no issues of downloading fw when plug/unplugging

Looking at the lsusb output, I take a wild guess that maybe something changed in the root_hub xhci-hcd driver that sometimes interferes with downloading firmware ?

lsusb -tvv
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    ID 1d6b:0003 Linux Foundation 3.0 root hub
    /sys/bus/usb/devices/usb4  /dev/bus/usb/004/001
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    ID 1d6b:0002 Linux Foundation 2.0 root hub
    /sys/bus/usb/devices/usb3  /dev/bus/usb/003/001
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    ID 1d6b:0003 Linux Foundation 3.0 root hub
    /sys/bus/usb/devices/usb2  /dev/bus/usb/002/001
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    ID 1d6b:0002 Linux Foundation 2.0 root hub
    /sys/bus/usb/devices/usb1  /dev/bus/usb/001/001
    |__ Port 2: Dev 17, If 0, Class=Wireless, Driver=btusb, 12M
        ID 0bda:8771 Realtek Semiconductor Corp. 
        /sys/bus/usb/devices/1-2  /dev/bus/usb/001/017
    |__ Port 2: Dev 17, If 1, Class=Wireless, Driver=btusb, 12M
        ID 0bda:8771 Realtek Semiconductor Corp. 
        /sys/bus/usb/devices/1-2  /dev/bus/usb/001/017

hkskoglund avatar Jul 24 '24 11:07 hkskoglund

just a raspberry pi keyboard and mouse, but as requested: sudo lsusb -v

lsusb output ``` Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 3.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 3 bMaxPacketSize0 9 idVendor 0x1d6b Linux Foundation idProduct 0x0003 3.0 root hub bcdDevice 6.06 iManufacturer 3 Linux 6.6.40-v8-16k+ xhci-hcd iProduct 2 xHCI Host Controller iSerial 1 xhci-hcd.1 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x001f bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 12 bMaxBurst 0 Hub Descriptor: bLength 12 bDescriptorType 42 nNbrPorts 1 wHubCharacteristic 0x0009 Per-port power switching Per-port overcurrent protection bPwrOn2PwrGood 50 * 2 milli seconds bHubContrCurrent 0 milli Ampere bHubDecLat 0.0 micro seconds wHubDelay 0 nano seconds DeviceRemovable 0x00 Hub Port Status: Port 1: 0000.02a0 5Gbps power Rx.Detect Binary Object Store Descriptor: bLength 5 bDescriptorType 15 wTotalLength 0x000f bNumDeviceCaps 1 SuperSpeed USB Device Capability: bLength 10 bDescriptorType 16 bDevCapabilityType 3 bmAttributes 0x02 Latency Tolerance Messages (LTM) Supported wSpeedsSupported 0x0008 Device can operate at SuperSpeed (5Gbps) bFunctionalitySupport 1 Lowest fully-functional device speed is Full Speed (12Mbps) bU1DevExitLat 10 micro seconds bU2DevExitLat 2047 micro seconds Device Status: 0x0001 Self Powered

Bus 003 Device 003: ID 093a:2510 Pixart Imaging, Inc. Optical Mouse Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 1.10 bDeviceClass 0 bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 8 idVendor 0x093a Pixart Imaging, Inc. idProduct 0x2510 Optical Mouse bcdDevice 1.00 iManufacturer 1 PixArt iProduct 2 USB Optical Mouse iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0022 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xa0 (Bus Powered) Remote Wakeup MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 3 Human Interface Device bInterfaceSubClass 1 Boot Interface Subclass bInterfaceProtocol 2 Mouse iInterface 0 HID Device Descriptor: bLength 9 bDescriptorType 33 bcdHID 1.11 bCountryCode 0 Not supported bNumDescriptors 1 bDescriptorType 34 Report wDescriptorLength 52 Report Descriptors: ** UNAVAILABLE ** Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 10 Device Status: 0x0000 (Bus Powered)

Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 1 Single TT bMaxPacketSize0 64 idVendor 0x1d6b Linux Foundation idProduct 0x0002 2.0 root hub bcdDevice 6.06 iManufacturer 3 Linux 6.6.40-v8-16k+ xhci-hcd iProduct 2 xHCI Host Controller iSerial 1 xhci-hcd.1 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0019 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 12 Hub Descriptor: bLength 9 bDescriptorType 41 nNbrPorts 2 wHubCharacteristic 0x0009 Per-port power switching Per-port overcurrent protection TT think time 8 FS bits bPwrOn2PwrGood 10 * 2 milli seconds bHubContrCurrent 0 milli Ampere DeviceRemovable 0x00 PortPwrCtrlMask 0xff Hub Port Status: Port 1: 0000.0100 power Port 2: 0000.0303 lowspeed power enable connect Device Status: 0x0001 Self Powered

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 3.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 3 bMaxPacketSize0 9 idVendor 0x1d6b Linux Foundation idProduct 0x0003 3.0 root hub bcdDevice 6.06 iManufacturer 3 Linux 6.6.40-v8-16k+ xhci-hcd iProduct 2 xHCI Host Controller iSerial 1 xhci-hcd.0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x001f bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 12 bMaxBurst 0 Hub Descriptor: bLength 12 bDescriptorType 42 nNbrPorts 1 wHubCharacteristic 0x0009 Per-port power switching Per-port overcurrent protection bPwrOn2PwrGood 50 * 2 milli seconds bHubContrCurrent 0 milli Ampere bHubDecLat 0.0 micro seconds wHubDelay 0 nano seconds DeviceRemovable 0x00 Hub Port Status: Port 1: 0000.02a0 5Gbps power Rx.Detect Binary Object Store Descriptor: bLength 5 bDescriptorType 15 wTotalLength 0x000f bNumDeviceCaps 1 SuperSpeed USB Device Capability: bLength 10 bDescriptorType 16 bDevCapabilityType 3 bmAttributes 0x02 Latency Tolerance Messages (LTM) Supported wSpeedsSupported 0x0008 Device can operate at SuperSpeed (5Gbps) bFunctionalitySupport 1 Lowest fully-functional device speed is Full Speed (12Mbps) bU1DevExitLat 10 micro seconds bU2DevExitLat 2047 micro seconds Device Status: 0x0001 Self Powered

Bus 001 Device 003: ID 04d9:0006 Holtek Semiconductor, Inc. Wired Keyboard (78/79 key) [RPI Wired Keyboard 5] Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 0 bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 8 idVendor 0x04d9 Holtek Semiconductor, Inc. idProduct 0x0006 Wired Keyboard (78/79 key) [RPI Wired Keyboard 5] bcdDevice 1.50 iManufacturer 1
iProduct 2 RPI Wired Keyboard 4 iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x003b bNumInterfaces 2 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xa0 (Bus Powered) Remote Wakeup MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 3 Human Interface Device bInterfaceSubClass 1 Boot Interface Subclass bInterfaceProtocol 1 Keyboard iInterface 0 HID Device Descriptor: bLength 9 bDescriptorType 33 bcdHID 1.11 bCountryCode 0 Not supported bNumDescriptors 1 bDescriptorType 34 Report wDescriptorLength 65 Report Descriptors: ** UNAVAILABLE ** Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0008 1x 8 bytes bInterval 10 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 1 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 3 Human Interface Device bInterfaceSubClass 0 bInterfaceProtocol 0 iInterface 0 HID Device Descriptor: bLength 9 bDescriptorType 33 bcdHID 1.11 bCountryCode 0 Not supported bNumDescriptors 1 bDescriptorType 34 Report wDescriptorLength 59 Report Descriptors: ** UNAVAILABLE ** Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x82 EP 2 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0005 1x 5 bytes bInterval 10 Device Status: 0x0000 (Bus Powered)

Bus 001 Device 002: ID 05e3:0610 Genesys Logic, Inc. Hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 2 TT per port bMaxPacketSize0 64 idVendor 0x05e3 Genesys Logic, Inc. idProduct 0x0610 Hub bcdDevice 32.98 iManufacturer 0 iProduct 1 USB2.0 Hub iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0029 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 1 Single TT iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0001 1x 1 bytes bInterval 12 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 1 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 2 TT per port iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0001 1x 1 bytes bInterval 12 Hub Descriptor: bLength 9 bDescriptorType 41 nNbrPorts 4 wHubCharacteristic 0x00e0 Ganged power switching Ganged overcurrent protection TT think time 32 FS bits Port indicators bPwrOn2PwrGood 50 * 2 milli seconds bHubContrCurrent 100 milli Ampere DeviceRemovable 0x00 PortPwrCtrlMask 0xff Hub Port Status: Port 1: 0000.0303 lowspeed power enable connect Port 2: 0000.0100 power Port 3: 0000.0100 power Port 4: 0000.0100 power Device Qualifier (for other device speed): bLength 10 bDescriptorType 6 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 0 Full speed (or root) hub bMaxPacketSize0 64 bNumConfigurations 1 Device Status: 0x0001 Self Powered

Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 9 Hub bDeviceSubClass 0 bDeviceProtocol 1 Single TT bMaxPacketSize0 64 idVendor 0x1d6b Linux Foundation idProduct 0x0002 2.0 root hub bcdDevice 6.06 iManufacturer 3 Linux 6.6.40-v8-16k+ xhci-hcd iProduct 2 xHCI Host Controller iSerial 1 xhci-hcd.0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0019 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xe0 Self Powered Remote Wakeup MaxPower 0mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 9 Hub bInterfaceSubClass 0 bInterfaceProtocol 0 Full speed (or root) hub iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0004 1x 4 bytes bInterval 12 Hub Descriptor: bLength 9 bDescriptorType 41 nNbrPorts 2 wHubCharacteristic 0x0009 Per-port power switching Per-port overcurrent protection TT think time 8 FS bits bPwrOn2PwrGood 10 * 2 milli seconds bHubContrCurrent 0 milli Ampere DeviceRemovable 0x00 PortPwrCtrlMask 0xff Hub Port Status: Port 1: 0000.0100 power Port 2: 0000.0503 highspeed power enable connect Device Status: 0x0001 Self Powered

</details>

sninaber avatar Jul 24 '24 13:07 sninaber

I can reproduce this. There's a dependency between Vbus being connected to the device and the time it takes for initialisation to complete. If the time is too long, the device will not respond to further HCI commands (usually this means failing to load firmware).

If I plug the device in slowly (more likely to occur on a Pi 5, as connectors are quite tight) then I get a high failure rate. If I ram the device in quickly, it almost always works. I have a hub that switches Vbus on/off at the upstream facing port, and has two cascaded 4-port hubs inside. If the device is plugged into the first hub port, and enumerated first, then it usually works after being switched on. If I plug it into the last hub port, which is cascaded off the first hub, it never works. It may also be the case that Pi 5 has more debounce on connection detection, increasing the time taken to enumerate.

My bet is there's some sort of watchdog inside the dongle that's initialised at start of day and is active, and the firmware blob deactivates it.

P33M avatar Jul 24 '24 14:07 P33M

ok, glad you could reproduce after all!. i guess we are slow pluggers. but timeout is indeed the issue. as hkskoglund mentioned in his/her second post, the routine for loading the firmware is called with a constant HCI_INIT_TIMEOUT which should be 10000 (hci.h) milliseconds. on the pi4 i observed it can take 5 seconds or more before the rtl8761 is initialised. but on the pi5 with kernel > 6.1.77 timeout occurs within 1 or maybe 2 seconds.

sninaber avatar Jul 24 '24 17:07 sninaber

I tried to capture usb traffic on usbmon1 enabling usbmon by sudo modprobe usbmon. When fw download fails, tshark does not print "controller → host HCI_EVT 71 Rcvd Command Complete (Vendor Command 0x0020 [opcode 0xFC20])".

henning@raspberrypi0:~ $ uname -a Linux raspberrypi0 6.6.31+rpt-rpi-2712 #1 SMP PREEMPT Debian 1:6.6.31-1+rpt1 (2024-05-29) aarch64 GNU/Linux henning@raspberrypi0:~ $ sudo tshark -i 8

Failed fw download (hci0: command 0xfc20 tx timeout)

614 4.495767 host → controller HCI_CMD 290 Sent Vendor Command 0x0020 (opcode 0xFC20) 615 4.495786 1.36.0 → host HCI_USB 64 Rcvd[Malformed Packet] 616 4.501761 1.36.0 → host HCI_USB 64 Rcvd[Malformed Packet] 617 6.506055 1.36.1 → host USB 64 URB_INTERRUPT in 618 6.506871 1.36.2 → host USB 64 URB_BULK in 619 6.506926 1.36.2 → host USB 64 URB_BULK in

Successfull fw download:

3258 161.271549 host → controller HCI_CMD 290 Sent Vendor Command 0x0020 (opcode 0xFC20) 3259 161.271568 1.35.0 → host HCI_USB 64 Rcvd[Malformed Packet] 3260 161.277541 1.35.0 → host HCI_USB 64 Rcvd[Malformed Packet] 3261 161.304544 controller → host HCI_EVT 71 Rcvd Command Complete (Vendor Command 0x0020 [opcode 0xFC20])

$ dmesg --ctime --follow [Thu Jul 25 09:24:34 2024] usb 1-2: new full-speed USB device number 37 using xhci-hcd [Thu Jul 25 09:24:34 2024] usb 1-2: New USB device found, idVendor=0bda, idProduct=8771, bcdDevice= 2.00 [Thu Jul 25 09:24:34 2024] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [Thu Jul 25 09:24:34 2024] usb 1-2: Product: Bluetooth Radio [Thu Jul 25 09:24:34 2024] usb 1-2: Manufacturer: Realtek [Thu Jul 25 09:24:34 2024] usb 1-2: SerialNumber: 00E04C239987 [Thu Jul 25 09:24:34 2024] Bluetooth: hci0: RTL: examining hci_ver=0a hci_rev=000b lmp_ver=0a lmp_subver=8761 [Thu Jul 25 09:24:34 2024] Bluetooth: hci0: RTL: rom_version status=0 version=1 [Thu Jul 25 09:24:34 2024] Bluetooth: hci0: RTL: loading rtl_bt/rtl8761bu_fw.bin [Thu Jul 25 09:24:34 2024] Bluetooth: hci0: RTL: loading rtl_bt/rtl8761bu_config.bin [Thu Jul 25 09:24:34 2024] Bluetooth: hci0: RTL: cfg_sz 6, total sz 30210 [Thu Jul 25 09:24:37 2024] Bluetooth: hci0: command 0xfc20 tx timeout [Thu Jul 25 09:24:37 2024] Bluetooth: hci0: RTL: download fw command failed (-110)

hkskoglund avatar Jul 25 '24 08:07 hkskoglund

I'm using just the single USB device with rtl8761bu and observing the same issue.

uname -a Linux 6.6.42-v8+ #1787 SMP PREEMPT Thu Jul 25 17:44:41 BST 2024 aarch64 GNU/Linux

Revision : d04170 Serial : 2f2d8041c9185fa0 Model : Raspberry Pi 5 Model B Rev 1.0

The issue happens also during restart of Rpi. Thus, it is not related to slow plug-in only. Sometimes, I have to un-plug and plug-in several times to get firware loaded successfully.

sislakd avatar Aug 02 '24 11:08 sislakd

Finally I've discovered why my Asus BT500 BT dongle doesn't work. I'm having the same issue. I use the dongle for a bit, but if I restart it isn't properly recognized, from what I read here the firmware isn't loaded into the chip at startup. Has anyone fixed this? Are there any updates since August?

FraH90 avatar Oct 06 '24 18:10 FraH90

Finally I've discovered why my Asus BT500 BT dongle doesn't work. I'm having the same issue.

I use the dongle for a bit, but if I restart it isn't properly recognized, from what I read here the firmware isn't loaded into the chip at startup.

Has anyone fixed this? Are there any updates since August?

which rpi release are you using? there was a release in July which may contain the fix for this issue.

buganini avatar Oct 06 '24 18:10 buganini

Finally I've discovered why my Asus BT500 BT dongle doesn't work. I'm having the same issue. I use the dongle for a bit, but if I restart it isn't properly recognized, from what I read here the firmware isn't loaded into the chip at startup. Has anyone fixed this? Are there any updates since August?

which rpi release are you using? there was a release in July which may contain the fix for this issue.

Bought it 2 weeks ago, problem still present

Linux raspberry 6.6.51+rpt-rpi-2712 #1 SMP PREEMPT Debian 1:6.6.51-1+rpt2 (2024-10-01) aarch64 GNU/Linux Raspberry Pi 5 Model B Rev 1.0 Revision : d04170

Kaitology avatar Oct 07 '24 09:10 Kaitology