search

bluez / bluez

Main BlueZ tree
https://bluez.github.io/bluez/
GNU General Public License v2.0
761 stars 278 forks source link

Possible regression (or new quirk required) for steam controller in BLE mode #919

Open fledermaus opened 3 months ago

fledermaus commented 3 months ago

We have seen a problem with Steam Controllers (in BLE mode, ie that have had their final firmware update and therefore capable of bluetooth connection) appear to become unresponsive after a while. We've managed to establish the following:

We think the problem started at 247ae8524888268bb075ff90a3d77a9b4449d08f hog-lib: Don't destroy UHID device on detach but reverting that on 5.76 or 5.77 was not sufficient to fix the problem.

Attached are btmon captures and journal output from sessions where there were at least 1 suspend/resume each and no hang (5.66) or a hang:

bluez-steam-controller-logs.tar.gz

The following trace items appear only on the no-hang case:

And this only occurs in the hang trace:

Vudentz commented 3 months ago

We have seen a problem with Steam Controllers (in BLE mode, ie that have had their final firmware update and therefore capable of bluetooth connection) appear to become unresponsive after a while. We've managed to establish the following:

* Bluez 5.66 does not trigger this problem

* Bluez 5.73 and later do trigger it

* Suspend/Resume cycles of the device (Steam Deck) make the problem more likely

* When the problem occurs

  * We appear to stop receiving input events (button presses, gyro, etc) from the controller
  * The controller does not respond when we ask it for a feature report (HIDIOCGFEATURE returns EIO)
  * bluetoothctl show the steam controller as connected

We think the problem started at 247ae8524888268bb075ff90a3d77a9b4449d08f hog-lib: Don't destroy UHID device on detach but reverting that on 5.76 or 5.77 was not sufficient to fix the problem.

Attached are btmon captures and journal output from sessions where there were at least 1 suspend/resume each and no hang (5.66) or a hang:

bluez-steam-controller-logs.tar.gz

The following trace items appear only on the no-hang case:

* `@ MGMT Command: Remove Device`

* `@ MGMT Command: Disconnect`

* `< HCI Command: Disconnect`

* `> HCI Event: Disconnect Complete`

* `@ MGMT Command: Add Device`

* `@ MGMT Event: Device Flags Changed`

* `@ MGMT Event: New Connection Parameter`

* `< HCI Command: LE Connection Update`

* `@ MGMT Command: Stop Discovery`

* `< HCI Command: Write Scan Enable`

* `@ MGMT Event: Device Disconnected`

* `< HCI Command: Set Event Mask`

And this only occurs in the hang trace:

* `@ MGMT Command: Confirm Name`

Have you guys tried selecting the kernel mode HOGP instead?

https://github.com/bluez/bluez/blob/master/profiles/input/input.conf#L14

Uncomment it and set to false restart bluetoothd:

UserspaceHID=false

fledermaus commented 3 months ago

We have not - I'll try it shortly, thanks for the hint.

jpwhiting commented 3 months ago

Tried that. I added UserspaceHID=false to /etc/bluetooth/input.conf. Rebooted the deck. Then hit the problem the first time I connected the steam controller to the deck.

bluetoothctl info <controller's current id> shows it as Connected, the steam settings shows it as connected, but it's not giving any input. A quick sdl test that does SDL_hid_get_feature_report gets -1 indicating it's in the error state as well.

Vudentz commented 3 months ago

Tried that. I added UserspaceHID=false to /etc/bluetooth/input.conf. Rebooted the deck. Then hit the problem the first time I connected the steam controller to the deck.

bluetoothctl info <controller's current id> shows it as Connected, the steam settings shows it as connected, but it's not giving any input. A quick sdl test that does SDL_hid_get_feature_report gets -1 indicating it's in the error state as well.

Ok, this is sort of high level though, does evtest should something when you press? Perhaps there is is something with the report ID again, but then it has nothing to do with uHID but something else then we have to bissect it to find out where it is.

Vudentz commented 3 months ago

The only thing that catch my eyes was:

Jul 25 21:28:21 oleddeck2 steamos-manager[607]: 2024-07-26T03:28:21.507790Z DEBUG steamos_manager::ds_inhibit: Checking if hidraw8 can be inhibited
Jul 25 21:28:21 oleddeck2 steamos-manager[607]: 2024-07-26T03:28:21.508075Z DEBUG steamos_manager::ds_inhibit: Not a PlayStation controller

Not really sure why it is trying to inhibit, also this indicates that hidraw driver is in use, not a dedicated driver.

