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
Best regards,
Julian
