[pulseaudio-discuss] Gap, silence and latency

[Tanu Kaskinen]

On Sat, 2012-03-10 at 00:11 +0000, James Lee wrote:
> Hi,
> 
> I am working on a small project to integrate pulse into our current ALSA system 
> to mix, re-sample and route audio.  I have a video player on the client side 
> that takes multicast streams and plays them on "channels."  Each channel 
> consists of one movie and a streamer on the server side streams the movie over 
> and over again (so the player plays it over and over again).

Did I understand correctly: there's a server and a client, and the
server sends multiple video streams to the client? And the client
machine has the audio and video hardware?

> I have one issue that I just cannot figure out and decided to ask for help 
> here. I believe this is an issue that is pulse related because without pulse I 
> do not see this.  There is a gap between when the movie ends and when it starts  
> playing again.  It is about 2-3 second gap during which nothing is being 
> streamed on the channel.

Is this gap expected or is it a part of the problem?

> And every time this is encountered I see the 
> following and audio gets out-of-sync (delayed) when the movie starts up again:

How long is this audio delay? Is it the same 2-3 seconds that you
mentioned?

Are audio and video interleaved when they arrive to the client, or are
they in separate streams? Does the client application create a new
stream in Pulseaudio when the movie ends and starts again, or is there
only one stream ever created for each movie channel?

> 
> D: [alsa-sink] ratelimit.c: 329 events suppressed
> D: [alsa-sink] alsa-sink.c: Wakeup from ALSA!
> I: [alsa-sink] alsa-sink.c: Underrun!
> I: [alsa-sink] alsa-sink.c: Increasing minimal latency to 26.00 ms
> D: [alsa-sink] alsa-sink.c: Latency set to 26.00ms
> D: [alsa-sink] alsa-sink.c: hwbuf_unused=126488
> D: [alsa-sink] alsa-sink.c: setting avail_min=32416
> D: [alsa-sink] alsa-sink.c: Latency set to 26.00ms
> D: [alsa-sink] alsa-sink.c: hwbuf_unused=126488
> D: [alsa-sink] alsa-sink.c: setting avail_min=32416
> D: [alsa-sink] protocol-native.c: Underrun on 'ALSA Playback', 0 bytes in 
> queue.
> D: [alsa-sink] alsa-sink.c: Wakeup from ALSA!
> I: [alsa-sink] alsa-sink.c: Underrun!
> I: [alsa-sink] alsa-sink.c: Increasing wakeup watermark to 15.99 ms
> D: [alsa-sink] alsa-sink.c: Wakeup from ALSA!
> D: [alsa-sink] alsa-sink.c: Wakeup from ALSA!
> D: [alsa-sink] protocol-native.c: Requesting rewind due to end of underrun.
> D: [alsa-sink] alsa-sink.c: Requested to rewind 29204 bytes.
> D: [alsa-sink] alsa-sink.c: Limited to 4328 bytes.
> D: [alsa-sink] alsa-sink.c: before2: 1082
> D: [alsa-sink] alsa-sink.c: after: 1082
> D: [alsa-sink] alsa-sink.c: Rewound 4328 bytes.
> D: [alsa-sink] sink.c: Processing rewind...
> D: [alsa-sink] sink-input.c: Have to rewind 4328 bytes on render memblockq.
> D: [alsa-sink] sink-input.c: Have to rewind 4328 bytes on render memblockq.
> D: [alsa-sink] source.c: Processing rewind...
> 
> What is the expected behavior here?  Does pulse try to write silence when it 
> runs into a complete underrun (0 bytes in queue)?  Even then, why would there 
> be a delay in audio?  It almost looks like pulse is writing too much or at 
> least more than it should during this gap?

There are two kinds of underruns: alsa underruns and stream underruns.
This log snippet shows both happening. Alsa underruns should ideally
never happen, and realtime scheduling is used to try to make sure that
we can always fill the hardware buffers in time. It seems like you have
disabled realtime scheduling. That's not recommended. When an alsa
underrun happens, that will cause a delay.

Stream underruns happen when the client isn't writing data fast enough
to fulfill the requests from the hardware. Pulseaudio writes silence to
the hardware during these underruns, which will cause delay if the
underrun lasts for long enough. The stream underruns don't always
translate into gaps and delays, because if more data arrives quickly
enough after the underrun, the silence that was written to the hardware
buffer will be overwritten with the real data. "Requesting rewind due to
end of underrun" is printed when new data is received during a stream
underrun. "Rewind" means here rewriting as much as possible of the
silence in the hardware buffer.

Regardless of any delays due to the underruns, Pulseaudio will report
the current latency to the client, and that latency information should
be used to synchronize the video playback with audio. If things get
permanently out-of-sync, then either the video player isn't using this
information properly, or the alsa driver is acting funny, leading to
incorrect latency information.

-- 
Tanu