tools/sgen/gcpausevis.py

   1 #!/usr/bin/env python
   2 import matplotlib.pyplot as plt
   3 from matplotlib.dates import DateFormatter, MinuteLocator, SecondLocator
   4 import numpy as np
   5 from StringIO import StringIO
   6 import os
   7 import re
   8 import sys
   9 from optparse import OptionParser
  10 import subprocess
  11
  12 parser = OptionParser (usage = "Usage: %prog [options] BINARY-PROTOCOL")
  13 parser.add_option ('--histogram', action = 'store_true', dest = 'histogram', help = "pause time histogram")
  14 parser.add_option ('--minor', action = 'store_true', dest = 'minor', help = "only show minor collections in histogram")
  15 parser.add_option ('--major', action = 'store_true', dest = 'major', help = "only show major collections in histogram")
  16 (options, files) = parser.parse_args ()
  17
  18 show_histogram = False
  19 show_minor = True
  20 show_major = True
  21 if options.minor:
  22     show_histogram = True
  23     show_major = False
  24 if options.major:
  25     show_histogram = True
  26     show_minor = False
  27 if options.histogram:
  28     show_histogram = True
  29
  30 script_path = os.path.realpath (__file__)
  31 sgen_grep_path = os.path.join (os.path.dirname (script_path), 'sgen-grep-binprot')
  32
  33 if not os.path.isfile (sgen_grep_path):
  34     sys.stderr.write ('Error: `%s` does not exist.\n' % sgen_grep_path)
  35     sys.exit (1)
  36
  37 if len (files) != 1:
  38     parser.print_help ()
  39     sys.exit (1)
  40
  41 data = []
  42
  43 class Event:
  44     def __init__(self, **kwargs):
  45         self.minor_work = kwargs['minor_work']
  46         self.major_work = kwargs['major_work']
  47         self.start = kwargs['start']
  48         self.stop = kwargs['stop']
  49         self.gc_type = kwargs['gc_type']
  50     def __repr__(self):
  51         return 'Event(minor_work={}, major_work={}, start={}, stop={}, gc_type={})'.format(
  52             self.minor_work,
  53             self.major_work,
  54             self.start,
  55             self.stop,
  56             self.gc_type,
  57         )
  58
  59 grep_input = open (files [0])
  60 proc = subprocess.Popen ([sgen_grep_path, '--pause-times'], stdin = grep_input, stdout = subprocess.PIPE)
  61 for line in iter (proc.stdout.readline, ''):
  62     m = re.match ('^pause-time (\d+) (\d+) (\d+) (\d+) (\d+)', line)
  63     if m:
  64         minor_work = major_work = False
  65         generation = int (m.group (1))
  66         concurrent = int (m.group (2)) != 0
  67         finish = int (m.group (3)) != 0
  68         msecs = int (m.group (4)) / 10.0 / 1000.0
  69         start = int (m.group (5)) / 10.0 / 1000.0
  70
  71         if concurrent:
  72             kind = "CONC"
  73         else:
  74             kind = "SYNC"
  75
  76         if generation == 0:
  77             minor_work = True
  78             if concurrent:
  79                 major_work = True
  80                 gc_type = "nursery+update"
  81             else:
  82                 gc_type = "nursery"
  83         else:
  84             major_work = True
  85             if concurrent:
  86                 if finish:
  87                     minor_work = True
  88                     gc_type = "nursery+finish"
  89                 else:
  90                     gc_type = "start"
  91             else:
  92                 gc_type = "full"
  93
  94         rec = Event(
  95             minor_work=minor_work,
  96             major_work=major_work,
  97             start=start,
  98             stop=start + msecs,
  99             kind=kind,
 100             gc_type=gc_type,
 101         )
 102         print rec
 103         data.append (rec)
 104
 105 class MajorGCEventGroup:
 106     pass
 107
 108 class FullMajorGCEventGroup(MajorGCEventGroup):
 109     def __init__(self, event):
 110         self.event = event
 111     def __repr__(self):
 112         return 'FullMajorGCEventGroup({})'.format(
 113             self.event,
 114         )
 115
 116 class ConcurrentMajorGCEventGroup(MajorGCEventGroup):
 117     def __init__(self, start, updates, finish):
 118         self.start = start
 119         self.updates = updates
 120         self.finish = finish
 121     def __repr__(self):
 122         return 'ConcurrentMajorEventGroup({}, {}, {})'.format(
 123             self.start,
 124             self.updates,
 125             self.finish,
 126         )
 127
 128 # ([Event], int) -> (MajorGCEventGroup, int) | None
 129 def parse_next_major_gc(data, i):
 130     assert i >= 0
 131     # Find start or full event.
 132     while i < len(data) and data[i].gc_type not in ['start', 'full']:
 133         i += 1
 134     if i == len(data):
 135         return None
 136     # If full event, done.
 137     if data[i].gc_type == 'full':
 138         return (FullMajorGCEventGroup(data[i]), i + 1)
 139     start_event = data[i]
 140     update_events = []
 141     # Filter update events and find finish event.
 142     while i < len(data) and data[i].gc_type != 'nursery+finish':
 143         if data[i].gc_type == 'nursery+update':
 144             update_events.append(data[i])
 145         i += 1
 146     if i == len(data):
 147         return None
 148     finish_event = data[i]
 149     i += 1
 150     return (ConcurrentMajorGCEventGroup(start_event, update_events, finish_event), i)
 151
 152 # [Event] -> [MajorGCEventGroup]
 153 def parse_major_gcs(data):
 154     major_gc_events = []
 155     i = 0
 156     while True:
 157         maybe_event_group = parse_next_major_gc(data, i)
 158         if maybe_event_group is None:
 159             return major_gc_events
 160         event_group, i = maybe_event_group
 161         major_gc_events.append(event_group)
 162
 163 if show_histogram:
 164     minor_pausetimes = []
 165     major_pausetimes = []
 166
 167     for rec in data:
 168         pause = rec.stop - rec.start
 169         if rec.minor_work and rec.major_work and show_minor and show_major:
 170             major_pausetimes.append (pause)
 171         else:
 172             if rec.minor_work:
 173                 minor_pausetimes.append (pause)
 174             if rec.major_work:
 175                 major_pausetimes.append (pause)
 176
 177     pausetimes = []
 178     colors = []
 179     if show_minor:
 180         pausetimes.append(minor_pausetimes)
 181         colors.append('blue')
 182     if show_major:
 183         pausetimes.append(major_pausetimes)
 184         colors.append('red')
 185
 186     plt.hist (pausetimes, 100, stacked=True, log=True, color=colors)
 187     plt.xlabel ('Pause time in msec')
 188 else:
 189     major_gc_event_groups = parse_major_gcs(data)
 190
 191     def bar(**kwargs):
 192         indices = kwargs['indices']
 193         pauses = kwargs['pauses']
 194         color = kwargs['color']
 195         if 'bottom' in kwargs:
 196             bottom = kwargs['bottom']
 197         else:
 198             bottom = 0
 199         plt.bar(
 200             [index for index in indices if pauses[index] is not None],
 201             np.array([pause for pause in pauses if pause is not None]),
 202             color=color,
 203             bottom=bottom,
 204         )
 205
 206     indices = np.arange(len(major_gc_event_groups))
 207     start_pauses = [
 208         event_group.start.stop - event_group.start.start
 209         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 210         for event_group in major_gc_event_groups
 211     ]
 212     bar(
 213         indices=indices,
 214         pauses=start_pauses,
 215         color='red',
 216     )
 217     update_pauses = [
 218         sum([
 219             update_event.stop - update_event.start
 220             for update_event in event_group.updates
 221         ]) if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 222         for event_group in major_gc_event_groups
 223     ]
 224     bar(
 225         indices=indices,
 226         pauses=update_pauses,
 227         color='green',
 228         bottom=[pause for pause in start_pauses if pause is not None],
 229     )
 230     finish_pauses = [
 231         event_group.finish.stop - event_group.finish.start
 232         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 233         for event_group in major_gc_event_groups
 234     ]
 235     start_update_pauses = [
 236         a + b
 237         for a, b in zip(start_pauses, update_pauses)
 238         if a is not None and b is not None
 239     ]
 240     bar(
 241         indices=indices,
 242         pauses=finish_pauses,
 243         color='blue',
 244         bottom=start_update_pauses,
 245     )
 246     full_pauses = [
 247         event_group.event.stop - event_group.event.start
 248         if isinstance(event_group, FullMajorGCEventGroup) else None
 249         for event_group in major_gc_event_groups
 250     ]
 251     bar(
 252         indices=indices,
 253         pauses=full_pauses,
 254         color='black',
 255     )
 256
 257     plt.ylabel("Pause Time (ms)")
 258     plt.xlabel("Collection")
 259
 260 plt.show()