File: process_perf_output.py

package info (click to toggle)
chromium-browser 41.0.2272.118-1
  • links: PTS, VCS
  • area: main
  • in suites: jessie-kfreebsd
  • size: 2,189,132 kB
  • sloc: cpp: 9,691,462; ansic: 3,341,451; python: 712,689; asm: 518,779; xml: 208,926; java: 169,820; sh: 119,353; perl: 68,907; makefile: 28,311; yacc: 13,305; objc: 11,385; tcl: 3,186; cs: 2,225; sql: 2,217; lex: 2,215; lisp: 1,349; pascal: 1,256; awk: 407; ruby: 155; sed: 53; php: 14; exp: 11
file content (133 lines) | stat: -rwxr-xr-x 4,450 bytes parent folder | download | duplicates (3)
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())