Latency Tracer

In this tutorial you will learn how to use latency_tracer to find element and pipeline frame latency. The time displayed in the logs has precision in the order of milliseconds. - element latency: Time that a buffer takes to travel from source pad of the previous element to source pad of the current element. - pipeline latency: Time that a buffer takes to travel from source pad of the source element to source pad of the element before sink element. This also provides latency and fps of full pipeline.

Pipeline

GST_DEBUG="GST_TRACER:7" GST_TRACERS="latency_tracer" gst-launch-1.0 videotestsrc num-buffers=500 ! videoconvert  ! avenc_h263p ! fakesink

Sample Output

0:00:03.014774818 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element_interval, name=(string)avenc_h263p0, interval=(double)1000.015783, avg=(double)0.259879, min=(double)0.206307, max=(double)0.587317;
0:00:03.014782371 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_pipeline, frame_latency=(double)0.240226, avg=(double)0.255766, min=(double)0.205778, max=(double)0.588363, latency=(double)0.340871, fps=(double)2933.657880, frame_num=(uint)8801;
0:00:03.014861287 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element, name=(string)videoconvert0, frame_latency=(double)0.000578, avg=(double)0.000571, min=(double)0.000423, max=(double)0.009837, frame_num=(uint)8802, is_bin=(boolean)0;
0:00:03.014865552 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element_interval, name=(string)videoconvert0, interval=(double)1000.019802, avg=(double)0.000578, min=(double)0.000423, max=(double)0.006638;
0:00:03.015110029 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element, name=(string)avenc_h263p0, frame_latency=(double)0.248802, avg=(double)0.255194, min=(double)0.205306, max=(double)0.587317, frame_num=(uint)8802, is_bin=(boolean)0;
0:00:03.015115274 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_pipeline, frame_latency=(double)0.249380, avg=(double)0.255765, min=(double)0.205778, max=(double)0.588363, latency=(double)0.340871, fps=(double)2933.658362, frame_num=(uint)8802;
0:00:03.015119796 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_pipeline_interval, interval=(double)1000.020829, avg=(double)0.260457, min=(double)0.206755, max=(double)0.588363, latency=(double)0.347350, fps=(double)2878.940035;

By default latency_tracer calculates latency for both pipeline and elements, you have option to select only pipeline or elements latency using flags.

Settings Flags

Pipeline latency flag

GST_DEBUG="GST_TRACER:7" GST_TRACERS="latency_tracer(flags=pipeline)" gst-launch-1.0 videotestsrc num-buffers=500 ! videoconvert  ! avenc_h263p ! fakesink

Sample Output

0:00:03.015115274 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_pipeline, frame_latency=(double)0.249380, avg=(double)0.255765, min=(double)0.205778, max=(double)0.588363, latency=(double)0.340871, fps=(double)2933.658362, frame_num=(uint)8802;
0:00:03.015119796 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_pipeline_interval, interval=(double)1000.020829, avg=(double)0.260457, min=(double)0.206755, max=(double)0.588363, latency=(double)0.347350, fps=(double)2878.940035;

Element latency flag

GST_DEBUG="GST_TRACER:7" GST_TRACERS="latency_tracer(flags=element)" gst-launch-1.0 videotestsrc num-buffers=500 ! videoconvert  ! avenc_h263p ! fakesink

Sample Output

0:00:03.014774818 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element_interval, name=(string)avenc_h263p0, interval=(double)1000.015783, avg=(double)0.259879, min=(double)0.206307, max=(double)0.587317;
0:00:03.014861287 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element, name=(string)videoconvert0, frame_latency=(double)0.000578, avg=(double)0.000571, min=(double)0.000423, max=(double)0.009837, frame_num=(uint)8802, is_bin=(boolean)0;
0:00:03.014865552 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element_interval, name=(string)videoconvert0, interval=(double)1000.019802, avg=(double)0.000578, min=(double)0.000423, max=(double)0.006638;
0:00:03.015110029 79459 0x55736c57a060 TRACE             GST_TRACER :0:: latency_tracer_element, name=(string)avenc_h263p0, frame_latency=(double)0.248802, avg=(double)0.255194, min=(double)0.205306, max=(double)0.587317, frame_num=(uint)8802, is_bin=(boolean)0;

Settings interval

Interval value can be set, the value must be set in milliseconds, default=1000

Setting interval example

GST_DEBUG="GST_TRACER:7" GST_TRACERS="latency_tracer(flags=pipeline,interval=100)" gst-launch-1.0 videotestsrc num-buffers=500 ! videoconvert  ! avenc_h263p ! fakesink

Sample Output

0:00:00.116094526 79468 0x556002934460 TRACE             GST_TRACER :0:: latency_tracer_pipeline_interval, interval=(double)100.219905, avg=(double)0.256772, min=(double)0.236046, max=(double)0.386057, latency=(double)0.345586, fps=(double)2893.636748;
0:00:00.116443843 79468 0x556002934460 TRACE             GST_TRACER :0:: latency_tracer_pipeline, frame_latency=(double)0.248532, avg=(double)0.256743, min=(double)0.236046, max=(double)0.386057, latency=(double)0.345622, fps=(double)2893.338508, frame_num=(uint)291;