> Message: 3 Date: Sat, 14 Oct 2017 01:43:42 +0300 From: Tanu Kaskinen
> <tanuk at iki.fi> To: General PulseAudio Discussion
> <pulseaudio-discuss at lists.freedesktop.org> Subject: Re:
> [pulseaudio-discuss] How to control latency with CLI? Message-ID:
> <1507934622.7449.10.camel at iki.fi> Content-Type: text/plain;
> charset="UTF-8" On Fri, 2017-10-13 at 19:09 +1030, Steven Wawryk wrote:
>> Today I noticed that there seems to be about 5minutes delay in
>> module-remap-source on the workstation rather than in module-loopback on
>> the embedded system.
>>
>> With the following CLI script items (selecting 1 of the 12 channels of
>> digitised audio from the embedded system):
>>
>> ...
>>
>> load-module module-null-sink sink_name=rtp_in_sink1
>> sink_properties=device.description=RTP_in1 format=ulaw rate=8000
>> channels=12
>> channel_map=aux0,aux1,aux2,aux3,aux4,aux5,aux6,aux7,aux8,aux9,aux10,aux11
>> ...
>>
>> load-module module-rtp-recv sink=rtp_in_sink1
>> sap_address=224.0.0.81 latency_msec=10
>> ...
>>
>> load-module module-remap-source source_name=voip_source
>> master=rtp_in_sink1.monitor
>> source_properties=device.description=VoIPSource format=ulaw rate=8000
>> channels=1 master_channel_map=aux4 channel_map=front-left remix=no
>>
>> ...
>>
>> ... and observing with pavucontrol, when I tapped or spoke into the
>> microphone, there was signal with no noticeable delay at rtp_in_sink1
>> and rtp_in_sink1.monitor, but the signal could not be seen on
>> voip_source until about 5minutes later. I can't see any obvious reason
>> in the module-remap-source source code.
>>
>> I will investigate further on Monday (including logs), but have I messed
>> up the above CLI statements?
> I don't see anything wrong with the CLI commands.
>
> The latency in module-remap-source is weird. The module itself doesn't
> do any buffering. module-remap-source connects to the master source
> using a pa_source_output, and pa_source_output contains
> delay_memblockq, which is a buffer. Maybe the delay_memblockq is
> involved in the huge latency? The purpose (or at least one purpose) of
> delay_memblockq is to keep enough data buffered in monitor sources to
> deal with the possibility of data getting changed in the unplayed
> portion of the sink playback buffer. The sink in your case (or in any
> other case) doesn't have a playback buffer of 5 minutes, so if the
> delay_memblockq holds 5 minutes worth of data, there's some bug. Maybe
> adding some extra logging to pa_source_output_push() will shed some
> light on the matter.
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).
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.
   * 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().
   * At some point in the "Oct 25 05:31:07" second, the above
behaviour switches from 1 to 2 immediately following calls with
"limit=2304000bytes (1)" logged.
That's as far as I got today. In the absence of any feedback or
guidance on this email, I'll investigate further tomorrow and hope I'm
not too far off track.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: logging.c
Type: text/x-csrc
Size: 4904 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/pulseaudio-discuss/attachments/20171025/04721ce3/attachment-0001.c>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: palog.gz
Type: application/gzip
Size: 42791 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/pulseaudio-discuss/attachments/20171025/04721ce3/attachment-0001.gz>
