On Wed, 2017-10-25 at 18:57 +1030, Steven Wawryk wrote:
> I've *finally* managed to get PulseAudio running on the test workstation
> with extra logging in pa_source_output_push()!
>
> I've attached a copy of pa_source_output_push() with the extra log
> statements to show where they are. Also, about 1second of gzipped
> output is attached (because otherwise there's a *lot* of output).
It seems that you're logging to syslog. In case you didn't know, you
can also run pulseaudio in a terminal and get the logs in the terminal,
or if running pulseaudio as a background process is important, it's
possible to set "log-target = newfile:/tmp/pulselog.txt" in
/etc/pulse/daemon.conf, or to pass --log-
target=newfile:/tmp/pulselog.txt on the command line. Of course, if you
prefer to use syslog for some reason, I have no problem with that.
> I don't fully understand what's going on, but here are a few things I
> noticed, which may be suspicious:
>
> * There seems to be a number of source-outputs logging output, but
> I assume the relevant one for module-remap-source is the one with the
> PA_RESAMPLER_NO_REMIX ("flags=0x04") flag set because of the "remix=no"
> parameter I gave it.
If you have pavucontrol running, it will create source outputs for both
the null sink monitor and the remap source to be able to get the data
for the volume meters.
I think it would be good to log the source name and some identifier for
the source output (either just the source output index, or some more
readable data from the source output proplist).
> * Whenever this source-output calls this function (outputting
> "rsmplr=30, flags=0x4" in the while loop), there seems to always be
> another immediately following call (outputting "limit=2304000bytes (1)"
> at the start of the function) with the *large* 2304000bytes limit that
> never executes the following "if" and "while" statement bodies. Hence
> it never calls o->push().
The limit is the source's max rewind amount, and I see a bug related to
that in module-remap-source (I wouldn't be surprised if it's in other
filter sources too). The remap source max rewind is supposed to mirror
the master source max rewind, but when the master source max rewind
changes, the remap source max rewind isn't updated. The remap source
should set the update_max_rewind source output callback, and use the
callback to update its own max rewind to match the master source.
If the max rewind isn't updated, as is now the case, it will stay at
whatever value the master source had when the remap source got loaded.
At that time there are likely no streams that are forcing lower
latency, leading to a too high max rewind value when a low latency
stream appears.
--
Tanu
https://www.patreon.com/tanuk
