Investigating GStreamer pipeline latency

Share

Just wanted to very briefly post a method I’ve used to investigate latency in complex GStreamer pipelines. This method is useful for showing how long each element is taking to process a frame.

GST_DEBUG=GST_SCHEDULING:6 ./application

This prints a lot of useful data, but far too much to read and interpret. Cut it down, by only displaying one message each time a buffer enters an element. Pipe stderr to the following grep:

grep "calling chainfunction"

If you only want to look at certain elements, this grep can be useful:

egrep "\<(element1name|element2name):sink\>"

Pipe the output to a file. Completed example:

GST_DEBUG=GST_SCHEDULING:6 ./application 2>&1 | grep "calling chainfunction" | egrep "\<(element1name|element2name):sink\>" > log.txt

Now, to time an individual frame flowing through the pipeline, open the log and pick one. Make a note of its pts. Grep for it and process the output for readability. eg:

grep 0:00:06.573958668 log.txt |sed "s/ .*</ /"|sed "s/:sink.*$//"

Example output:

0:00:02.593278667 element1:sink
0:00:02.593474334 element2:sink
0:00:02.595585334 element3:sink
0:00:02.595757667 element4:sink
0:00:02.603250000 element5:sink
0:00:02.603501334 element6:sink
0:00:02.603622334 element7:sink

The times are the time the frame entered that element. You may like to use a spreadsheet to calculate the time spent in each element.

Share

Leave a Reply