Bug 58746

Bumping this due to the fact that this bug is still very much present in 5, 6, 7, 8 and renders the act of using a bluetooth headset on most linux operating systems using pulseaudio utterly useless. The slightest blip throws the whole audio out of sync with the video. I noticed this when trying to watch a movie from a 6ft distance away (sill in range) but occasionally the signal would blip and cause said problem. Evidence in the logs:

Three of many lines: 

    Feb 13 17:25:49 saturn.net.overtmind.com pulseaudio[30599]: [bluetooth] module-bluez5-device.c: Skipping 5124656 us (= 903988 bytes) in audio stream
    Feb 13 17:25:49 saturn.net.overtmind.com pulseaudio[30599]: [bluetooth] mod ule-bluez5-device.c: Skipping 220060 us (= 38816 bytes) in audio stream
    Feb 13 17:25:49 saturn.net.overtmind.com pulseaudio[30599]: [bluetooth] module-bluez5-device.c: Skipping 346147 us (= 61060 bytes) in audio stream

Packages tested in Fedora 23:

rawhide:

    bluez-5.37-2.fc24.x86_64
    pulseaudio-8.0-3.fc24.x86_64

and also tried initially with:

    bluez-5.36-1.fc23.x86_64
    pulseaudio-7.1-1.fc23.x86_64

The rest of my findings are here, where someone else has also mentioned seeing this on Gentoo with PA 5,6 - I have tested 7 and 8:

https://www.reddit.com/r/linuxquestions/comments/45n710/pulseaudio_bluetooth_degraded_signal_out_of_sync/

If you want audio sync with video after audio transmission is broken, you need the application to skip some audio and restart audio playback

Shouldn't the buffer reset after detecting a skip event?

(In reply to xenith from comment #3)
> Shouldn't the buffer reset after detecting a skip event?

This would seem to be the most logical thing. The way it is now, even stopping and re-starting the audio stream doesn't fix the latency issue if there has ever been a brief blip in the current Bluetooth connection. Quite a showstopper for watching video with bluetooth speakers/headphones.

I've tried to reproduce this behaviour in the past, but it doesn't always happen this way (but I have seen the delays turn up on drops at times). If someone has a patch that definitely works (or a way to repro that is 100% reliable), I can try to look at this.

(In reply to Arun Raghavan from comment #5)
> I've tried to reproduce this behaviour in the past, but it doesn't always
> happen this way (but I have seen the delays turn up on drops at times). If
> someone has a patch that definitely works (or a way to repro that is 100%
> reliable), I can try to look at this.

I have about 6 different cheap Chinese bluetooth speakers, and they all exhibit this behavior. They all use the A2DP protocol, are you possibly seeing different behavior with HSP/HFP?

I can reproduce this easily by running 'speaker-test -c2 -t wav' and then walking away from my computer with my headphones on until the signal strength drops sufficiently that the headphones go silent. Then, when I walk back to the computer, the audio is waaaay out of sync, and pulseaudio has issued the 'skipping' message many times.

Created attachment 125291 [details] [review]
Proof-of-concept patch

I've solved this issue for myself - I've been using pulseaudio with my changes for several months now with no major problems.

I've noticed that every time signal degrades audio gets more out of sync - up to about 10-15 seconds (if I remember correctly).

I've debugged bluez5 pulseaudio module and suspect that the problem lies in buffering for bluetooth socket. Here's my analysis:

1) Pulseaudio detects BT signal drop when write() on bluetooth socket returns EAGAIN (i.e., when the buffer is full).
2) Bluetooth socket buffer is quite big (by default)
3) When pulseaudio stops sending audio packets to BT socket the buffer still contains a lot of packets
4) pulseaudio considers those packets as successfully sent - but they aren't
5) BT connection seems to never be able to "catch up" with the amount of buffered packets and audio becomes out-of-sync.

So here's my patch. The main change is to decrease the buffer size as much as possible. I've experimented and found out that settings buffer size to 2x-5x of packet size works best for me. This ensures that audio lag won't accumulate after BT signal degradation while preventing audio skipping due to buffer underruns. Audio still may skip (sometimes several times in a row) - but without the lag after BT signal restores.

