Bug 1293250 - Make reftest log generation less magical, r=ahal, jmaher
Ensure that the first line of the log for failing tests is identical to
one that would be produced by the tbplformatter from mozlog. This means
that treeherder will be able to sucessfully cross-match error lines.
Also make the data structures used for storing screenshots identical
between reftests and web-platform-tests so that we can start to move
toward removing the reftest-specific codepath here.
MozReview-Commit-ID: FZQXLjj9Ejv
--- a/layout/tools/reftest/output.py
+++ b/layout/tools/reftest/output.py
@@ -32,44 +32,40 @@ class ReftestFormatter(TbplFormatter):
def log(self, data):
prefix = "%s |" % data['level'].upper()
return "%s %s\n" % (prefix, data['message'])
def test_end(self, data):
extra = data.get('extra', {})
status = data['status']
+ test = data['test']
status_msg = "TEST-"
if 'expected' in data:
status_msg += "UNEXPECTED-%s" % status
else:
if status != "PASS":
status_msg += "KNOWN-"
status_msg += status
if extra.get('status_msg') == 'Random':
status_msg += "(EXPECTED RANDOM)"
- test = self.id_str(data['test'])
- if 'message' in data:
- status_details = data['message']
- elif isinstance(data['test'], tuple):
- status_details = 'image comparison ({})'.format(data['test'][1])
- else:
- status_details = '(LOAD ONLY)'
+
+
+ output_text = "%s | %s | %s" % (status_msg, test, data.get("message", ""))
- output_text = "%s | %s | %s" % (status_msg, test, status_details)
- if 'differences' in extra:
- diff_msg = (", max difference: %(max_difference)s"
- ", number of differing pixels: %(differences)s") % extra
- diagnostic_data = ("REFTEST IMAGE 1 (TEST): %(image1)s\n"
- "REFTEST IMAGE 2 (REFERENCE): %(image2)s") % extra
- output_text += '%s\n%s' % (diff_msg, diagnostic_data)
- elif "image1" in extra:
- diagnostic_data = "REFTEST IMAGE: %(image1)s" % extra
- output_text += '\n%s' % diagnostic_data
+ if "reftest_screenshots" in extra:
+ screenshots = extra["reftest_screenshots"]
+ if len(screenshots) == 3:
+ output_text += ("\nREFTEST IMAGE 1 (TEST): %s\n"
+ "REFTEST IMAGE 2 (REFERENCE): %s") % (screenshots[0]["screenshot"],
+ screenshots[2]["screenshot"])
+ elif len(screenshots) == 1:
+ output_text += "\nREFTEST IMAGE: %(image1)s" % screenshots[0]["screenshot"]
+
output_text += "\nREFTEST TEST-END | %s" % test
return "%s\n" % output_text
def process_output(self, data):
return "%s\n" % data["data"]
def suite_end(self, data):
@@ -94,21 +90,16 @@ class ReftestFormatter(TbplFormatter):
"%(AssertionKnown)s known asserts, " +
"%(Random)s random, " +
"%(Skip)s skipped, " +
"%(Slow)s slow)") % summary)
lines = ["REFTEST INFO | %s" % s for s in lines]
lines.append("REFTEST SUITE-END | Shutdown")
return "INFO | Result summary:\n{}\n".format('\n'.join(lines))
- def id_str(self, test_id):
- if isinstance(test_id, basestring):
- return test_id
- return test_id[0]
-
class OutputHandler(object):
"""Process the output of a process during a test run and translate
raw data logged from reftest.js to an appropriate structured log action,
where applicable.
"""
def __init__(self, log, utilityPath, symbolsPath=None):
--- a/layout/tools/reftest/reftest.jsm
+++ b/layout/tools/reftest/reftest.jsm
@@ -1696,29 +1696,37 @@ function RecordResult(testRunTime, error
failures.push("failed reftest-opaque-layer: " + gFailedOpaqueLayerMessages.join(", "));
}
if (gFailedAssignedLayer) {
failures.push("failed reftest-assigned-layer: " + gFailedAssignedLayerMessages.join(", "));
}
var failureString = failures.join(", ");
logger.testEnd(gURLs[0].identifier, output.s[0], output.s[1], failureString, null, extra);
} else {
+ var message = "image comparison";
if (!test_passed && expected == EXPECTED_PASS ||
!test_passed && expected == EXPECTED_FUZZY ||
test_passed && expected == EXPECTED_FAIL) {
if (!equal) {
extra.max_difference = maxDifference.value;
extra.differences = differences;
+ extra.reftest_screenshots = [
+ {url:gURLs[0].identifier[0], screenshot: gCanvas1.toDataURL()},
+ gURLs[0].identifier[1],
+ {url:gURLs[0].identifier[1], screenshot: gCanvas2.toDataURL()}
+ ];
extra.image1 = gCanvas1.toDataURL();
extra.image2 = gCanvas2.toDataURL();
+ message += (", max difference: " + extra.max_difference +
+ ", number of differing pixels: " + differences);
} else {
extra.image1 = gCanvas1.toDataURL();
}
}
- logger.testEnd(gURLs[0].identifier, output.s[0], output.s[1], null, null, extra);
+ logger.testEnd(gURLs[0].identifier, output.s[0], output.s[1], message, null, extra);
if (gURLs[0].prefSettings1.length == 0) {
UpdateCanvasCache(gURLs[0].url1, gCanvas1);
}
if (gURLs[0].prefSettings2.length == 0) {
UpdateCanvasCache(gURLs[0].url2, gCanvas2);
}
}
--- a/testing/mozbase/mozlog/mozlog/formatters/tbplformatter.py
+++ b/testing/mozbase/mozlog/mozlog/formatters/tbplformatter.py
@@ -82,17 +82,17 @@ class TbplFormatter(BaseFormatter):
@output_subtests
def process_exit(self, data):
return "TEST-INFO | %s: %s\n" % (data['process'],
strstatus(data['exitcode']))
@output_subtests
def crash(self, data):
- id = self.id_str(data["test"]) if "test" in data else "pid: %s" % data["process"]
+ id = data["test"] if "test" in data else "pid: %s" % data["process"]
signature = data["signature"] if data["signature"] else "unknown top frame"
rv = ["PROCESS-CRASH | %s | application crashed [%s]" % (id, signature)]
if data.get("minidump_path"):
rv.append("Crash dump filename: %s" % data["minidump_path"])
if data.get("stackwalk_stderr"):
@@ -116,17 +116,17 @@ class TbplFormatter(BaseFormatter):
def suite_start(self, data):
self.suite_start_time = data["time"]
return "SUITE-START | Running %i tests\n" % len(data["tests"])
def test_start(self, data):
self.test_start_times[self.test_id(data["test"])] = data["time"]
- return "TEST-START | %s\n" % self.id_str(data["test"])
+ return "TEST-START | %s\n" % data["test"]
def test_status(self, data):
if self.compact:
if "expected" in data:
rv = []
rv.append(self._format_subtests(data.get("component"), subtract_context=True))
rv.extend(self._format_status(item) for item in self.buffer)
rv.append(self._format_status(data))
@@ -144,25 +144,25 @@ class TbplFormatter(BaseFormatter):
message += "\n%s" % data["stack"]
if message and message[-1] == "\n":
message = message[:-1]
if "expected" in data:
if not message:
message = "- expected %s" % data["expected"]
failure_line = "TEST-UNEXPECTED-%s | %s | %s %s\n" % (
- data["status"], self.id_str(data["test"]), data["subtest"],
+ data["status"], data["test"], data["subtest"],
message)
if data["expected"] != "PASS":
info_line = "TEST-INFO | expected %s\n" % data["expected"]
return failure_line + info_line
return failure_line
return "TEST-%s | %s | %s %s\n" % (
- data["status"], self.id_str(data["test"]), data["subtest"],
+ data["status"], data["test"], data["subtest"],
message)
def test_end(self, data):
rv = []
if self.compact and self.subtests_count:
print_context = "expected" in data
rv.append(self._format_subtests(data.get("component"),
subtract_context=print_context))
@@ -182,28 +182,38 @@ class TbplFormatter(BaseFormatter):
message = data.get("message", "")
if not message:
message = "expected %s" % data["expected"]
if "stack" in data:
message += "\n%s" % data["stack"]
if message and message[-1] == "\n":
message = message[:-1]
+ extra = data.get("extra", {})
+ if "reftest_screenshots" in extra:
+ screenshots = extra["reftest_screenshots"]
+ if len(screenshots) == 3:
+ message += ("\nREFTEST IMAGE 1 (TEST): %s\n"
+ "REFTEST IMAGE 2 (REFERENCE): %s") % (screenshots[0]["screenshot"],
+ screenshots[2]["screenshot"])
+ elif len(screenshots) == 1:
+ message += "\nREFTEST IMAGE: %(image1)s" % screenshots[0]["screenshot"]
+
failure_line = "TEST-UNEXPECTED-%s | %s | %s\n" % (
- data["status"], self.id_str(test_id), message)
+ data["status"], test_id, message)
if data["expected"] not in ("PASS", "OK"):
expected_msg = "expected %s | " % data["expected"]
else:
expected_msg = ""
info_line = "TEST-INFO %s%s\n" % (expected_msg, duration_msg)
return failure_line + info_line
- sections = ["TEST-%s" % data['status'], self.id_str(test_id)]
+ sections = ["TEST-%s" % data['status'], test_id]
if duration_msg:
sections.append(duration_msg)
rv.append(' | '.join(sections) + '\n')
return "".join(rv)
def suite_end(self, data):
start_time = self.suite_start_time
time = int((data["time"] - start_time) / 1000)
@@ -211,21 +221,15 @@ class TbplFormatter(BaseFormatter):
return "SUITE-END | took %is\n" % time
def test_id(self, test_id):
if isinstance(test_id, (str, unicode)):
return test_id
else:
return tuple(test_id)
- def id_str(self, test_id):
- if isinstance(test_id, (str, unicode)):
- return test_id
- else:
- return " ".join(test_id)
-
@output_subtests
def valgrind_error(self, data):
rv = "TEST-UNEXPECTED-VALGRIND-ERROR | " + data['primary'] + "\n"
for line in data['secondary']:
rv = rv + line + "\n"
return rv