[pulseaudio-discuss] Best Case Latency

[Patrick Shirkey]

On Thu, October 3, 2013 5:14 pm, Tanu Kaskinen wrote:
> On Thu, 2013-10-03 at 02:33 +1000, Patrick Shirkey wrote:
>> On Thu, October 3, 2013 12:14 am, Tanu Kaskinen wrote:
>> > On Tue, 2013-10-01 at 00:38 +1000, Patrick Shirkey wrote:
>> >> On Sat, September 28, 2013 3:12 am, Patrick Shirkey wrote:
>> >> >
>> >> >> On Sat, September 28, 2013 12:53 am, Tanu Kaskinen wrote:
>> >> >> I don't remember if the alsa compatibility layer forwards the
>> >> >> stream under/overrun notifications to the alsa application - IIRC
>> >> there
>> >> >> were problems when those were reported and there were different
>> >> >> problems
>> >> >> when those were not reported, and I don't remember what the
>> current
>> >> >> code
>> >> >> does.
>> >> >>
>> >>
>> >> This seems like it would be a good place to verify.
>> >
>> > Looking at the pulse alsa plugin source, it seems that stream overflow
>> > events (the recording direction) are not reported. Underflows (the
>> > playback direction) are reported by default (configurable in
>> asoundrc).
>> > Overflows are pretty unlikely, since the maximum stream buffer length
>> > appears to be configured to 4 MB.
>> >
>>
>> I see the following sprinkled in /var/log/messages
>>
>> Sep 30 12:19:02 xxx pulseaudio[28845]: [pulseaudio] ratelimit.c: 1997
>> events suppressed
>> Sep 30 12:19:02 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>>
>> <snip>
>>
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [jack-source] ratelimit.c: 41
>> events suppressed
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Sep 30 21:40:04 xxx pulseaudio[28845]: [jack-source] asyncq.c: q
>> overrun,
>> queuing locally
>>
>> <snip>
>>
>> Oct  1 09:53:30 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] ratelimit.c: 2291
>> events suppressed
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:20 xxx pulseaudio[28845]: [pulseaudio] asyncq.c: q overrun,
>> queuing locally
>> Oct  1 10:01:42 xxx pulseaudio[28845]: [pulseaudio] ratelimit.c: 2321
>> events suppressed
>
> 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?




--
Patrick Shirkey
Boost Hardware Ltd