Bug 1048288 - Log test_end messages instead of errors to prevent useful messages about assertion counts from being buffered.;r=ahal
authorChris Manchester <cmanchester@mozilla.com>
Wed, 06 Aug 2014 17:14:11 -0400
changeset 198229 1dfcf17f47d91182fe51c3718a29fb7a4d31fad2
parent 198228 24a71651c6a38eb95894c4f4fa30776df9bba3a4
child 198230 9ff7c80c47904a45e8c4d080416090da3416615c
push id27264
push usernigelbabu@gmail.com
push dateThu, 07 Aug 2014 03:31:37 +0000
treeherdermozilla-central@afcb3af79d09 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersahal
bugs1048288
milestone34.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1048288 - Log test_end messages instead of errors to prevent useful messages about assertion counts from being buffered.;r=ahal
testing/mochitest/tests/SimpleTest/TestRunner.js
testing/mozbase/mozlog/mozlog/structured/formatters/tbplformatter.py
--- a/testing/mochitest/tests/SimpleTest/TestRunner.js
+++ b/testing/mochitest/tests/SimpleTest/TestRunner.js
@@ -159,22 +159,16 @@ function StructuredLogger(name) {
         }
         if (expected != status) {
             data.expected = expected;
         }
         if (extra !== null) {
             data.extra = extra;
         }
 
-        if (!this.testsStarted.pop(test)) {
-            this.error("Test '" + test + "' was ended more than once or never started. " +
-                       "Ended with this data: " + JSON.stringify(data));
-            return;
-        }
-
         this._logData("test_end", data);
     };
 
     this.suiteStart = function(tests, runinfo) {
         runinfo = typeof runinfo !== "undefined" ? runinfo : null;
 
         var data = {tests: tests};
         if (runinfo !== null) {
--- a/testing/mozbase/mozlog/mozlog/structured/formatters/tbplformatter.py
+++ b/testing/mozbase/mozlog/mozlog/structured/formatters/tbplformatter.py
@@ -43,28 +43,33 @@ class TbplFormatter(BaseFormatter):
             info_line = "TEST-INFO | expected %s\n" % data["expected"]
             return "\n".join([failure_line, info_line])
 
         return "TEST-%s | %s | %s %s\n" % (
             data["status"], self.id_str(data["test"]), data["subtest"],
             message)
 
     def test_end(self, data):
-        start_time = self.test_start_times.pop(self.test_id(data["test"]))
-        time = data["time"] - start_time
+        test_id = self.test_id(data["test"])
+        time_msg = ""
+
+        if test_id in self.test_start_times:
+            start_time = self.test_start_times.pop(test_id)
+            time = data["time"] - start_time
+            time_msg = " | took %ims" % time
 
         if "expected" in data:
             failure_line = "TEST-UNEXPECTED-%s | %s | %s" % (
-                data["status"], self.id_str(data["test"]),
-                data.get("message", ""))
-            info_line = "TEST-INFO expected %s | took %ims\n" % (data["expected"], time)
+                data["status"], test_id, data.get("message", ""))
+
+            info_line = "TEST-INFO expected %s%s\n" % (data["expected"], time_msg)
             return "\n".join([failure_line, info_line])
 
-        return "TEST-%s | %s | took %ims\n" % (
-            data["status"], self.id_str(data["test"]), time)
+        return "TEST-%s | %s%s\n" % (
+            data["status"], test_id, time_msg)
 
     def suite_end(self, data):
         start_time = self.suite_start_time
         time = int((data["time"] - start_time) / 1000)
 
         return "SUITE-END | took %is\n" % time
 
     def test_id(self, test_id):