ao_pulse: work around PulseAudio timing bugs

Work around PulseAudio bugs more effectively. In particular, this
should avoid two issues: playback never finishing at end of file /
segment due to PulseAudio always claiming there's still time before
audio playback reaches the end, and jerky playback especially after
seeking due to bogus output from PulseAudio's timing interpolation
code.

This time, I looked into the PulseAudio code itself and analyzed the
bugs causing problems. Fortunately, two of the serious ones can be
worked around in client code. Write a new get_delay() implementation
doing that, and remove some of the previous workarounds which are now
unnecessary. Also add a pa_stream_trigger() call to ensure playback of
files shorter than prebuf value starts (btw doing that by setting a
low prebuf hits yet another PulseAudio bug, even if you then write the
whole file in one call).

There are still a couple of known PulseAudio bugs that can not be
worked around in client code. Especially, bug 4 below can cause issues
when pausing.

Below is a copy of a message I sent to the pulseaudio-discuss mailing
list, describing some of the PulseAudio bugs:

==================================================

A lot of mplayer2 users with PulseAudio have experienced problems. I
investigated some of those and confirmed that they are caused by
PulseAudio. There are quite a few distinct PulseAudio bugs; some are
analyzed below. Overall, however, I wonder why there are so many fairly
obvious bugs in a widely used piece of software. Is there no
maintenance? Or do people not test it? Some of the bugs are probably
less obvious if you request low latency (though they're not specific to
higher-latency case); do people test the low-latency case only?

1. The timing interpolation functionality can return completely bogus
values for playback position and latency, especially after seeking
(mplayer2 does cork / flush / uncork, as flushing alone does not seem to
remove data already in sink). I've seen quickly repeated seeks report
over 10 second latency, when there aren't any buffers anywhere that big.
I have not investigated the exact cause. Instead I disabled
interpolation and added code to always call
pa_stream_update_timing_info(). (I assume that always waiting for this
to complete, instead of doing custom interpolation, may give bad
performance if it queries a remote server. But at least it works better
locally.)

2. Position/latency reporting is wrong at the end of a stream (after the
lack of more data triggers underflow status). As a result mplayer2 never
ends the playback of a file, as it's waiting forever for audio to finish
playing. The reason for this is that the calculations in PulseAudio add
the whole length of data in the sink to the current latency (subtract
from position), even if the sink does not contain that much data *from
this stream* in underflow conditions. I was able to work around this bug
by calculating latency from pa_timing_info data myself as follows
(ti=pa_timing_info):

    int64_t latency = pa_bytes_to_usec(ti->write_index - ti->read_index, ss);
    latency -= ti->transport_usec;
    int64_t sink_latency = ti->sink_usec;
    if (!ti->playing)
        // this part is missing from PulseAudio itself
        sink_latency -= pa_bytes_to_usec(ti->since_underrun, ss);
    if (sink_latency > 0)
        latency += sink_latency;
    if (latency < 0)
        latency = 0;

However, this still doesn't always work due to the next bug.

3. The since_underrun field in pa_timing_info is wrong if PulseAudio is
resampling the stream. As a result, the above code indicated that the
playback of a 0.1 second 8-bit mono file would take about 0.5 seconds.
This bug is in pa_sink_input_peek(). The problematic parts are:

ilength = pa_resampler_request(i->thread_info.resampler, slength);
...
if (ilength > block_size_max_sink_input)
    ilength = block_size_max_sink_input;
...
pa_memblockq_seek(i->thread_info.render_memblockq, (int64_t) slength, PA_SEEK_RELATIVE, TRUE);
...
i->thread_info.underrun_for += ilength;

This is measuring audio in two different units, bytes for
resampled-to-sink (slength) and original stream (ilength). However, the
block_size_max_sink_input test only adjusts ilength; after that the
values may be out of sync. Thus underrun_for is incremented by less than
it should be to match the slength value used in pa_memblockq_seek.

