OLD | NEW |
(Empty) | |
| 1 # Copyright 2014 The Chromium Authors. All rights reserved. |
| 2 # Use of this source code is governed by a BSD-style license that can be |
| 3 # found in the LICENSE file. |
| 4 |
| 5 """This module contains PerformanceLogProcessor and subclasses. |
| 6 |
| 7 Several performance tests have complicated log output, this module is intended |
| 8 to help buildsteps parse these logs and identify if tests had anomalies. |
| 9 |
| 10 The classes in this file all have the same method ProcessLine, just like |
| 11 GTestLogParser in //tools/build/scripts/common/gtest_utils.py. They also |
| 12 construct a set of files which are used for graphing. |
| 13 |
| 14 Note: This module is doomed to be deprecated in the future, as Telemetry |
| 15 results will be passed more directly to the new performance dashboard. |
| 16 """ |
| 17 |
| 18 import collections |
| 19 import json |
| 20 import logging |
| 21 import os |
| 22 import re |
| 23 |
| 24 from common import chromium_utils |
| 25 |
| 26 # TODO(crbug.com/403564). |
| 27 import config |
| 28 |
| 29 # Status codes that can be returned by the evaluateCommand method. |
| 30 # From buildbot.status.builder. |
| 31 # See: http://docs.buildbot.net/current/developer/results.html |
| 32 SUCCESS, WARNINGS, FAILURE, SKIPPED, EXCEPTION, RETRY = range(6) |
| 33 |
| 34 |
| 35 class PerformanceLogProcessor(object): |
| 36 """Parent class for performance log parsers. |
| 37 |
| 38 The only essential public method that subclasses must define is the method |
| 39 ProcessLine, which takes one line of a test output log and uses it |
| 40 to change the internal state of the PerformanceLogProcessor object, |
| 41 so that methods such as PerformanceLogs return the right thing. |
| 42 """ |
| 43 |
| 44 # The file perf_expectations.json holds performance expectations. |
| 45 # For more info, see: http://goo.gl/BhYvDa |
| 46 PERF_EXPECTATIONS_PATH = 'src/tools/perf_expectations/' |
| 47 |
| 48 def __init__(self, revision=None, factory_properties=None, |
| 49 build_properties=None, webkit_revision='undefined'): |
| 50 """Initializes the log processor. |
| 51 |
| 52 Args: |
| 53 revision: Revision number; this currently could also be a git number. |
| 54 It is sent to the perf dashboard to be used as the x-value. |
| 55 factory_properties: Factory properties dict. |
| 56 build_properties: Build properties dict. |
| 57 webkit_revision: Blink revision number. |
| 58 """ |
| 59 if factory_properties is None: |
| 60 factory_properties = {} |
| 61 |
| 62 # Performance regression/speedup alerts. |
| 63 self._read_expectations = False |
| 64 |
| 65 self._perf_id = factory_properties.get('perf_id') |
| 66 self._perf_name = factory_properties.get('perf_name') |
| 67 self._perf_filename = factory_properties.get('perf_filename') |
| 68 self._test_name = factory_properties.get('test_name') |
| 69 |
| 70 self._perf_data = {} |
| 71 self._perf_test_keys = {} |
| 72 self._perf_ref_keys = {} |
| 73 self._perf_regress = [] |
| 74 self._perf_improve = [] |
| 75 |
| 76 # A dict mapping output file names to lists of lines in a file. |
| 77 self._output = {} |
| 78 |
| 79 # Whether or not the processing has been finalized (i.e. whether |
| 80 # self._FinalizeProcessing has been called.) |
| 81 self._finalized = False |
| 82 |
| 83 # The text summary will be built by other methods as we go. |
| 84 # This is a list of strings with messages about the processing. |
| 85 self._text_summary = [] |
| 86 |
| 87 # Enable expectations if the local configuration supports it. |
| 88 self._expectations = (factory_properties.get('expectations') |
| 89 and self._perf_id and self._perf_name) |
| 90 if self._expectations and not self._perf_filename: |
| 91 self._perf_filename = os.path.join(self.PERF_EXPECTATIONS_PATH, |
| 92 'perf_expectations.json') |
| 93 |
| 94 if revision: |
| 95 self._revision = revision |
| 96 else: |
| 97 raise ValueError('Must provide a revision to PerformanceLogProcessor.') |
| 98 |
| 99 self._webkit_revision = webkit_revision |
| 100 |
| 101 if not build_properties: |
| 102 build_properties = {} |
| 103 self._git_revision = build_properties.get('git_revision', 'undefined') |
| 104 self._version = build_properties.get('version', 'undefined') |
| 105 self._channel = build_properties.get('channel', 'undefined') |
| 106 self._webrtc_revision = build_properties.get('got_webrtc_revision', |
| 107 'undefined') |
| 108 |
| 109 self._v8_revision = 'undefined' |
| 110 if factory_properties.get('show_v8_revision'): |
| 111 self._v8_revision = build_properties.get('got_v8_revision', 'undefined') |
| 112 |
| 113 self._percentiles = [.1, .25, .5, .75, .90, .95, .99] |
| 114 |
| 115 def IsChartJson(self): # pylint: disable=R0201 |
| 116 """This is not the new telemetry --chartjson output format.""" |
| 117 return False |
| 118 |
| 119 def PerformanceLogs(self): |
| 120 if not self._finalized: |
| 121 self._FinalizeProcessing() |
| 122 self._finalized = True |
| 123 return self._output |
| 124 |
| 125 def PerformanceSummary(self): |
| 126 """Returns a list of strings about performance changes and other info.""" |
| 127 if not self._finalized: |
| 128 self._FinalizeProcessing() |
| 129 self._finalized = True |
| 130 return self.PerformanceChanges() + self._text_summary |
| 131 |
| 132 def _FinalizeProcessing(self): |
| 133 """Hook for subclasses to do final operations before output is returned.""" |
| 134 # This method is to be defined by inheriting classes. |
| 135 pass |
| 136 |
| 137 def AppendLog(self, filename, data): |
| 138 """Appends some data to an output file.""" |
| 139 self._output[filename] = self._output.get(filename, []) + data |
| 140 |
| 141 def PrependLog(self, filename, data): |
| 142 """Prepends some data to an output file.""" |
| 143 self._output[filename] = data + self._output.get(filename, []) |
| 144 |
| 145 def FailedTests(self): # pylint: disable=R0201 |
| 146 return [] |
| 147 |
| 148 def MemoryToolReportHashes(self): # pylint: disable=R0201 |
| 149 return [] |
| 150 |
| 151 def ParsingErrors(self): # pylint: disable=R0201 |
| 152 return [] |
| 153 |
| 154 def LoadPerformanceExpectationsData(self, all_perf_data): |
| 155 """Load the expectations data. |
| 156 |
| 157 All keys in perf_expectations have 4 components: |
| 158 slave/test/graph/trace |
| 159 |
| 160 LoadPerformanceExpectationsData finds all keys that match the initial |
| 161 portion of the string ("slave/test") and adds the graph and result |
| 162 portions to the expected performance structure. |
| 163 """ |
| 164 |
| 165 for perf_key in all_perf_data.keys(): |
| 166 # tools/perf_expectations/tests/perf_expectations_unittest.py should have |
| 167 # a matching regular expression. |
| 168 m = re.search(r'^' + self._perf_name + '/' + self._test_name + |
| 169 r'/([\w\.-]+)/([\w\.-]+)$', perf_key) |
| 170 if not m: |
| 171 continue |
| 172 |
| 173 perf_data = all_perf_data[perf_key] |
| 174 graph = m.group(1) |
| 175 trace = m.group(2) |
| 176 |
| 177 # By default, all perf data is type=relative. |
| 178 perf_data.setdefault('type', 'relative') |
| 179 |
| 180 # By default, relative perf data is compare against the fqtn+'_ref'. |
| 181 if perf_data['type'] == 'relative' and 'ref' not in perf_data: |
| 182 perf_data['ref'] = '%s/%s/%s/%s_ref' % ( |
| 183 self._perf_name, self._test_name, graph, trace) |
| 184 |
| 185 # For each test key, we add a reference in _perf_test_keys to perf_data. |
| 186 self._perf_test_keys.setdefault(perf_key, []) |
| 187 self._perf_test_keys[perf_key].append(perf_data) |
| 188 |
| 189 # For each ref key, we add a reference in _perf_ref_keys to perf_data. |
| 190 if 'ref' in perf_data: |
| 191 self._perf_ref_keys.setdefault(perf_data['ref'], []) |
| 192 self._perf_ref_keys[perf_data['ref']].append(perf_data) |
| 193 |
| 194 self._perf_data.setdefault(graph, {}) |
| 195 self._perf_data[graph][trace] = perf_data |
| 196 |
| 197 def LoadPerformanceExpectations(self): |
| 198 if not self._expectations: |
| 199 # self._expectations is false when a given factory doesn't enable |
| 200 # expectations, or doesn't have both perf_id and perf_name set. |
| 201 return |
| 202 try: |
| 203 perf_file = open(self._perf_filename, 'r') |
| 204 except IOError, e: |
| 205 logging.error('I/O Error reading expectations %s(%s): %s' % |
| 206 (self._perf_filename, e.errno, e.strerror)) |
| 207 return |
| 208 |
| 209 perf_data = {} |
| 210 if perf_file: |
| 211 try: |
| 212 perf_data = json.load(perf_file) |
| 213 except ValueError: |
| 214 perf_file.seek(0) |
| 215 logging.error('Error parsing expectations %s: \'%s\'' % |
| 216 (self._perf_filename, perf_file.read().strip())) |
| 217 perf_file.close() |
| 218 |
| 219 # Find this perf/test entry |
| 220 if perf_data and perf_data.has_key('load') and perf_data['load']: |
| 221 self.LoadPerformanceExpectationsData(perf_data) |
| 222 else: |
| 223 logging.error('not loading perf expectations: perf_data is disabled') |
| 224 self._read_expectations = True |
| 225 |
| 226 def TrackActualPerformance(self, graph=None, trace=None, value=None, |
| 227 stddev=None): |
| 228 """Set actual performance data when we come across useful values. |
| 229 |
| 230 trace will be of the form "RESULTTYPE" or "RESULTTYPE_ref". |
| 231 A trace with _ref in its name refers to a reference build. |
| 232 |
| 233 Common result types for page cyclers: t, vm_rss_f_r, IO_b_b, etc. |
| 234 A test's result types vary between test types. Currently, a test |
| 235 only needs to output the appropriate text format to embed a new |
| 236 result type. |
| 237 """ |
| 238 |
| 239 fqtn = '%s/%s/%s/%s' % (self._perf_name, self._test_name, graph, trace) |
| 240 if fqtn in self._perf_test_keys: |
| 241 for perf_data in self._perf_test_keys[fqtn]: |
| 242 perf_data['actual_test'] = value |
| 243 perf_data['actual_var'] = stddev |
| 244 |
| 245 if perf_data['type'] == 'absolute' and 'actual_test' in perf_data: |
| 246 perf_data['actual_delta'] = perf_data['actual_test'] |
| 247 |
| 248 elif perf_data['type'] == 'relative': |
| 249 if 'actual_test' in perf_data and 'actual_ref' in perf_data: |
| 250 perf_data['actual_delta'] = ( |
| 251 perf_data['actual_test'] - perf_data['actual_ref']) |
| 252 |
| 253 if fqtn in self._perf_ref_keys: |
| 254 for perf_data in self._perf_ref_keys[fqtn]: |
| 255 perf_data['actual_ref'] = value |
| 256 |
| 257 if 'actual_test' in perf_data and 'actual_ref' in perf_data: |
| 258 perf_data['actual_delta'] = ( |
| 259 perf_data['actual_test'] - perf_data['actual_ref']) |
| 260 |
| 261 def PerformanceChangesAsText(self): |
| 262 """Returns a list of strings which describe performance changes.""" |
| 263 |
| 264 text = [] |
| 265 |
| 266 if self._expectations and not self._read_expectations: |
| 267 text.append('MISS_EXPECTATIONS') |
| 268 |
| 269 if self._perf_regress: |
| 270 text.append('PERF_REGRESS: ' + ', '.join(self._perf_regress)) |
| 271 |
| 272 if self._perf_improve: |
| 273 text.append('PERF_IMPROVE: ' + ', '.join(self._perf_improve)) |
| 274 |
| 275 return text |
| 276 |
| 277 def ComparePerformance(self, graph, trace): |
| 278 """Populates internal data about improvements and regressions.""" |
| 279 # Skip graphs and traces we don't expect values for. |
| 280 if not graph in self._perf_data or not trace in self._perf_data[graph]: |
| 281 return |
| 282 |
| 283 perfdata = self._perf_data[graph][trace] |
| 284 graph_result = graph + '/' + trace |
| 285 |
| 286 # Skip result types that didn't calculate a delta. |
| 287 if not 'actual_delta' in perfdata: |
| 288 return |
| 289 |
| 290 # Skip result types that don't have regress/improve values. |
| 291 if 'regress' not in perfdata or 'improve' not in perfdata: |
| 292 return |
| 293 |
| 294 # Set the high and low performance tests. |
| 295 # The actual delta needs to be within this range to keep the perf test |
| 296 # green. If the results fall above or below this range, the test will go |
| 297 # red (signaling a regression) or orange (signaling a speedup). |
| 298 actual = perfdata['actual_delta'] |
| 299 regress = perfdata['regress'] |
| 300 improve = perfdata['improve'] |
| 301 if (('better' in perfdata and perfdata['better'] == 'lower') or |
| 302 ('better' not in perfdata and regress > improve)): |
| 303 # The "lower is better" case. (ie. time results) |
| 304 if actual < improve: |
| 305 ratio = 1 - _Divide(actual, improve) |
| 306 self._perf_improve.append('%s (%s)' % (graph_result, |
| 307 _FormatPercentage(ratio))) |
| 308 elif actual > regress: |
| 309 ratio = _Divide(actual, regress) - 1 |
| 310 self._perf_regress.append('%s (%s)' % (graph_result, |
| 311 _FormatPercentage(ratio))) |
| 312 else: |
| 313 # The "higher is better" case. (ie. score results) |
| 314 if actual > improve: |
| 315 ratio = _Divide(actual, improve) - 1 |
| 316 self._perf_improve.append('%s (%s)' % (graph_result, |
| 317 _FormatPercentage(ratio))) |
| 318 elif actual < regress: |
| 319 ratio = 1 - _Divide(actual, regress) |
| 320 self._perf_regress.append('%s (%s)' % (graph_result, |
| 321 _FormatPercentage(ratio))) |
| 322 |
| 323 def PerformanceChanges(self): |
| 324 """Compares actual and expected results. |
| 325 |
| 326 Returns: |
| 327 A list of strings indicating improvements or regressions. |
| 328 """ |
| 329 # Compare actual and expected results. |
| 330 for graph in self._perf_data: |
| 331 for trace in self._perf_data[graph]: |
| 332 self.ComparePerformance(graph, trace) |
| 333 |
| 334 return self.PerformanceChangesAsText() |
| 335 |
| 336 # Unused argument cmd. |
| 337 # pylint: disable=W0613 |
| 338 def evaluateCommand(self, cmd): |
| 339 """Returns a status code indicating success, failure, etc. |
| 340 |
| 341 See: http://docs.buildbot.net/current/developer/cls-buildsteps.html |
| 342 |
| 343 Args: |
| 344 cmd: A command object. Not used here. |
| 345 |
| 346 Returns: |
| 347 A status code (One of SUCCESS, WARNINGS, FAILURE, etc.) |
| 348 """ |
| 349 if self._expectations and not self._read_expectations: |
| 350 return WARNINGS |
| 351 |
| 352 # make sure regression and improvement logs are calculated |
| 353 self.PerformanceSummary() |
| 354 |
| 355 if self._perf_regress: |
| 356 return FAILURE |
| 357 |
| 358 if self._perf_improve: |
| 359 return WARNINGS |
| 360 |
| 361 # There was no change in performance, report success. |
| 362 return SUCCESS |
| 363 |
| 364 def ProcessLine(self, line): |
| 365 """Process one line of a log file.""" |
| 366 # This method must be overridden by subclass |
| 367 pass |
| 368 |
| 369 |
| 370 class GraphingLogProcessor(PerformanceLogProcessor): |
| 371 """Parent class for any log processor expecting standard data to be graphed. |
| 372 |
| 373 The log will be parsed looking for any lines of the forms: |
| 374 <*>RESULT <graph_name>: <trace_name>= <value> <units> |
| 375 or |
| 376 <*>RESULT <graph_name>: <trace_name>= [<value>,value,value,...] <units> |
| 377 or |
| 378 <*>RESULT <graph_name>: <trace_name>= {<mean>, <std deviation>} <units> |
| 379 |
| 380 For example, |
| 381 *RESULT vm_final_browser: OneTab= 8488 kb |
| 382 RESULT startup: ref= [167.00,148.00,146.00,142.00] ms |
| 383 RESULT TabCapturePerformance_foo: Capture= {30.7, 1.45} ms |
| 384 |
| 385 The leading * is optional; it indicates that the data from that line should |
| 386 be considered "important", which may mean for example that it's graphed by |
| 387 default. |
| 388 |
| 389 If multiple values are given in [], their mean and (sample) standard |
| 390 deviation will be written; if only one value is given, that will be written. |
| 391 A trailing comma is permitted in the list of values. |
| 392 |
| 393 NOTE: All lines except for RESULT lines are ignored, including the Avg and |
| 394 Stddev lines output by Telemetry! |
| 395 |
| 396 Any of the <fields> except <value> may be empty, in which case the |
| 397 not-terribly-useful defaults will be used. The <graph_name> and <trace_name> |
| 398 should not contain any spaces, colons (:) nor equals-signs (=). Furthermore, |
| 399 the <trace_name> will be used on the waterfall display, so it should be kept |
| 400 short. If the trace_name ends with '_ref', it will be interpreted as a |
| 401 reference value, and shown alongside the corresponding main value on the |
| 402 waterfall. |
| 403 |
| 404 Semantic note: The terms graph and chart are used interchangeably here. |
| 405 """ |
| 406 |
| 407 # The file into which the GraphingLogProcessor will save a list of graph |
| 408 # names for use by the JS doing the plotting. |
| 409 GRAPH_LIST = config.Master.perf_graph_list |
| 410 |
| 411 RESULTS_REGEX = re.compile(r'(?P<IMPORTANT>\*)?RESULT ' |
| 412 r'(?P<GRAPH>[^:]*): (?P<TRACE>[^=]*)= ' |
| 413 r'(?P<VALUE>[\{\[]?[-\d\., ]+[\}\]]?)(' |
| 414 r' ?(?P<UNITS>.+))?') |
| 415 HISTOGRAM_REGEX = re.compile(r'(?P<IMPORTANT>\*)?HISTOGRAM ' |
| 416 r'(?P<GRAPH>[^:]*): (?P<TRACE>[^=]*)= ' |
| 417 r'(?P<VALUE_JSON>{.*})(?P<UNITS>.+)?') |
| 418 |
| 419 class Trace(object): |
| 420 """Encapsulates data for one trace. Here, this means one point.""" |
| 421 |
| 422 def __init__(self): |
| 423 self.important = False |
| 424 self.value = 0.0 |
| 425 self.stddev = 0.0 |
| 426 |
| 427 def __str__(self): |
| 428 result = _FormatHumanReadable(self.value) |
| 429 if self.stddev: |
| 430 result += '+/-%s' % _FormatHumanReadable(self.stddev) |
| 431 return result |
| 432 |
| 433 class Graph(object): |
| 434 """Encapsulates a set of points that should appear on the same graph.""" |
| 435 |
| 436 def __init__(self): |
| 437 self.units = None |
| 438 self.traces = {} |
| 439 |
| 440 def IsImportant(self): |
| 441 """A graph is considered important if any of its traces is important.""" |
| 442 for trace in self.traces.itervalues(): |
| 443 if trace.important: |
| 444 return True |
| 445 return False |
| 446 |
| 447 def BuildTracesDict(self): |
| 448 """Returns a dictionary mapping trace names to [value, stddev].""" |
| 449 traces_dict = {} |
| 450 for name, trace in self.traces.items(): |
| 451 traces_dict[name] = [str(trace.value), str(trace.stddev)] |
| 452 return traces_dict |
| 453 |
| 454 def __init__(self, *args, **kwargs): |
| 455 """Initiates this log processor.""" |
| 456 PerformanceLogProcessor.__init__(self, *args, **kwargs) |
| 457 |
| 458 # A dict of Graph objects, by name. |
| 459 self._graphs = {} |
| 460 |
| 461 # Load performance expectations for this test. |
| 462 self.LoadPerformanceExpectations() |
| 463 |
| 464 def ProcessLine(self, line): |
| 465 """Processes one result line, and updates the state accordingly.""" |
| 466 results_match = self.RESULTS_REGEX.search(line) |
| 467 histogram_match = self.HISTOGRAM_REGEX.search(line) |
| 468 if results_match: |
| 469 self._ProcessResultLine(results_match) |
| 470 elif histogram_match: |
| 471 self._ProcessHistogramLine(histogram_match) |
| 472 |
| 473 def _ProcessResultLine(self, line_match): |
| 474 """Processes a line that matches the standard RESULT line format. |
| 475 |
| 476 Args: |
| 477 line_match: A MatchObject as returned by re.search. |
| 478 """ |
| 479 match_dict = line_match.groupdict() |
| 480 graph_name = match_dict['GRAPH'].strip() |
| 481 trace_name = match_dict['TRACE'].strip() |
| 482 |
| 483 graph = self._graphs.get(graph_name, self.Graph()) |
| 484 graph.units = match_dict['UNITS'] or '' |
| 485 trace = graph.traces.get(trace_name, self.Trace()) |
| 486 trace.value = match_dict['VALUE'] |
| 487 trace.important = match_dict['IMPORTANT'] or False |
| 488 |
| 489 # Compute the mean and standard deviation for a multiple-valued item, |
| 490 # or the numerical value of a single-valued item. |
| 491 if trace.value.startswith('['): |
| 492 try: |
| 493 value_list = [float(x) for x in trace.value.strip('[],').split(',')] |
| 494 except ValueError: |
| 495 # Report, but ignore, corrupted data lines. (Lines that are so badly |
| 496 # broken that they don't even match the RESULTS_REGEX won't be |
| 497 # detected.) |
| 498 logging.warning("Bad test output: '%s'" % trace.value.strip()) |
| 499 return |
| 500 trace.value, trace.stddev, filedata = self._CalculateStatistics( |
| 501 value_list, trace_name) |
| 502 assert filedata is not None |
| 503 for filename in filedata: |
| 504 self.PrependLog(filename, filedata[filename]) |
| 505 elif trace.value.startswith('{'): |
| 506 stripped = trace.value.strip('{},') |
| 507 try: |
| 508 trace.value, trace.stddev = [float(x) for x in stripped.split(',')] |
| 509 except ValueError: |
| 510 logging.warning("Bad test output: '%s'" % trace.value.strip()) |
| 511 return |
| 512 else: |
| 513 try: |
| 514 trace.value = float(trace.value) |
| 515 except ValueError: |
| 516 logging.warning("Bad test output: '%s'" % trace.value.strip()) |
| 517 return |
| 518 |
| 519 graph.traces[trace_name] = trace |
| 520 self._graphs[graph_name] = graph |
| 521 |
| 522 # Store values in actual performance. |
| 523 self.TrackActualPerformance(graph=graph_name, trace=trace_name, |
| 524 value=trace.value, stddev=trace.stddev) |
| 525 |
| 526 def _ProcessHistogramLine(self, line_match): |
| 527 """Processes a line that matches the HISTOGRAM line format. |
| 528 |
| 529 Args: |
| 530 line_match: A MatchObject as returned by re.search. |
| 531 """ |
| 532 match_dict = line_match.groupdict() |
| 533 graph_name = match_dict['GRAPH'].strip() |
| 534 trace_name = match_dict['TRACE'].strip() |
| 535 units = (match_dict['UNITS'] or '').strip() |
| 536 histogram_json = match_dict['VALUE_JSON'] |
| 537 important = match_dict['IMPORTANT'] or False |
| 538 try: |
| 539 histogram_data = json.loads(histogram_json) |
| 540 except ValueError: |
| 541 # Report, but ignore, corrupted data lines. (Lines that are so badly |
| 542 # broken that they don't even match the HISTOGRAM_REGEX won't be |
| 543 # detected.) |
| 544 logging.warning("Bad test output: '%s'" % histogram_json.strip()) |
| 545 return |
| 546 |
| 547 # Compute percentile data, create a graph for all percentile values. |
| 548 percentiles = self._CalculatePercentiles(histogram_data, trace_name) |
| 549 for i in percentiles: |
| 550 percentile_graph_name = graph_name + "_" + str(i['percentile']) |
| 551 graph = self._graphs.get(percentile_graph_name, self.Graph()) |
| 552 graph.units = units |
| 553 trace = graph.traces.get(trace_name, self.Trace()) |
| 554 trace.value = i['value'] |
| 555 trace.important = important |
| 556 graph.traces[trace_name] = trace |
| 557 self._graphs[percentile_graph_name] = graph |
| 558 self.TrackActualPerformance(graph=percentile_graph_name, |
| 559 trace=trace_name, |
| 560 value=i['value']) |
| 561 |
| 562 # Compute geometric mean and standard deviation. |
| 563 graph = self._graphs.get(graph_name, self.Graph()) |
| 564 graph.units = units |
| 565 trace = graph.traces.get(trace_name, self.Trace()) |
| 566 trace.value, trace.stddev = self._CalculateHistogramStatistics( |
| 567 histogram_data, trace_name) |
| 568 trace.important = important |
| 569 graph.traces[trace_name] = trace |
| 570 self._graphs[graph_name] = graph |
| 571 self.TrackActualPerformance(graph=graph_name, trace=trace_name, |
| 572 value=trace.value, stddev=trace.stddev) |
| 573 |
| 574 # _CalculateStatistics needs to be a member function. |
| 575 # pylint: disable=R0201 |
| 576 # Unused argument value_list. |
| 577 # pylint: disable=W0613 |
| 578 def _CalculateStatistics(self, value_list, trace_name): |
| 579 """Returns a tuple with some statistics based on the given value list. |
| 580 |
| 581 This method may be overridden by subclasses wanting a different standard |
| 582 deviation calcuation (or some other sort of error value entirely). |
| 583 |
| 584 Args: |
| 585 value_list: the list of values to use in the calculation |
| 586 trace_name: the trace that produced the data (not used in the base |
| 587 implementation, but subclasses may use it) |
| 588 |
| 589 Returns: |
| 590 A 3-tuple - mean, standard deviation, and a dict which is either |
| 591 empty or contains information about some file contents. |
| 592 """ |
| 593 mean, stddev = chromium_utils.MeanAndStandardDeviation(value_list) |
| 594 return mean, stddev, {} |
| 595 |
| 596 def _CalculatePercentiles(self, histogram, trace_name): |
| 597 """Returns a list of percentile values from a histogram. |
| 598 |
| 599 This method may be overridden by subclasses. |
| 600 |
| 601 Args: |
| 602 histogram: histogram data (relevant keys: "buckets", and for each bucket, |
| 603 "min", "max" and "count"). |
| 604 trace_name: the trace that produced the data (not used in the base |
| 605 implementation, but subclasses may use it) |
| 606 |
| 607 Returns: |
| 608 A list of dicts, each of which has the keys "percentile" and "value". |
| 609 """ |
| 610 return chromium_utils.HistogramPercentiles(histogram, self._percentiles) |
| 611 |
| 612 def _CalculateHistogramStatistics(self, histogram, trace_name): |
| 613 """Returns the geometric mean and standard deviation for a histogram. |
| 614 |
| 615 This method may be overridden by subclasses. |
| 616 |
| 617 Args: |
| 618 histogram: histogram data (relevant keys: "buckets", and for each bucket, |
| 619 "min", "max" and "count"). |
| 620 trace_name: the trace that produced the data (not used in the base |
| 621 implementation, but subclasses may use it) |
| 622 """ |
| 623 geom_mean, stddev = chromium_utils.GeomMeanAndStdDevFromHistogram(histogram) |
| 624 return geom_mean, stddev |
| 625 |
| 626 def _BuildSummaryJson(self, graph): |
| 627 """Returns JSON with the data in the given graph plus revision information. |
| 628 |
| 629 Args: |
| 630 graph: A GraphingLogProcessor.Graph object. |
| 631 |
| 632 Returns: |
| 633 The format output here is the "-summary.dat line" format; that is, it |
| 634 is a JSON encoding of a dictionary that has the key "traces" |
| 635 """ |
| 636 assert self._revision, 'revision must always be present' |
| 637 |
| 638 graph_dict = collections.OrderedDict([ |
| 639 ('traces', graph.BuildTracesDict()), |
| 640 ('rev', str(self._revision)), |
| 641 ('git_revision', str(self._git_revision)), |
| 642 ('webkit_rev', str(self._webkit_revision)), |
| 643 ('webrtc_rev', str(self._webrtc_revision)), |
| 644 ('v8_rev', str(self._v8_revision)), |
| 645 ('ver', str(self._version)), |
| 646 ('chan', str(self._channel)), |
| 647 ('units', str(graph.units)), |
| 648 ]) |
| 649 |
| 650 # Include a sorted list of important trace names if there are any. |
| 651 important = [t for t in graph.traces.keys() if graph.traces[t].important] |
| 652 if important: |
| 653 graph_dict['important'] = sorted(important) |
| 654 |
| 655 return json.dumps(graph_dict) |
| 656 |
| 657 def _FinalizeProcessing(self): |
| 658 self._CreateSummaryOutput() |
| 659 self._GenerateGraphInfo() |
| 660 |
| 661 def _CreateSummaryOutput(self): |
| 662 """Writes the summary data file and collect the waterfall display text. |
| 663 |
| 664 The summary file contains JSON-encoded data. |
| 665 |
| 666 The waterfall contains lines for each important trace, in the form |
| 667 tracename: value< (refvalue)> |
| 668 """ |
| 669 |
| 670 for graph_name, graph in self._graphs.iteritems(): |
| 671 # Write a line in the applicable summary file for each graph. |
| 672 filename = ('%s-summary.dat' % graph_name) |
| 673 data = [self._BuildSummaryJson(graph) + '\n'] |
| 674 self._output[filename] = data + self._output.get(filename, []) |
| 675 |
| 676 # Add a line to the waterfall for each important trace. |
| 677 for trace_name, trace in graph.traces.iteritems(): |
| 678 if trace_name.endswith('_ref'): |
| 679 continue |
| 680 if trace.important: |
| 681 display = '%s: %s' % (trace_name, _FormatHumanReadable(trace.value)) |
| 682 if graph.traces.get(trace_name + '_ref'): |
| 683 display += ' (%s)' % _FormatHumanReadable( |
| 684 graph.traces[trace_name + '_ref'].value) |
| 685 self._text_summary.append(display) |
| 686 |
| 687 self._text_summary.sort() |
| 688 |
| 689 def _GenerateGraphInfo(self): |
| 690 """Outputs a list of graphs viewed this session, for use by the plotter. |
| 691 |
| 692 These will be collated and sorted on the master side. |
| 693 """ |
| 694 graphs = {} |
| 695 for name, graph in self._graphs.iteritems(): |
| 696 graphs[name] = {'name': name, |
| 697 'important': graph.IsImportant(), |
| 698 'units': graph.units} |
| 699 self._output[self.GRAPH_LIST] = json.dumps(graphs).split('\n') |
| 700 |
| 701 def GetGraphs(self): |
| 702 """Returns a list of graph names.""" |
| 703 return self._graphs.keys() |
| 704 |
| 705 def GetTraces(self, graph): |
| 706 """Returns a dict of traces associated with the given graph. |
| 707 |
| 708 Returns: |
| 709 A dict mapping names of traces to two-element lists of value, stddev. |
| 710 """ |
| 711 return self._graphs[graph].BuildTracesDict() |
| 712 |
| 713 def GetUnits(self, graph): |
| 714 """Returns the units associated with the given graph.""" |
| 715 return str(self._graphs[graph].units) |
| 716 |
| 717 |
| 718 class GraphingPageCyclerLogProcessor(GraphingLogProcessor): |
| 719 """Handles additional processing for page-cycler timing data.""" |
| 720 |
| 721 _page_list = ['(unknown)'] |
| 722 PAGES_REGEXP = re.compile(r'^Pages: \[(?P<LIST>.*)\]') |
| 723 |
| 724 def ProcessLine(self, line): |
| 725 """Also looks for the Pages: line to find the page count.""" |
| 726 # super() should be used instead of GetParentClass(). |
| 727 # pylint: disable=W0212 |
| 728 line_match = self.PAGES_REGEXP.search(line) |
| 729 if line_match: |
| 730 self._page_list = line_match.groupdict()['LIST'].strip().split(',') |
| 731 if len(self._page_list) < 1: |
| 732 self._page_list = ['(unknown)'] |
| 733 else: |
| 734 chromium_utils.GetParentClass(self).ProcessLine(self, line) |
| 735 |
| 736 def _CalculateStatistics(self, value_list, trace_name): |
| 737 """Handles statistics generation and recording for page-cycler data. |
| 738 |
| 739 Sums the timings over all pages for each iteration and returns a tuple |
| 740 (mean, standard deviation) of those sums. Also saves a data file |
| 741 <revision>_<tracename>.dat holding a line of times for each URL loaded, |
| 742 for use by humans when debugging a regression. |
| 743 """ |
| 744 |
| 745 # If the name of the trace is one of the pages in the page list then we are |
| 746 # dealing with the results for that page only, not the overall results. So |
| 747 # calculate the statistics like a normal GraphingLogProcessor, not the |
| 748 # GraphingPageCyclerLogProcessor. |
| 749 if trace_name in self._page_list: |
| 750 return super(GraphingPageCyclerLogProcessor, self)._CalculateStatistics( |
| 751 value_list, trace_name) |
| 752 |
| 753 value_count = len(value_list) |
| 754 page_count = len(self._page_list) |
| 755 # Chunk value_list into groups, where each sub-list |
| 756 # has all the page times of one iteration. |
| 757 iterations = [value_list[start:start+page_count] |
| 758 for start in xrange(0, value_count, page_count)] |
| 759 |
| 760 iteration_times = map(sum, iterations) |
| 761 page_times_list = map(list, zip(*iterations)) |
| 762 page_times_dict = dict(zip(self._page_list, page_times_list)) |
| 763 |
| 764 pagedata = self._SavePageData(page_times_dict, trace_name) |
| 765 val, stddev = chromium_utils.FilteredMeanAndStandardDeviation( |
| 766 iteration_times) |
| 767 return val, stddev, pagedata |
| 768 |
| 769 def _SavePageData(self, page_times, trace_name): |
| 770 """Saves a file holding the timing data for each page loaded. |
| 771 |
| 772 Args: |
| 773 page_times: a dict mapping a page URL to a list of its times |
| 774 trace_name: the trace that produced this set of times |
| 775 |
| 776 Returns: |
| 777 A dict with one entry, mapping filename to file contents. |
| 778 """ |
| 779 file_data = [] |
| 780 for page, times in sorted(page_times.iteritems()): |
| 781 mean, stddev = chromium_utils.FilteredMeanAndStandardDeviation(times) |
| 782 file_data.append('%s (%s+/-%s): %s' % (page, |
| 783 _FormatFloat(mean), |
| 784 _FormatFloat(stddev), |
| 785 _JoinWithSpacesAndNewLine(times))) |
| 786 |
| 787 filename = '%s_%s.dat' % (self._revision, trace_name) |
| 788 return {filename: file_data} |
| 789 |
| 790 |
| 791 def _FormatFloat(number): |
| 792 """Formats float with two decimal points.""" |
| 793 if number: |
| 794 return '%.2f' % number |
| 795 else: |
| 796 return '0.00' |
| 797 |
| 798 |
| 799 def _FormatPercentage(ratio): |
| 800 """Formats a number as a string with a percentage (e.g. 0.5 => "50%").""" |
| 801 return '%s%%' % _FormatFloat(100 * ratio) |
| 802 |
| 803 |
| 804 def _Divide(x, y): |
| 805 """Divides with float division, or returns infinity if denominator is 0.""" |
| 806 if y == 0: |
| 807 return float('inf') |
| 808 return float(x) / y |
| 809 |
| 810 |
| 811 def _FormatHumanReadable(number): |
| 812 """Formats a float into three significant figures, using metric suffixes. |
| 813 |
| 814 Only m, k, and M prefixes (for 1/1000, 1000, and 1,000,000) are used. |
| 815 Examples: |
| 816 0.0387 => 38.7m |
| 817 1.1234 => 1.12 |
| 818 10866 => 10.8k |
| 819 682851200 => 683M |
| 820 """ |
| 821 metric_prefixes = {-3: 'm', 0: '', 3: 'k', 6: 'M'} |
| 822 scientific = '%.2e' % float(number) # 6.83e+005 |
| 823 e_idx = scientific.find('e') # 4, or 5 if negative |
| 824 digits = float(scientific[:e_idx]) # 6.83 |
| 825 exponent = int(scientific[e_idx + 1:]) # int('+005') = 5 |
| 826 while exponent % 3: |
| 827 digits *= 10 |
| 828 exponent -= 1 |
| 829 while exponent > 6: |
| 830 digits *= 10 |
| 831 exponent -= 1 |
| 832 while exponent < -3: |
| 833 digits /= 10 |
| 834 exponent += 1 |
| 835 if digits >= 100: |
| 836 # Don't append a meaningless '.0' to an integer number. |
| 837 digits = int(digits) |
| 838 # Exponent is now divisible by 3, between -3 and 6 inclusive: (-3, 0, 3, 6). |
| 839 return '%s%s' % (digits, metric_prefixes[exponent]) |
| 840 |
| 841 |
| 842 def _JoinWithSpacesAndNewLine(words): |
| 843 """Joins a list of words together with spaces.""" |
| 844 return ' '.join(str(w) for w in words) + '\n' |
OLD | NEW |