Bug 219088

Summary: bluetooth scanning doesn't work in 6.10.0
Product: Drivers Reporter: Eugene Shalygin (eugene.shalygin)
Component: BluetoothAssignee: linux-bluetooth (linux-bluetooth)
Status: RESOLVED CODE_FIX    
Severity: normal CC: luiz.dentz, regressions
Priority: P3    
Hardware: All   
OS: Linux   
Kernel Version: 6.10 Subsystem:
Regression: Yes Bisected commit-id: 2e2515c1ba384ae44f6bf13dd64b9a0a950798c4
Attachments: btmon trace 6.10.0
btmon trace 6.9.9
Bluetooth: hci_event: Fix setting DISCOVERY_FINDING for passive scanning

Description Eugene Shalygin 2024-07-23 19:39:38 UTC
With kernel 6.10.0 bluetooth scanning finds no devices (Intel AX210). 6.9.9 works.
Comment 1 Eugene Shalygin 2024-07-24 06:56:42 UTC
$ dmesg | grep -e 'iwlwifi\|Bluetooth'                                                                                                                                                                                          
[    2.633116] iwlwifi 0000:03:00.0: enabling device (0000 -> 0002)
[    2.643454] Bluetooth: Core ver 2.22
[    2.646521] Bluetooth: HCI device and connection manager initialized
[    2.647920] Bluetooth: HCI socket layer initialized
[    2.648885] Bluetooth: L2CAP socket layer initialized
[    2.649972] Bluetooth: SCO socket layer initialized
[    2.658734] iwlwifi 0000:03:00.0: Detected crf-id 0x400410, cnv-id 0x400410 wfpm id 0x80000000
[    2.660717] iwlwifi 0000:03:00.0: PCI dev 2725/0024, rev=0x420, rfid=0x10d000
[    2.662120] Loading firmware: iwlwifi-ty-a0-gf-a0-89.ucode
[    2.667789] iwlwifi 0000:03:00.0: TLV_FW_FSEQ_VERSION: FSEQ Version: 0.0.2.42
[    2.668164] iwlwifi 0000:03:00.0: loaded firmware version 89.202a2f7b.0 ty-a0-gf-a0-89.ucode op_mode iwlmvm
[    2.693021] Bluetooth: hci0: Device revision is 0
[    2.694469] Bluetooth: hci0: Secure boot is enabled
[    2.698894] Bluetooth: hci0: OTP lock is enabled
[    2.700339] Bluetooth: hci0: API lock is enabled
[    2.701262] Bluetooth: hci0: Debug lock is disabled
[    2.702069] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
[    2.702719] Bluetooth: hci0: Bootloader timestamp 2019.40 buildtype 1 build 38
[    2.703431] Bluetooth: hci0: No support for _PRR ACPI method
[    2.708740] Bluetooth: hci0: Found device firmware: intel/ibt-0041-0041.sfi
[    2.711227] Bluetooth: hci0: Boot Address: 0x100800
[    2.711230] Bluetooth: hci0: Firmware Version: 120-18.24
[    2.773104] iwlwifi 0000:03:00.0: Detected Intel(R) Wi-Fi 6 AX210 160MHz, REV=0x420
[    2.783598] iwlwifi 0000:03:00.0: WRT: Invalid buffer destination
[    2.943521] iwlwifi 0000:03:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    2.943552] iwlwifi 0000:03:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    2.943578] iwlwifi 0000:03:00.0: WFPM_AUTH_KEY_0: 0x90
[    2.943602] iwlwifi 0000:03:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
[    2.943608] Loading firmware: iwlwifi-ty-a0-gf-a0.pnvm
[    2.944080] iwlwifi 0000:03:00.0: loaded PNVM version 35148b80
[    2.959773] iwlwifi 0000:03:00.0: Detected RF GF, rfid=0x10d000
[    3.029643] iwlwifi 0000:03:00.0: base HW address: 2c:33:58:e9:d5:1d
[    3.822131] Bluetooth: hci0: Waiting for firmware download to complete
[    3.822963] Bluetooth: hci0: Firmware loaded in 1085762 usecs
[    3.822999] Bluetooth: hci0: Waiting for device to boot
[    3.848969] Bluetooth: hci0: Device booted in 25377 usecs
[    3.848982] Bluetooth: hci0: Malformed MSFT vendor event: 0x02
[    3.858349] Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-0041-0041.ddc
[    3.864001] Bluetooth: hci0: Applying Intel DDC parameters completed
[    3.872025] Bluetooth: hci0: Firmware timestamp 2024.18 buildtype 1 build 81528
[    3.872028] Bluetooth: hci0: Firmware SHA1: 0xa8bb3f39
[    3.882989] Bluetooth: hci0: Fseq status: Success (0x00)
[    3.883003] Bluetooth: hci0: Fseq executed: 00.00.02.41
[    3.883014] Bluetooth: hci0: Fseq BT Top: 00.00.02.41
[    6.943128] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    6.943131] Bluetooth: BNEP filters: protocol multicast
[    6.943133] Bluetooth: BNEP socket layer initialized
[    6.943661] Bluetooth: MGMT ver 1.22
[    6.946103] Bluetooth: ISO socket layer initialized
[    7.068883] iwlwifi 0000:03:00.0: WRT: Invalid buffer destination
[    7.224190] iwlwifi 0000:03:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    7.225614] iwlwifi 0000:03:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    7.226232] iwlwifi 0000:03:00.0: WFPM_AUTH_KEY_0: 0x90
[    7.226803] iwlwifi 0000:03:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
[    7.384675] iwlwifi 0000:03:00.0: WRT: Invalid buffer destination
[    7.539920] iwlwifi 0000:03:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    7.541272] iwlwifi 0000:03:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    7.541861] iwlwifi 0000:03:00.0: WFPM_AUTH_KEY_0: 0x90
[    7.542422] iwlwifi 0000:03:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
[   16.078066] Bluetooth: RFCOMM TTY layer initialized
[   16.078073] Bluetooth: RFCOMM socket layer initialized
[   16.078077] Bluetooth: RFCOMM ver 1.11
Comment 2 Artem S. Tashkinov 2024-07-24 10:54:22 UTC
Please perform regression testing:

