Bug#674145: mplayer2: mplayer does not stop after playing a file

[Reinhard Tartler]

tag 674145 important
retitle 674145 mplayer does not stop after playing a file with
pulseaudio backend, breaks playback of multiple files
stop

On Sat, May 26, 2012 at 12:55 AM, Uoti Urpala <uoti.urpala at pp1.inet.fi> wrote:
> On Thu, 2012-05-24 at 13:47 +0200, Martin Ziegler wrote:
>> mplayer said that the output device was pulse:
>>
>> AO: [pulse]
>>
>> Wenn I use mplayer with the option "-ao alsa" everything
>> works fine. Thanks!
>
> This is most likely a Pulseaudio bug then.
>
>
>> It might be interesting that the version of mplayer in the
>> package "mplayer" does not hit this bug. It works also with
>> the option "-ao pulse".
>
> The old code in MPlayer 1 exits the main play loop after all audio has
> been buffered, regardless of the amount of audio not actually played yet
> (a "flush all buffered audio" operation is performed later). So it's
> expected that this Pulseaudio bug does not have the same effect. The
> problem with the old code is that the player can become unresponsive for
> relatively long periods during the flush operation, even with audio
> output drivers that function perfectly.
>
> It would be possible to add some workarounds on the player side for this
> bug. But I'm not sure whether that would be worth it, as there are so
> many bugs in Pulseaudio, and 2.0 broke more things again. Trying to work
> around just this bug feels somewhat pointless in this situation. The
> current situation where Pulseaudio has become the standard sound output
> method but seems to lack developers to fix even fairly blatant bugs in
> basic functionality is unfortunate.


Thanks for this investigation. As a followup to the conversation on
IRC this afternoon, I have noticed this commit in mplayer2.git:
http://git.mplayer2.org/mplayer2/commit/?id=de435ed56eafee040fe286151e51b94c144badc7

For full context, I'm quoting the excellent and very verbose commit
message in full here:

ao_pulse: work around PulseAudio timing bugsHEADmaster
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.

----cut----

Just to be sure, are there other commits that are related to this
particular bug? The explanation above (as well as the code changes)
read reasonable to me so that I'm inclined to work at an update for
testing.

BTW, I guess that
http://git.mplayer2.org/mplayer2/commit/libao2/ao_pulse.c?id=bb908027178fe8bfd7d6e3fc255dea8c5051cd4a
should get included into wheezy as well, but let's track that in
another bug report.

Thanks for your time,
Reinhard

-- 
regards,
    Reinhard