jpwhiting commented 3 months ago

sudo evtest No device specified, trying to scan all of /dev/input/event* Available devices: /dev/input/event0: Power Button /dev/input/event1: Lid Switch /dev/input/event10: FTS3528:00 2808:1015 UNKNOWN /dev/input/event11: Valve Software Steam Controller /dev/input/event12: AT Translated Set 2 keyboard /dev/input/event13: PC Speaker /dev/input/event14: sof-nau8821-max Headset Jack /dev/input/event15: HD-Audio Generic HDMI/DP,pcm=7 /dev/input/event16: HD-Audio Generic HDMI/DP,pcm=8 /dev/input/event17: HD-Audio Generic HDMI/DP,pcm=9 /dev/input/event18: Valve Software Steam Controller /dev/input/event19: Microsoft X-Box 360 pad 0 /dev/input/event2: Power Button /dev/input/event20: Logitech M570 /dev/input/event21: SteamController Mouse /dev/input/event22: SteamController Keyboard /dev/input/event3: FTS3528:00 2808:1015 /dev/input/event4: HD-Audio Generic HDMI/DP,pcm=3 /dev/input/event5: SEMICO USB Gaming Keyboard /dev/input/event6: SEMICO USB Gaming Keyboard Consumer Control /dev/input/event7: SEMICO USB Gaming Keyboard System Control /dev/input/event8: SEMICO USB Gaming Keyboard Keyboard /dev/input/event9: Video Bus Select the device event number [0-22]: 21 Input driver version is 1.0.1 Input device ID: bus 0x5 vendor 0x28de product 0x1106 version 0x1 Input device name: "SteamController Mouse" Supported events: Event type 0 (EV_SYN) Event type 1 (EV_KEY) Event code 272 (BTN_LEFT) Event code 273 (BTN_RIGHT) Event code 274 (BTN_MIDDLE) Event code 275 (BTN_SIDE) Event code 276 (BTN_EXTRA) Event type 2 (EV_REL) Event code 0 (REL_X) Event code 1 (REL_Y) Event code 8 (REL_WHEEL) Event code 11 (REL_WHEEL_HI_RES) Event type 4 (EV_MSC) Event code 4 (MSC_SCAN) Properties: Testing ... (interrupt to exit)

Yeah, evtest gives nothing when it's in this state.

The inhibit stuff is just a service checking if the controllers are ps5 controllers to inhibit their mouse mode if so (while steam is running) to not do that so steam can do other things instead with the ps5 controller touchpad.

jpwhiting commented 3 months ago

Rebooting to compare to working state (once I get it back to working state)

Vudentz commented 3 months ago

@jpwhiting btw have you tried with latest master? There is the following fix: 5ebaeab4164f80539904b9a520d9b7a8307e06e2 that has not been released yet.

jpwhiting commented 3 months ago

I tried with master a couple of weeks ago. looking.

Oh, yes, we have tried with that change. We added it to our 5.76 package iirc. That helped, but didn't solve the problem unfortunately.

fledermaus commented 3 months ago

Was about to say. I get no evtest events when it's in this state. Behaved the same with both user and kernel space hid handling. Although I don't consistently get events from the built in controller, presumably because steam already grabbed it?

jpwhiting commented 3 months ago

Right, installed bluez 5.66 to get back to working state. And sudo evtest gives nothing for this device while it's giving input to steam fine... So that doesn't seem to be a good test, or I'm trying the wrong device, or something. When the steam controller is not turned on I don't have /dev/input/event21 and 22, so the controller must be one of those, but I get nothing for evtest from either one.

jpwhiting commented 3 months ago

Yeah, steam probably is consuming the events I guess...

fledermaus commented 3 months ago

IIRC only one process can get events at a time so if steam is grabbing the device you get nothing.

fledermaus commented 3 months ago

Managed a much faster repro - controller "died" within a few seconds of connecting:

bluez-steam-controller-debug-2.tar.gz

It is worth noting that once this had happened:

jpwhiting commented 3 months ago

One more thing I just tried was using 5.77 with the input.conf changed as suggested earlier to UserspaceHID=false and also 247ae8524888268bb075ff90a3d77a9b4449d08f. reverted. After a few suspend/resume cycles I hit the bug again. Here's the btsnoop I got from btmon and the journal from this boot.

577recreate.tar.gz

Vudentz commented 3 months ago

