Bug 58746 - bluetooth audio out of sync when connection temporarily drops
Summary: bluetooth audio out of sync when connection temporarily drops
Status: RESOLVED FIXED
Alias: None
Product: PulseAudio
Classification: Unclassified
Component: modules (show other bugs)
Version: unspecified
Hardware: x86-64 (AMD64) Linux (All)
: high normal
Assignee: pulseaudio-bugs
QA Contact: pulseaudio-bugs
URL:
Whiteboard:
Keywords:
: 95411 102989 (view as bug list)
Depends on:
Blocks:
 
Reported: 2012-12-25 13:10 UTC by Daniel Schaal
Modified: 2018-05-12 18:46 UTC (History)
28 users (show)

See Also:
i915 platform:
i915 features:


Attachments
Proof-of-concept patch (9.37 KB, patch)
2016-07-24 15:46 UTC, Dmitry Kalyanov
Details | Splinter Review
patch: rewrite of thread function (18.81 KB, text/plain)
2018-02-19 15:01 UTC, Georg Chini
Details
patch: rewrite of thread function (18.69 KB, text/plain)
2018-02-20 20:51 UTC, Georg Chini
Details
patch: rewrite of thread function (18.09 KB, text/plain)
2018-03-04 14:24 UTC, Georg Chini
Details
patch: rewrite of thread function (19.57 KB, text/plain)
2018-04-04 09:30 UTC, Georg Chini
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Daniel Schaal 2012-12-25 13:10:22 UTC
I'm using a bluetooth headset with pulseaudio. Whenever the connection temporarily drops (e.g. by moving too far from the bt device), I get the message in the syslog:

[bluetooth] module-bluetooth-device.c: Skipping 24275 us (= 4280 bytes) in audio stream

and the audio lags behind after that. A workaround is to suspend and resume the sink using "pactl suspend-sink 1 && pactl suspend-sink 0", after which the audio is in sync again.

Using the same headset on Windows doesn't show the same behavior.
Comment 1 mike 2016-02-13 23:32:25 UTC
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/
Comment 2 Raymond 2016-02-14 09:53:05 UTC
If you want audio sync with video after audio transmission is broken, you need the application to skip some audio and restart audio playback
Comment 3 mike 2016-02-14 10:21:54 UTC
Shouldn't the buffer reset after detecting a skip event?
Comment 4 S. 2016-05-04 01:37:04 UTC
(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.
Comment 5 Arun Raghavan 2016-05-08 15:46:53 UTC
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.
Comment 6 S. 2016-05-10 15:58:47 UTC
(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?
Comment 7 Sam Morris 2016-06-22 23:13:10 UTC
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.
Comment 8 Dmitry Kalyanov 2016-07-24 15:46:33 UTC
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.
Comment 9 teppot 2016-09-11 08:23:51 UTC
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.
Comment 10 Tanu Kaskinen 2016-09-11 09:22:04 UTC
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.
Comment 11 Dmitry Kalyanov 2016-10-13 09:30:53 UTC
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.
Comment 12 Tanu Kaskinen 2016-10-29 17:31:05 UTC
*** Bug 95411 has been marked as a duplicate of this bug. ***
Comment 13 Sam Tyler 2017-01-07 15:59:01 UTC
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
Comment 14 paco3346 2017-01-16 16:02:49 UTC
(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.
Comment 15 Andrew McClure 2017-07-02 17:42:36 UTC
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.
Comment 16 Tanu Kaskinen 2017-10-12 16:36:50 UTC
*** Bug 102989 has been marked as a duplicate of this bug. ***
Comment 17 philipp+freedesktop 2018-02-07 13:29:40 UTC
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?
Comment 18 Vincent Petry 2018-02-14 19:24:05 UTC
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 :-)
Comment 19 Tanu Kaskinen 2018-02-16 06:44:32 UTC
(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).
Comment 20 Vincent Petry 2018-02-16 08:16:36 UTC
So are you saying that getting you a new machine (or a working setup) is also a possible approach ? :-D
Comment 21 Tanu Kaskinen 2018-02-17 06:37:10 UTC
(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.
Comment 22 Georg Chini 2018-02-19 15:01:01 UTC
Created attachment 137440 [details]
patch: rewrite of thread function

Could you try if the attached patch fixes your issues?
Comment 23 Georg Chini 2018-02-20 20:51:25 UTC
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.
Comment 24 Georg Chini 2018-03-03 13:07:28 UTC
Nobody willing to test?
Comment 25 Johannes Larsen 2018-03-03 18:33:20 UTC
(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
Comment 26 Georg Chini 2018-03-04 11:39:38 UTC
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?
Comment 27 Georg Chini 2018-03-04 14:24:15 UTC
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.
Comment 28 Johannes Larsen 2018-03-04 15:21:05 UTC
(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.
Comment 29 Georg Chini 2018-03-04 16:15:03 UTC
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.
Comment 30 Johannes Larsen 2018-03-04 16:59:04 UTC
(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.
Comment 31 Georg Chini 2018-04-04 09:30:21 UTC
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.
Comment 32 Johannes Larsen 2018-04-05 19:35:38 UTC
(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.
Comment 33 Georg Chini 2018-04-05 19:39:45 UTC
Perfect. Thanks a lot for your tests.
Comment 34 Amaury Pouly 2018-04-06 12:02:10 UTC
(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.
Comment 35 garis 2018-04-25 06:42:47 UTC
(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.
Comment 36 Georg Chini 2018-05-09 05:50:34 UTC
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.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.