tools/gst-plot-timeline.py

   1 #!/usr/bin/env python
   2 #
   3 # based on plot-timeline.py by Federico Mena-Quintero <federico at ximian dotcom>
   4 # example:
   5 #   GST_DEBUG_NO_COLOR=1 GST_DEBUG="*:3" gst-launch-0.10 2>debug.log audiotestsrc num-buffers=10 ! audioconvert ! alsasink
   6 #   gst-plot-timeline.py debug.log --output=debug.png
   7
   8 import math
   9 import optparse
  10 import os
  11 import re
  12 import sys
  13
  14 import cairo
  15
  16 FONT_NAME = "Bitstream Vera Sans"
  17 FONT_SIZE = 8
  18 # how many pixels for a second on the timeline
  19 PIXELS_PER_SECOND = 300
  20 # how many pixels for one line of log
  21 PIXELS_PER_LINE = 10
  22 PLOT_WIDTH = 1400
  23 TIME_SCALE_WIDTH = 20
  24 SYSCALL_MARKER_WIDTH = 20
  25 LOG_TEXT_XPOS = 400
  26 LOG_MARKER_WIDTH = 20
  27 BACKGROUND_COLOR = (0, 0, 0)
  28
  29 # assumes GST_DEBUG_LOG_COLOR=1
  30 #                             timestamp          pid  thread        level   category,file,line,msg
  31 mark_regex = re.compile (r'^(\d:\d\d:\d\d\.\d+) +\d+ 0?x?[0-9a-f]+ [A-Z]+ +([-a-zA-Z0-9_]+ )(.*)')
  32 mark_timestamp_group = 1
  33 mark_program_group = 2
  34 mark_log_group = 3
  35
  36 success_result = "0"
  37
  38 class BaseMark:
  39     colors = 0, 0, 0
  40     def __init__(self, timestamp, log):
  41         self.timestamp = timestamp
  42         self.log = log
  43         self.timestamp_ypos = 0
  44         self.log_ypos = 0
  45
  46 class AccessMark(BaseMark):
  47     pass
  48
  49 class LastMark(BaseMark):
  50     colors = 1.0, 0, 0
  51
  52 class FirstMark(BaseMark):
  53     colors = 1.0, 0, 0
  54
  55 class ExecMark(BaseMark):
  56 #    colors = 0.75, 0.33, 0.33
  57     colors = (1.0, 0.0, 0.0)
  58     def __init__(self, timestamp, log):
  59         BaseMark.__init__(self, timestamp,
  60                           'execve: ' + os.path.basename(log))
  61
  62 class Metrics:
  63     def __init__(self):
  64         self.width = 0
  65         self.height = 0
  66
  67 # don't use black or red
  68 palette = [
  69     (0.12, 0.29, 0.49),
  70     (0.36, 0.51, 0.71),
  71     (0.75, 0.31, 0.30),
  72     (0.62, 0.73, 0.38),
  73     (0.50, 0.40, 0.63),
  74     (0.29, 0.67, 0.78),
  75     (0.96, 0.62, 0.34)
  76     ]
  77
  78 class SyscallParser:
  79     def __init__ (self):
  80         self.syscalls = []
  81
  82     def add_line (self, str):
  83         m = mark_regex.search (str)
  84         if m:
  85             timestr = m.group (mark_timestamp_group)
  86             timestamp = float (timestr[5:]) + (float (timestr[2:3]) * 60.0) + (float (timestr[0]) * 60.0*60.0)
  87             program = m.group (mark_program_group)
  88             text = program + m.group (mark_log_group)
  89             if text == 'last':
  90                 self.syscalls.append (LastMark (timestamp, text))
  91             elif text == 'first':
  92                 self.syscalls.append (FirstMark (timestamp, text))
  93             else:
  94                 s = AccessMark (timestamp, text)
  95                 program_hash = program.__hash__ ()
  96                 s.colors = palette[program_hash % len (palette)]
  97                 self.syscalls.append (s)
  98         else:
  99             print 'No log in %s' % str
 100             return
 101
 102 def parse_strace(filename):
 103     parser = SyscallParser ()
 104
 105     for line in file(filename, "r").readlines():
 106         if line == "":
 107             break
 108
 109         parser.add_line (line)
 110
 111     return parser.syscalls
 112
 113 def normalize_timestamps(syscalls):
 114
 115     first_timestamp = syscalls[0].timestamp
 116
 117     for syscall in syscalls:
 118         syscall.timestamp -= first_timestamp
 119
 120 def compute_syscall_metrics(syscalls):
 121     global PIXELS_PER_SECOND
 122     global PIXELS_PER_LINE
 123
 124     num_syscalls = len(syscalls)
 125
 126     metrics = Metrics()
 127     metrics.width = PLOT_WIDTH
 128
 129     last_timestamp = syscalls[num_syscalls - 1].timestamp
 130     num_seconds = int(math.ceil(last_timestamp))
 131
 132     time_height = num_seconds * PIXELS_PER_SECOND
 133     line_height = num_syscalls * PIXELS_PER_LINE
 134     if time_height > line_height:
 135         metrics.height = time_height
 136         print "Adjusting PIXELS_PER_LINE = %d" % PIXELS_PER_LINE
 137         PIXELS_PER_LINE = metrics.height / num_syscalls
 138         print "          PIXELS_PER_LINE = %d" % PIXELS_PER_LINE
 139     else:
 140         metrics.height = line_height
 141         print "Adjusting PIXELS_PER_SECOND %d" % PIXELS_PER_SECOND
 142         PIXELS_PER_SECOND = metrics.height / num_seconds
 143         print "          PIXELS_PER_SECOND %d" % PIXELS_PER_SECOND
 144
 145     text_ypos = 0
 146
 147     for syscall in syscalls:
 148         syscall.timestamp_ypos = syscall.timestamp * PIXELS_PER_SECOND
 149         syscall.log_ypos = text_ypos + FONT_SIZE
 150
 151         text_ypos += PIXELS_PER_LINE
 152
 153     return metrics
 154
 155 def plot_time_scale(surface, ctx, metrics):
 156     num_seconds = (metrics.height + PIXELS_PER_SECOND - 1) / PIXELS_PER_SECOND
 157
 158     ctx.set_source_rgb(0.5, 0.5, 0.5)
 159     ctx.set_line_width(1.0)
 160
 161     for i in range(num_seconds):
 162         ypos = i * PIXELS_PER_SECOND
 163
 164         ctx.move_to(0, ypos + 0.5)
 165         ctx.line_to(TIME_SCALE_WIDTH, ypos + 0.5)
 166         ctx.stroke()
 167
 168         ctx.move_to(0, ypos + 2 + FONT_SIZE)
 169         ctx.show_text("%d s" % i)
 170
 171 def plot_syscall(surface, ctx, syscall):
 172     ctx.set_source_rgb(*syscall.colors)
 173
 174     # Line
 175
 176     ctx.move_to(TIME_SCALE_WIDTH, syscall.timestamp_ypos)
 177     ctx.line_to(TIME_SCALE_WIDTH + SYSCALL_MARKER_WIDTH, syscall.timestamp_ypos)
 178     ctx.line_to(LOG_TEXT_XPOS - LOG_MARKER_WIDTH, syscall.log_ypos - FONT_SIZE / 2 + 0.5)
 179     ctx.line_to(LOG_TEXT_XPOS, syscall.log_ypos - FONT_SIZE / 2 + 0.5)
 180     ctx.stroke()
 181
 182     # Log text
 183
 184     ctx.move_to(LOG_TEXT_XPOS, syscall.log_ypos)
 185     ctx.show_text("%8.5f: %s" % (syscall.timestamp, syscall.log))
 186
 187 def plot_syscalls_to_surface(syscalls, metrics):
 188     num_syscalls = len(syscalls)
 189
 190     print 'picture size: %d x %d' % (metrics.width, metrics.height);
 191
 192     surface = cairo.ImageSurface(cairo.FORMAT_RGB24,
 193                                  metrics.width, metrics.height)
 194
 195     ctx = cairo.Context(surface)
 196     ctx.select_font_face(FONT_NAME)
 197     ctx.set_font_size(FONT_SIZE)
 198
 199     # Background
 200
 201     ctx.set_source_rgb (*BACKGROUND_COLOR)
 202     ctx.rectangle(0, 0, metrics.width, metrics.height)
 203     ctx.fill()
 204
 205     # Time scale
 206
 207     plot_time_scale(surface, ctx, metrics)
 208
 209     # Contents
 210
 211     ctx.set_line_width(1.0)
 212
 213     for syscall in syscalls:
 214         plot_syscall(surface, ctx, syscall)
 215
 216     return surface
 217
 218 def main(args):
 219     option_parser = optparse.OptionParser(
 220         usage="usage: %prog -o output.png <debug.log>")
 221     option_parser.add_option("-o",
 222                              "--output", dest="output",
 223                              metavar="FILE",
 224                              help="Name of output file (output is a PNG file)")
 225
 226     options, args = option_parser.parse_args()
 227
 228     if not options.output:
 229         print 'Please specify an output filename with "-o file.png" or "--output=file.png".'
 230         return 1
 231
 232     if len(args) != 1:
 233         print 'Please specify only one input filename, which is an debug log taken with "GST_DEBUG_NO_COLOR=1 GST_DEBUG=XXX <application>"'
 234         return 1
 235
 236     in_filename = args[0]
 237     out_filename = options.output
 238
 239     syscalls = []
 240     for syscall in parse_strace(in_filename):
 241         syscalls.append(syscall)
 242         if isinstance(syscall, FirstMark):
 243             syscalls = []
 244         elif isinstance(syscall, LastMark):
 245             break
 246
 247     if not syscalls:
 248         print 'No logs in %s' % in_filename
 249         return 1
 250
 251     normalize_timestamps(syscalls)
 252     metrics = compute_syscall_metrics(syscalls)
 253
 254     surface = plot_syscalls_to_surface(syscalls, metrics)
 255     surface.write_to_png(out_filename)
 256
 257     return 0
 258
 259 if __name__ == "__main__":
 260     sys.exit(main(sys.argv))