4. Stream rewind functionality breaks if the sink is suspended (while
the stream is corked). Thus, if you pause for more than 5 seconds
without other audio playing, things are broken after that. The most
obvious symptom is that playback can continue for a significant time
after corking. This is caused by sink_input and sink getting out of
sync. First, after uncorking a stream on a suspended sink,
pa_sink_input_request_rewind() is called while the sink is still in
suspended state. This sets sink_input->thread_info.rewrite_nbytes to -1
and calls pa_sink_request_rewind(). However, the sink ignores rewind
requests while suspended. Thus this particular rewind does nothing. The
problem is that rewrite_nbytes is left at -1. Further calls to
pa_sink_input_request_rewind() do nothing because "nbytes =
PA_MAX(i->thread_info.rewrite_nbytes, nbytes);" sets nbytes to -1, and
the call to pa_sink_request_rewind() is under "if (nbytes != (size_t)
-1) {". Usually, after a sink responds to a rewind request,
rewrite_bytes is reset in pa_sink_input_process_rewind(), but this
doesn't happen if the sink ever ignores one request. This broken state
can be resolved if pa_sink_input_process_rewind() is called due to a
rewind triggered by _another_ stream.

There were more bugs, but I'll leave those for later.

1 files changed, 55 insertions, 29 deletions

diff --git a/libao2/ao_pulse.c b/libao2/ao_pulse.c
index e48c402fa6..b266d66bac 100644
--- a/libao2/ao_pulse.c
+++ b/libao2/ao_pulse.c
@@ -50,7 +50,6 @@ struct priv {
 
     bool broken_pause;
     int retval;
-    bool did_reset;
 };
 
 #define GENERIC_ERR_MSG(ctx, str) \
@@ -275,9 +274,7 @@ static int init(struct ao *ao, char *params)
         .fragsize = -1,
     };
     if (pa_stream_connect_playback(priv->stream, sink, &bufattr,
-                                   PA_STREAM_INTERPOLATE_TIMING
-                                   | PA_STREAM_AUTO_TIMING_UPDATE, NULL,
-                                   NULL) < 0)
+                                   PA_STREAM_NOT_MONOTONIC, NULL, NULL) < 0)
         goto unlock_and_fail;
 
     /* Wait until the stream is ready */
@@ -318,25 +315,18 @@ static void cork(struct ao *ao, bool pause)
 static int play(struct ao *ao, void *data, int len, int flags)
 {
     struct priv *priv = ao->priv;
-    /* For some reason Pulseaudio behaves worse if this is done after
-     * the write - rapidly repeated seeks result in bogus increasing
-     * reported latency. */
-    if (priv->did_reset)
-        cork(ao, false);
     pa_threaded_mainloop_lock(priv->mainloop);
     if (pa_stream_write(priv->stream, data, len, NULL, 0,
                         PA_SEEK_RELATIVE) < 0) {
         GENERIC_ERR_MSG(priv->context, "pa_stream_write() failed");
         len = -1;
     }
-    if (priv->did_reset) {
-        priv->did_reset = false;
-        if (!waitop(priv, pa_stream_update_timing_info(priv->stream,
-                                                       success_cb, ao))
-            || !priv->retval)
-            GENERIC_ERR_MSG(priv->context, "pa_stream_UPP() failed");
-    } else
-        pa_threaded_mainloop_unlock(priv->mainloop);
+    if (flags & AOPLAY_FINAL_CHUNK) {
+        // Force start in case the stream was too short for prebuf
+        pa_operation *op = pa_stream_trigger(priv->stream, NULL, NULL);
+        pa_operation_unref(op);
+    }
+    pa_threaded_mainloop_unlock(priv->mainloop);
     return len;
 }
 
@@ -351,7 +341,7 @@ static void reset(struct ao *ao)
     if (!waitop(priv, pa_stream_flush(priv->stream, success_cb, ao)) ||
         !priv->retval)
         GENERIC_ERR_MSG(priv->context, "pa_stream_flush() failed");
