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.