From: Stefan Kost Date: Wed, 23 Aug 2006 18:53:44 +0000 (+0000) Subject: tools/: add debug-log plotting developer tool (#340674) X-Git-Tag: RELEASE-0_10_10~35 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=7c84afffacaf02455170c9a7ae8c0728594e1d65;p=platform%2Fupstream%2Fgstreamer.git tools/: add debug-log plotting developer tool (#340674) Original commit message from CVS: * tools/Makefile.am: * tools/gst-plot-timeline.py: add debug-log plotting developer tool (#340674) --- diff --git a/ChangeLog b/ChangeLog index 576e8e6..d44e23f 100644 --- a/ChangeLog +++ b/ChangeLog @@ -1,3 +1,9 @@ +2006-08-23 Stefan Kost + + * tools/Makefile.am: + * tools/gst-plot-timeline.py: + add debug-log plotting developer tool (#340674) + 2006-08-23 Wim Taymans * gst/gstpad.c: (gst_pad_start_task), (gst_pad_pause_task), diff --git a/tools/Makefile.am b/tools/Makefile.am index ea26c35..e8544dc 100644 --- a/tools/Makefile.am +++ b/tools/Makefile.am @@ -122,7 +122,8 @@ EXTRA_DIST = \ gst-typefind.1.in \ gst-xmlinspect.1.in \ gst-xmllaunch.1.in \ - gst-feedback-m.m + gst-feedback-m.m \ + gst-plot-timeline.py %-@GST_MAJORMINOR@.1: %.1.in sed \ diff --git a/tools/gst-plot-timeline.py b/tools/gst-plot-timeline.py new file mode 100755 index 0000000..5a05814 --- /dev/null +++ b/tools/gst-plot-timeline.py @@ -0,0 +1,250 @@ +#!/usr/bin/env python +# +# based on plot-timeline.py by Federico Mena-Quintero +# example: +# GST_DEBUG_NO_COLOR=1 GST_DEBUG="*:3" gst-launch-0.10 2>debug.log audiotestsrc num-buffers=10 ! audioconvert ! alsasink +# gst-plot-timeline.py debug.log --output=debug.png + +import math +import optparse +import os +import re +import sys + +import cairo + +FONT_NAME = "Bitstream Vera Sans" +FONT_SIZE = 9 +PIXELS_PER_SECOND = 1000 +PIXELS_PER_LINE = 12 +PLOT_WIDTH = 1400 +TIME_SCALE_WIDTH = 20 +SYSCALL_MARKER_WIDTH = 20 +LOG_TEXT_XPOS = 400 +LOG_MARKER_WIDTH = 20 +BACKGROUND_COLOR = (0, 0, 0) + +# assumes GST_DEBUG_LOG_COLOR=1 +mark_regex = re.compile (r'^(\d:\d\d:\d\d\.\d+) \d+ 0x[0-9a-f]+ [A-Z]+ +([a-zA-Z_]+ )(.*)') +mark_timestamp_group = 1 +mark_program_group = 2 +mark_log_group = 3 + +success_result = "0" + +class BaseMark: + colors = 0, 0, 0 + def __init__(self, timestamp, log): + self.timestamp = timestamp + self.log = log + self.timestamp_ypos = 0 + self.log_ypos = 0 + +class AccessMark(BaseMark): + pass + +class LastMark(BaseMark): + colors = 1.0, 0, 0 + +class FirstMark(BaseMark): + colors = 1.0, 0, 0 + +class ExecMark(BaseMark): +# colors = 0.75, 0.33, 0.33 + colors = (1.0, 0.0, 0.0) + def __init__(self, timestamp, log): + BaseMark.__init__(self, timestamp, + 'execve: ' + os.path.basename(log)) + +class Metrics: + def __init__(self): + self.width = 0 + self.height = 0 + +# don't use black or red +palette = [ + (0.12, 0.29, 0.49), + (0.36, 0.51, 0.71), + (0.75, 0.31, 0.30), + (0.62, 0.73, 0.38), + (0.50, 0.40, 0.63), + (0.29, 0.67, 0.78), + (0.96, 0.62, 0.34) + ] + +class SyscallParser: + def __init__ (self): + self.pending_execs = [] + self.syscalls = [] + + def search_pending_execs (self, search_pid): + n = len (self.pending_execs) + for i in range (n): + (pid, timestamp, command) = self.pending_execs[i] + if pid == search_pid: + return (i, timestamp, command) + + return (None, None, None) + + def add_line (self, str): + m = mark_regex.search (str) + if m: + timestr = m.group (mark_timestamp_group) + timestamp = float (timestr[5:]) + (float (timestr[2:3]) * 60.0) + (float (timestr[0]) * 60.0*60.0) + program = m.group (mark_program_group) + text = program + m.group (mark_log_group) + if text == 'last': + self.syscalls.append (LastMark (timestamp, text)) + elif text == 'first': + self.syscalls.append (FirstMark (timestamp, text)) + else: + s = AccessMark (timestamp, text) + program_hash = program.__hash__ () + s.colors = palette[program_hash % len (palette)] + self.syscalls.append (s) + + return + +def parse_strace(filename): + parser = SyscallParser () + + for line in file(filename, "r").readlines(): + if line == "": + break + + parser.add_line (line) + + return parser.syscalls + +def normalize_timestamps(syscalls): + + first_timestamp = syscalls[0].timestamp + + for syscall in syscalls: + syscall.timestamp -= first_timestamp + +def compute_syscall_metrics(syscalls): + num_syscalls = len(syscalls) + + metrics = Metrics() + metrics.width = PLOT_WIDTH + + last_timestamp = syscalls[num_syscalls - 1].timestamp + num_seconds = int(math.ceil(last_timestamp)) + metrics.height = max(num_seconds * PIXELS_PER_SECOND, + num_syscalls * PIXELS_PER_LINE) + + text_ypos = 0 + + for syscall in syscalls: + syscall.timestamp_ypos = syscall.timestamp * PIXELS_PER_SECOND + syscall.log_ypos = text_ypos + FONT_SIZE + + text_ypos += PIXELS_PER_LINE + + return metrics + +def plot_time_scale(surface, ctx, metrics): + num_seconds = (metrics.height + PIXELS_PER_SECOND - 1) / PIXELS_PER_SECOND + + ctx.set_source_rgb(0.5, 0.5, 0.5) + ctx.set_line_width(1.0) + + for i in range(num_seconds): + ypos = i * PIXELS_PER_SECOND + + ctx.move_to(0, ypos + 0.5) + ctx.line_to(TIME_SCALE_WIDTH, ypos + 0.5) + ctx.stroke() + + ctx.move_to(0, ypos + 2 + FONT_SIZE) + ctx.show_text("%d s" % i) + +def plot_syscall(surface, ctx, syscall): + ctx.set_source_rgb(*syscall.colors) + + # Line + + ctx.move_to(TIME_SCALE_WIDTH, syscall.timestamp_ypos) + ctx.line_to(TIME_SCALE_WIDTH + SYSCALL_MARKER_WIDTH, syscall.timestamp_ypos) + ctx.line_to(LOG_TEXT_XPOS - LOG_MARKER_WIDTH, syscall.log_ypos - FONT_SIZE / 2 + 0.5) + ctx.line_to(LOG_TEXT_XPOS, syscall.log_ypos - FONT_SIZE / 2 + 0.5) + ctx.stroke() + + # Log text + + ctx.move_to(LOG_TEXT_XPOS, syscall.log_ypos) + ctx.show_text("%8.5f: %s" % (syscall.timestamp, syscall.log)) + +def plot_syscalls_to_surface(syscalls, metrics): + num_syscalls = len(syscalls) + + surface = cairo.ImageSurface(cairo.FORMAT_RGB24, + metrics.width, metrics.height) + + ctx = cairo.Context(surface) + ctx.select_font_face(FONT_NAME) + ctx.set_font_size(FONT_SIZE) + + # Background + + ctx.set_source_rgb (*BACKGROUND_COLOR) + ctx.rectangle(0, 0, metrics.width, metrics.height) + ctx.fill() + + # Time scale + + plot_time_scale(surface, ctx, metrics) + + # Contents + + ctx.set_line_width(1.0) + + for syscall in syscalls: + plot_syscall(surface, ctx, syscall) + + return surface + +def main(args): + option_parser = optparse.OptionParser( + usage="usage: %prog -o output.png ") + option_parser.add_option("-o", + "--output", dest="output", + metavar="FILE", + help="Name of output file (output is a PNG file)") + + options, args = option_parser.parse_args() + + if not options.output: + print 'Please specify an output filename with "-o file.png" or "--output=file.png".' + return 1 + + if len(args) != 1: + print 'Please specify only one input filename, which is an debug log taken with "GST_DEBUG_NO_COLOR=1 GST_DEBUG=XXX "' + return 1 + + in_filename = args[0] + out_filename = options.output + + syscalls = [] + for syscall in parse_strace(in_filename): + syscalls.append(syscall) + if isinstance(syscall, FirstMark): + syscalls = [] + elif isinstance(syscall, LastMark): + break + + if not syscalls: + print 'No logs in %s' % in_filename + return 1 + + normalize_timestamps(syscalls) + metrics = compute_syscall_metrics(syscalls) + + surface = plot_syscalls_to_surface(syscalls, metrics) + surface.write_to_png(out_filename) + + return 0 + +if __name__ == "__main__": + sys.exit(main(sys.argv))