Unfortunately with this patch bluetooth microphone (headset profile) won't work - since I don't use one and couldn't test it. I hope that someone would be able to pick it up and make into a form that would be possible to merge in master branch.

The changes are contained in attached path on github: https://github.com/dmitryvk/pulseaudio/commit/12b13c75d3a9b377e0f7de7c86116e3af41ce5ee. Patch was developed against Pulseaudio-8.0 but it works with Pulseaudio-9.0.

Could someone please look at the attached patch. This bug is super annoying and essentially makes it impossible to use a Bluetooth headset to watch movies.

I have taken a look, but as the submitter himself says, it's not ready for merging. Someone needs to improve the patch so that it doesn't break stuff. I'm not volunteering to do that myself (at least any time soon). The general idea of reducing the socket buffer size seems good.

I've recently found out that there exists SIOCOUTQ ioctl which supposedly should work on bluetooth sockets (I haven't verified this).
ioctl(.., SIOCOUTQ, ..) returns amount of bytes in send buffer.
Using it should be more reliable way than simply reducing buffer size.

*** Bug 95411 has been marked as a duplicate of this bug. ***

Tried a patch from comment #8. 
The issue still persists but it happens less frequently with the patch. And instead of bluetooth disconnecting, I get messages like the following every second until I reconnect the bluetooth device manually.

module-bluez5-device.c: Skipping 32025 us (= 5648 bytes) in audio stream

(In reply to Dmitry Kalyanov from comment #8)
> Created attachment 125291 [details] [review] [review]
> Proof-of-concept patch
> 
> I've solved this issue for myself - I've been using pulseaudio with my
> changes for several months now with no major problems.
> 
> I've noticed that every time signal degrades audio gets more out of sync -
> up to about 10-15 seconds (if I remember correctly).
> 
> I've debugged bluez5 pulseaudio module and suspect that the problem lies in
> buffering for bluetooth socket. Here's my analysis:
> 
> 1) Pulseaudio detects BT signal drop when write() on bluetooth socket
> returns EAGAIN (i.e., when the buffer is full).
> 2) Bluetooth socket buffer is quite big (by default)
> 3) When pulseaudio stops sending audio packets to BT socket the buffer still
> contains a lot of packets
> 4) pulseaudio considers those packets as successfully sent - but they aren't
> 5) BT connection seems to never be able to "catch up" with the amount of
> buffered packets and audio becomes out-of-sync.
> 
> So here's my patch. The main change is to decrease the buffer size as much
> as possible. I've experimented and found out that settings buffer size to
> 2x-5x of packet size works best for me. This ensures that audio lag won't
> accumulate after BT signal degradation while preventing audio skipping due
> to buffer underruns. Audio still may skip (sometimes several times in a row)
> - but without the lag after BT signal restores.
> 
> Unfortunately with this patch bluetooth microphone (headset profile) won't
> work - since I don't use one and couldn't test it. I hope that someone would
> be able to pick it up and make into a form that would be possible to merge
> in master branch.
> 
> The changes are contained in attached path on github:
> https://github.com/dmitryvk/pulseaudio/commit/
> 12b13c75d3a9b377e0f7de7c86116e3af41ce5ee. Patch was developed against
> Pulseaudio-8.0 but it works with Pulseaudio-9.0.

Genius! I understand the problems with this patch but for now it's music to my ears (pun intended). Using on Arch with Pulseaudio 9.

I have used a version of a workaround -- though not adopting the code below, instead having an auto resetting of the headset mode which is a work around. 

For the Pulseaudio developers -- I think the code that is causing this issue are around or between lines 1421 and 1503 of the below github code page for: module-bluez4-device.c

pulseaudio/src/modules/bluetooth/module-bluez5-device.c

https://github.com/pulseaudio/pulseaudio/blob/2417305ae755cbb3a92ca43a058f550809069cd9/src/modules/bluetooth/module-bluez5-device.c


The work around in the code seems to be about using a timer a to sync everything back up when a disruption occurs -- but either the timer is not working as intended, or the thresholds for the re-syncing process need to be considered. 



This is what I can gather but am interpreting as best I can. 

