W dniu 02.09.2020 o 01:14, Luiz Augusto von Dentz pisze: > 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. > Hi Luiz, it looks like a different issue. I tried both passing --noplugin=avrcp and applying the two patches mentioned in the github issue to Fedora RPM, neither helped. I am attaching a new btmon capture in case something changed. In this one the disconnect happens after #371. Best regards, Julian >>>> 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 > > >
<<attachment: btmon-m2aebt-2.zip>>