-    priv->did_reset = true;
+    cork(ao, false);
 }
 
 // Pause the audio stream by corking it on the server
@@ -364,8 +354,6 @@ static void pause(struct ao *ao)
 static void resume(struct ao *ao)
 {
     struct priv *priv = ao->priv;
-    if (priv->did_reset)
-        return;
     /* Without this, certain versions will cause an infinite hang because
      * pa_stream_writable_size returns 0 always.
      * Note that this workaround causes A-V desync after pause. */
@@ -387,19 +375,57 @@ static int get_space(struct ao *ao)
 // Return the current latency in seconds
 static float get_delay(struct ao *ao)
 {
+    /* This code basically does what pa_stream_get_latency() _should_
+     * do, but doesn't due to multiple known bugs in PulseAudio (at
+     * PulseAudio version 2.1). In particular, the timing interpolation
+     * mode (PA_STREAM_INTERPOLATE_TIMING) can return completely bogus
+     * values, and the non-interpolating code has a bug causing too
+     * large results at end of stream (so a stream never seems to finish).
+     * This code can still return wrong values in some cases due to known
+     * PulseAudio bugs that can not be worked around on the client side.
+     *
+     * We always query the server for latest timing info. This may take
+     * too long to work well with remote audio servers, but at least
+     * this should be enough to fix the normal local playback case.
+     */
     struct priv *priv = ao->priv;
-    pa_usec_t latency = (pa_usec_t) -1;
     pa_threaded_mainloop_lock(priv->mainloop);
-    while (pa_stream_get_latency(priv->stream, &latency, NULL) < 0) {
-        if (pa_context_errno(priv->context) != PA_ERR_NODATA) {
-            GENERIC_ERR_MSG(priv->context, "pa_stream_get_latency() failed");
-            break;
-        }
-        /* Wait until latency data is available again */
-        pa_threaded_mainloop_wait(priv->mainloop);
+    if (!waitop(priv, pa_stream_update_timing_info(priv->stream, NULL, NULL))) {
+        GENERIC_ERR_MSG(priv->context, "pa_stream_update_timing_info() failed");
+        return 0;
+    }
+    pa_threaded_mainloop_lock(priv->mainloop);
+    const pa_timing_info *ti = pa_stream_get_timing_info(priv->stream);
+    if (!ti) {
+        pa_threaded_mainloop_unlock(priv->mainloop);
+        GENERIC_ERR_MSG(priv->context, "pa_stream_get_timing_info() failed");
+        return 0;
+    }
+    const struct pa_sample_spec *ss = pa_stream_get_sample_spec(priv->stream);
+    if (!ss) {
+        pa_threaded_mainloop_unlock(priv->mainloop);
+        GENERIC_ERR_MSG(priv->context, "pa_stream_get_sample_spec() failed");
+        return 0;
     }
+    // data left in PulseAudio's main buffers (not written to sink yet)
+    int64_t latency = pa_bytes_to_usec(ti->write_index - ti->read_index, ss);
+    // since this info may be from a while ago, playback has progressed since
+    latency -= ti->transport_usec;
+    // data already moved from buffers to sink, but not played yet
+    int64_t sink_latency = ti->sink_usec;
+    if (!ti->playing)
+        /* At the end of a stream, part of the data "left" in the sink may
+         * be padding silence after the end; that should be subtracted to
+         * get the amount of real audio from our stream. This adjustment
+         * is missing from Pulseaudio's own get_latency calculations
+         * (as of PulseAudio 2.1). */
+        sink_latency -= pa_bytes_to_usec(ti->since_underrun, ss);
+    if (sink_latency > 0)
+        latency += sink_latency;
+    if (latency < 0)
+        latency = 0;
     pa_threaded_mainloop_unlock(priv->mainloop);
-    return latency == (pa_usec_t) -1 ? 0 : latency / 1000000.0;
+    return latency / 1e6;
 }
 
 /* A callback function that is called when the