Arch Linux

LordChaos73

Member

From: .nl

Registered: 2008-11-11

Posts: 183

[SOLVED] Bluetooth connection reset

Hi,

Every ten minutes or so, my bluetooth mouse stops working entirely and up until now I'm not able to figure out why. This is what I see in the logs:

jan 10 09:27:40 x1carbon kernel: usb 2-7: reset full-speed USB device number 7 using xhci_hcd

The only way to recover from this after powering down the mouse, is to execute the following steps:

sudo rfkill block 0

sudo rfkill unblock 0

jan 10 09:28:46 x1carbon kernel: usb 2-7: USB disconnect, device number 7
jan 10 09:28:46 x1carbon rfkill[3402]: block set for id 0
jan 10 09:28:46 x1carbon sudo[3401]: pam_unix(sudo:session): session closed for user root
jan 10 09:28:46 x1carbon systemd[1]: Starting Load/Save RF Kill Switch Status...
jan 10 09:28:46 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) config/udev: removing device ThinkPad Bluetooth Laser Mouse
jan 10 09:28:46 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) Option "fd" "64"
jan 10 09:28:46 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) device removed
jan 10 09:28:46 x1carbon systemd[1]: Started Load/Save RF Kill Switch Status.
jan 10 09:28:46 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) UnloadModule: "libinput"
jan 10 09:28:46 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) systemd-logind: releasing fd for 13:86
jan 10 09:28:46 x1carbon upowerd[809]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0/bluetooth/hci0/hci0:256/0005:17EF:6038.0004
jan 10 09:28:46 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.266 path=/MediaEndpoint/A2DPSource
jan 10 09:28:46 x1carbon systemd-rfkill[3404]: Failed to open device rfkill4: No such device
jan 10 09:28:46 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.132 path=/MediaEndpoint/A2DPSource
jan 10 09:28:46 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.132 path=/MediaEndpoint/A2DPSink
jan 10 09:28:46 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.266 path=/MediaEndpoint/A2DPSink
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.266" (uid=1000 pid=1155 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoi
jan 10 09:28:46 x1carbon NetworkManager[500]: <info>  [1515572926.2318] bluez5: NAP: removed interface 28:B2:BD:87:43:FC
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.266" (uid=1000 pid=1155 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoi
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.266" (uid=1000 pid=1155 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoi
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.266" (uid=1000 pid=1155 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoi
jan 10 09:28:46 x1carbon systemd[1]: bluetooth.target: Unit not needed anymore. Stopping.
jan 10 09:28:46 x1carbon systemd[1]: Stopped target Bluetooth.
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.132" (uid=120 pid=840 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoint
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.132" (uid=120 pid=840 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoint
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.132" (uid=120 pid=840 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoint
jan 10 09:28:46 x1carbon dbus-daemon[489]: [system] Rejected send message, 1 matched rules; type="error", sender=":1.132" (uid=120 pid=840 comm="/usr/bin/pulseaudio --daemonize=no ") interface="(unset)" member="(unset)" error name="org.bluez.MediaEndpoint
jan 10 09:28:46 x1carbon upowerd[809]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.1
jan 10 09:28:46 x1carbon upowerd[809]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0
jan 10 09:28:46 x1carbon upowerd[809]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7
jan 10 09:28:50 x1carbon sudo[3427]:    ericd : TTY=pts/0 ; PWD=/home/ericd ; USER=root ; COMMAND=/usr/bin/rfkill list
jan 10 09:28:50 x1carbon sudo[3427]: pam_unix(sudo:session): session opened for user root by (uid=0)
jan 10 09:28:50 x1carbon sudo[3427]: pam_unix(sudo:session): session closed for user root
jan 10 09:29:02 x1carbon sudo[3436]:    ericd : TTY=pts/0 ; PWD=/home/ericd ; USER=root ; COMMAND=/usr/bin/rfkill unblock 0
jan 10 09:29:02 x1carbon sudo[3436]: pam_unix(sudo:session): session opened for user root by (uid=0)
jan 10 09:29:02 x1carbon rfkill[3437]: unblock set for id 0
jan 10 09:29:02 x1carbon sudo[3436]: pam_unix(sudo:session): session closed for user root
jan 10 09:29:02 x1carbon systemd[1]: Starting Load/Save RF Kill Switch Status...
jan 10 09:29:02 x1carbon systemd[1]: Started Load/Save RF Kill Switch Status.
jan 10 09:29:02 x1carbon kernel: usb 2-7: new full-speed USB device number 8 using xhci_hcd
jan 10 09:29:02 x1carbon kernel: Bluetooth: hci0: read Intel version: 370710018002030d00
jan 10 09:29:02 x1carbon kernel: Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq
jan 10 09:29:02 x1carbon kernel: Bluetooth: hci0: Intel Bluetooth firmware patch completed and activated
jan 10 09:29:02 x1carbon bluetoothd[762]: RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)
jan 10 09:29:02 x1carbon bluetoothd[762]: RFCOMM server failed for :1.266/Profile/HSPHSProfile/00001108-0000-1000-8000-00805f9b34fb: rfcomm_bind: Address already in use (98)
jan 10 09:29:02 x1carbon pulseaudio[1155]: E: [pulseaudio] bluez5-util.c: Device /org/bluez/hci0/dev_F0_65_DD_95_AB_31 points to a nonexistent adapter /org/bluez/hci0.
jan 10 09:29:02 x1carbon pulseaudio[840]: E: [pulseaudio] bluez5-util.c: Device /org/bluez/hci0/dev_F0_65_DD_95_AB_31 points to a nonexistent adapter /org/bluez/hci0.
jan 10 09:29:02 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.266 path=/MediaEndpoint/A2DPSource
jan 10 09:29:02 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.266 path=/MediaEndpoint/A2DPSink
jan 10 09:29:02 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.132 path=/MediaEndpoint/A2DPSource
jan 10 09:29:02 x1carbon NetworkManager[500]: <info>  [1515572942.9020] bluez5: NAP: added interface 28:B2:BD:87:43:FC
jan 10 09:29:02 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.132 path=/MediaEndpoint/A2DPSink
jan 10 09:29:03 x1carbon systemd[1]: Reached target Bluetooth.
jan 10 09:29:03 x1carbon upowerd[809]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.1
jan 10 09:29:03 x1carbon upowerd[809]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0
jan 10 09:29:03 x1carbon upowerd[809]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7
jan 10 09:29:11 x1carbon kernel: hid-generic 0005:17EF:6038.0005: unknown main item tag 0x0
jan 10 09:29:11 x1carbon kernel: input: ThinkPad Bluetooth Laser Mouse as /devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0/bluetooth/hci0/hci0:256/0005:17EF:6038.0005/input/input25
jan 10 09:29:11 x1carbon kernel: hid-generic 0005:17EF:6038.0005: input,hidraw2: BLUETOOTH HID v2.00 Mouse [ThinkPad Bluetooth Laser Mouse] on 28:b2:bd:87:43:fc
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) config/udev: Adding input device ThinkPad Bluetooth Laser Mouse (/dev/input/mouse2)
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) No input driver specified, ignoring this device.
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) This device may have been added with another device file.
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) config/udev: Adding input device ThinkPad Bluetooth Laser Mouse (/dev/input/mouse2)
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) No input driver specified, ignoring this device.
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) This device may have been added with another device file.
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) config/udev: Adding input device ThinkPad Bluetooth Laser Mouse (/dev/input/event22)
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (**) ThinkPad Bluetooth Laser Mouse: Applying InputClass "evdev pointer catchall"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (**) ThinkPad Bluetooth Laser Mouse: Applying InputClass "libinput pointer catchall"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) Using input driver 'libinput' for 'ThinkPad Bluetooth Laser Mouse'
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) config/udev: Adding input device ThinkPad Bluetooth Laser Mouse (/dev/input/event22)
jan 10 09:29:11 x1carbon upowerd[809]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0/bluetooth/hci0/hci0:256/0005:17EF:6038.0005
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: Applying InputClass "evdev pointer catchall"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: Applying InputClass "libinput pointer catchall"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) Using input driver 'libinput' for 'ThinkPad Bluetooth Laser Mouse'
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) systemd-logind: got fd for /dev/input/event22 13:86 fd 22 paused 1
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[718]: (II) systemd-logind: releasing fd for 13:86
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) systemd-logind: got fd for /dev/input/event22 13:86 fd 66 paused 0
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: always reports core events
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) Option "Device" "/dev/input/event22"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) Option "_source" "server/udev"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) is tagged by udev as: Mouse
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) device is a pointer
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) device removed
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) Option "config_info" "udev:/sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0/bluetooth/hci0/hci0:256/0005:17EF:6038.0005/input/input25/event22"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) XINPUT: Adding extended input device "ThinkPad Bluetooth Laser Mouse" (type: MOUSE, id 17)
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) Option "AccelerationScheme" "none"
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: (accel) selected scheme none/0
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: (accel) acceleration factor: 2.000
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (**) ThinkPad Bluetooth Laser Mouse: (accel) acceleration threshold: 4
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) is tagged by udev as: Mouse
jan 10 09:29:11 x1carbon /usr/lib/gdm/gdm-x-session[1082]: (II) event22 - (II) ThinkPad Bluetooth Laser Mouse: (II) device is a pointer
jan 10 09:29:11 x1carbon upowerd[809]: treating change event as add on /sys/devices/pci0000:00/0000:00:14.0/usb2/2-7/2-7:1.0/bluetooth/hci0/hci0:256/0005:17EF:6038.0005/power_supply/hid-f0:65:dd:95:ab:31-battery

