Hi,
I have a problem that sound played by a custom application using the ALSA API is
cracked for the first ca. 10 seconds.
I've reproduced the same problem with aplay: I'm playing a short (~19 seconds)
wav file and the first ~7 seconds of the playback is cracked / has gaps but
after that audio is played back properly, i.e. there are no noticeable cracks in
the playback.
Some observations I have made:
* pulseaudio reports a potential problem with the ALSA driver:
E: [alsa-sink-HiFi sgtl5000-0] alsa-sink.c: ALSA woke us up to write new \
data to the device, but there was actually nothing to write.
E: [alsa-sink-HiFi sgtl5000-0] alsa-sink.c: Most likely this is a bug in \
the ALSA driver '(null)'. Please report this issue to the ALSA developers.
E: [alsa-sink-HiFi sgtl5000-0] alsa-sink.c: We were woken up with POLLOUT \
set -- however a subsequent snd_pcm_avail() returned 0 or ano ther value < \
min_avail.
* I can only reproduce the problem with pulseaudio. I.e. when I remove
pulseaudio from the system playback is fine
* Re-nicing all the running pulseaudio threads to a nice value of -20 (adjusted
using htop just before running aplay) does not have any impact on the observed
behavior
* alsa-sink seems to suffer from underruns both in the beginning and end of the
playback; my assumption is that these are not the cause of the cracks because
underruns are not reported during playback when the audio is cracked
* alsa-sink monotonically increases the "minimal latency" during the
problematic playback period starting with 1.00 ms and ending up close to 200
ms; these log messages disappear when the playback stabilizes (or vice versa)
* Enabling shared ringbuffer support for module-native-protocol-unix
as suggested related to a similar problem discussed at
https://lists.freedesktop.org/archives/pulseaudio-discuss/2016-March/025795.html
in default.pa
load-module module-native-protocol-unix srbchannel=true
did not have any impact on the observed behavior
* With DEBUG_TIMING enabled in alsa-sink.c, alsa-source.c, and rtpoll.c,
pulseaudio reports significant deltas in expected sleep times, e.g.:
D: [alsa-sink-HiFi sgtl5000-0] alsa-sink.c: Expected sleep: 106.62ms, real
sleep: 0.88ms (diff -105.74 ms)
but the deltas get significantly smaller shortly after the playback,
presumably, starts.
Log: https://www.dropbox.com/s/c6hvu6hi7rv4uye/pulseverbose.log.8?dl=0
(I'm sorry for dropbox links but the log files were too big to be attached and
my options for sharing files are very limited.)
My test cases:
1. With the default daemon configuration including
; default-sample-rate = 44100
; alternate-sample-rate = 48000
; default-sample-channels = 2
; default-channel-map = front-left,front-right
by running
$ time aplay /tmp/10-beeps.wav
Playing WAVE '/tmp/10-beeps.wav' : Signed 16 bit Little Endian, Rate
16000 Hz, Mono
real 0m 20.28s
user 0m 0.08s
sys 0m 0.34s
audio stabilizes after 10 seconds (what I described above).
Log: https://www.dropbox.com/s/toz0a07l2gsi17u/pulseverbose.log?dl=0
2. With modified configuration intended to match the output of our application
and the format of the wav file
default-sample-rate = 16000
default-sample-channels = 1
default-channel-map = mono
audio does not stabilize at all but playback is cracked all the way until the
end, and aplay prints out the following:
$ time aplay /tmp/10-beeps.wav
Playing WAVE '/tmp/10-beeps.wav' : Signed 16 bit Little Endian, Rate
16000 Hz, Mono
underrun!!! (at least 5968.392 ms long)
underrun!!! (at least 12947.380 ms long)
underrun!!! (at least 9962.868 ms long)
underrun!!! (at least 1954.116 ms long)
underrun!!! (at least 3955.021 ms long)
real 0m 37.94s
user 0m 0.12s
sys 0m 0.52s
This is probably a bad configuration as it makes the problem even worse. Even
the aplay execution time is longer and the pulseaudio logs show multiple
connections although aplay was only run once.
Log: https://www.dropbox.com/s/53xm83jcxpmbq58/pulseverbose.log.2?dl=0
My configuration:
* pulseaudio 8.0 built with Yocto (krogoth, commit
6c1c01392d91f512e2949ad1d57a75a8077478ba) containing the following patches on
top of the upstream 8.0 release:
Revert "module-switch-on-port-available: Route to preferred profile"
alsa: set availability for (some) unavailable profiles
card: move profile selection after pa_card_new()
alsa, bluetooth: fail if user-requested profile doesn't exist
card: add pa_card_profile.ports
client-conf: Add allow-autospawn-for-root
padsp: Make it compile on musl
* Default (daemon and client) configuration produced by the build (the Yocto
recipe does not seem to do any changes, and by changing the configuration
manually I have only been able to make the problem worse; see my observations
above)
* pulseaudio run as a non-privileged user
* Verbose logs captured using
-vvvv --log-target=newfile:/tmp/pulseverbose.log --log-time=1
I see two potential causes for the issue:
1. A bug in the ALSA driver like pulseaudio reported, or
2. A pulseaudio configuration problem
I'm not familiar enough with pulseaudio nor ALSA to reliably interpret the logs
and to decide what is the most probable cause to further investigate so I'd
appreciate any feedback regarding the problem.
Thanks,
--
-Hannu
