[pulseaudio-discuss] Bluetooth connection disconnects every few minutes

[Julian Sikorski]

W dniu 29.06.2018 o 21:47, Julian Sikorski pisze:
> Hi list,
> 
> I have noticed that the bluetooth connection between my laptop (Intel
> 7260) and my headphones (Sennheiser Momentum Wirelless) is very
> unreliable. While under Windows 10 devices stay connected for hours on
> end, under Fedora 28 the connection is lost every few minutes at most.
> Often the connection will be reestablished only to be lost again.
> bluetoothd shows messages like:
> 
> cze 29 21:31:13 snowball2 bluetoothd[3832]: Endpoint unregistered:
> sender=:1.145 path=/MediaEndpoint/A2DPSource
> cze 29 21:31:13 snowball2 bluetoothd[3832]: Endpoint unregistered:
> sender=:1.145 path=/MediaEndpoint/A2DPSink
> cze 29 21:31:13 snowball2 bluetoothd[3832]: Endpoint registered:
> sender=:1.145 path=/MediaEndpoint/A2DPSource
> cze 29 21:31:13 snowball2 bluetoothd[3832]: Endpoint registered:
> sender=:1.145 path=/MediaEndpoint/A2DPSink
> cze 29 21:31:39 snowball2 bluetoothd[3832]:
> /org/bluez/hci0/dev_00_1B_66_81_8D_76/fd5: fd(25) ready
> cze 29 21:33:02 snowball2 bluetoothd[3832]: Unable to get io data for
> Headset Voice gateway: getpeername: Transport endpoint is not connected
> (107)
> cze 29 21:33:02 snowball2 bluetoothd[3832]: Endpoint unregistered:
> sender=:1.145 path=/MediaEndpoint/A2DPSource
> cze 29 21:33:02 snowball2 bluetoothd[3832]: Endpoint unregistered:
> sender=:1.145 path=/MediaEndpoint/A2DPSink
> cze 29 21:33:03 snowball2 bluetoothd[3832]: Endpoint registered:
> sender=:1.145 path=/MediaEndpoint/A2DPSource
> cze 29 21:33:03 snowball2 bluetoothd[3832]: Endpoint registered:
> sender=:1.145 path=/MediaEndpoint/A2DPSink
> cze 29 21:33:31 snowball2 bluetoothd[3832]:
> /org/bluez/hci0/dev_00_1B_66_81_8D_76/fd6: fd(25) ready
> cze 29 21:35:38 snowball2 bluetoothd[3832]: Unable to get io data for
> Headset Voice gateway: getpeername: Transport endpoint is not connected
> (107)
> 
> dmesg for the same period looks as follows:
> 
> 2018-06-29T21:30:58,743292+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:31:12,613199+02:00 usb 2-1.4: USB disconnect, device number 8
> 2018-06-29T21:31:12,809196+02:00 usb 2-1.4: new full-speed USB device
> number 9 using ehci-pci
> 2018-06-29T21:31:12,889200+02:00 usb 2-1.4: New USB device found,
> idVendor=8087, idProduct=07dc, bcdDevice= 0.01
> 2018-06-29T21:31:12,889203+02:00 usb 2-1.4: New USB device strings:
> Mfr=0, Product=0, SerialNumber=0
> 2018-06-29T21:31:12,903435+02:00 Bluetooth: hci0: read Intel version:
> 3707100180012d0d2a
> 2018-06-29T21:31:12,903438+02:00 Bluetooth: hci0: Intel device is
> already patched. patch num: 2a
> 2018-06-29T21:31:13,002369+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:31:28,853543+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:31:39,625447+02:00 input: 00:1B:66:81:8D:76 as
> /devices/virtual/input/input31
> 2018-06-29T21:31:44,742251+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:32:00,746866+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:32:16,747075+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:32:32,746099+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:32:48,747212+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:33:02,403071+02:00 usb 2-1.4: USB disconnect, device number 9
> 2018-06-29T21:33:02,595275+02:00 usb 2-1.4: new full-speed USB device
> number 10 using ehci-pci
> 2018-06-29T21:33:02,675493+02:00 usb 2-1.4: New USB device found,
> idVendor=8087, idProduct=07dc, bcdDevice= 0.01
> 2018-06-29T21:33:02,675502+02:00 usb 2-1.4: New USB device strings:
> Mfr=0, Product=0, SerialNumber=0
> 2018-06-29T21:33:02,691213+02:00 Bluetooth: hci0: read Intel version:
> 3707100180012d0d2a
> 2018-06-29T21:33:02,691216+02:00 Bluetooth: hci0: Intel device is
> already patched. patch num: 2a
> 2018-06-29T21:33:02,791228+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:33:18,854324+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:33:31,481782+02:00 input: 00:1B:66:81:8D:76 as
> /devices/virtual/input/input32
> 2018-06-29T21:33:34,742175+02:00 Bluetooth: hci0: last event is not cmd
> complete (0x0f)
> 2018-06-29T21:35:37,864703+02:00 usb 2-1.4: USB disconnect, device number 10
> 2018-06-29T21:35:38,056428+02:00 usb 2-1.4: new full-speed USB device
> number 11 using ehci-pci
> 2018-06-29T21:35:38,140706+02:00 usb 2-1.4: New USB device found,
> idVendor=8087, idProduct=07dc, bcdDevice= 0.01
> 2018-06-29T21:35:38,140712+02:00 usb 2-1.4: New USB device strings:
> Mfr=0, Product=0, SerialNumber=0
> 2018-06-29T21:35:38,155840+02:00 Bluetooth: hci0: read Intel version:
> 3707100180012d0d2a
> 2018-06-29T21:35:38,155843+02:00 Bluetooth: hci0: Intel device is
> already patched. patch num: 2a
> 
> I am not sure where to look further. Does it look like an issue with
> pulseaudio, or a deeper problem with linux bluetooth stack? Thanks for
> your input in advance!
> 
> Best regards,
> Julian

This is what is logged by pulseaudio at the time the connection is lost:

( 118.064|  34.694) I: [bluetooth] module-bluez5-device.c: FD error:
POLLERR POLLHUP
( 118.064|   0.000) I: [bluetooth] bluez5-util.c: Transport
/org/bluez/hci0/dev_00_1B_66_81_8D_76/fd27 auto-released by BlueZ or
already released
( 118.064|   0.000) I: [pulseaudio] backend-native.c: Lost RFCOMM
connection.