Added a tool to process GST traces and provide latencies for each element
authorOlivier Naudan <o-naudan@ti.com>
Mon, 29 Oct 2012 17:58:48 +0000 (13:58 -0400)
committerVincent Penquerc'h <vincent.penquerch@collabora.co.uk>
Fri, 16 Nov 2012 14:46:18 +0000 (14:46 +0000)
tools/pp-gst-sched.py [new file with mode: 0755]

diff --git a/tools/pp-gst-sched.py b/tools/pp-gst-sched.py
new file mode 100755 (executable)
index 0000000..cc4395a
--- /dev/null
@@ -0,0 +1,101 @@
+#! /usr/bin/python
+# Usage:
+#DISPLAY=:0 GST_PERFORMANCE=*:5 GST_DEBUG=*:2,GST_SCHEDULING:5 gst-launch --gst-debug-no-color -e omx_camera num-buffers=200 do-timestamp=1 mode=0 device=0 name=cam focus=off cam.src ! "video/x-raw-yuv, format=(fourcc)NV12, width=1280, height=720, framerate=30/1" ! ducatih264enc profile=66 ! ducatih264dec! dri2videosink sync=false 2>&1 | ./pp-gst-sched.py
+# or ducatimpeg4enc ! ducatimpeg4dec 
+
+import sys
+import time
+import fileinput
+import re
+import operator
+from datetime import datetime
+
+def string_to_time (d):
+  return datetime.strptime(d[0:14], "%H:%M:%S.%f")
+
+def main():
+  tr = dict()
+  cam = dict()
+  dec = dict()
+  ecs = 0
+
+  ### Parse stdin or any file on the command line
+  for line in fileinput.input():       
+
+    # Filter out GST traces from other output
+    m = re.match(r"([\w:.]+)[\s]+([\w]+)[\s]+([\w]+)[\s]+([\w]+)[\s]+(.*)",line)
+    if m == None:
+      print line
+      continue
+    (tsr,pid,adr,sev,msg) = m.groups()
+
+    # Parse GST_SCHEDULING traces
+    m = re.match(r"GST_SCHEDULING[\s]+gstpad.c:[\w]+:([\w:.<>]+) calling chainfunction &([\w]+) with buffer ([\w]+), data ([\w]+), malloc ([\w()]+), ts ([\w:.]+), dur ([\w:.]+)", msg)
+    if m != None:
+      (func, elem, gstBuffer, data, malloc, tsb, dur) = m.groups()
+      if func == r"gst_pad_push:<cam:src>" and gstBuffer in cam:
+        tr[tsb] = [(cam[gstBuffer], "FillBufferDone")]
+      elif func == r"gst_pad_push:<ducatih264dec0:src>":
+        dec[gstBuffer] = tsb
+
+      if tsb not in tr:
+        tr[tsb] = []
+      tr[tsb].append((tsr, func))
+      continue
+
+    # Parse omx_camera traces
+    m = re.match(r"GST_PERFORMANCE gstomx_core.c:[\w]+:FillBufferDone:<cam> FillBufferDone: GstBuffer=([\w]+)", msg)
+    if m != None:
+      gstBuffer = m.group(1)
+      cam[gstBuffer] = tsr
+      continue
+
+    # Parse encoder traces
+    m = re.match(r"ducati gstducatividenc.c:[\w]+:gst_ducati_videnc_handle_frame:<ducatih264enc[\w]+> Encoded frame in ([\w]+) bytes", msg)
+    if m != None:
+       ecs += int(m.group(1))
+       continue
+
+    # Parse dri2videosink traces
+    m = re.match(r"GST_PERFORMANCE gstdri2util.c:[\w]+:gst_dri2window_buffer_show:<dri2videosink[\w]+> (Before DRI2SwapBuffersVid|After DRI2WaitSBC), buf=([\w]+)", msg)
+    if m != None:
+      (ba, dri2_buf) = m.groups()
+      if dri2_buf in dec:
+        tr[dec[dri2_buf]].append((tsr, ba))
+      continue
+
+  ### End of parse stdin 
+
+  # Display the results, frame per frame
+  avg = cnt = 0
+  for tsb, tfs in tr.iteritems():
+    cnt +=1
+    first = prev = string_to_time(tfs[0][0])
+    print "\n*** New frame %d, timestamp: %s" % (cnt, tsb)
+    for el in tfs:
+      cur = string_to_time(el[0])
+      print "At %s (%6d us later) Func: %s" % \
+        (el[0][5:14], (cur - prev).microseconds, el[1])
+      prev = cur
+    total = cur - first
+    avg += total.microseconds
+    print "*** Total: %6d us" % (total.microseconds)
+
+  # Display the totals
+  if (cnt != 0):
+    if (ecs != 0):
+      print "\n=-= Encoded stream size: %d KB" % (ecs / 1024)
+      ecm = "(not optimal, due to encoder traces)"
+    else:
+      print "\n=-= Encoded stream size: N/A (lack of encoder traces)"
+      ecm = ""
+    print "\n=-= Average: %6d us on %d frames %s" % (avg / cnt, cnt, ecm)
+  else:
+    print "\n=-= No frame, the pipeline have failed"
+
+  return 0
+if __name__ == '__main__':
+  main()
+
+
+