https://bugs.webkit.org/show_bug.cgi?id=124496
Reviewed by Antti Koivisto.
PerformanceTests:
As a preparation to support subtests for Dromaeo and DoYouEvenBench, simplify the output performance tests generate.
Also modernize the output to better support "metric" concept we introduced a while ago.
New output on Dromaeo/dom-attr looks like this:
-----------------------------------------------
Running 5 times
getAttribute -> [1105, 1108, 1134, 1137, 1154]
element.property -> [1634, 1655, 1685, 1696, 1723]
setAttribute -> [646.
3536463536464, 651, 651, 656.
3436563436563, 658]
element.property = value -> [934, 949, 963, 964, 974]
element.expando = value -> [419, 419.
5804195804196, 421.
57842157842157, 425.
57442557442556, 429]
element.expando -> [501, 517, 519.
4805194805194, 521.
4785214785214, 525]
1: 117.
40644785571585 runs/s
2: 118.
84720469666297 runs/s
3: 119.
80547640905021 runs/s
4: 120.
51886194758805 runs/s
5: 121.
51924380569295 runs/s
:Time -> [117.
40644785571585, 118.
84720469666297, 119.
80547640905021, 120.
51886194758805, 121.
51924380569295] runs/s
mean: 119.
619446942942 runs/s
median: 119.
80547640905021 runs/s
stdev: 1.
5769040458730506 runs/s
min: 117.
40644785571585 runs/s
max: 121.
51924380569295 runs/s
-----------------------------------------------
* Dromaeo/resources/dromaeorunner.js:
(DRT.progress): Use the new format for subtest reports.
* resources/runner.js:
(.): Declare verboseLogging, which is set to true outside of test runners.
(PerfTestRunner.logInfo): Use verboseLogging instead of directly checking window.testRunner.
(PerfTestRunner.logDetail): Added. Logs informative text with a label such as "mean: 123 s" with 4-space indentation.
(PerfTestRunner.logStatistics): Use logDetail.
(.start): Initialize verboseLogging. Also log "Running 20 times" as an informative log using logDetail.
(.ignoreWarmUpAndLog): Use logDetail for showing the progress. These logs were useless inside test runners anyway
because perftest didn't get to see any output until the test finished running.
(.finish): Call logStatistics with metric name as opposed to a label. Each metric name is now prefixed with ':' to be
distinguishable from subtests, making the new format forward compatible.
Tools:
As a preparation to support subtests for Dromaeo and DoYouEvenBench, simplify the output
performance tests generate. Instead of spitting out noise in PerfTestRunner (runner.js)
and ignoring it in PerfTest._filter_output (perftest.py), simply avoid generating it in
the first place.
Also modernize the output to adopt "metric" concept better and make it forward compatible
with subtests.
With this patch, performance tests written using runner.js only produces empty lines or
lines of the following format inside test runners (DumpRenderTree and WebKitTestRunner):
<subtest name> -> [<value 1>, <value 2>, ...]
:<metric name> -> [<value 1>, <value 2>, ...]
This greatly simplifies the parsing logic inside PerfTest._run_with_driver.
* Scripts/webkitpy/performance_tests/perftest.py:
(PerfTest): Removed a bunch of regular expressions that are no longer used.
(PerfTest._run_with_driver): Just parse the values and description and treat everything
else as errors.
* Scripts/webkitpy/performance_tests/perftest_unittest.py:
(TestPerfTest.test_parse_output): Removed the junk.
(TestPerfTest._assert_failed_on_line): Extracted from test_parse_output_with_failing_line,
which was removed in favor of the tests below.
(TestPerfTest.test_parse_output_with_running_five_times): Added.
(TestPerfTest.test_parse_output_with_detailed_info): Added.
(TestPerfTest.test_parse_output_with_statistics): Added.
(TestPerfTest.test_parse_output_with_description): Removed the junk.
(TestPerfTest.test_parse_output_with_subtests): Ditto.
(TestSingleProcessPerfTest.test_use_only_one_process): Ditto.
* Scripts/webkitpy/performance_tests/perftestsrunner_integrationtest.py:
(EventTargetWrapperTestData): Ditto.
(SomeParserTestData): Ditto.
(MemoryTestData): Ditto.
LayoutTests:
Rebaseline the expected result now that the output has been simplified.
* fast/harness/perftests/runs-per-second-log-expected.txt:
git-svn-id: https://svn.webkit.org/repository/webkit/trunk@159465
268f45cc-cd09-0410-ab3c-
d52691b4dbfc
+2013-11-18 Ryosuke Niwa <rniwa@webkit.org>
+
+ Simplify and reformat the output of performance tests inside test runners
+ https://bugs.webkit.org/show_bug.cgi?id=124496
+
+ Reviewed by Antti Koivisto.
+
+ Rebaseline the expected result now that the output has been simplified.
+
+ * fast/harness/perftests/runs-per-second-log-expected.txt:
+
2013-11-18 David Hyatt <hyatt@apple.com>
Add a quirk to not respect center text-align when positioning
This test verifies PerfTestRunner.runPerSecond() outputs log as expected.
-Running 5 times
-Ignoring warm-up run (1 runs/s)
-2 runs/s
-4 runs/s
-5 runs/s
-8 runs/s
-10 runs/s
-Time:
-values 2, 4, 5, 8, 10 runs/s
-avg 5.8 runs/s
-median 5 runs/s
-stdev 3.19 runs/s
-min 2 runs/s
-max 10 runs/s
+:Time -> [2, 4, 5, 8, 10] runs/s
+2013-11-18 Ryosuke Niwa <rniwa@webkit.org>
+
+ Simplify and reformat the output of performance tests inside test runners
+ https://bugs.webkit.org/show_bug.cgi?id=124496
+
+ Reviewed by Antti Koivisto.
+
+ As a preparation to support subtests for Dromaeo and DoYouEvenBench, simplify the output performance tests generate.
+ Also modernize the output to better support "metric" concept we introduced a while ago.
+
+ New output on Dromaeo/dom-attr looks like this:
+ -----------------------------------------------
+ Running 5 times
+ getAttribute -> [1105, 1108, 1134, 1137, 1154]
+ element.property -> [1634, 1655, 1685, 1696, 1723]
+ setAttribute -> [646.3536463536464, 651, 651, 656.3436563436563, 658]
+ element.property = value -> [934, 949, 963, 964, 974]
+ element.expando = value -> [419, 419.5804195804196, 421.57842157842157, 425.57442557442556, 429]
+ element.expando -> [501, 517, 519.4805194805194, 521.4785214785214, 525]
+
+ 1: 117.40644785571585 runs/s
+ 2: 118.84720469666297 runs/s
+ 3: 119.80547640905021 runs/s
+ 4: 120.51886194758805 runs/s
+ 5: 121.51924380569295 runs/s
+
+ :Time -> [117.40644785571585, 118.84720469666297, 119.80547640905021, 120.51886194758805, 121.51924380569295] runs/s
+ mean: 119.619446942942 runs/s
+ median: 119.80547640905021 runs/s
+ stdev: 1.5769040458730506 runs/s
+ min: 117.40644785571585 runs/s
+ max: 121.51924380569295 runs/s
+ -----------------------------------------------
+
+ * Dromaeo/resources/dromaeorunner.js:
+ (DRT.progress): Use the new format for subtest reports.
+ * resources/runner.js:
+ (.): Declare verboseLogging, which is set to true outside of test runners.
+ (PerfTestRunner.logInfo): Use verboseLogging instead of directly checking window.testRunner.
+ (PerfTestRunner.logDetail): Added. Logs informative text with a label such as "mean: 123 s" with 4-space indentation.
+ (PerfTestRunner.logStatistics): Use logDetail.
+ (.start): Initialize verboseLogging. Also log "Running 20 times" as an informative log using logDetail.
+ (.ignoreWarmUpAndLog): Use logDetail for showing the progress. These logs were useless inside test runners anyway
+ because perftest didn't get to see any output until the test finished running.
+ (.finish): Call logStatistics with metric name as opposed to a label. Each metric name is now prefixed with ':' to be
+ distinguishable from subtests, making the new format forward compatible.
+
2013-11-18 Ryosuke Niwa <rniwa@webkit.org>
[Performance tests] Interactive/SelectAll.html throws an exception
},
progress: function(message) {
- var score = message.status.score;
- if (score)
- DRT.log(score.name + ': [' + score.times.join(', ') + ']');
+ var score = message.status.score;
+ if (score)
+ DRT.log(score.name + ' -> [' + score.times.join(', ') + ']');
},
teardown: function(data) {
(function () {
var logLines = null;
+ var verboseLogging = false;
var completedIterations = -1;
var callsPerIteration = 1;
var currentTest = null;
PerfTestRunner.now = window.performance && window.performance.now ? function () { return window.performance.now(); } : Date.now;
PerfTestRunner.logInfo = function (text) {
- if (!window.testRunner)
+ if (verboseLogging)
this.log(text);
}
+ PerfTestRunner.logDetail = function (label, value) {
+ if (verboseLogging)
+ this.log(' ' + label + ': ' + value);
+ }
+
PerfTestRunner.loadFile = function (path) {
var xhr = new XMLHttpRequest();
xhr.open("GET", path, false);
PerfTestRunner.logStatistics = function (values, unit, title) {
var statistics = this.computeStatistics(values, unit);
this.log("");
- this.log(title);
- if (statistics.values)
- this.log("values " + statistics.values.join(", ") + " " + statistics.unit);
- this.log("avg " + statistics.mean + " " + statistics.unit);
- this.log("median " + statistics.median + " " + statistics.unit);
- this.log("stdev " + statistics.stdev + " " + statistics.unit);
- this.log("min " + statistics.min + " " + statistics.unit);
- this.log("max " + statistics.max + " " + statistics.unit);
+ this.log(title + " -> [" + statistics.values.join(", ") + "] " + statistics.unit);
+ ["mean", "median", "stdev", "min", "max"].forEach(function (name) {
+ PerfTestRunner.logDetail(name, statistics[name] + ' ' + statistics.unit);
+ });
}
function getUsedMallocHeap() {
// FIXME: Don't hard code the number of in-process iterations to use inside a test runner.
iterationCount = test.dromaeoIterationCount || (window.testRunner ? 5 : 20);
logLines = window.testRunner ? [] : null;
- PerfTestRunner.log("Running " + iterationCount + " times");
+ verboseLogging = !window.testRunner;
+ PerfTestRunner.logInfo("Running " + iterationCount + " times");
if (test.doNotIgnoreInitialRun)
completedIterations++;
if (runner)
function ignoreWarmUpAndLog(measuredValue) {
var labeledResult = measuredValue + " " + PerfTestRunner.unit;
if (completedIterations <= 0)
- PerfTestRunner.log("Ignoring warm-up run (" + labeledResult + ")");
+ PerfTestRunner.logDetail(completedIterations, labeledResult + " (Ignored warm-up run)");
else {
results.push(measuredValue);
if (window.internals && !currentTest.doNotMeasureMemoryUsage) {
jsHeapResults.push(getUsedJSHeap());
mallocHeapResults.push(getUsedMallocHeap());
}
- PerfTestRunner.log(labeledResult);
+ PerfTestRunner.logDetail(completedIterations, labeledResult);
}
}
try {
if (currentTest.description)
PerfTestRunner.log("Description: " + currentTest.description);
- PerfTestRunner.logStatistics(results, PerfTestRunner.unit, "Time:");
+ PerfTestRunner.logStatistics(results, PerfTestRunner.unit, ":Time");
if (jsHeapResults.length) {
- PerfTestRunner.logStatistics(jsHeapResults, "bytes", "JS Heap:");
- PerfTestRunner.logStatistics(mallocHeapResults, "bytes", "Malloc:");
+ PerfTestRunner.logStatistics(jsHeapResults, "bytes", ":JSHeap");
+ PerfTestRunner.logStatistics(mallocHeapResults, "bytes", ":Malloc");
}
if (logLines)
logLines.forEach(logInDocument);
+2013-11-18 Ryosuke Niwa <rniwa@webkit.org>
+
+ Simplify and reformat the output of performance tests inside test runners
+ https://bugs.webkit.org/show_bug.cgi?id=124496
+
+ Reviewed by Antti Koivisto.
+
+ As a preparation to support subtests for Dromaeo and DoYouEvenBench, simplify the output
+ performance tests generate. Instead of spitting out noise in PerfTestRunner (runner.js)
+ and ignoring it in PerfTest._filter_output (perftest.py), simply avoid generating it in
+ the first place.
+
+ Also modernize the output to adopt "metric" concept better and make it forward compatible
+ with subtests.
+
+ With this patch, performance tests written using runner.js only produces empty lines or
+ lines of the following format inside test runners (DumpRenderTree and WebKitTestRunner):
+ <subtest name> -> [<value 1>, <value 2>, ...]
+ :<metric name> -> [<value 1>, <value 2>, ...]
+
+ This greatly simplifies the parsing logic inside PerfTest._run_with_driver.
+
+ * Scripts/webkitpy/performance_tests/perftest.py:
+ (PerfTest): Removed a bunch of regular expressions that are no longer used.
+ (PerfTest._run_with_driver): Just parse the values and description and treat everything
+ else as errors.
+
+ * Scripts/webkitpy/performance_tests/perftest_unittest.py:
+ (TestPerfTest.test_parse_output): Removed the junk.
+ (TestPerfTest._assert_failed_on_line): Extracted from test_parse_output_with_failing_line,
+ which was removed in favor of the tests below.
+ (TestPerfTest.test_parse_output_with_running_five_times): Added.
+ (TestPerfTest.test_parse_output_with_detailed_info): Added.
+ (TestPerfTest.test_parse_output_with_statistics): Added.
+ (TestPerfTest.test_parse_output_with_description): Removed the junk.
+ (TestPerfTest.test_parse_output_with_subtests): Ditto.
+ (TestSingleProcessPerfTest.test_use_only_one_process): Ditto.
+
+ * Scripts/webkitpy/performance_tests/perftestsrunner_integrationtest.py:
+ (EventTargetWrapperTestData): Ditto.
+ (SomeParserTestData): Ditto.
+ (MemoryTestData): Ditto.
+
2013-11-18 Tim Horton <timothy_horton@apple.com>
Occasionally, hundreds of tests fail with small text diffs on Mavericks
-# Copyright (C) 2012 Google Inc. All rights reserved.
+# Copyright (C) 2012, 2013 Apple Inc. All rights reserved.
+# Copyright (C) 2012, 2013 Google Inc. All rights reserved.
# Copyright (C) 2012 Zoltan Horvath, Adobe Systems Incorporated. All rights reserved.
#
# Redistribution and use in source and binary forms, with or without
(median, unit, stdev, unit, sorted_values[0], unit, sorted_values[-1], unit))
_description_regex = re.compile(r'^Description: (?P<description>.*)$', re.IGNORECASE)
- _metrics_regex = re.compile(r'^(?P<metric>Time|Malloc|JS Heap):')
- _statistics_keys = ['avg', 'median', 'stdev', 'min', 'max', 'unit', 'values']
- _score_regex = re.compile(r'^(?P<key>' + r'|'.join(_statistics_keys) + r')\s+(?P<value>([0-9\.]+(,\s+)?)+)\s*(?P<unit>.*)')
+ _metrics_regex = re.compile(r'^:(?P<metric>Time|Malloc|JSHeap) -> \[(?P<values>(\d+(\.\d+)?)(, \d+(\.\d+)?)+)\] (?P<unit>[a-z/]+)')
def _run_with_driver(self, driver, time_out_ms):
output = self.run_single(driver, self.test_path(), time_out_ms)
current_metric = None
for line in re.split('\n', output.text):
description_match = self._description_regex.match(line)
- metric_match = self._metrics_regex.match(line)
- score = self._score_regex.match(line)
-
if description_match:
self._description = description_match.group('description')
- elif metric_match:
- current_metric = metric_match.group('metric').replace(' ', '')
- elif score:
- if score.group('key') != 'values':
- continue
-
- metric = self._ensure_metrics(current_metric, score.group('unit'))
- metric.append_group(map(lambda value: float(value), score.group('value').split(', ')))
- else:
+ continue
+
+ metric_match = self._metrics_regex.match(line)
+ if not metric_match:
_log.error('ERROR: ' + line)
return False
+ metric = self._ensure_metrics(metric_match.group('metric'), metric_match.group('unit'))
+ metric.append_group(map(lambda value: float(value), metric_match.group('values').split(', ')))
+
return True
def _ensure_metrics(self, metric_name, unit=None):
return False
_lines_to_ignore_in_parser_result = [
- re.compile(r'^Running \d+ times$'),
- re.compile(r'^Ignoring warm-up '),
- re.compile(r'^Info:'),
- re.compile(r'^\d+(.\d+)?(\s*(runs\/s|ms|fps))?$'),
# Following are for handle existing test like Dromaeo
re.compile(re.escape("""main frame - has 1 onunload handler(s)""")),
re.compile(re.escape("""frame "<!--framePath //<!--frame0-->-->" - has 1 onunload handler(s)""")),
re.compile(r"CONSOLE MESSAGE: (line \d+: )?Blocked script execution in '[A-Za-z0-9\-\.:]+' because the document's frame is sandboxed and the 'allow-scripts' permission is not set."),
re.compile(r"CONSOLE MESSAGE: (line \d+: )?Not allowed to load local resource"),
# Dromaeo reports values for subtests. Ignore them for now.
- re.compile(r'(?P<name>.+): \[(?P<values>(\d+(.\d+)?,\s+)*\d+(.\d+)?)\]'),
+ # FIXME: Remove once subtests are supported
+ re.compile(r'^[A-Za-z0-9\. =]+( -> )(\[?[0-9\., ]+\])( [a-z/]+)?$'),
]
def _filter_output(self, output):
def test_parse_output(self):
output = DriverOutput("""
-Running 20 times
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50862 ms
-min 1080 ms
-max 1120 ms
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
""", image=None, image_hash=None, audio=None)
output_capture = OutputCapture()
output_capture.capture_output()
self.assertEqual(actual_stderr, '')
self.assertEqual(actual_logs, '')
- def test_parse_output_with_failing_line(self):
- output = DriverOutput("""
-Running 20 times
-Ignoring warm-up run (1115)
-
-some-unrecognizable-line
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50862 ms
-min 1080 ms
-max 1120 ms
-""", image=None, image_hash=None, audio=None)
+ def _assert_failed_on_line(self, output_text, expected_log):
+ output = DriverOutput(output_text, image=None, image_hash=None, audio=None)
output_capture = OutputCapture()
output_capture.capture_output()
try:
actual_stdout, actual_stderr, actual_logs = output_capture.restore_output()
self.assertEqual(actual_stdout, '')
self.assertEqual(actual_stderr, '')
- self.assertEqual(actual_logs, 'ERROR: some-unrecognizable-line\n')
+ self.assertEqual(actual_logs, expected_log)
+
+ def test_parse_output_with_running_five_times(self):
+ self._assert_failed_on_line("""
+Running 5 times
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
+""", 'ERROR: Running 5 times\n')
+
+ def test_parse_output_with_detailed_info(self):
+ self._assert_failed_on_line("""
+ 1: 1080 ms
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
+""", 'ERROR: 1: 1080 ms\n')
+
+ def test_parse_output_with_statistics(self):
+ self._assert_failed_on_line("""
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
+ mean: 105 ms
+""", 'ERROR: mean: 105 ms\n')
def test_parse_output_with_description(self):
output = DriverOutput("""
Description: this is a test description.
-Running 20 times
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50862 ms
-min 1080 ms
-max 1120 ms""", image=None, image_hash=None, audio=None)
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
+""", image=None, image_hash=None, audio=None)
test = PerfTest(MockPort(), 'some-test', '/path/some-dir/some-test')
self._assert_results_are_correct(test, output)
self.assertEqual(test.description(), 'this is a test description.')
def test_parse_output_with_subtests(self):
output = DriverOutput("""
-Running 20 times
-some test: [1, 2, 3, 4, 5]
-other test = else: [6, 7, 8, 9, 10]
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50862 ms
-min 1080 ms
-max 1120 ms
+Description: this is a test description.
+some test -> [1, 2, 3, 4, 5]
+some other test = else -> [6, 7, 8, 9, 10]
+
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
""", image=None, image_hash=None, audio=None)
output_capture = OutputCapture()
output_capture.capture_output()
def run_single(driver, path, time_out_ms):
called[0] += 1
return DriverOutput("""
-Running 20 times
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50862 ms
-min 1080 ms
-max 1120 ms""", image=None, image_hash=None, audio=None)
+Description: this is a test description.
+:Time -> [1080, 1120, 1095, 1101, 1104] ms
+""", image=None, image_hash=None, audio=None)
test = SingleProcessPerfTest(MockPort(), 'some-test', '/path/some-dir/some-test')
test.run_single = run_single
class EventTargetWrapperTestData:
- text = """Running 20 times
-Ignoring warm-up run (1502)
-1504
-1505
-1510
-1504
-1507
-1509
-1510
-1487
-1488
-1472
-1472
-1488
-1473
-1472
-1475
-1487
-1486
-1486
-1475
-1471
-
-Time:
-values 1486, 1471, 1510, 1505, 1478, 1490 ms
-avg 1490 ms
-median 1488 ms
-stdev 15.13935 ms
-min 1471 ms
-max 1510 ms
+ text = """:Time -> [1486, 1471, 1510, 1505, 1478, 1490] ms
"""
output = """Running Bindings/event-target-wrapper.html (1 of 2)
class SomeParserTestData:
- text = """Running 20 times
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50861 ms
-min 1080 ms
-max 1120 ms
+ text = """:Time -> [1080, 1120, 1095, 1101, 1104] ms
"""
output = """Running Parser/some-parser.html (2 of 2)
class MemoryTestData:
- text = """Running 20 times
-Ignoring warm-up run (1115)
-
-Time:
-values 1080, 1120, 1095, 1101, 1104 ms
-avg 1100 ms
-median 1101 ms
-stdev 14.50861 ms
-min 1080 ms
-max 1120 ms
-
-JS Heap:
-values 825000, 811000, 848000, 837000, 829000 bytes
-avg 830000 bytes
-median 829000 bytes
-stdev 13784.04875 bytes
-min 811000 bytes
-max 848000 bytes
-
-Malloc:
-values 529000, 511000, 548000, 536000, 521000 bytes
-avg 529000 bytes
-median 529000 bytes
-stdev 14124.44689 bytes
-min 511000 bytes
-max 548000 bytes
+ text = """:Time -> [1080, 1120, 1095, 1101, 1104] ms
+
+:JSHeap -> [825000, 811000, 848000, 837000, 829000] bytes
+
+:Malloc -> [529000, 511000, 548000, 536000, 521000] bytes
"""
output = """Running 1 tests
git://git.webkit.org / WebKit-https.git / commitdiff