Bug 1270507 - Elide subtest results from web-platform-tests on treeherder when they match expectations, r=ahal

MozReview-Commit-ID: DyatYcpdjvQ

--HG--
extra : rebase_source : 8947cfc0084a2523c570ff2f832a7ce79852ba1d

testing/mozbase/mozlog/mozlog/commandline.py

@@ -32,6 +32,10 @@ def verbose_wrapper(formatter, verbose):
     formatter.verbose = verbose
     return formatter
 
+def compact_wrapper(formatter, compact):
+    formatter.compact = compact
+    return formatter
+
 def buffer_handler_wrapper(handler, buffer_limit):
     if buffer_limit == "UNLIMITED":
         buffer_limit = None
@@ -63,6 +67,9 @@ fmt_options = {
     'verbose': (verbose_wrapper,
                 "Enables verbose mode for the given formatter.",
                 ["mach"], "store_true"),
+    'compact': (compact_wrapper,
+                "Enables compact mode for the given formatter.",
+                ["tbpl"], "store_true"),
     'level': (level_filter_wrapper,
               "A least log level to subscribe to for the given formatter (debug, info, error, etc.)",
               ["mach", "raw", "tbpl"], "store"),

testing/mozbase/mozlog/mozlog/formatters/tbplformatter.py

@@ -2,23 +2,63 @@
 # License, v. 2.0. If a copy of the MPL was not distributed with this
 # file, You can obtain one at http://mozilla.org/MPL/2.0/.
 
+import functools
+from collections import deque
+
 from .base import BaseFormatter
 from .process import strstatus
 
+def output_subtests(func):
+    @functools.wraps(func)
+    def inner(self, data):
+        if self.subtests_count:
+            return self._format_subtests(data.get("component")) + func(self, data)
+        else:
+            return func(self, data)
+    return inner
+
 
 class TbplFormatter(BaseFormatter):
     """Formatter that formats logs in the legacy formatting format used by TBPL
     This is intended to be used to preserve backward compatibility with existing tools
     hand-parsing this format.
     """
-    def __init__(self):
+    def __init__(self, compact=False):
         self.suite_start_time = None
         self.test_start_times = {}
+        self.buffer = None
+        self.compact = compact
+        self.subtests_count = 0
+
+    @property
+    def compact(self):
+        return self._compact
+
+    @compact.setter
+    def compact(self, value):
+        self._compact = value
+        if value:
+            self.buffer = deque([], 10)
+        else:
+            self.buffer = None
 
     def __call__(self, data):
         return getattr(self, data["action"])(data)
 
+    def _format_subtests(self, component, subtract_context=False):
+        count = self.subtests_count
+        if subtract_context:
+            count -= len(self.buffer)
+        self.subtests_count = 0
+        return self._log({"level": "INFO",
+                          "message": "." * count,
+                          "component": component})
+
+    @output_subtests
     def log(self, data):
+        return self._log(data)
+
+    def _log(self, data):
         if data.get('component'):
             message = "%s %s" % (data["component"], data["message"])
         else:
@@ -29,19 +69,23 @@ class TbplFormatter(BaseFormatter):
 
         return "%s\n" % message
 
+    @output_subtests
     def process_output(self, data):
         return "PROCESS | %(process)s | %(data)s\n" % data
 
+    @output_subtests
     def process_start(self, data):
         msg = "TEST-INFO | started process %s" % data['process']
         if 'command' in data:
             msg = '%s (%s)' % (msg, data['command'])
         return msg + '\n'
 
+    @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"]
 
@@ -80,6 +124,21 @@ class TbplFormatter(BaseFormatter):
         return "TEST-START | %s\n" % self.id_str(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))
+                self.buffer.clear()
+                return "".join(rv)
+            else:
+                self.subtests_count += 1
+                self.buffer.append(data)
+        else:
+            return self._format_status(data)
+
+    def _format_status(self, data):
         message = "- " + data["message"] if "message" in data else ""
         if "stack" in data:
             message += "\n%s" % data["stack"]
@@ -102,6 +161,15 @@ class TbplFormatter(BaseFormatter):
             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))
+            if print_context:
+                rv.extend(self._format_status(item) for item in self.buffer)
+            self.buffer.clear()
+
         test_id = self.test_id(data["test"])
         duration_msg = ""
 
@@ -133,7 +201,8 @@ class TbplFormatter(BaseFormatter):
         sections = ["TEST-%s" % data['status'], self.id_str(test_id)]
         if duration_msg:
             sections.append(duration_msg)
-        return ' | '.join(sections) + '\n'
+        rv.append(' | '.join(sections) + '\n')
+        return "".join(rv)
 
     def suite_end(self, data):
         start_time = self.suite_start_time
@@ -153,6 +222,7 @@ class TbplFormatter(BaseFormatter):
         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']:

testing/mozharness/mozharness/mozilla/structuredlog.py

@@ -28,10 +28,11 @@ class StructuredOutputParser(OutputParser):
 
         self.suite_category = kwargs.pop('suite_category', None)
 
+        tbpl_compact = kwargs.pop("log_compact", False)
         super(StructuredOutputParser, self).__init__(**kwargs)
 
         mozlog = self._get_mozlog_module()
-        self.formatter = mozlog.formatters.TbplFormatter()
+        self.formatter = mozlog.formatters.TbplFormatter(compact=tbpl_compact)
         self.handler = mozlog.handlers.StatusHandler()
         self.log_actions = mozlog.structuredlog.log_actions()
 
@@ -82,8 +83,10 @@ class StructuredOutputParser(OutputParser):
         if action == "log":
             level = getattr(log, data["level"].upper())
 
-        self.log(self.formatter(data), level=level)
-        self.update_levels(tbpl_level, level)
+        log_data = self.formatter(data)
+        if log_data is not None:
+            self.log(log_data, level=level)
+            self.update_levels(tbpl_level, level)
 
     def evaluate_parser(self, return_code, success_codes=None):
         success_codes = success_codes or [0]

testing/mozharness/scripts/web_platform_tests.py

@@ -179,7 +179,8 @@ class WebPlatformTest(TestingMixin, MercurialScript, BlobUploadMixin):
         cmd = self._query_cmd()
 
         parser = StructuredOutputParser(config=self.config,
-                                        log_obj=self.log_obj)
+                                        log_obj=self.log_obj,
+                                        log_compact=True)
 
         env = {'MINIDUMP_SAVE_PATH': dirs['abs_blob_upload_dir']}
         env = self.query_env(partial_env=env, log_level=INFO)