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', 'nursery+update']:
 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     bin_data_minor = []
 165     bin_data_both = []
 166     bin_data_major = []
 167     bin_names = []
 168
 169     for rec in data:
 170         pause = rec.stop - rec.start
 171         for i in range(100):
 172             time = (1.3)**(i+6)
 173             prev_time = 0 if i==0 else (1.3)**(i+5)
 174             if len(bin_names) <= i:
 175                 bin_data_minor.append(0)
 176                 bin_data_both.append(0)
 177                 bin_data_major.append(0)
 178                 bin_names.append('%d-%dms' % (int(prev_time), int(time)))
 179             if pause <= time:
 180                 if rec.major_work:
 181                     if rec.minor_work:
 182                         bin_data_both[i] += pause
 183                     else:
 184                         bin_data_major[i] += pause
 185                 else:
 186                     bin_data_minor[i] += pause
 187                 break
 188
 189     bin_data_minor=np.array(bin_data_minor)
 190     bin_data_both=np.array(bin_data_both)
 191     bin_data_major=np.array(bin_data_major)
 192
 193     if show_minor:
 194         plt.bar(range(len(bin_data_minor)), bin_data_minor, color='blue', label="minor")  #, align='center')
 195         plt.bar(range(len(bin_data_both)), bin_data_both, bottom=bin_data_minor, color='purple', label="minor & major")
 196         if show_major:
 197             plt.bar(range(len(bin_data_major)), bin_data_major, bottom=(bin_data_minor+bin_data_both), color='red', label="only major")
 198     else:
 199         plt.bar(range(len(bin_data_major)), bin_data_major, color='red')
 200     plt.xticks(range(len(bin_names)), bin_names)
 201     plt.ylabel('Cumulative time spent in GC pauses (ms)')
 202     plt.xlabel('GC pause length')
 203     plt.xticks(rotation=60)
 204     plt.legend(loc='upper left')
 205 else:
 206     major_gc_event_groups = parse_major_gcs(data)
 207
 208     def bar(**kwargs):
 209         indices = kwargs['indices']
 210         pauses = kwargs['pauses']
 211         color = kwargs['color']
 212         if 'bottom' in kwargs:
 213             bottom = kwargs['bottom']
 214         else:
 215             bottom = 0
 216         plt.bar(
 217             [index for index in indices if pauses[index] is not None],
 218             np.array([pause for pause in pauses if pause is not None]),
 219             color=color,
 220             bottom=bottom,
 221         )
 222
 223     indices = np.arange(len(major_gc_event_groups))
 224     start_pauses = [
 225         event_group.start.stop - event_group.start.start
 226         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 227         for event_group in major_gc_event_groups
 228     ]
 229     bar(
 230         indices=indices,
 231         pauses=start_pauses,
 232         color='red',
 233     )
 234     update_pauses = [
 235         sum([
 236             update_event.stop - update_event.start
 237             for update_event in event_group.updates
 238         ]) if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 239         for event_group in major_gc_event_groups
 240     ]
 241     bar(
 242         indices=indices,
 243         pauses=update_pauses,
 244         color='green',
 245         bottom=[pause for pause in start_pauses if pause is not None],
 246     )
 247     finish_pauses = [
 248         event_group.finish.stop - event_group.finish.start
 249         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 250         for event_group in major_gc_event_groups
 251     ]
 252     start_update_pauses = [
 253         a + b
 254         for a, b in zip(start_pauses, update_pauses)
 255         if a is not None and b is not None
 256     ]
 257     bar(
 258         indices=indices,
 259         pauses=finish_pauses,
 260         color='blue',
 261         bottom=start_update_pauses,
 262     )
 263     full_pauses = [
 264         event_group.event.stop - event_group.event.start
 265         if isinstance(event_group, FullMajorGCEventGroup) else None
 266         for event_group in major_gc_event_groups
 267     ]
 268     bar(
 269         indices=indices,
 270         pauses=full_pauses,
 271         color='black',
 272     )
 273
 274     plt.ylabel("Pause Time (ms)")
 275     plt.xlabel("Collection")
 276
 277 plt.show()