[pulseaudio-discuss] How to control latency with CLI?

[Steven Wawryk]

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?


On 10/10/17 01:36, Tanu Kaskinen wrote:
> On Mon, 2017-10-09 at 19:52 +1030, Steven Wawryk wrote:
>> On 08/10/17 03:30, Tanu Kaskinen wrote:
>>> On Tue, 2017-09-26 at 19:27 +0930, Steven Wawryk wrote:
>>>> We've upgraded the I/O board (the platform with the module-loopback) to
>>>> use PulseAudio 11.1, but seem to be getting the same result.  Also tried
>>>> adding the latency parameters that are used by module-loopback,
>>>> module-alsa-sink, module-alsa-source and module-rtp-recv.  We've even
>>>> observed latencies of several minutes.
>>>>
>>>> Using pactl list sinks/sources/sink-inputs/source-outputs, the biggest
>>>> latencies listed are in the tens of thousands of usec, so there doesn't
>>>> seem to anything that accounts for it.  This is true on the workstation
>>>> too.  I can't work out where the big latency is added.
>>>>
>>>> There are some odd messages in the log (with -v).  I've attached the
>>>> compressed, filtered log ("grep pulse"):
>>>>
>>>> * module-loopback seems to be "dropping" a lot of audio
>>>> ("module-loopback.c: Dropping 920177108 usec of audio from queue") and
>>>> "adding" a lot of silence ("module-loopback.c: Adding 920174784 usec of
>>>> silence to queue") to the "queue".
>>> If module-loopback is adding 920 seconds of silence to its buffer, that
>>> seems like the likely reason for the extremely high latencies. The code
>>> that calculates this number seems to be getting garbage from some
>>> input. I suggest adding more logging to the module-loopback code to
>>> find the garbage source.
>> I've attached a compressed, filtered log with -vvvv supplied to
>> PulseAudio.  There's nothing that jumps out at me to help find the
>> source of the garbage.
> By "adding more logging to the module-loopback code" I meant editing
> the source code in src/modules/module-loopback.c. The interesting log
> message is this:
>
> pa_log_info("Adding %lu usec of silence to queue", pa_bytes_to_usec(buffer_correction, &u->sink_input->sample_spec));
>
> buffer_correction appears to be garbage, but it's not known why. You
> can add more log messages that show each step of the buffer_correction
> calculation. If you trace the calculations back far enough, you'll
> hopefully find the root cause of the abnormally large buffer_correction
> value.
>