This is a common topic in troubleshooting boards for Bluetooth on linux distros.

*** Bug 102989 has been marked as a duplicate of this bug. ***

This bug is extremely annoying during calls, when resetting the audio profile (as suggested as workaround by several people) can disrupt the call / cause feedback. How has this been open for over 5 years?

Any guidance what we could do to help get the patch merged or an alternative fix developed ? Would testing the patch be enough or needs more research ?

Or can the maintainers not reproduce the issue yet ?

Let us know :-)

(In reply to Vincent Petry from comment #18)
> Any guidance what we could do to help get the patch merged or an alternative
> fix developed ? Would testing the patch be enough or needs more research ?

See comment #10, I think the comment answers all your questions. If you can't improve the patch yourself or find someone else to do it, I don't think there's anything you can do.

> Or can the maintainers not reproduce the issue yet ?

Speaking only for myself here: bluetooth works so badly on my machine that testing anything is a huge pain, if possible at all. For that reason I don't work much on bluetooth issues (and there's no shortage of other work).

So are you saying that getting you a new machine (or a working setup) is also a possible approach ? :-D

(In reply to Vincent Petry from comment #20)
> So are you saying that getting you a new machine (or a working setup) is
> also a possible approach ? :-D

I suppose so :) Now that I think about it, I have another machine that I could and should try first, so don't send me stuff yet!

I have more urgent things to work on first, though, so I don't expect progress on this in the near future.

Created attachment 137440 [details]
patch: rewrite of thread function

Could you try if the attached patch fixes your issues?

Created attachment 137477 [details]
patch: rewrite of thread function

Sorry, I had other patches in my tree, so the posted patch would not apply cleanly to current master. Here an updated version.

Nobody willing to test?