Here's the list of devices when everything works:

x1carbon :: ~ » rfkill list
0: tpacpi_bluetooth_sw: Bluetooth
	Soft blocked: no
	Hard blocked: no
1: phy0: Wireless LAN
	Soft blocked: no
	Hard blocked: no
6: hci0: Bluetooth
	Soft blocked: no
	Hard blocked: no

My setup consists of a Thinkpad X1 Carbon laptop attached to an external monitor.

x1carbon :: ~ » systemctl status bluetooth 
● bluetooth.service - Bluetooth service
   Loaded: loaded (/usr/lib/systemd/system/bluetooth.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2018-01-10 08:42:31 CET; 53min ago
     Docs: man:bluetoothd(8)
 Main PID: 762 (bluetoothd)
   Status: "Running"
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/bluetooth.service
           └─762 /usr/lib/bluetooth/bluetoothd

jan 10 09:31:31 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.266 path=/MediaEndpoint/A2DPSource
jan 10 09:31:31 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.266 path=/MediaEndpoint/A2DPSink
jan 10 09:31:31 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.132 path=/MediaEndpoint/A2DPSource
jan 10 09:31:31 x1carbon bluetoothd[762]: Endpoint unregistered: sender=:1.132 path=/MediaEndpoint/A2DPSink
jan 10 09:31:39 x1carbon bluetoothd[762]: RFCOMM server failed for Headset Voice gateway: rfcomm_bind: Address already in use (98)
jan 10 09:31:39 x1carbon bluetoothd[762]: RFCOMM server failed for :1.266/Profile/HSPHSProfile/00001108-0000-1000-8000-00805f9b34fb: rfcomm_bind: Address already in use (98)
jan 10 09:31:39 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.266 path=/MediaEndpoint/A2DPSource
jan 10 09:31:39 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.132 path=/MediaEndpoint/A2DPSource
jan 10 09:31:39 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.132 path=/MediaEndpoint/A2DPSink
jan 10 09:31:39 x1carbon bluetoothd[762]: Endpoint registered: sender=:1.266 path=/MediaEndpoint/A2DPSink

x1carbon :: ~ » uname -a
Linux x1carbon 4.14.12-1-ARCH #1 SMP PREEMPT Fri Jan 5 18:19:34 UTC 2018 x86_64 GNU/Linux

Any help would be very much appreciated.

Last edited by LordChaos73 (2018-01-16 09:34:38)

LordChaos73

Member

From: .nl

Registered: 2008-11-11

Posts: 183

Re: [SOLVED] Bluetooth connection reset

I may have solved this issue by blacklisting the USB id of the bluetooth controller in /etc/default/tlp, but only time will tell. I'll mark this topic as solved if that is truly the case.

Last edited by LordChaos73 (2018-01-16 09:35:09)

LordChaos73

Member

From: .nl

Registered: 2008-11-11

Posts: 183

Re: [SOLVED] Bluetooth connection reset

What also seems to work is enabling this setting in /etv/default/tlp:

# Bluetooth devices are excluded from USB autosuspend:
#   0=do not exclude, 1=exclude
USB_BLACKLIST_BTUSB=1

MiguelNdeCarvalho

Member

Registered: 2019-06-05

Posts: 4

Re: [SOLVED] Bluetooth connection reset

Hey,
I am getting almost the same. I have a lenovo thinkpad t440, can you help me please?
Thanks,
Miguel de Carvalho

ewaller

Administrator

From: Pasadena, CA

Registered: 2009-07-13

Posts: 19,772

Re: [SOLVED] Bluetooth connection reset

MiguelNdeCarvalho,

I am going to go ahead and close this year and a half old thread, and invite you to start a new thread you will own.   A lot has happened in the kernel in the last 19 moths.

---

Nothing is too wonderful to be true, if it be consistent with the laws of nature -- Michael Faraday
Sometimes it is the people no one can imagine anything of who do the things no one can imagine. -- Alan Turing
---
How to Ask Questions the Smart Way