Bug 1874082 - bluetooth mouse does not autoconnect after sleep
Summary: bluetooth mouse does not autoconnect after sleep
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: bluez
Version: 32
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Don Zickus
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: AcceptedFreezeException RejectedBlock...
Depends On:
Blocks: F33FinalFreezeException
TreeView+ depends on / blocked
 
Reported: 2020-08-31 14:09 UTC by J. Bruce Fields
Modified: 2020-11-29 20:45 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-11-29 20:45:35 UTC
Type: Bug


Attachments (Terms of Use)
journal (490.43 KB, text/plain)
2020-10-14 13:07 UTC, Kamil Páral
no flags Details

Description J. Bruce Fields 2020-08-31 14:09:42 UTC
After my laptop sleeps, my bluetooth mouse doesn't work until I open the gnome bluetooth settings dialog.

In more detail: laptop is a ThinkPad X1 Carbon 6th generation.  Mouse is a Logitech M720 Triathlon.  If I put the laptop to sleep, then wake it up, the bluetooth mouse no longer works.  I've tried waiting a minute or so.  However if I then open the gnome bluetooth settings dialog, the mouse connects in a few seconds.

Kernel 5.7.17-200.fc32.x86_64
bluez bluez-5.54-1.fc32.x86_64

Comment 1 Fedora Update System 2020-09-07 15:09:56 UTC
FEDORA-2020-00bf5ac290 has been submitted as an update to Fedora 32. https://bodhi.fedoraproject.org/updates/FEDORA-2020-00bf5ac290