(In reply to Georg Chini from comment #24)
> Nobody willing to test?

I have tested the patch with a pair of Mackie CR4BT bluetooth speakers that suffers from the lag issues after they reconnect. That patch was applied 7f09164e and built as part of the [pulseaudio-git] AUR package.

When the computer initiate connection with the speakers (i.e. `echo connect MAC | bluetoothctl`) everything works fine, but every few seconds the logs are flooded with 1000s of these messages: 

  [bluetooth] module-bluez5-device.c: Broken kernel: we got EAGAIN on write() after POLLOUT!

When the speakers initiate the connection they disconnect after about a second (even before they start making sound), and when the speakers disconnects (either a second after they connected or if I turn them off after computer initiated the connection) pulseaudio aborts with:

  [bluetooth] module-bluez5-device.c: Skipping 2176 us (= 384 bytes) in audio stream
  [bluetooth] module-bluez5-device.c: Assertion 'u->write_memchunk.length == u->write_block_size' failed at modules/bluetooth/module-bluez5-device.c:437, function a2dp_process_render(). Aborting.


I only observe the out-of-sync audio problems when the connection is initiated by the audio device (e.g. power on, pushing their connect buttons, after signal loss). I am happy to test further patches, but I do not see any means to reproduce the problem as long as pulseaudio aborts whenever any of my devices tries to reconnect.

I also have a Bose QC35 and a RHA MA 650 Wireless headset to test with, but they usually take longer to suffer from audio sync problems than the Mackie CR4BT speakers. I tested the patch with the headsets to, and they observed the same crashing behavior as when I tested it with the speakers. 


BTW, as a workaround until the problem is fixed I have a script I use whenever I notice audio sync problems that disconnect then reconnects the device, so that it is the computer that initiated the connection. This seems to work consistently and avoids the problem until there are intermittent connection problem (e.g. I walk too far away from the computer with a headset) or I turn off and on the audio devices.

[pulseaudio-git] https://aur.archlinux.org/cgit/aur.git/tree/PKGBUILD?h=pulseaudio-git

Thanks for testing. I can not reproduce your problems here with both of my headsets using current master. Can you please send a full log from the moment you press the connect button on your BT device, so that I can see what happens?

Created attachment 137779 [details]
patch: rewrite of thread function

I think I figured out what went wrong. Could you give the updated patch a try? If it still causes problems, please send a log as requested earlier.

(In reply to Georg Chini from comment #27)
> Could you give the updated patch a try?

I tried the new patch. With it I do not get any aborts. Additionally I am getting way fewer of these messages:

  [bluetooth][modules/bluetooth/module-bluez5-device.c:1464 write_block()] Broken kernel: we got EAGAIN on write() after POLLOUT! (libpulsecommon-11.0.so(+0x414e7) [0x7f6f7492b4e7]<<libpulsecommon-11.0.so(pa_log_levelv_meta+0x4af) [0x7f6f7492beb9])

And most importantly, I cannot reproduce the audio sync issues. I have tried to have my Mackie CR4BT speakers autoconnect when they power on, which caused audio sync problems for me almost immediately before. Along with moving so far away from the computer with my headsets that the sound crackles and disappears, and then moving back before the device disconnects.

Thanks again for testing. Sounds good. Regarding those broken kernel messages, do you only get them once in a while or still annoyingly often? It is just a warning message, so if it's annoying I could drop it completely.

(In reply to Georg Chini from comment #29)
> Thanks again for testing. Sounds good. 

You are welcome. Thanks for making bluetooth audio usable in linux.

> Regarding those broken kernel messages, do you only get them once in a while or still annoyingly often?

I seem to only get them when there are intermittent signal problems, so it is not annoyingly often.

Created attachment 138573 [details]
patch: rewrite of thread function

Could you test this updated patch? There have been a few changes due to review and I want to make sure that it still works.

(In reply to Georg Chini from comment #31)
> Could you test this updated patch?

Sure, I have applied the new patch to b1d74c86, and it seems to work as well as the previous patch. Also, I have yet to see any warning messages in the system log.

I had the previous patch running since the start of march and I did not notice any new problems. I will be running with the new patch from now on, and I will report if I notice any further problems.

Perfect. Thanks a lot for your tests.

(In reply to Georg Chini from comment #31)
> Created attachment 138573 [details]
> patch: rewrite of thread function
> 
> Could you test this updated patch? There have been a few changes due to
> review and I want to make sure that it still works.

I have tried this patch (applied against pulseaudio 11.1 in Debian unstable, it applies with fuzz but works) and I saw a great improvement! My bluetooth chip is very susceptible to interferences, it was common for me to have a few seconds of delays. With this patch, the delay stays small at all times. The fact that it drops samples more aggressively was not noticeable for me because on drop out the speaker just stops anyway. I did not get any warning in the log, just debug messages about skipping.

Thank you for your work, I hope it will make it to mainline.

(In reply to Georg Chini from comment #31)
> Created attachment 138573 [details]
> patch: rewrite of thread function
> 
> Could you test this updated patch? There have been a few changes due to
> review and I want to make sure that it still works.

Thank you very much for the patch!

I also was having loss of audio sync. This patch solved the problem.

Occasionaly will still delay the audio, but before the delay was something like 3-4 seconds, now the worst case that I have seen so far is a couple tens of milliseconds (very small and ok for music and films).

Tested on Arch linux, patch applied to the latest version of Pulseaudio on github (last commit Apr 19, 2018), zero problems applying the patch.

Thank you all for testing. The patch is in master now and will be part of the 12.0 release. I will (finally, after five and a half years) close this bug.

OMG. You are my favorite people ever.

I can confirm that this path fixes _all_ of my out of sync issues. I run a 2015 MBP on which the bluetooth and Wifi share the same antenna. When running on a 2.4Ghz network I have little blips when there's interference but the audio doesn't get out of sync.

Also, my connection issues are gone. Previously I'd need to re-pair the headset nearly every time otherwise the connection would close almost immediately.

Furthermore- HFP/HSP _finally_ works!! I can actually use my mic now! This is just the best day.

Hey folks - I'm still experiencing sound disruptions. 

Is a specific Kernel version expected to be present in order the patch to work fine?

I'm using Kubuntu 18.04 with updated bluetooth and pulseaudio related pkgs:

root@xtigyro-kubuntu:~# pulseaudio --version
pulseaudio 12.2-2
root@xtigyro-kubuntu:~# bluetoothd --version
5.50


Thank you for your time!