hacks/analog.py

   1 #!/usr/bin/python
   2
   3 import sys
   4 import time
   5 import argparse
   6 import matplotlib.pyplot as plt
   7
   8 parser = argparse.ArgumentParser()
   9 parser.add_argument('log_file')
  10 parser.add_argument('-q', '--queue', help='plot queue size', action='store_true')
  11 parser.add_argument('-e', '--encoder-threads', help='plot encoder thread activity', action='store_true')
  12 parser.add_argument('-f', '--plot-first-encoder', help='plot more detailed activity of the first encoder thread', action='store_true')
  13 parser.add_argument('--dump-first-encoder', help='dump activity of the first encoder thread', action='store_true')
  14 parser.add_argument('--from', help='time in seconds to start at', type=int, dest='from_time')
  15 parser.add_argument('--to', help='time in seconds to stop at', type=int, dest='to_time')
  16 args = parser.parse_args()
  17
  18 def find_nth(haystack, needle, n):
  19     start = haystack.find(needle)
  20     while start >= 0 and n > 1:
  21         start = haystack.find(needle, start+len(needle))
  22         n -= 1
  23     return start
  24
  25 class Time:
  26     def __init__(self, s, m = 0):
  27         self.seconds = s
  28         self.microseconds = m
  29
  30     def __str__(self):
  31         return '%d:%d' % (self.seconds, self.microseconds)
  32
  33     def float_seconds(self):
  34         return self.seconds + self.microseconds / 1000000.0
  35
  36     def __sub__(self, x):
  37         m = self.microseconds - x.microseconds
  38         if m < 0:
  39             return Time(self.seconds - x.seconds - 1, m + 1000000)
  40         else:
  41             return Time(self.seconds - x.seconds, m)
  42
  43 queue_size = []
  44 encoder_thread_events = dict()
  45
  46 def add_encoder_thread_event(thread, time, event):
  47     global encoder_thread_events
  48     if thread in encoder_thread_events:
  49         encoder_thread_events[thread].append((time, event))
  50     else:
  51         encoder_thread_events[thread] = [(time, event)]
  52
  53 f = open(args.log_file)
  54 start = None
  55 while True:
  56     l = f.readline()
  57     if l == '':
  58         break
  59
  60     l = l.strip()
  61     p = l.split()
  62
  63     if len(p) == 0:
  64         continue
  65
  66     if len(p[0].split(':')) == 2:
  67         # s:us timestamp
  68         x = p[0].split(':')
  69         T = Time(int(x[0]), int(x[1]))
  70         message = l[l.find(' ')+1:]
  71     else:
  72         # Date/time timestamp
  73         s = find_nth(l, ':', 3)
  74         T = Time(time.mktime(time.strptime(l[:s])))
  75         message = l[s+2:]
  76
  77     if start is None:
  78         start = T
  79     else:
  80         T = T - start
  81
  82     thread = None
  83     if message.startswith('['):
  84         thread = message.split()[0][1:-1]
  85         message = message[message.find(' ')+1:]
  86
  87     if message.startswith('adding to queue of '):
  88         queue_size.append((T, int(message.split()[4])))
  89     elif message.startswith('encoder thread sleeps'):
  90         add_encoder_thread_event(thread, T, 'sleep')
  91     elif message.startswith('encoder thread wakes'):
  92         add_encoder_thread_event(thread, T, 'wake')
  93     elif message.startswith('encoder thread begins local encode'):
  94         add_encoder_thread_event(thread, T, 'begin_encode')
  95     elif message.startswith('MagickImageProxy begins read and decode'):
  96         add_encoder_thread_event(thread, T, 'magick_begin_decode')
  97     elif message.startswith('MagickImageProxy completes read and decode'):
  98         add_encoder_thread_event(thread, T, 'magick_end_decode')
  99     elif message.startswith('encoder thread finishes local encode'):
 100         add_encoder_thread_event(thread, T, 'end_encode')
 101
 102 if args.queue:
 103     plt.figure()
 104     x = []
 105     y = []
 106     for q in queue_size:
 107         x.append(q[0].seconds)
 108         y.append(q[1])
 109
 110     plt.plot(x, y)
 111     plt.show()
 112 elif args.encoder_threads:
 113     plt.figure()
 114     N = len(encoder_thread_events)
 115     n = 1
 116     for thread, events in encoder_thread_events.iteritems():
 117         plt.subplot(N, 1, n)
 118         x = []
 119         y = []
 120         previous = 0
 121         for e in events:
 122             if args.from_time is not None and e[0].float_seconds() <= args.from_time:
 123                 continue
 124             if args.to_time is not None and e[0].float_seconds() >= args.to_time:
 125                 continue
 126             x.append(e[0].float_seconds())
 127             x.append(e[0].float_seconds())
 128             y.append(previous)
 129             if e[1] == 'sleep':
 130                 y.append(0)
 131             elif e[1] == 'wake':
 132                 y.append(1)
 133             elif e[1] == 'begin_encode':
 134                 y.append(2)
 135             elif e[1] == 'end_encode':
 136                 y.append(1)
 137             elif e[1] == 'magick_begin_decode':
 138                 y.append(3)
 139             elif e[1] == 'magick_end_decode':
 140                 y.append(2)
 141
 142             previous = y[-1]
 143
 144         plt.plot(x, y)
 145         n += 1
 146         break
 147
 148     plt.show()
 149 elif args.plot_first_encoder:
 150     plt.figure()
 151     N = len(encoder_thread_events)
 152     n = 1
 153     events = encoder_thread_events.itervalues().next()
 154
 155     N = 6
 156     n = 1
 157     for t in ['sleep', 'wake', 'begin_encode', 'magick_begin_decode', 'magick_end_decode', 'end_encode']:
 158         plt.subplot(N, 1, n)
 159         x = []
 160         y = []
 161         for e in events:
 162             if args.from_time is not None and e[0].float_seconds() <= args.from_time:
 163                 continue
 164             if args.to_time is not None and e[0].float_seconds() >= args.to_time:
 165                 continue
 166             if e[1] == t:
 167                 x.append(e[0].float_seconds())
 168                 x.append(e[0].float_seconds())
 169                 x.append(e[0].float_seconds())
 170                 y.append(0)
 171                 y.append(1)
 172                 y.append(0)
 173
 174         plt.plot(x, y)
 175         plt.title(t)
 176         n += 1
 177
 178     plt.show()
 179 elif args.dump_first_encoder:
 180     events = encoder_thread_events.itervalues().next()
 181     last = 0
 182     for e in events:
 183         print e[0].float_seconds(), (e[0].float_seconds() - last), e[1]
 184         last = e[0].float_seconds()