1 #! /usr/bin/python
2 # GStreamer scheduling parser
3 # Analyze GST traces and shows the time spent for each buffer at each element level.
4 #
5 # Usage: GST_DEBUG=*:2,GST_SCHEDULING:5,GST_PERFORMANCE:5 gst-launch --gst-debug-no-color -e [PIPELINE] >foo 2>&1
6 # ./parse-gst-traces.py foo
7 # Example of pipeline: videotestsrc num-buffers=200 ! "video/x-raw-yuv, format=(fourcc)NV12, width=1280, height=720, framerate=30/1" ! ducatih264enc profile=66 ! ducatih264dec! dri2videosink sync=false
9 import sys
10 import time
11 import fileinput
12 import re
13 import operator
14 from datetime import datetime
16 def string_to_time (d):
17 return datetime.strptime(d[0:14], "%H:%M:%S.%f")
19 def main():
20 tr = dict()
21 cam = dict()
22 dec = dict()
23 ecs = 0
25 ### Parse stdin or any file on the command line
26 for line in fileinput.input():
28 # Filter out GST traces from other output
29 m = re.match(r"([\w:.]+)[\s]+([\w]+)[\s]+([\w]+)[\s]+([\w]+)[\s]+(.*)",line)
30 if m == None:
31 print line
32 continue
33 (tsr,pid,adr,sev,msg) = m.groups()
35 # Parse GST_SCHEDULING traces
36 m = re.match(r"GST_SCHEDULING[\s]+gstpad.c:[\w]+:([\w_]+):<([A-Za-z0-9_]+)([0-9]+):([\w_]+)> calling chainfunction &[\w]+ with buffer ([\w]+), data ([\w]+), malloc ([\w()]+), ts ([\w:.]+), dur ([\w:.]+)", msg)
37 if m != None:
38 (func, elem, number, pad, gstBuffer, data, malloc, tsb, dur) = m.groups()
39 if func != "gst_pad_push":
40 continue
41 if elem == "cam" and pad == "src" and gstBuffer in cam:
42 tr[tsb] = [(cam[gstBuffer], "FillBufferDone")]
43 elif elem == "ducatih264dec" and pad == "src":
44 dec[gstBuffer] = tsb
45 elif elem == "udpsrc" or elem == "recv_rtp_sink_" or elem == "rtpsession" or elem =="rtpssrcdemux":
46 continue
47 if tsb not in tr:
48 tr[tsb] = []
49 tr[tsb].append((tsr, "%s:<%s%s:%s>" % (func, elem, number, pad) ))
50 continue
52 # Parse omx_camera traces
53 m = re.match(r"GST_PERFORMANCE gstomx_core.c:[\w]+:FillBufferDone:<cam> FillBufferDone: GstBuffer=([\w]+)", msg)
54 if m != None:
55 gstBuffer = m.group(1)
56 cam[gstBuffer] = tsr
57 continue
59 # Parse encoder traces
60 m = re.match(r"GST_PERFORMANCE gstducatividenc.c:[\w]+:gst_ducati_videnc_handle_frame:<ducatih264enc[\w]+> Encoded frame in ([\w]+) bytes", msg)
61 if m != None:
62 ecs += int(m.group(1))
63 continue
65 # Parse dri2videosink traces
66 m = re.match(r"GST_PERFORMANCE gstdri2util.c:[\w]+:gst_dri2window_buffer_show:<dri2videosink[\w]+> (Before DRI2SwapBuffersVid|After DRI2WaitSBC), buf=([\w]+)", msg)
67 if m != None:
68 (ba, dri2_buf) = m.groups()
69 if dri2_buf in dec:
70 tr[dec[dri2_buf]].append((tsr, ba))
71 continue
73 ### End of stdin parsing
75 # Display the results, frame per frame
76 avg = cnt = 0
77 for tsb, tfs in tr.iteritems():
78 cnt +=1
79 first = prev = string_to_time(tfs[0][0])
80 print "\n*** Frame no: %d, timestamp: %s" % (cnt, tsb)
81 for el in tfs:
82 cur = string_to_time(el[0])
83 if cur != prev:
84 later = "(%6d us later)" % (cur - prev).microseconds
85 else:
86 later = "( first event)"
87 print "At %s %s Func: %s" % (el[0][5:14], later, el[1])
88 prev = cur
89 total = cur - first
90 avg += total.microseconds
91 print "*** Total: %6d us" % (total.microseconds)
93 # Display the totals
94 if (cnt != 0):
95 if (ecs != 0):
96 ecs = "%s KB" % (ecs / 1024)
97 else:
98 ecs = "N/A (lack of encoder traces)"
99 print "\n=-= Encoded stream size: %s" % (ecs)
100 print "\n=-= Average: %6d us on %d frames" % (avg / cnt, cnt)
101 else:
102 print "\n=-= No frame, the pipeline have failed"
104 return 0
105 if __name__ == '__main__':
106 main()