Announcement

Collapse
No announcement yet.

Bluetooth headphone / speaker connectivity problems after suspend / resume

Collapse
This topic is closed.
X
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

    Bluetooth headphone / speaker connectivity problems after suspend / resume

    There are several varying connectivity problems with bluetooth headsets / speakers after suspend / resume (listed below from earth-shatteringly grave to somewhat annoying).
    • The device is completely missing from the device list
    • The device is in the device list, but I cannot connect
    • I can manually connect to the device, but get only HSP/HFF playback, not A2DP Sink
    • The device automatically connects, but still get no A2DP Sink playback
    • The device doesn't automatically reconnect


    Notes:
    • 'sudo systemctl restart bluetooth' allows connecting to device and A2DP Sink playback (sometimes I have to do the command twice)
    • Running Kubuntu 19.10, but had similar connectivity problems running Manjaro 18.04 on same Acer Spin 1 laptop (I can't say if the problems were actually the same, but I had KDE both times and I remember being annoyed)
    • Problems happen (as far as I can tell) with high CPU / memory usage, like when I have a browser with 10 bajillion tabs open
    • I documented reproduction of the problems with some information from 'sudo service bluetooth status' and the JournalD entries filtered for 'bluetooth' (see below, because I'm having trouble with attachments for some reason)
    • Troubleshot on Sony MDR-XB650BT headphones, but I had these problems also with three other devices


    So the problems aren't so bad, really, and I could feasibly make a script to fix them. Nonetheless, I would be interested in knowing whether I am on the right track with the high memory usage thing, and what to do about it. Clearly, leaving the browser open with so many tabs is a bad habit of mine. From my research into the problems, I'm not sure whether they are specific to KDE or Bluez or what; there are lots of people on diverse platforms with similar but different problems with bluetooth. I'm posting here with [solved] prefix in case other people have these problems. My questions:
    • Assuming I'm right about the high CPU / Memory usage hunch, where might I go to resolve that (unfortunately, bad habits die hard!)?
    • What other troubleshooting can I do / information should I provide here?


    Thanks in advance for your input!

    Reproduction of the problem:
    Code:
    // FRESH START
    -- Bluetooth works as expected
    
    sudo service bluetooth status
    [sudo] password for pan: 
    ● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2019-12-26 17:09:38 CET; 1min 29s ago
       Docs: man:bluetoothd(8)
    Main PID: 886 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 4432)
     Memory: 2.6M
     CGroup: /system.slice/bluetooth.service
             └─886 /usr/lib/bluetooth/bluetoothd
    
    Dec 26 17:09:37 panspin systemd[1]: Starting Bluetooth service...
    Dec 26 17:09:37 panspin bluetoothd[886]: Bluetooth daemon 5.50
    Dec 26 17:09:38 panspin systemd[1]: Started Bluetooth service.
    Dec 26 17:09:38 panspin bluetoothd[886]: Starting SDP server
    Dec 26 17:09:38 panspin bluetoothd[886]: Bluetooth management interface 1.14 initialized
    Dec 26 17:09:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:09:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:10:21 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd0: fd(37) ready
    
    // FIRST REPRODUCTION ATTEMPT
    -- Bluetooth automatically reconnects and works as expected
    
    sudo service bluetooth status
    ● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2019-12-26 17:09:38 CET; 5min ago
       Docs: man:bluetoothd(8)
    Main PID: 886 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 4432)
     Memory: 2.8M
     CGroup: /system.slice/bluetooth.service
             └─886 /usr/lib/bluetooth/bluetoothd
    
    Dec 26 17:09:38 panspin bluetoothd[886]: Bluetooth management interface 1.14 initialized
    Dec 26 17:09:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:09:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:10:21 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd0: fd(37) ready
    Dec 26 17:13:10 panspin bluetoothd[886]: Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
    Dec 26 17:13:10 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:13:10 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:13:10 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:13:10 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:13:14 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd1: fd(34) ready
    
    // FIFTH REPRODUCTION ATTEMPT
    -- Headset doesn't automatically connect, but can connect manually (might have automatically connected if I had waited longer)
    
    $ sudo service bluetooth status
    ● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2019-12-26 17:09:38 CET; 16min ago
       Docs: man:bluetoothd(8)
    Main PID: 886 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 4432)
     Memory: 2.7M
     CGroup: /system.slice/bluetooth.service
             └─886 /usr/lib/bluetooth/bluetoothd
    
    Dec 26 17:22:42 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:22:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:22:42 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:23:06 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd5: fd(37) ready
    Dec 26 17:24:27 panspin bluetoothd[886]: Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:25:41 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd6: fd(37) ready
    
    // SIXTH REPRODUCTION ATTEMPT
    -- After using opening lots of apps with heavy system load
    -- Bluetooth device in use missing from device list
    
    $ sudo service bluetooth status
    ● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2019-12-26 17:09:38 CET; 31min ago
       Docs: man:bluetoothd(8)
    Main PID: 886 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 4432)
     Memory: 1.4M
     CGroup: /system.slice/bluetooth.service
             └─886 /usr/lib/bluetooth/bluetoothd
    
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:24:27 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:25:41 panspin bluetoothd[886]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd6: fd(37) ready
    Dec 26 17:39:43 panspin bluetoothd[886]: Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
    Dec 26 17:39:43 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:39:43 panspin bluetoothd[886]: Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:39:43 panspin bluetoothd[886]: Unable to register device interface for 00:18:09:F5:BD:75
    Dec 26 17:39:46 panspin bluetoothd[886]: Loading LTKs timed out for hci0
    Dec 26 17:39:46 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:39:46 panspin bluetoothd[886]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    
    //RESTARTING BLUETOOTH (sudo systemctl restart bluetooth)
    -- Device reappears, can connect and listen to fine
    
    $ sudo service bluetooth status
    ● bluetooth.service - Bluetooth service
     Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2019-12-26 17:54:10 CET; 3min 39s ago
       Docs: man:bluetoothd(8)
    Main PID: 14980 (bluetoothd)
     Status: "Running"
      Tasks: 1 (limit: 4432)
     Memory: 2.0M
     CGroup: /system.slice/bluetooth.service
             └─14980 /usr/lib/bluetooth/bluetoothd
    
    Dec 26 17:54:10 panspin systemd[1]: Stopped Bluetooth service.
    Dec 26 17:54:10 panspin systemd[1]: Starting Bluetooth service...
    Dec 26 17:54:10 panspin bluetoothd[14980]: Bluetooth daemon 5.50
    Dec 26 17:54:10 panspin bluetoothd[14980]: Starting SDP server
    Dec 26 17:54:10 panspin systemd[1]: Started Bluetooth service.
    Dec 26 17:54:10 panspin bluetoothd[14980]: Bluetooth management interface 1.14 initialized
    Dec 26 17:54:10 panspin bluetoothd[14980]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    Dec 26 17:54:10 panspin bluetoothd[14980]: Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    Dec 26 17:54:25 panspin bluetoothd[14980]: Unable to get Headset Voice gateway SDP record: Host is down
    Dec 26 17:54:37 panspin bluetoothd[14980]: /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd0: fd(37) ready
    
    // JOURNALD LOG ('bluetooth' filter)
    
    26.12.19 17:22    systemd    Reached target Bluetooth.
    26.12.19 17:22    kernel    Bluetooth: hci0: unexpected event for opcode 0xfc2f
    26.12.19 17:22    kernel    Bluetooth: hci0: Intel firmware patch completed and activated
    26.12.19 17:22    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    26.12.19 17:22    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    26.12.19 17:23    bluetoothd    /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd5: fd(37) ready
    26.12.19 17:24    kernel    Bluetooth: hci0: read Intel version: 370810011003110e00
    26.12.19 17:24    kernel    Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq
    26.12.19 17:24    bluetoothd    Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
    26.12.19 17:24    dbus-daemon    [system] Rejected send message, 1 matched rules; type="method_return", sender=":1.47" (uid=1000 pid=1138 comm="/usr/bin/pulseaudio --daemonize=no " label="unconfined") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.5" (uid=0 pid=886 comm="/usr/lib/bluetooth/bluetoothd " label="unconfined")
    26.12.19 17:24    bluetoothd    Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    26.12.19 17:24    bluetoothd    Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    26.12.19 17:24    systemd    Stopped target Bluetooth.
    26.12.19 17:24    systemd    Reached target Bluetooth.
    26.12.19 17:24    kernel    Bluetooth: hci0: unexpected event for opcode 0xfc2f
    26.12.19 17:24    kernel    Bluetooth: hci0: Intel firmware patch completed and activated
    26.12.19 17:24    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    26.12.19 17:24    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    26.12.19 17:25    bluetoothd    /org/bluez/hci0/dev_00_18_09_F5_BD_75/fd6: fd(37) ready
    26.12.19 17:26    sudo         pan : TTY=pts/1 ; PWD=/home/pan ; USER=root ; COMMAND=/usr/sbin/service bluetooth status
    26.12.19 17:39    kernel    Bluetooth: hci0: read Intel version: 370810011003110e00
    26.12.19 17:39    kernel    Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.8.10-fw-1.10.3.11.e.bseq
    26.12.19 17:39    kernel    Bluetooth: hci0: unexpected event for opcode 0xfc2f
    26.12.19 17:39    kernel    Bluetooth: hci0: Intel firmware patch completed and activated
    26.12.19 17:39    systemd    Stopped target Bluetooth.
    26.12.19 17:39    bluetoothd    Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)
    26.12.19 17:39    bluetoothd    Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    26.12.19 17:39    bluetoothd    Endpoint unregistered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    26.12.19 17:39    bluetoothd    Unable to register device interface for 00:18:09:F5:BD:75
    26.12.19 17:39    dbus-daemon    [system] Rejected send message, 1 matched rules; type="method_return", sender=":1.47" (uid=1000 pid=1138 comm="/usr/bin/pulseaudio --daemonize=no " label="unconfined") interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" destination=":1.5" (uid=0 pid=886 comm="/usr/lib/bluetooth/bluetoothd " label="unconfined")
    26.12.19 17:39    bluetoothd    Loading LTKs timed out for hci0
    26.12.19 17:39    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSink/sbc
    26.12.19 17:39    bluetoothd    Endpoint registered: sender=:1.47 path=/MediaEndpoint/A2DPSource/sbc
    26.12.19 17:41    sudo         pan : TTY=pts/1 ; PWD=/home/pan ; USER=root ; COMMAND=/usr/sbin/service bluetooth status
Working...
X