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 ('--scatter', action = 'store_true', dest = 'scatter', help = "pause time scatterplot")
  15 parser.add_option ('--minor', action = 'store_true', dest = 'minor', help = "only show minor collections in histogram")
  16 parser.add_option ('--major', action = 'store_true', dest = 'major', help = "only show major collections in histogram")
  17 (options, files) = parser.parse_args ()
  18
  19 show_histogram = False
  20 show_scatter = False
  21 show_minor = True
  22 show_major = True
  23 if options.minor:
  24     show_major = False
  25 if options.major:
  26     show_minor = False
  27 if options.histogram:
  28     show_histogram = True
  29 if options.scatter:
  30     show_scatter = True
  31 if (options.minor or options.major) and not options.scatter:
  32     show_histogram = True
  33
  34 script_path = os.path.realpath (__file__)
  35 sgen_grep_path = os.path.join (os.path.dirname (script_path), 'sgen-grep-binprot')
  36
  37 if not os.path.isfile (sgen_grep_path):
  38     sys.stderr.write ('Error: `%s` does not exist.\n' % sgen_grep_path)
  39     sys.exit (1)
  40
  41 if len (files) != 1:
  42     parser.print_help ()
  43     sys.exit (1)
  44
  45 data = []
  46
  47 class Event:
  48     def __init__(self, **kwargs):
  49         self.minor_work = kwargs['minor_work']
  50         self.major_work = kwargs['major_work']
  51         self.start = kwargs['start']
  52         self.stop = kwargs['stop']
  53         self.gc_type = kwargs['gc_type']
  54     def __repr__(self):
  55         return 'Event(minor_work={}, major_work={}, start={}, stop={}, gc_type={})'.format(
  56             self.minor_work,
  57             self.major_work,
  58             self.start,
  59             self.stop,
  60             self.gc_type,
  61         )
  62
  63 grep_input = open (files [0])
  64 proc = subprocess.Popen ([sgen_grep_path, '--pause-times'], stdin = grep_input, stdout = subprocess.PIPE)
  65 for line in iter (proc.stdout.readline, ''):
  66     m = re.match ('^pause-time (\d+) (\d+) (\d+) (\d+) (\d+)', line)
  67     if m:
  68         minor_work = major_work = False
  69         generation = int (m.group (1))
  70         concurrent = int (m.group (2)) != 0
  71         finish = int (m.group (3)) != 0
  72         msecs = int (m.group (4)) / 10.0 / 1000.0
  73         start = int (m.group (5)) / 10.0 / 1000.0
  74
  75         if concurrent:
  76             kind = "CONC"
  77         else:
  78             kind = "SYNC"
  79
  80         if generation == 0:
  81             minor_work = True
  82             if concurrent:
  83                 major_work = True
  84                 gc_type = "nursery+update"
  85             else:
  86                 gc_type = "nursery"
  87         else:
  88             major_work = True
  89             if concurrent:
  90                 if finish:
  91                     minor_work = True
  92                     gc_type = "nursery+finish"
  93                 else:
  94                     gc_type = "start"
  95             else:
  96                 gc_type = "full"
  97
  98         rec = Event(
  99             minor_work=minor_work,
 100             major_work=major_work,
 101             start=start,
 102             stop=start + msecs,
 103             kind=kind,
 104             gc_type=gc_type,
 105         )
 106         print rec
 107         data.append (rec)
 108
 109 class MajorGCEventGroup:
 110     pass
 111
 112 class FullMajorGCEventGroup(MajorGCEventGroup):
 113     def __init__(self, event):
 114         self.event = event
 115     def __repr__(self):
 116         return 'FullMajorGCEventGroup({})'.format(
 117             self.event,
 118         )
 119
 120 class ConcurrentMajorGCEventGroup(MajorGCEventGroup):
 121     def __init__(self, start, updates, finish):
 122         self.start = start
 123         self.updates = updates
 124         self.finish = finish
 125     def __repr__(self):
 126         return 'ConcurrentMajorEventGroup({}, {}, {})'.format(
 127             self.start,
 128             self.updates,
 129             self.finish,
 130         )
 131
 132 # ([Event], int) -> (MajorGCEventGroup, int) | None
 133 def parse_next_major_gc(data, i):
 134     assert i >= 0
 135     # Find start or full event.
 136     while i < len(data) and data[i].gc_type not in ['start', 'full', 'nursery+update']:
 137         i += 1
 138     if i == len(data):
 139         return None
 140     # If full event, done.
 141     if data[i].gc_type == 'full':
 142         return (FullMajorGCEventGroup(data[i]), i + 1)
 143     start_event = data[i]
 144     update_events = []
 145     # Filter update events and find finish event.
 146     while i < len(data) and data[i].gc_type != 'nursery+finish':
 147         if data[i].gc_type == 'nursery+update':
 148             update_events.append(data[i])
 149         i += 1
 150     if i == len(data):
 151         return None
 152     finish_event = data[i]
 153     i += 1
 154     return (ConcurrentMajorGCEventGroup(start_event, update_events, finish_event), i)
 155
 156 # [Event] -> [MajorGCEventGroup]
 157 def parse_major_gcs(data):
 158     major_gc_events = []
 159     i = 0
 160     while True:
 161         maybe_event_group = parse_next_major_gc(data, i)
 162         if maybe_event_group is None:
 163             return major_gc_events
 164         event_group, i = maybe_event_group
 165         major_gc_events.append(event_group)
 166
 167 if show_histogram or show_scatter:
 168     bin_data_minor = []
 169     bin_data_both = []
 170     bin_data_major = []
 171     bin_names = []
 172
 173     timeline_x = []
 174     timeline_y = []
 175     timeline_c = []
 176
 177     for rec in data:
 178         pause = rec.stop - rec.start
 179
 180         color = None
 181         if rec.major_work:
 182             if rec.minor_work:
 183                 color = 'purple'
 184             else:
 185                 color = 'red' if show_major else None
 186         else:
 187             color = 'blue' if show_minor else None
 188
 189         if color:
 190             timeline_x.append(rec.start)
 191             timeline_y.append(pause)
 192             timeline_c.append(color)
 193
 194         for i in range(100):
 195             time = (1.3)**(i+6)
 196             prev_time = 0 if i==0 else (1.3)**(i+5)
 197             if len(bin_names) <= i:
 198                 bin_data_minor.append(0)
 199                 bin_data_both.append(0)
 200                 bin_data_major.append(0)
 201                 bin_names.append('%d-%dms' % (int(prev_time), int(time)))
 202             if pause <= time:
 203                 if rec.major_work:
 204                     if rec.minor_work:
 205                         bin_data_both[i] += pause
 206                     else:
 207                         bin_data_major[i] += pause
 208                 else:
 209                     bin_data_minor[i] += pause
 210                 break
 211
 212     bin_data_minor=np.array(bin_data_minor)
 213     bin_data_both=np.array(bin_data_both)
 214     bin_data_major=np.array(bin_data_major)
 215
 216     if show_scatter:
 217         plt.scatter(timeline_x, timeline_y, c=timeline_c)
 218     else:
 219         if show_minor:
 220             plt.bar(range(len(bin_data_minor)), bin_data_minor, color='blue', label="minor")  #, align='center')
 221             plt.bar(range(len(bin_data_both)), bin_data_both, bottom=bin_data_minor, color='purple', label="minor & major")
 222             if show_major:
 223                 plt.bar(range(len(bin_data_major)), bin_data_major, bottom=(bin_data_minor+bin_data_both), color='red', label="only major")
 224         else:
 225             plt.bar(range(len(bin_data_both)), bin_data_both, color='purple', label="minor & major")
 226             plt.bar(range(len(bin_data_major)), bin_data_major, bottom=bin_data_both, color='red')
 227         plt.xticks(range(len(bin_names)), bin_names)
 228         plt.ylabel('Cumulative time spent in GC pauses (ms)')
 229         plt.xlabel('GC pause length')
 230         plt.xticks(rotation=60)
 231         plt.legend(loc='upper left')
 232 else:
 233     major_gc_event_groups = parse_major_gcs(data)
 234
 235     def bar(**kwargs):
 236         indices = kwargs['indices']
 237         pauses = kwargs['pauses']
 238         color = kwargs['color']
 239         if 'bottom' in kwargs:
 240             bottom = kwargs['bottom']
 241         else:
 242             bottom = 0
 243         plt.bar(
 244             [index for index in indices if pauses[index] is not None],
 245             np.array([pause for pause in pauses if pause is not None]),
 246             color=color,
 247             bottom=bottom,
 248         )
 249
 250     indices = np.arange(len(major_gc_event_groups))
 251     start_pauses = [
 252         event_group.start.stop - event_group.start.start
 253         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 254         for event_group in major_gc_event_groups
 255     ]
 256     bar(
 257         indices=indices,
 258         pauses=start_pauses,
 259         color='red',
 260     )
 261     update_pauses = [
 262         sum([
 263             update_event.stop - update_event.start
 264             for update_event in event_group.updates
 265         ]) if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 266         for event_group in major_gc_event_groups
 267     ]
 268     bar(
 269         indices=indices,
 270         pauses=update_pauses,
 271         color='green',
 272         bottom=[pause for pause in start_pauses if pause is not None],
 273     )
 274     finish_pauses = [
 275         event_group.finish.stop - event_group.finish.start
 276         if isinstance(event_group, ConcurrentMajorGCEventGroup) else None
 277         for event_group in major_gc_event_groups
 278     ]
 279     start_update_pauses = [
 280         a + b
 281         for a, b in zip(start_pauses, update_pauses)
 282         if a is not None and b is not None
 283     ]
 284     bar(
 285         indices=indices,
 286         pauses=finish_pauses,
 287         color='blue',
 288         bottom=start_update_pauses,
 289     )
 290     full_pauses = [
 291         event_group.event.stop - event_group.event.start
 292         if isinstance(event_group, FullMajorGCEventGroup) else None
 293         for event_group in major_gc_event_groups
 294     ]
 295     bar(
 296         indices=indices,
 297         pauses=full_pauses,
 298         color='black',
 299     )
 300
 301     plt.ylabel("Pause Time (ms)")
 302     plt.xlabel("Collection")
 303
 304 plt.show()