https://docs.kernel.org/admin-guide/bug-bisect.html
Comment 3 Eugene Shalygin 2024-07-25 00:13:34 UTC
Converges to 2e2515c1ba384ae44f6bf13dd64b9a0a950798c4
Comment 4 The Linux kernel's regression tracker (Thorsten Leemhuis) 2024-07-25 08:29:59 UTC
(In reply to Eugene Shalygin from comment #3)
> Converges to 2e2515c1ba384ae44f6bf13dd64b9a0a950798c4

thx; I would like to forward this report by mail; can I CC you? this would expose name and email address to the public
Comment 5 Eugene Shalygin 2024-07-25 08:32:06 UTC
(In reply to The Linux kernel's regression tracker (Thorsten Leemhuis) from comment #4)
> thx; I would like to forward this report by mail; can I CC you? this would
> expose name and email address to the public

Thanks, no problem.
Comment 6 Luiz Von Dentz 2024-07-25 13:44:11 UTC
I wasn't able to reproduce with current bluetooth-next:

https://gist.github.com/Vudentz/da22fb40ad55091b4a1e67f14a8ad033

@Eugene please collect the btmon traces.

That change should actually help to detect scanning had started so it would be quite surprising if it caused events to not be submitted to userspace.
Comment 7 Eugene Shalygin 2024-07-25 20:49:21 UTC
(In reply to Luiz Von Dentz from comment #6)
> I wasn't able to reproduce with current bluetooth-next:

I now have two machines with this issue.
Comment 8 Eugene Shalygin 2024-07-25 20:50:03 UTC
Created attachment 306619 [details]
btmon trace 6.10.0
Comment 9 Eugene Shalygin 2024-07-25 20:50:19 UTC
Created attachment 306620 [details]
btmon trace 6.9.9
Comment 10 Eugene Shalygin 2024-07-25 20:52:17 UTC
(In reply to Luiz Von Dentz from comment #6)
> @Eugene please collect the btmon traces.

Please find the traces attached. The Samsung phone device is paired, the HTC one is not.
Comment 11 Luiz Von Dentz 2024-07-25 21:28:59 UTC
On 6.9 there is the Start Discovery but on 6.10 there is nothing which indicates the userspace is not even attempting to start it for some reason:

bluetoothd[945]: @ MGMT Command: Start Discovery (0x0023) plen 1                                                                                                                                                                    {0x0001} [hci0] 12.038247
        Address type: 0x07
          BR/EDR
          LE Public
          LE Random
Comment 12 Eugene Shalygin 2024-07-25 21:31:13 UTC
How can I learn why is that?
Comment 13 Luiz Von Dentz 2024-07-25 21:33:50 UTC
(In reply to Eugene Shalygin from comment #12)
> How can I learn why is that?

Are you sure you are issuing any command? Or you are using some UI that perhaps thinks it is scanning for some reason?

Anyway if you try bluetoothctl> scan on that should trigger the command above.
Comment 14 Eugene Shalygin 2024-07-25 21:43:12 UTC
Yes, I'm sure. Nothing new appears in the btmon log after issuing scan on in bluetoothctl, scan off results in:

@ MGMT Event: Command Complete (0x0001) plen 4                                                                                                                                                                                      {0x0001} [hci0] 89.970607
      Stop Discovery (0x0024) plen 1
        Status: Rejected (0x0b)
        Address type: 0x00
Comment 15 Luiz Von Dentz 2024-07-25 21:53:01 UTC
(In reply to Eugene Shalygin from comment #14)
> Yes, I'm sure. Nothing new appears in the btmon log after issuing scan on in
> bluetoothctl, scan off results in:
> 
> @ MGMT Event: Command Complete (0x0001) plen 4                              
> {0x0001} [hci0] 89.970607
>       Stop Discovery (0x0024) plen 1
>         Status: Rejected (0x0b)
>         Address type: 0x00

Hmm, this sounds like the states are no in sync then, bluetoothd thinks Start Discovery has been triggered but when it tries to stop the kernel don't think it is discovering. Do you see anything like Discovering events when starting bluetoothd or have Discovering: yes when you do bluetoothctl> show?
Comment 16 Eugene Shalygin 2024-07-25 22:09:02 UTC
Seems like it's more complicated. 

In attempt to get a clean btmon log, I reloaded the btusb module a few times. And it turns out if I issue the scan command right after reloading the module, before moving my Bluetooth mouse, scan works. But if it gets busy with the mouse, scanning can not even be stopped (Discovering: yes is still present after multiple "scan off").
Comment 17 Luiz Von Dentz 2024-07-25 22:38:41 UTC
Looks like I found what it was, is is passive scanning triggering DISCOVERY_FINDING state when in fact it shouldn't because passive scanning doesn't generate events such as MGMT Device Found, it is just meant to auto-connect devices already know/paired/bonded.
Comment 18 Luiz Von Dentz 2024-07-25 22:39:57 UTC
Created attachment 306621 [details]
Bluetooth: hci_event: Fix setting DISCOVERY_FINDING for passive scanning
Comment 19 Eugene Shalygin 2024-07-25 23:39:18 UTC
(In reply to Luiz Von Dentz from comment #18)
> Created attachment 306621 [details]
> Bluetooth: hci_event: Fix setting DISCOVERY_FINDING for passive scanning

Applied that to 6.10.0 and it helped. Thank you!
Comment 20 Artem S. Tashkinov 2024-07-26 10:08:21 UTC
(In reply to Luiz Von Dentz from comment #18)
> Created attachment 306621 [details]
> Bluetooth: hci_event: Fix setting DISCOVERY_FINDING for passive scanning

Please push to stable.