High latency with my JPEG VAAPI pipeline

[Wolfgang Grandegger]

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:

  # 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:

  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?

And I can lower the latency using:

  gst_pipeline_set_latency (GST_PIPELINE (pipeline), latency:ms * 1000000);

Wolfgang