[pulseaudio-discuss] Best Case Latency

[Patrick Shirkey]

On Mon, October 7, 2013 7:41 pm, Tanu Kaskinen wrote:
>
> On Fri, 2013-10-04 at 21:49 +1000, Patrick Shirkey wrote:
>> On Thu, October 3, 2013 11:41 pm, Thomas Martitz wrote:
>> > Am 03.10.2013 10:20, schrieb Patrick Shirkey:
>> >> On Thu, October 3, 2013 5:14 pm, Tanu Kaskinen wrote:
>> >>>
>> >>> That doesn't look healthy. The message is printed when
>> >>> pa_asyncmsgq_post() is called and the message queue is full. The
>> >>> message
>> >>> queue can store 256 messages before this starts to happen, so some
>> >>> queue
>> >>> consumer is having serious trouble keeping up with the producer. It
>> >>> would be nice to know which pa_asyncmsgq_post() call this is (you
>> could
>> >>> set a breakpoint on the line that prints "q overrun", and then get a
>> >>> backtrace).
>> >>>
>> >> Sorry, if this is dense but how do I set a breakpoint on this line in
>> PA
>> >> while it is running?
>> >
>> > $ gdb --pid=$(pidof pulseaudio)
>> >
>> > If you're on debian you need to install debug symbols ($ sudo apt-get
>> > install pulseaudio-dbg). For other distros I can't help. Compiling
>> from
>> > source in debug mode of course also works.
>> >
>>
>> Thanks. FYI, installing "pulseaudio-dbg" hosed my NVIDIA video driver
>> which was a bit confusing.
>>
>> Looking at /var/log/messages I spotted this when starting PA:
>>
>> ----
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] sink.c: Default and
>> alternate sample rates are the same.
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] module-jack-sink.c:
>> JACK error >Cannot use real-time scheduling (RR/5)(1: Operation not
>> permitted)<
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] module-jack-sink.c:
>> JACK error >JackClient::AcquireSelfRealTime error<
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] source.c: Default and
>> alternate sample rates are the same.
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] module-jack-source.c:
>> JACK error >Cannot use real-time scheduling (RR/5)(1: Operation not
>> permitted)<
>> Oct  4 17:30:49 xxx pulseaudio[6571]: [pulseaudio] module-jack-source.c:
>> JACK error >JackClient::AcquireSelfRealTime error<
>> ----
>>
>> - Not sure why it is being printed twice.
>
> Once for the sink and once for the source.
>
>> I have enabled realtime in
>> /etc/pulse/daemon.conf and jack is running in realtime mode so not sure
>> why PA is unhappy. It could be a bug that is already fixed though.
>
> It's not really PA that is unhappy. The "JACK error >foo<" messages come
> from libjack. If you are able to run jackd with RT scheduling, under the
> same user that you're running pulseaudio, I don't know what could be the
> problem. Pulseaudio limits the realtime priority that it can use
> (configured with the rlimit-rtprio option in daemon.conf), but if I
> understand the log message correctly, libjack tries to use priority 5,
> which shouldn't be a problem, because the default priority that
> pulseaudio limits itself is 9.
>
>> - I'm running pulseaudio 4.0 in debian  pulseaudio-dbg:amd64/unstable
>> 4.0-6+b1
>>
>> - Here's the backtrace based on the line number that Tanu provided. Not
>> sure if I nailed it though.
>>
>> (gdb) break asyncq.c:211
>> Breakpoint 1 at 0x7f4d4572ff90: file pulsecore/asyncq.c, line 211.
>> (gdb) continue
>> Continuing.
>> [Switching to Thread 0x7f4d39b2b700 (LWP 6686)]
>>
>> Breakpoint 1, 0x00007f4d4572ff90 in pa_asyncq_post () from
>> /usr/lib/libpulsecore-4.0.so
>> (gdb) bt
>> #0  0x00007f4d4572ff90 in pa_asyncq_post () from
>> /usr/lib/libpulsecore-4.0.so
>> #1  0x00007f4d4572ee7b in pa_asyncmsgq_post () at
>> pulsecore/asyncmsgq.c:137
>> #2  0x00007f4d3bf374f3 in source_output_push_cb () at
>> pulsecore/protocol-native.c:1832
>> #3  0x00007f4d4576d3b3 in pa_source_output_push () at
>> pulsecore/source-output.c:822
>> #4  0x00007f4d45773e5b in pa_source_post () at pulsecore/source.c:935
>> #5  0x00007f4d39baf820 in source_process_msg () at
>> modules/jack/module-jack-source.c:115
>> #6  0x00007f4d4574d084 in asyncmsgq_read_work () from
>> /usr/lib/libpulsecore-4.0.so
>> #7  0x00007f4d4574c607 in pa_rtpoll_run () from
>> /usr/lib/libpulsecore-4.0.so
>> #8  0x00007f4d39baf953 in thread_func () at
>> modules/jack/module-jack-source.c:201
>> #9  0x00007f4d454f5d08 in ?? () from
>> /usr/lib/x86_64-linux-gnu/pulseaudio/libpulsecommon-4.0.so
>> #10 0x00007f4d449fae0e in start_thread () from
>> /lib/x86_64-linux-gnu/libpthread.so.0
>> #11 0x00007f4d4402593d in clone () from /lib/x86_64-linux-gnu/libc.so.6
>
> Ok, so this happens when the native protocol tries to send a block of
> audio from the jack source thread to the main thread. My guess is that
> the main thread is not getting enough CPU time to deal with all the
> incoming audio (it's not RT scheduled).
>
> This could very well cause growing latency. If the jack source pushes
> audio blocks to the message queue faster than the main thread reads
> those blocks, then that message queue becomes a significant (and
> constantly growing?) audio buffer.
>
> What to do? I don't know. Currently there's no upper limit for how long
> the message queue can grow (so this is effectively also a memory leak
> problem), and no way to query the queue length. Even if there was a
> maximum length for the queue, what should be done if that maximum length
> is exceeded? Perhaps the native protocol should kill the stream that is
> not able to keep up with the source.
>

There are two options that JACK allows for

1) Kick the offender from the graph
2) Allow dropouts in the stream (softmode)

