1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133
|
#!/usr/bin/python
# Copyright (c) 2011 The Native Client Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.
import re
import sys
# Process log output from various components (e.g., sel_ldr, browser tester),
# line-by-line and prints out a summary of TIME performance measurements.
#
# ================
# LOG INPUTS:
# ================
# Logs can contain information from any number of Sources.
#
# For example, the sel_ldr logs and browser test logs might be Sources.
#
# This processor expects to match at least one line of info from each
# Source. If a source does not provide any events, then this is an error
# (the motivation being that we will pick up on log format changes this way).
# TODO(jvoung): Allow an escape hatch for some Sources.
#
# Each Eventful line with time info should contain:
#
# (a) an event name
# (b) a time value
#
# The time values can be in any unit, but will be converted to millisecs.
#
# NOTE: If multiple events with the same event name are present, then
# the time values will be summed. This is useful, for example, to get the
# total validation time of all dynamic libraries that are loaded.
# However, this means that if a nexe is loaded twice, then the two time
# values will get merged into one.
# TODO(jvoung): provide a mechanism to split multiple merged event streams.
#
# ================
# SUMMARY OUTPUT:
# ================
# Should be formatted according to the chrome buildbot format.
def GetEventPatterns():
return [
# NaClPerfCounterInterval (${SERIES} ${EVENT_A}:*${EVENT_B}): N microsecs
# -->
# RESULT ${GRAPH}: ${EVENT_B}_${SETUP_INFO}= N/1000 ms
# Thus, this assumes that the EVENT_B provides the useful name
# E.g., EVENT_A might be "Pre-Validation"
# while EVENT_B is "Validation" (so this times validation)
# Note, there is an asterisk in EVENT_B to indicate that it is important
# enough to be included here.
Pattern('SelLdr',
'NaClPerfCounterInterval\(.*:\*(.*)\): (\d+) microsecs',
1, 2, 0.001),
# NaClPerf [${EVENT_NAME}]: N millisecs
# -->
# RESULT ${GRAPH}: ${EVENT_NAME}_${SETUP_INFO}= N ms
Pattern('BrowserTester',
'NaClPerf \[(.*)\] (\d+\.*\d*) millisecs',
1, 2, 1.0),
]
class Pattern(object):
def __init__(self,
name,
patternRE,
eventIndex,
timeIndex,
scaleToMilli):
self.name = name
self.re = re.compile(patternRE)
self.eventIndex = eventIndex
self.timeIndex = timeIndex
self.scaleToMilli = scaleToMilli
self.didMatch = False
self.accumulatedTimes = {}
def _eventLabel(self, match):
return match.group(self.eventIndex)
def _timeInMillis(self, match):
return float(match.group(self.timeIndex)) * self.scaleToMilli
def _match(self, s):
return self.re.search(s)
def ProcessLine(self, line):
match = self._match(line)
if not match:
return False
self.didMatch = True
event = self._eventLabel(match)
time = self._timeInMillis(match)
# Sum up the times for a particular event.
self.accumulatedTimes[event] = self.accumulatedTimes.get(event, 0) + time
return True
def SanityCheck(self):
# Make sure all patterns matched at least once.
if not self.didMatch:
sys.stderr.write(('Pattern for %s did not match anything.\n'
'Perhaps the format has changed.\n') % self.name)
assert False
def PrintSummary(self, graph_label, trace_label_extra):
for event, time in self.accumulatedTimes.iteritems():
sys.stdout.write('RESULT %s: %s_%s= %f ms\n' %
(graph_label, event, trace_label_extra, time))
def Main():
usage = 'usage: %prog graphLabel traceExtra < stdin\n'
if len(sys.argv) != 3:
sys.stderr.write(usage)
return 1
graph_label = sys.argv[1]
trace_label_extra = sys.argv[2]
event_patterns = GetEventPatterns()
for line in sys.stdin.readlines():
for pat in event_patterns:
if pat.ProcessLine(line):
continue
# Also echo the original data for debugging.
sys.stdout.write(line)
# Print the summary in the end.
for pat in event_patterns:
pat.SanityCheck()
pat.PrintSummary(graph_label, trace_label_extra)
return 0
if __name__ == '__main__':
sys.exit(Main())
|