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