I suppose in this case PA is trying to stop dropouts from happening which
is a noble cause because most of the audio flowing through PA is probably
fine with a variable buffer.

>From the user perspective combining JACK and PA together to provide low
latency high performance audio I'm not sure if anything should be done to
change the existing system. However from the developer perspective this
leans in favour of adding Bluez support to JACK directly so that systems
that explicitly require low latency with hard time limits can keep the
bluetooth stream running while JACK is also running. I'm not sure how that
affects managing policy with Murphy.

There are a couple of things that have been identified in this test process.

- PA Stream Buffer adds approx 10ms latency to the stream at 64/48000/2
- PA main loop handles the audio stream in a way that allows the buffer to
grow causing variable latency on systems that cannot keep up.
- I should try to find out why realtime is not working for PA+JACK on my
test system.

It seems there are a some of issues to figure out in terms of supporting
the combination of JACK + PA.

Given that the PA Stream buffer adds 10ms latency and there are cases
where 20ms is the max time available to the entire audio graph is it
viable that we should try to make PA + JACK more efficient?

For example enabling apps to bypass the Stream Buffer while JACK is running.

Is it a productive use of resources or is it better to recommend to
developers to add direct support to their audio system for routing audio
through JACK when JACK is running? That also means adding logic to JACK to
deal with Bluez and Murphy which seems like a double up of effort when it
is already being handled in PA.

If we go with the combination can PA manage the Bluetooth stream and
Murphy requests while JACK is running?

I'm not advocating one way or another although I lean in favour of
combining PA+JACK rather than extending JACK.



--
Patrick Shirkey
Boost Hardware Ltd