Disturbed audio at startup
Speech-dispatcher users have reported (https://github.com/brailcom/speechd/issues/198) getting disturbed audio when they first start their computer, and it happens to get fixed over time. I looked more carefully, and it seems to me it is an issue in pulseaudio itself, and speech-dispatcher just happens to trigger it.
I have attached a pulseaudio.log of what is happening in the following scenario:
- I start pulsaudio with debugging enabled
- I run
spd-say foo
many times - I ^C pulseaudio
spd-say triggers the start of speech-dispatcher
, which connects to pulseaudio. Running spd-say
several times keeps speech-dispatcher
alive, and simply makes it send some audio to pulseaudio from times to times.
The first times spd-say foo
is called, the sound is a bit crackled, and there is even some odd echo, i.e. for each spd-say foo
call, we hear a distorted "foo", then something like one second later, a distant distorted "foo" again. So this looks to me like some leftover in some buffer that the sound card happens to keep playing.
In the log we can notice several times:
D: [alsa-sink-ALC3271 Analog] protocol-native.c: Implicit underrun of 'playback'
D: [alsa-sink-ALC3271 Analog] sink.c: alsa_output.pci-0000_00_1f.3.analog-stereo: Found underrun 28 bytes ago (68 bytes ahead in playback buffer)
D: [alsa-sink-ALC3271 Analog] sink.c: alsa_output.pci-0000_00_1f.3.analog-stereo: Found underrun 60 bytes ago (36 bytes ahead in playback buffer)
D: [alsa-sink-ALC3271 Analog] sink.c: alsa_output.pci-0000_00_1f.3.analog-stereo: Found underrun 60 bytes ago (36 bytes ahead in playback buffer)
D: [alsa-sink-ALC3271 Analog] sink.c: alsa_output.pci-0000_00_1f.3.analog-stereo: Found underrun 92 bytes ago (4 bytes ahead in playback buffer)
D: [alsa-sink-ALC3271 Analog] protocol-native.c: Requesting rewind due to end of underrun.
D: [alsa-sink-ALC3271 Analog] alsa-sink.c: Requested to rewind 96 bytes.
D: [alsa-sink-ALC3271 Analog] alsa-sink.c: Mhmm, actually there is nothing to rewind.
that last line looks frightening to me :) As well as these lines
/* make sure rewind doesn't go too far, can cause issues with DMAs */
unused_nbytes += u->rewind_safeguard;
Eventually, at some point we get
I: [alsa-sink-ALC3271 Analog] alsa-sink.c: Underrun!
I: [alsa-sink-ALC3271 Analog] alsa-sink.c: Increasing minimal latency to 1,00 ms
D: [alsa-sink-ALC3271 Analog] alsa-sink.c: Latency set to 1,00ms
and from then on, the sound is not distorted at all any more, everything goes smoothly.
Another thing probably worth noticing is:
D: [pulseaudio] protocol-native.c: Adjust latency mode enabled, configuring sink latency to half of overall latency.
D: [pulseaudio] protocol-native.c: Requested latency=0,29 ms, Received latency=0,50 ms
so in the speech-dispatcher case, the computed requested latency is very small (it was on purpose in speech-dispatcher to make it as snap as possible for users), possibly beyond what is possible with the ALSA driver, and possibly that is the actual trigger for the bug.
One patch that cured the issue for me is the following: patch which I'll submit as MR. Basically, instead of waiting for an eventual "Underrun!" situation (which in my tests can take a very long time, like a dozen of spd-say
calls) before calling increase_watermark
, the Mhmm, actually there is nothing to rewind.
is taken also as a sign that the watermark should be increased. With that fix in, the latency gets increased to 1 or 2ms very early, and thus even the very first spd-say
call gets played properly.