Author: Armin Rigo <[email protected]>
Branch: stmgc-c7
Changeset: r73781:e51b6e693dec
Date: 2014-10-05 15:16 +0200
http://bitbucket.org/pypy/pypy/changeset/e51b6e693dec/
Log: Reporting a summary of a PYPYSTM file
diff --git a/pypy/stm/print_stm_log.py b/pypy/stm/print_stm_log.py
new file mode 100755
--- /dev/null
+++ b/pypy/stm/print_stm_log.py
@@ -0,0 +1,175 @@
+#!/usr/bin/env python
+import sys
+import struct
+
+# ____________________________________________________________
+
+STM_TRANSACTION_START = 0
+STM_TRANSACTION_COMMIT = 1
+STM_TRANSACTION_ABORT = 2
+
+# contention; see details at the start of contention.c
+STM_CONTENTION_WRITE_WRITE = 3 # markers: self loc / other written loc
+STM_CONTENTION_WRITE_READ = 4 # markers: self written loc / other missing
+STM_CONTENTION_INEVITABLE = 5 # markers: self loc / other inev loc
+
+# following a contention, we get from the same thread one of
+# STM_ABORTING_OTHER_CONTENTION, STM_TRANSACTION_ABORT (self-abort),
+# or STM_WAIT_CONTENTION (self-wait).
+STM_ABORTING_OTHER_CONTENTION = 6
+
+# always one STM_WAIT_xxx followed later by STM_WAIT_DONE
+STM_WAIT_FREE_SEGMENT = 7
+STM_WAIT_SYNC_PAUSE = 8
+STM_WAIT_CONTENTION = 9
+STM_WAIT_DONE = 10
+
+# start and end of GC cycles
+STM_GC_MINOR_START = 11
+STM_GC_MINOR_DONE = 12
+STM_GC_MAJOR_START = 13
+STM_GC_MAJOR_DONE = 14
+
+event_name = {}
+for _key, _value in globals().items():
+ if _key.startswith('STM_'):
+ event_name[_value] = _key
+
+# ____________________________________________________________
+
+
+class LogEntry(object):
+ def __init__(self, timestamp, threadnum, otherthreadnum,
+ event, marker1, marker2):
+ self.timestamp = timestamp
+ self.threadnum = threadnum
+ self.otherthreadnum = otherthreadnum
+ self.event = event
+ self.marker1 = marker1
+ self.marker2 = marker2
+
+
+def parse_log(filename):
+ f = open(filename, 'rb')
+ result = []
+ try:
+ header = f.read(16)
+ if header != "STMGC-C7-PROF01\n":
+ raise ValueError("wrong format in file %r" % (filename,))
+ result = []
+ while True:
+ packet = f.read(19)
+ if not packet: break
+ sec, nsec, threadnum, otherthreadnum, event, len1, len2 = \
+ struct.unpack("IIIIBBB", packet)
+ m1 = f.read(len1)
+ m2 = f.read(len2)
+ result.append(LogEntry(sec + 0.000000001 * nsec,
+ threadnum, otherthreadnum, event, m1, m2))
+ finally:
+ f.close()
+ return result
+
+
+
+class ThreadState(object):
+ def __init__(self, threadnum):
+ self.threadnum = threadnum
+ self.cpu_time = 0.0
+
+ def transaction_start(self, entry):
+ self._start = entry
+ self._conflict = None
+
+ def transaction_stop(self, entry):
+ transaction_time = entry.timestamp - self._start.timestamp
+ self.cpu_time += transaction_time
+ self._start = None
+ if self._conflict and entry.event == STM_TRANSACTION_ABORT:
+ c = self._conflict[1]
+ c.aborted_time += transaction_time
+ self._conflict = None
+
+ def in_transaction(self):
+ return self._start is not None
+
+
+class ConflictSummary(object):
+ def __init__(self, event, marker1, marker2):
+ self.event = event
+ self.marker1 = marker1
+ self.marker2 = marker2
+ self.aborted_time = 0.0
+ self.paused_time = 0.0
+ self.num_events = 0
+
+ def sortkey(self):
+ return self.aborted_time + self.paused_time
+
+
+def percent(fraction, total):
+ r = '%.1f' % (fraction * 100.0 / total)
+ if len(r) > 3:
+ r = r.split('.')[0]
+ return r + '%'
+
+def dump(logentries):
+ total_time = logentries[-1].timestamp - logentries[0].timestamp
+ print 'Total real time: %.3fs' % (total_time,)
+ #
+ threads = {}
+ conflicts = {}
+ for entry in logentries:
+ if entry.event == STM_TRANSACTION_START:
+ t = threads.get(entry.threadnum)
+ if t is None:
+ t = threads[entry.threadnum] = ThreadState(entry.threadnum)
+ t.transaction_start(entry)
+ elif (entry.event == STM_TRANSACTION_COMMIT or
+ entry.event == STM_TRANSACTION_ABORT):
+ t = threads.get(entry.threadnum)
+ if t is not None and t.in_transaction():
+ t.transaction_stop(entry)
+ elif entry.event in (STM_CONTENTION_WRITE_WRITE,
+ STM_CONTENTION_WRITE_READ,
+ STM_CONTENTION_INEVITABLE):
+ summary = (entry.event, entry.marker1, entry.marker2)
+ c = conflicts.get(summary)
+ if c is None:
+ c = conflicts[summary] = ConflictSummary(*summary)
+ c.num_events += 1
+ t = threads.get(entry.threadnum)
+ if t is not None and t.in_transaction():
+ t._conflict = ("local", c, entry)
+ elif entry.event == STM_ABORTING_OTHER_CONTENTION:
+ t = threads.get(entry.threadnum)
+ if t is not None and t._conflict and t._conflict[0] == "local":
+ _, c, entry = t._conflict
+ t._conflict = None
+ t2 = threads.get(entry.otherthreadnum)
+ if t2 is not None and t2.in_transaction():
+ t2._conflict = ("remote", c, entry)
+ #elif entry.event == ...STM_WAIT...
+ #
+ total_cpu_time = sum([t.cpu_time for t in threads.values()])
+ print 'Total CPU time in STM mode: %.3fs (%s)' % (
+ total_cpu_time, percent(total_cpu_time, total_time))
+ print
+ #
+ values = sorted(conflicts.values(), key=ConflictSummary.sortkey)
+ for c in values[-1:-15:-1]:
+ print '%.3fs lost in aborts, %.3fs paused (%s)' % (
+ c.aborted_time, c.paused_time, event_name[c.event])
+ print ' ', c.marker1
+ if c.marker2:
+ print ' ', c.marker2
+ print
+
+
+def main(argv):
+ assert len(argv) == 1, "expected a filename argument"
+ dump(parse_log(argv[0]))
+ return 0
+
+if __name__ == '__main__':
+ sys.exit(main(sys.argv[1:]))
_______________________________________________
pypy-commit mailing list
[email protected]
https://mail.python.org/mailman/listinfo/pypy-commit