One more thing I just tried was using 5.77 with the input.conf changed as suggested earlier to UserspaceHID=false and also 247ae85. reverted. After a few suspend/resume cycles I hit the bug again. Here's the btsnoop I got from btmon and the journal from this boot.

577recreate.tar.gz

Hmm, so it is not 100% reproducible? How about 5.66 had you done the same same testing with that?

fledermaus commented 3 months ago

We've never been able to repro this with 5.66. We discovered it after we bumped our shipped version to 5.76, and then a lot of bisecting and testing led to the conclusions above.

fledermaus commented 3 months ago

Also, it's not always immediate but usually happens within 10-20 minutes, if we're unlucky an hour or so, and on one occasion a day and a half of testing was required (but usually an hour, tops).

Vudentz commented 3 months ago

@fledermaus hmm, that is weird since you are saying even if you do disable uHID it still behave the same even though it would be acting like 5.66, so perhaps something else is at play. Btw, is this on the same kernel version? Also what is the model this problem is reproducible, perhaps I can attempt to acquire one for myself.

fledermaus commented 3 months ago

We're seeing this on the Steam Deck OLED model (I think we see it on the LCD model too? Will have to check) Controller is the Steam Controller with the BLE firmware update.

Kernel is a 6.5 based one (the changes are to do with the APU etc on the Deck, don't think any bluez related patches are carried).

Controllers may be hard to find but let me see if I can get one for you to test with.

fledermaus commented 3 months ago

And yes, everything about this bug has been weird :/

Vudentz commented 3 months ago

And yes, everything about this bug has been weird :/

I have a steam deck btw, LCD version, but I don't have a controller, it this the one we are talking about:

https://www.amazon.com/Steam-Controller-SteamOS/dp/B016KBVBCS?th=1

It is a bit on the expensive side, PS5 is quite a lot cheaper, but perhaps I can get a used one if that works.

fledermaus commented 3 months ago

Yeah, I'm trying to scare one up for you. Might take a day or so.

fledermaus commented 3 months ago

We only see this bug with the steam controller, it took me quite a while to get one to test with.

fledermaus commented 3 months ago

@Vudentz if you let me (vivek AT collabora.com) know where to ship one I can get one sent to you.

Vudentz commented 3 months ago

@Vudentz if you let me (vivek AT collabora.com) know where to ship one I can get one sent to you.

Hmm, we might take this off the issues then, can we do this via slack? https://bluezorg.slack.com/join/shared_invite/zt-opurnyz7-QbHRp5mxxezDcQSQrHFybw#/shared-invite/email

RodoMa92 commented 3 months ago

Yeah, the bug is also present on LCD, can personally confirm.

Vudentz commented 3 months ago

@RodoMa92 @fledermaus what is the type of the device:

type = bt_uhid_icon_to_type(btd_device_get_icon(dev->device));

static inline uint8_t bt_uhid_icon_to_type(const char *icon)
{
    if (!icon)
        return BT_UHID_NONE;

    if (!strcmp(icon, "input-keyboard"))
        return BT_UHID_KEYBOARD;
    else if (!strcmp(icon, "input-mouse"))
        return BT_UHID_MOUSE;
    else if (!strcmp(icon, "input-gaming"))
        return BT_UHID_GAMING;
    else if (!strcmp(icon, "input-tablet"))
        return BT_UHID_TABLET;
    else
        return BT_UHID_NONE;
}

That is important since we have a special logic for keyboards:

    /* Force destroy for non-keyboard devices - keyboards are not destroyed
     * on disconnect since they can glitch on reconnection losing
     * keypresses.
     */
    if (!force && uhid->type != BT_UHID_KEYBOARD)
        force = true;

I would have assumed it would be input-gaming/BT_UHID_GAMING but perhaps that is not the case.

jpwhiting commented 3 months ago

According to bluez 5.66 bluetoothctl (I think it's the same with 5.76 also iirc) it's input-mouse:

bluetoothctl devices
Device F6:C9:D3:D4:03:48 SteamController
bluetoothctl info F6:C9:D3:D4:03:48
Device F6:C9:D3:D4:03:48 (random)
    Name: SteamController
    Alias: SteamController
    Appearance: 0x03c2
    Icon: input-mouse
    Paired: yes
    Bonded: yes
    Trusted: no
    Blocked: no
    Connected: yes
    WakeAllowed: yes
    LegacyPairing: no
    UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
    UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
    UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
    UUID: Human Interface Device    (00001812-0000-1000-8000-00805f9b34fb)
    UUID: Vendor specific           (100f6c32-1735-4313-b402-38567131e5f3)
    Modalias: usb:v28DEp1106d0001

I believe it also presents as a keyboard in some cases, maybe on first connect. for Enter and Escape keys to be sent while it's not yet set itself up by talking to steam as a controller yet.

Vudentz commented 3 months ago

According to bluez 5.66 bluetoothctl (I think it's the same with 5.76 also iirc) it's input-mouse:

bluetoothctl devices
Device F6:C9:D3:D4:03:48 SteamController
bluetoothctl info F6:C9:D3:D4:03:48
Device F6:C9:D3:D4:03:48 (random)
  Name: SteamController
  Alias: SteamController
  Appearance: 0x03c2
  Icon: input-mouse
  Paired: yes
  Bonded: yes
  Trusted: no
  Blocked: no
  Connected: yes
  WakeAllowed: yes
  LegacyPairing: no
  UUID: Generic Access Profile    (00001800-0000-1000-8000-00805f9b34fb)
  UUID: Generic Attribute Profile (00001801-0000-1000-8000-00805f9b34fb)
  UUID: Device Information        (0000180a-0000-1000-8000-00805f9b34fb)
  UUID: Human Interface Device    (00001812-0000-1000-8000-00805f9b34fb)
  UUID: Vendor specific           (100f6c32-1735-4313-b402-38567131e5f3)
  Modalias: usb:v28DEp1106d0001

I believe it also presents as a keyboard in some cases, maybe on first connect. for Enter and Escape keys to be sent while it's not yet set itself up by talking to steam as a controller yet.

Does the input node stay alive while disconnected?

jpwhiting commented 3 months ago

bluetoothctl info shows the same result except Connected: changes from yes to no when I've got the steam controller turned off. Is that what you mean?

Also, I'm currently running bluez 5.66 which doesn't have the bug. If needed I can try again with 5.76 or so.

Vudentz commented 3 months ago

bluetoothctl info shows the same result except Connected: changes from yes to no when I've got the steam controller turned off. Is that what you mean?

Also, I'm currently running bluez 5.66 which doesn't have the bug. If needed I can try again with 5.76 or so.

Nope, I mean the input node which you can list with evtest for example, if it remains available while disconnected?

jpwhiting commented 3 months ago

bluetoothctl info shows the same result except Connected: changes from yes to no when I've got the steam controller turned off. Is that what you mean? Also, I'm currently running bluez 5.66 which doesn't have the bug. If needed I can try again with 5.76 or so.

Nope, I mean the input node which you can list with evtest for example, if it remains available while disconnected?

No, evtest doesn't show any item for the disconnected steam controller currently.

Vudentz commented 3 months ago

bluetoothctl info shows the same result except Connected: changes from yes to no when I've got the steam controller turned off. Is that what you mean? Also, I'm currently running bluez 5.66 which doesn't have the bug. If needed I can try again with 5.76 or so.

Nope, I mean the input node which you can list with evtest for example, if it remains available while disconnected?

No, evtest doesn't show any item for the disconnected steam controller currently.

Ok, then at least this is working as intended, I just posted some tentative fixes:

https://patchwork.kernel.org/project/bluetooth/list/?series=878946

I just tested with the mouse I have, which did work properly even without these changes, but perhaps there is something related to input queue not being cleanup properly or something.

jpwhiting commented 3 months ago

bluetoothctl info shows the same result except Connected: changes from yes to no when I've got the steam controller turned off. Is that what you mean? Also, I'm currently running bluez 5.66 which doesn't have the bug. If needed I can try again with 5.76 or so.

Nope, I mean the input node which you can list with evtest for example, if it remains available while disconnected?

No, evtest doesn't show any item for the disconnected steam controller currently.

Ok, then at least this is working as intended, I just posted some tentative fixes:

https://patchwork.kernel.org/project/bluetooth/list/?series=878946

I just tested with the mouse I have, which did work properly even without these changes, but perhaps there is something related to input queue not being cleanup properly or something.

TLDR; This doesn't seem to fix the problem.

I just built 5.77 with the holo patches on top and the 2 patches from this series. I connected the steam controller after rebooting and immediately got the problem. bluetoothctl devices shows the device, but bluetoothctl info give this now:

bluetoothctl info F6:C3:D3:D4:03:48
Device F6:C3:D3:D4:03:48 not available
DeviceSet F6:C3:D3:D4:03:48 not available

I was running bluetoothd with -d argument. Here's the journal in case that helps

577withpatches.txt