Comment 2 Fedora Update System 2020-09-07 17:21:49 UTC
FEDORA-2020-00bf5ac290 has been pushed to the Fedora 32 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-00bf5ac290`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-00bf5ac290

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 3 J. Bruce Fields 2020-09-08 14:36:56 UTC
(In reply to Fedora Update System from comment #2)
> FEDORA-2020-00bf5ac290 has been pushed to the Fedora 32 testing repository.
> In short time you'll be able to install the update with the following
> command:
> `sudo dnf upgrade --enablerepo=updates-testing
> --advisory=FEDORA-2020-00bf5ac290`

I successfully ran that command, and bluez-5.55-1.fc32.x86_64 is now installed.  I also rebooted just for good measure.

Behavior is still the same as described in comment 0.

Comment 4 Fedora Update System 2020-09-15 16:17:09 UTC
FEDORA-2020-00bf5ac290 has been pushed to the Fedora 32 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 5 J. Bruce Fields 2020-09-15 20:46:17 UTC
Still not working, as in comment 3.

My workaround for now is

cat <<EOF >/usr/lib/systemd/system-sleep/bluetooth-hack 
#!/bin/bash

if [ "${1}" == "post" ]; then
	bluetoothctl connect E5:55:D7:17:18:57
fi
EOF
chmod a+x EOF

(where the device address to connect to was found with "bluetoothctl devices").

Comment 6 Kamil Páral 2020-10-14 12:58:11 UTC
I can reproduce this 100% (I have exactly the same mouse, not sure if that's an accident or a symptom). In F33, every time I resume the system, I have to either restart the bluetooth service (using multimedia keys) or go to gnome-control-center->Bluetooth->select my mouse->Connect.

bluez-5.55-1.fc33.x86_64

Comment 7 Kamil Páral 2020-10-14 13:07:27 UTC
Created attachment 1721468 [details]
journal

Here's system journal from my session.

I booted the system, my bluetooth mouse worked just fine right after logging in. At 14:39:04 I suspended the system, immediately resumed. My bluetooth mouse didn't work. I waited 10 minutes whether it reconnects, it didn't. At 14:49:34 I searched for "Bluetooth" in GNOME overlay, started GNOME Settings on the Bluetooth tab,then navigated (using keyboard) onto my mouse device and toggled Connection to ON. My mouse started to work. The log shows:

Oct 14 14:49:36 phoenix systemd[1799]: Starting Bluetooth OBEX service...
Oct 14 14:49:36 phoenix obexd[3477]: OBEX daemon 5.55
Oct 14 14:49:36 phoenix systemd[1799]: Started Bluetooth OBEX service.
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:49:47 phoenix kernel: input: M720 Triathlon Keyboard as /devices/virtual/misc/uhid/0005:046D:B015.0004/input/input25
Oct 14 14:49:47 phoenix kernel: input: M720 Triathlon Mouse as /devices/virtual/misc/uhid/0005:046D:B015.0004/input/input26
Oct 14 14:49:47 phoenix kernel: hid-generic 0005:046D:B015.0004: input,hidraw2: BLUETOOTH HID v0.07 Keyboard [M720 Triathlon] on 14:4f:8a:a0:fc:11
...


At 14:50:10 I suspended again, immediately resumed. My mouse didn't work once again. Waited a short while, then stopped the bluetooth service using multimedia keys at 14:50:58. I see:

Oct 14 14:50:58 phoenix kernel: Bluetooth: hci0: command 0x0c03 tx timeout
Oct 14 14:50:59 phoenix kernel: usb 1-7: USB disconnect, device number 3
Oct 14 14:50:59 phoenix kernel: Bluetooth: hci0: HCI reset during shutdown failed
Oct 14 14:50:59 phoenix bluetoothd[947]: Endpoint unregistered: sender=:1.93 path=/MediaEndpoint/A2DPSink/sbc
Oct 14 14:50:59 phoenix bluetoothd[947]: Endpoint unregistered: sender=:1.93 path=/MediaEndpoint/A2DPSource/sbc
Oct 14 14:50:59 phoenix systemd[1799]: Stopped target Bluetooth.
Oct 14 14:50:59 phoenix systemd[1]: Stopped target Bluetooth.


I started Bluetooth service again using multimedia keys at 14:51:09 and my mouse started working again:

Oct 14 14:51:09 phoenix systemd[1]: Starting Load/Save RF Kill Switch Status...
Oct 14 14:51:09 phoenix systemd[1]: Started Load/Save RF Kill Switch Status.
Oct 14 14:51:09 phoenix audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-rfkill comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 14 14:51:09 phoenix kernel: usb 1-7: new full-speed USB device number 5 using xhci_hcd
Oct 14 14:51:09 phoenix kernel: usb 1-7: New USB device found, idVendor=8087, idProduct=0a2b, bcdDevice= 0.10
Oct 14 14:51:09 phoenix kernel: usb 1-7: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Bootloader revision 0.0 build 26 week 38 2015
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Device revision is 16
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Secure boot is enabled
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: OTP lock is enabled
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: API lock is enabled
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Debug lock is disabled
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Minimum firmware build 1 week 10 2014
Oct 14 14:51:09 phoenix kernel: Bluetooth: hci0: Found device firmware: intel/ibt-12-16.sfi
Oct 14 14:51:09 phoenix systemd[1]: Reached target Bluetooth.
Oct 14 14:51:09 phoenix systemd[1799]: Reached target Bluetooth.
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Waiting for firmware download to complete
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Firmware loaded in 1896213 usecs
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Waiting for device to boot
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Device booted in 11850 usecs
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Found Intel DDC parameters: intel/ibt-12-16.ddc
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Applying Intel DDC parameters completed
Oct 14 14:51:11 phoenix kernel: Bluetooth: hci0: Firmware revision 0.1 build 50 week 12 2019
Oct 14 14:51:11 phoenix bluetoothd[947]: Endpoint registered: sender=:1.93 path=/MediaEndpoint/A2DPSink/sbc
Oct 14 14:51:11 phoenix bluetoothd[947]: Endpoint registered: sender=:1.93 path=/MediaEndpoint/A2DPSource/sbc
Oct 14 14:51:13 phoenix kernel: Bluetooth: hci0: link tx timeout
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix bluetoothd[947]: profiles/input/hog-lib.c:report_value_cb() bt_uhid_send: Invalid argument (22)
Oct 14 14:51:14 phoenix kernel: input: M720 Triathlon Keyboard as /devices/virtual/misc/uhid/0005:046D:B015.0005/input/input28
Oct 14 14:51:14 phoenix kernel: input: M720 Triathlon Mouse as /devices/virtual/misc/uhid/0005:046D:B015.0005/input/input29
Oct 14 14:51:14 phoenix kernel: hid-generic 0005:046D:B015.0005: input,hidraw2: BLUETOOTH HID v0.07 Keyboard [M720 Triathlon] on 14:4f:8a:a0:fc:11

Comment 8 Kamil Páral 2020-10-14 13:10:55 UTC
While this might have been introduced as a regression in some F32 update according to comment 0, I propose it as a blocker for F33. A working bluetooth mouse is very probably an expected basic functionality of a graphical desktop. There is a workaround (restart the bluetooth service or navigate into GNOME Settings and manually connect your mouse again), but doing that after each system resume is tiresome and not everybody will be able to do it without a mouse cursor (unless you're on a laptop and have touchpad available, of course).

Please note that more testing is necessary to investigate whether this only affects this particular mouse (Logitech M720) or any bluetooth mouse on the market.

Comment 9 Adam Williamson 2020-10-14 16:09:38 UTC
Does turning the mouse off and on again make it work? That seems like a more convenient workaround, if it does.

Comment 10 Kamil Páral 2020-10-14 16:20:20 UTC
(In reply to Adam Williamson from comment #9)
> Does turning the mouse off and on again make it work? That seems like a more
> convenient workaround, if it does.

According to my testing, no it doesn't. This feels like a server problem to me, not a client problem.

Also, I can say that just opening GNOME Settings -> Bluetooth and waiting ~10 seconds is enough to make the mouse reconnect, I don't need to select it in the list and toggle the connection manually (that works immediately without the delay, though).

Comment 11 Adam Williamson 2020-10-14 16:45:10 UTC
pbrobinson seems to have been taking care of bluez lately, so adding him to CC.

I saw a couple of interesting things in upstream kernel and bluez git, but the timing is off, those are from September while the bug was initially reported in August.

Comment 12 Peter Robinson 2020-10-14 17:10:05 UTC
> In more detail: laptop is a ThinkPad X1 Carbon 6th generation.  Mouse is a
> Logitech M720 Triathlon.  If I put the laptop to sleep, then wake it up, the
> bluetooth mouse no longer works.  I've tried waiting a minute or so. 
> However if I then open the gnome bluetooth settings dialog, the mouse
> connects in a few seconds.
> 
> Kernel 5.7.17-200.fc32.x86_64
> bluez bluez-5.54-1.fc32.x86_64

What about linux-firmware? This could also be due to a change in the firmware of the hci controller. What bluetooth controller is in the devices that are having issues?

Comment 13 Richard Ryniker 2020-10-14 18:03:55 UTC
I tried a Logi (Logitech) K600 Bluetooth keyboard-with-touchpad and it reconnected without problem after suspend/resume to a Minisforum N40 ultra-compact PC that runs F33.

The Bluetooth keyboard was not able to wake the computer from the suspend state.  I had to use a USB-connected keyboard or mouse to do that, or press the machine's power button.

Comment 14 J. Bruce Fields 2020-10-14 19:50:30 UTC
(In reply to Peter Robinson from comment #12)
> What about linux-firmware?

linux-firmware-20200918-112.fc32.noarch

> This could also be due to a change in the
> firmware of the hci controller. What bluetooth controller is in the devices
> that are having issues?

lsusb says:

Bus 001 Device 004: ID 8087:0a2b Intel Corp. Bluetooth wireless interface

Comment 15 J. Bruce Fields 2020-10-14 19:52:41 UTC
By the way, I only bought this mouse in August, so for me this wasn't a regression.

Comment 16 Kamil Páral 2020-10-15 07:27:55 UTC
(In reply to Peter Robinson from comment #12)
> What about linux-firmware? This could also be due to a change in the
> firmware of the hci controller. What bluetooth controller is in the devices
> that are having issues?

kernel-5.8.14-300.fc33.x86_64
linux-firmware-20200918-112.fc33.noarch
bluez-5.55-1.fc33.x86_64

Bus 001 Device 005: ID 8087:0a2b Intel Corp. Bluetooth wireless interface

Thinkpad T480s

Comment 17 Kamil Páral 2020-10-15 07:35:06 UTC
There is a request for more testing and feedback available here:
https://lists.fedoraproject.org/archives/list/test@lists.fedoraproject.org/thread/DZ2U6X7Q6VTHXXMKUZWOWFOEJ7WYPGAG/

Comment 18 sumantro 2020-10-15 13:22:37 UTC
I have a Logitech M185 mouse and Logitech K270 Keyboard. Both connect with a single reciever and I am not facing any issues. I have been using them since about 8 weeks

Comment 19 sumantro 2020-10-15 13:27:51 UTC
kernel-core-5.8.12-300.fc33.x86_64
linux-firmware-20200918-112.fc33.noarch
bluez-5.55-1.fc33.x86_64

Comment 20 Kamil Páral 2020-10-15 13:52:41 UTC
Sumantro, if you have a USB dongle together with the mouse and/or keyboard, then it is not a Bluetooth connection. From the system point of view, it is a standard USB connection.

Comment 21 Adam Williamson 2020-10-15 19:41:33 UTC
We have +3 FE votes in https://pagure.io/fedora-qa/blocker-review/issue/171 , accepted as an FE. (blocker vote is +1 / -3 ATM, so still open).

Comment 22 Jonathan Haas 2020-10-17 07:34:03 UTC
If you need another tester, my Microsoft Sculpt Comfort Mouse ( https://www.microsoft.com/accessories/en-us/products/mice/sculpt-comfort-mouse/h3s-00003 ) also stops working after sleep (closing the lid or hitting the power button), when connected to the internal Bluetooth adapter of my Dell XPS 9350 with latest Fedora 33 update.

Comment 23 Ondřej Budai 2020-10-17 19:04:47 UTC
I have the same issue with Thinkpad T480s and Logitech M590. The issue started when I once updated Fedora 32. Sadly, I cannot recall when it was. :(

Comment 24 Adam Williamson 2020-10-19 15:45:35 UTC
We have a total of -5 (-6, +1) votes for blocker status on the ticket - https://pagure.io/fedora-qa/blocker-review/issue/171 - so rejecting. This is broadly due to the feedback here and on test@ suggesting this bug affects only certain hardware (bluetooth devices and/or controllers) and is not new to F33.

Comment 25 Ondřej Budai 2020-11-23 08:03:09 UTC
Thinkpad T480s and Logitech M590 on F33: This issue seemed to disappear for me. I have no idea which update fixed it. Does anyone still has this problem on a fully upgraded F33?

Comment 26 Peter Robinson 2020-11-23 08:04:49 UTC
(In reply to obudai from comment #25)
> Thinkpad T480s and Logitech M590 on F33: This issue seemed to disappear for
> me. I have no idea which update fixed it. Does anyone still has this problem
> on a fully upgraded F33?

You don't mention what bluebooth HCI device the T480s has. There's been new major kernels and firmware of late.

Comment 27 Ondřej Budai 2020-11-23 08:08:21 UTC
Ah, sorry, here it is: Intel Corporation Dual Band Wireless-AC 8265

Comment 28 J. Bruce Fields 2020-11-23 22:28:47 UTC
I removed the workaround from comment 5, rebooted, and suspended and resumed and tried the mouse.  It works OK now.  I could reliably reproduce the problem on every suspend before.  So, maybe it's fixed.

I'm on Fedora 33.
kernel 5.9.9-200.fc33.x86_64
bluez-5.55-1.fc33.x86_64
linux-firmware-20201118-115.fc33.noarch.

Comment 29 Marc Ponschab 2020-11-29 19:47:43 UTC
I can confirm this, current Fedora 33 connects reliably with M590 at resume (XPS 9550 with Intel 7265). Before it also needed a systemd post-sleep hook.


Note You need to log in before you can comment on or make changes to this bug.