QCA6390 bluetooth doesn't work after warm boot or disable/reenable

[Wren Turkal]

On 4/11/24 1:30 PM, Wren Turkal wrote:
> On 4/10/24 3:40 PM, Wren Turkal wrote:
>> On 4/10/24 3:00 PM, Wren Turkal wrote:
>>> +Johan since he's a former BT drivers maintainer.
>>>
>>> On 4/9/24 1:11 PM, Wren Turkal wrote:
>>>> On 4/9/24 1:03 PM, Luiz Augusto von Dentz wrote:
>>>>> 5.19 seems a little too old, imo, or has it been broken for that long,
>>>>> did you at least tried with bluetooth-next? Try contacting the people
>>>>> who actually wrote the driver.
>>>>
>>>> Sorry, I didn't answer your question. Yes, I do think it's been 
>>>> broken for longer than that, but I wanted to confirm.
>>>
>>> Okay, so I tried 6.9-rc3 and every main release 5.19-6.8.
>>>
>>> I have found the following:
>>>
>>> * older kernels (6.3 and before) seem to be far less likely to kill 
>>> on a cycling the bluetooth service.
>>> * 6.8/6.9-rcs consistently destroy bluetooth when stopping and 
>>> restarting the service
>>> * If I destroy the bluetooth service with a BT service restart in 
>>> 6.9-rc3 and warm reboot into any release back to 5.19, bluetooth does 
>>> not work
>>> * cold boot works in all cases assuming I give the laptop about 5s 
>>> between power off/on
>>
>> I just did another experiment on 6.9-rc3. I blacklisted relevant 
>> bluetooth modules and then warm booted without the blacklist. I did 
>> this for both the "bluetooth" and "btqca" modules. In both cases, I 
>> cold booted with and appropriate "module_blacklist" kernel arg. After 
>> the boot, I verified the module was not loaded. I then warm booted 
>> without the blacklist, and the bluetooth works, so bluetooth only 
>> seems to fail when the linux module code for closing the device is run 
>> before a warm boot.
> 
> And another experiment. I disabled the bluetooth.service and 
> bluetooth.target with systemctl. I then shutdown and cold booted. After 
> logging into GNOME, starting the service. Similar failures show up in 
> the kernel logs as after the failure during a warm boot:
> 
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Bluetooth 
> management interface 1.22 initialized
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: 
> src/adapter.c:reset_adv_monitors_complete() Failed to reset Adv 
> Monitors: Failed (0x03)
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Battery Provider 
> Manager created
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: MGMT ver 1.22
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: 
> src/device.c:device_set_wake_support() Unable to set wake_support 
> without RPA resolution
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Failed to clear 
> UUIDs: Failed (0x03)
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:17:54 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:17:54 braindead.localdomain wireplumber[2139]: 
> org.bluez.GattManager1.RegisterApplication() failed: 
> GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Invalid method call
> Apr 11 13:17:54 braindead.localdomain wireplumber[2139]: 
> org.bluez.GattManager1.RegisterApplication() failed: 
> GDBus.Error:org.freedesktop.DBus.Error.UnknownMethod: Invalid method call
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: setting 
> up ROME/QCA6390
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: RFCOMM TTY 
> layer initialized
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: RFCOMM socket 
> layer initialized
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: RFCOMM ver 1.11
> 
> ... skip some logs about registering modules in the bluetoothd ...
> 
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA 
> Product ID   :0x00000010
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA SOC 
> Version  :0x400a0200
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA ROM 
> Version  :0x00000200
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA Patch 
> Version:0x00003ac0
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA 
> controller version 0x02000200
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA 
> Downloading qca/htbtfw20.tlv
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA 
> Failed to send TLV segment (-110)
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: QCA 
> Failed to download patch (-110)
> Apr 11 13:17:54 braindead.localdomain kernel: Bluetooth: hci0: Retry BT 
> power ON:0
> Apr 11 13:17:57 braindead.localdomain kernel: Bluetooth: hci0: command 
> 0xfc00 tx timeout
> Apr 11 13:17:57 braindead.localdomain kernel: Bluetooth: hci0: Reading 
> QCA version information failed (-110)
> Apr 11 13:17:57 braindead.localdomain kernel: Bluetooth: hci0: Retry BT 
> power ON:1
> Apr 11 13:17:59 braindead.localdomain kernel: Bluetooth: hci0: command 
> 0xfc00 tx timeout
> Apr 11 13:17:59 braindead.localdomain kernel: Bluetooth: hci0: Reading 
> QCA version information failed (-110)
> Apr 11 13:17:59 braindead.localdomain kernel: Bluetooth: hci0: Retry BT 
> power ON:2
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to set 
> mode: Authentication Failed (0x05)
> Apr 11 13:18:01 braindead.localdomain kernel: Bluetooth: hci0: command 
> 0xfc00 tx timeout
> Apr 11 13:18:01 braindead.localdomain kernel: Bluetooth: hci0: Reading 
> QCA version information failed (-110)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Too small Add 
> Device complete event
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)
> Apr 11 13:18:01 braindead.localdomain bluetoothd[4408]: Failed to add 
> UUID: Failed (0x03)

I have captured a full log of my system since boot including debug 
messages for the hci_hca.c file. Should I attach that log to a message 
here? In general, I am not totally certain of how I should track the 
troubleshooting for this problem. Do y'all want it on the mailing list?

> 
> It looks like the firmware is failing to load. Is there some kind of 
> time limit on loading the firmware after the module is loaded?
> 
> Why would this work if I allow the service to be started on boot, but 
> not if I wait until after logging into GNOME?
> 
>>> So, I suspsect that the process of closing out the hardware may be 
>>> leaving it in a state that the reset cannot handle (and probably 
>>> never could handle).
>>>
>>> I also found that qualcomm has docs here: 
>>> https://www.qualcomm.com/products/technology/wi-fi/fastconnect/fastconnect-6800#Documentation
>>>
>>> However, I am not a member of a Qualcomm verified company (mentioned 
>>> in the doc links). Luiz, Marcel, or Johan, do you have any contacts 
>>> that might be able to help me in getting info about the technical 
>>> docs for this hardware? I would love to see if I can find any issues 
>>> in how the hardware is being reset.
>>>
>>> As an independent dev, I don't even know what it takes to get that 
>>> kind of access. I would welcome any help here. Hey Qualcomm, are you 
>>> hiring? :P
>>>
>>> wt
>>
> 

-- 
You're more amazing than you think!