High latency with my JPEG VAAPI pipeline

[Nicolas Dufresne]

On mer, 2020-02-19 at 15:53 +0100, Wolfgang Grandegger wrote:
> Hello,
> 
> Am 18.02.20 um 23:23 schrieb Nicolas Dufresne:
> > 
> > Le mar. 18 févr. 2020 10 h 45, Wolfgang Grandegger <wg at grandegger.com
> > <mailto:wg at grandegger.com>> a écrit :
> > 
> >     Hello,
> > 
> >     still hunting latency! When I use "vaapisink sync=false" the latency
> >     drops from 130 ms to 60 ms. There seem to be a kind of backlog
> >     somewhere. Any idea how that could happen or be avoided. Is there a
> >     tracer showing buffer/queue usage?
> > 
> > 
> > I would investigated why the depaylaoder reports that 80ms. For this use
> > case, you should use the fast start on the JB too, it should remove the
> > 100ms start-up latency, and most likely drops at start.
> 
> "faststart-min-packets=0" is the default, but when I look to the
> following debug lines:

0 means it will wait for "latency" before emitting anything. Use 3 here for a
good and safe fast start. Mean if you have 3 packets following each other, it
starts.

> 
>   # egrep "rendering|setting last buffer" /tmp/gst5.log
>   0:00:00.030705838   407       0x419400 DEBUG              vaapisink
> gstvaapisink.c:1241:gst_vaapisink_display_changed: use texture rendering mode
>   0:00:00.086864483   407       0x4d1000 DEBUG               basesink
> gstbasesink.c:1014:gst_base_sink_set_last_buffer_unlocked:<vaapisink0> setting
> last buffer to 0x7fa0d4057240
>   0:00:00.171122862   407       0x4d1000 DEBUG               basesink
> gstbasesink.c:3641:gst_base_sink_chain_unlocked:<vaapisink0> rendering object
> 0x7fa0d4057240
> 
> I see, that the first frame is rendered with a delay of approx.
> 80..90 ms.
> 
>   0:00:00.204135691   407       0x4d1000 DEBUG               basesink
> gstbasesink.c:3641:gst_base_sink_chain_unlocked:<vaapisink0> rendering object
> 0x7fa0d40575a0
>   0:00:00.204142943   407       0x4d1000 DEBUG               basesink
> gstbasesink.c:1014:gst_base_sink_set_last_buffer_unlocked:<vaapisink0> setting
> last buffer to 0x7fa0d40575a0
>   0:00:00.237458751   407       0x4d1000 DEBUG               basesink
> gstbasesink.c:3641:gst_base_sink_chain_unlocked:<vaapisink0> rendering object
> 0x7fa0d4057240
> 
> I think the problem is that the calculated latency is simply too long.
> I see events like:

Yes.

> 
>   0:00:00.088237076   407 0x7fa0d000a8a0 DEBUG               basesink
> gstbasesink.c:4612:gst_base_sink_send_event:<vaapisink0> sending event
> 0x7fa0d0010520 latency event: 0x7fa0d0010520,
>                                                              time
> 99:99:99.999999999, seq-num 66, GstEventLatency, latency=(guint64)100000000;
> 
> How can I find out how much time each element is contributing to the latency?

GST_TRACERS=latency\(flags=reported\) GST_DEBUG=GST_TRACER:7 ./pipeline-app-...

> 
> And I can lower the latency using:
> 
>   gst_pipeline_set_latency (GST_PIPELINE (pipeline), latency:ms * 1000000);
> 
> Wolfgang
> _______________________________________________
> gstreamer-devel mailing list
> gstreamer-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/gstreamer-devel