Hi Julian,
On Tue, Sep 1, 2020 at 1:42 PM Julian Sikorski <belegdol@xxxxxxxxx> wrote:
>
> W dniu 01.09.2020 o 22:10, Julian Sikorski pisze:
> > W dniu 12.08.2018 o 17:49, Julian Sikorski pisze:
> >> W dniu 01.08.2018 o 19:46, Julian Sikorski pisze:
> >>> W dniu 09.07.2018 o 18:51, Julian Sikorski pisze:
> >>>> W dniu 08.07.2018 o 19:46, Georg Chini pisze:
> >>>>> On 08.07.2018 15:21, Julian Sikorski wrote:
> >>>>>> W dniu 02.07.2018 o 20:09, Julian Sikorski pisze:
> >>>>>>> W dniu 02.07.2018 o 18:04, Georg Chini pisze:
> >>>>>>>> On 02.07.2018 17:58, Julian Sikorski wrote:
> >>>>>>>>> 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:
> >>>>>>>>>>
> >>>>>
> >>>>>>>>>> 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.
> >>>>>>>>>
> >>>>>>>>>
> >>>>>>>> From what you are writing, it looks to me as if the issue is in the
> >>>>>>>> USB
> >>>>>>>> stack and the BT dongle keeps disconnecting/connecting. Have you
> >>>>>>>> tried another dongle?
> >>>>>>> Hi,
> >>>>>>>
> >>>>>>> I unfortunately do not own any other dongles. I tried getting some
> >>>>>>> useful info with btmon but the log seems flooded with way too many
> >>>>>>> messages to make anything out.
> >>>>>>>
> >>>>>> Hi Georg,
> >>>>>>
> >>>>>> it looks like the problem is more related to how the dongle interacts
> >>>>>> with this specific headphone model. I have recently bought another one
> >>>>>> for running (AfterShokz Trekz Air) and it works perfectly, connecting
> >>>>>> automatically, staying connected and even switching profiles
> >>>>>> automatically without issues so far.
> >>>>>> The hci0: last event is not cmd complete (0x0f) message seems harmless
> >>>>>> as it spams the dmesg output regardless of the device connected (and
> >>>>>> also when no device is connected at all.
> >>>>>> It appears that whatever is happening it makes the dongle reconnect:
> >>>>>>
> >>>>>> [nie lip 8 15:14:12 2018] usb 2-1.4: USB disconnect, device number 6
> >>>>>> [nie lip 8 15:14:12 2018] usb 2-1.4: new full-speed USB device number 7
> >>>>>> using ehci-pci
> >>>>>> [nie lip 8 15:14:12 2018] usb 2-1.4: New USB device found,
> >>>>>> idVendor=8087, idProduct=07dc, bcdDevice= 0.01
> >>>>>> [nie lip 8 15:14:12 2018] usb 2-1.4: New USB device strings: Mfr=0,
> >>>>>> Product=0, SerialNumber=0
> >>>>>> [nie lip 8 15:14:12 2018] Bluetooth: hci0: read Intel version:
> >>>>>> 3707100180012d0d2a
> >>>>>> [nie lip 8 15:14:12 2018] Bluetooth: hci0: Intel device is already
> >>>>>> patched. patch num: 2a
> >>>>>>
> >>>>>> Where would you recommend to look for reasons for this behaviour? btmon?
> >>>>>> Thank you for the pointers!
> >>>>>>
> >>>>>> Best regards,
> >>>>>> Julian
> >>>>>>
> >>>>>>
> >>>>> Hi Julian,
> >>>>>
> >>>>> sorry, I have no further ideas. Maybe Luiz can help you to investigate.
> >>>>> To me it looks like the headphone is sending something that makes the
> >>>>> dongle reset.
> >>>>>
> >>>>> Regards
> >>>>> Georg
> >>>>
> >>>> Hi Georg,
> >>>>
> >>>> no worries - hopefully Luiz will find some time to look into this.
> >>>> In the meantime I have been getting acquainted with btmon. I have
> >>>> managed to pinpoint the exact moment during which sound stops coming
> >>>> through the headphones and starts coming through the laptop speakers. In
> >>>> the below testcase, it happens at 18:42:58:
> >>>>
> >>>> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >>>> #1825 [hci0] 18:42:58.908586
> >>>> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >>>> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >>>> #1826 [hci0] 18:42:58.928877
> >>>> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >>>> @ MGMT Event: Class Of Device Changed (0x0007) plen 3
> >>>> {0x0002} [hci0] 18:43:00.653578
> >>>> Class: 0x000000
> >>>> Major class: Miscellaneous
> >>>> Minor class: 0x00
> >>>> @ MGMT Event: Class Of Device Changed (0x0007) plen 3
> >>>> {0x0001} [hci0] 18:43:00.653578
> >>>> Class: 0x000000
> >>>> Major class: Miscellaneous
> >>>> Minor class: 0x00
> >>>> @ MGMT Event: New Settings (0x0006) plen 4
> >>>> {0x0002} [hci0] 18:43:00.653609
> >>>> Current settings: 0x00000ada
> >>>> Connectable
> >>>> Discoverable
> >>>> Bondable
> >>>> Secure Simple Pairing
> >>>> BR/EDR
> >>>> Low Energy
> >>>> Secure Connections
> >>>> @ MGMT Event: New Settings (0x0006) plen 4
> >>>> {0x0001} [hci0] 18:43:00.653609
> >>>> Current settings: 0x00000ada
> >>>> Connectable
> >>>> Discoverable
> >>>> Bondable
> >>>> Secure Simple Pairing
> >>>> BR/EDR
> >>>> Low Energy
> >>>> Secure Connections
> >>>> = bluetoothd: Unable to get io data for Headset Voice gateway:
> >>>> getpeername: Transport endpoint is not connected.. 18:43:00.654133
> >>>> = Close Index: 7C:5C:F8:B2:DF:08
> >>>> [hci0] 18:43:00.678348
> >>>> @ MGMT Event: Index Removed (0x0005) plen 0
> >>>> {0x0002} [hci0] 18:43:00.678372
> >>>> @ MGMT Event: Index Removed (0x0005) plen 0
> >>>> {0x0001} [hci0] 18:43:00.678372
> >>>> = Delete Index: 7C:5C:F8:B2:DF:08
> >>>> [hci0] 18:43:00.678377
> >>>> = bluetoothd: Endpoint unregistered: sender=:1.1492
> >>>> path=/MediaEndpoint/A2DPSource
> >>>> 18:43:00.678966
> >>>> = bluetoothd: Endpoint unregistered: sender=:1.1492
> >>>> path=/MediaEndpoint/A2DPSink
> >>>> 18:43:00.678984
> >>>>
> >>>> I am copying linux-bluetooth, maybe someone there will have an idea as
> >>>> well. Thank you for all your help in advance!
> >>>>
> >>>> Best regards,
> >>>> Julian
> >>>
> >>> Hi all,
> >>>
> >>> I tried to get more information using hcidump, but it does not appear
> >>> very interesting. I am attaching it here just in case. The last entry
> >>> appearing - command complete (read encryption key size) - appears upon
> >>> successful connection, not when the connection is dropped. How else
> >>> could I try to figure out what is being sent at the time of
> >>> disconnection? Thank you!
> >>>
> >>> Best regards,
> >>> Julian
> >>
> >> Hi list,
> >>
> >> I just realised I never attached the full btmon dump. Here it goes, the
> >> connection drops at 17:32:04:
> >>
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1340 [hci0] 17:32:04.774611
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >>> HCI Event: Number of Completed Packets (0x13) plen 5
> >> #1341 [hci0] 17:32:04.783175
> >> Num handles: 1
> >> Handle: 256
> >> Count: 1
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1342 [hci0] 17:32:04.794981
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >>> HCI Event: Number of Completed Packets (0x13) plen 5
> >> #1343 [hci0] 17:32:04.803054
> >> Num handles: 1
> >> Handle: 256
> >> Count: 1
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1344 [hci0] 17:32:04.815326
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >>> HCI Event: Number of Completed Packets (0x13) plen 5
> >> #1345 [hci0] 17:32:04.823198
> >> Num handles: 1
> >> Handle: 256
> >> Count: 1
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1346 [hci0] 17:32:04.835578
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1347 [hci0] 17:32:04.856093
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1348 [hci0] 17:32:04.876186
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1349 [hci0] 17:32:04.896454
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >> < ACL Data TX: Handle 256 flags 0x02 dlen 850
> >> #1350 [hci0] 17:32:04.916869
> >> Channel: 450 len 846 [PSM 25 mode 0] {chan 2}
> >> @ MGMT Event: Class Of Device Changed (0x0007) plen 3
> >> {0x0002} [hci0] 17:32:06.637019
> >> Class: 0x000000
> >> Major class: Miscellaneous
> >> Minor class: 0x00
> >> @ MGMT Event: Class Of Device Changed (0x0007) plen 3
> >> {0x0001} [hci0] 17:32:06.637019
> >> Class: 0x000000
> >> Major class: Miscellaneous
> >> Minor class: 0x00
> >> @ MGMT Event: New Settings (0x0006) plen 4
> >> {0x0002} [hci0] 17:32:06.637034
> >> Current settings: 0x00000ada
> >> Connectable
> >> Discoverable
> >> Bondable
> >> Secure Simple Pairing
> >> BR/EDR
> >> Low Energy
> >> Secure Connections
> >> @ MGMT Event: New Settings (0x0006) plen 4
> >> {0x0001} [hci0] 17:32:06.637034
> >> Current settings: 0x00000ada
> >> Connectable
> >> Discoverable
> >> Bondable
> >> Secure Simple Pairing
> >> BR/EDR
> >> Low Energy
> >> Secure Connections
> >> = Close Index: 7C:5C:F8:B2:DF:08
> >> [hci0] 17:32:06.654087
> >> @ MGMT Event: Index Removed (0x0005) plen 0
> >> {0x0002} [hci0] 17:32:06.654114
> >> @ MGMT Event: Index Removed (0x0005) plen 0
> >> {0x0001} [hci0] 17:32:06.654114
> >> = Delete Index: 7C:5C:F8:B2:DF:08
> >> [hci0] 17:32:06.654120
> >> = bluetoothd: Unable to get io data for Headset Voice gateway:
> >> getpeername: Transport endpoint is not connected.. 17:32:06.654352
> >> = bluetoothd: Endpoint unregistered: sender=:1.750
> >> path=/MediaEndpoint/A2DPSource
> >> 17:32:06.654796
> >> = bluetoothd: Endpoint unregistered: sender=:1.750
> >> path=/MediaEndpoint/A2DPSink
> >> 17:32:06.654836
> >>
> >> I tried sending the btmon capture as attachment but it appears to be too
> >> large for the list, so I uploaded it here instead:
> >>
> >> https://belegdol.fedorapeople.org/btmon-aug.log
Is this perhaps related to https://github.com/bluez/bluez/issues/18,
we have a fix already applied upstream for it.
> >> Best regards,
> >> Julian
> >>
> >
> > Hi all,
> >
> > I have tried the headset again with kernel-5.8.4, bluez-5.54 and
> > pulseaudio-13.99.1. The situation has unfortunately not improved in the
> > last two years.
> > I am attaching the btmon capture of two connection attempts:
> > - the first connects and then almost immediately disconnects
> > - the second never succeeds
> > Does the capture provide any information as to why the connection is
> > failing? If I can provide any more data, please let me know. Thanks!
> >
> > Best regards,
> > Julian
> >
> If I am not mistaken, the disconnect happens right after #636
>
> Best regards,
> Julian
--
Luiz Augusto von Dentz
