Bug 957768 - Add an option to hide mochitest subtest results, r=jmaher
authorAndrew Halberstadt <ahalberstadt@mozilla.com>
Thu, 09 Jan 2014 15:41:54 -0500
changeset 162898 7cbba8097c61923e8465be43a58e74185c29666a
parent 162897 f138d20db7d3f7d1331c3df5995aa45bc546062f
child 162899 4210f0c1067958d1dbe1a3be7de98ad64c7f067a
push id25975
push userryanvm@gmail.com
push dateFri, 10 Jan 2014 19:46:47 +0000
treeherderautoland@e89afc241513 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjmaher
bugs957768
milestone29.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 957768 - Add an option to hide mochitest subtest results, r=jmaher
testing/mochitest/mach_commands.py
testing/mochitest/mochitest_options.py
testing/mochitest/runtests.py
--- a/testing/mochitest/mach_commands.py
+++ b/testing/mochitest/mach_commands.py
@@ -442,16 +442,20 @@ def MochitestCommand(func):
     chunk_total = CommandArgument('--total-chunks', type=int,
         help='Total number of chunks to split tests into.')
     func = chunk_total(func)
 
     this_chunk = CommandArgument('--this-chunk', type=int,
         help='If running tests by chunks, the number of the chunk to run.')
     func = this_chunk(func)
 
+    hide_subtests = CommandArgument('--hide-subtests', action='store_true',
+        help='If specified, will only log subtest results on failure or timeout.')
+    func = hide_subtests(func)
+
     debug_on_failure = CommandArgument('--debug-on-failure', action='store_true',
         help='Breaks execution and enters the JS debugger on a test failure. ' \
              'Should be used together with --jsdebugger.')
     func = debug_on_failure(func)
 
     jsdebugger = CommandArgument('--jsdebugger', action='store_true',
         help='Start the browser JS debugger before running the test. Implies --no-autorun.')
     func = jsdebugger(func)
@@ -530,16 +534,20 @@ def B2GCommand(func):
     chunk_total = CommandArgument('--total-chunks', type=int,
         help='Total number of chunks to split tests into.')
     func = chunk_total(func)
 
     this_chunk = CommandArgument('--this-chunk', type=int,
         help='If running tests by chunks, the number of the chunk to run.')
     func = this_chunk(func)
 
+    hide_subtests = CommandArgument('--hide-subtests', action='store_true',
+        help='If specified, will only log subtest results on failure or timeout.')
+    func = hide_subtests(func)
+
     path = CommandArgument('test_file', default=None, nargs='?',
         metavar='TEST',
         help='Test to run. Can be specified as a single file, a ' \
             'directory, or omitted. If omitted, the entire test suite is ' \
             'executed.')
     func = path(func)
 
     return func
--- a/testing/mochitest/mochitest_options.py
+++ b/testing/mochitest/mochitest_options.py
@@ -64,16 +64,22 @@ class MochitestOptions(optparse.OptionPa
         [["--log-file"],
         { "action": "store",
           "type": "string",
           "dest": "logFile",
           "metavar": "FILE",
           "help": "file to which logging occurs",
           "default": "",
         }],
+        [["--hide-subtests"],
+        { "action": "store_true",
+          "dest": "hide_subtests",
+          "help": "only show subtest log output if there was a failure",
+          "default": False,
+        }],
         [["--autorun"],
         { "action": "store_true",
           "dest": "autorun",
           "help": "start running tests when the application starts",
           "default": False,
         }],
         [["--timeout"],
         { "type": "int",
--- a/testing/mochitest/runtests.py
+++ b/testing/mochitest/runtests.py
@@ -10,17 +10,16 @@ from __future__ import with_statement
 import os
 import sys
 SCRIPT_DIR = os.path.abspath(os.path.realpath(os.path.dirname(__file__)))
 sys.path.insert(0, SCRIPT_DIR);
 
 import json
 import mozcrash
 import mozinfo
-import mozlog
 import mozprocess
 import mozrunner
 import optparse
 import re
 import shutil
 import signal
 import subprocess
 import tempfile
@@ -756,17 +755,18 @@ class Mochitest(MochitestUtilsMixin):
              extraArgs,
              utilityPath,
              xrePath,
              certPath,
              debuggerInfo=None,
              symbolsPath=None,
              timeout=-1,
              onLaunch=None,
-             webapprtChrome=False):
+             webapprtChrome=False,
+             hide_subtests=False):
     """
     Run the app, log the duration it took to execute, return the status code.
     Kills the app if it runs for longer than |maxTime| seconds, or outputs nothing for |timeout| seconds.
     """
 
     # debugger information
     interactive = False
     debug_args = None
@@ -844,20 +844,22 @@ class Mochitest(MochitestUtilsMixin):
     else:
       shutdownLeaks = None
 
     # create an instance to process the output
     outputHandler = self.OutputHandler(harness=self,
                                        utilityPath=utilityPath,
                                        symbolsPath=symbolsPath,
                                        dump_screen_on_timeout=not debuggerInfo,
+                                       hide_subtests=hide_subtests,
                                        shutdownLeaks=shutdownLeaks,
       )
 
     def timeoutHandler():
+      outputHandler.log_output_buffer()
       browserProcessId = outputHandler.browserProcessId
       self.handleTimeout(timeout, proc, utilityPath, debuggerInfo, browserProcessId)
     kp_kwargs = {'kill_on_timeout': False,
                  'onTimeout': [timeoutHandler]}
     kp_kwargs['processOutputLine'] = [outputHandler]
 
     # create mozrunner instance and start the system under test process
     self.lastTestSeen = self.test_name
@@ -1016,17 +1018,18 @@ class Mochitest(MochitestUtilsMixin):
                            extraArgs=options.browserArgs,
                            utilityPath=options.utilityPath,
                            xrePath=options.xrePath,
                            certPath=options.certPath,
                            debuggerInfo=debuggerInfo,
                            symbolsPath=options.symbolsPath,
                            timeout=timeout,
                            onLaunch=onLaunch,
-                           webapprtChrome=options.webapprtChrome
+                           webapprtChrome=options.webapprtChrome,
+                           hide_subtests=options.hide_subtests
                            )
     except KeyboardInterrupt:
       log.info("runtests.py | Received keyboard interrupt.\n");
       status = -1
     except:
       traceback.print_exc()
       log.error("Automation Error: Received unexpected exception while running application\n")
       status = 1
@@ -1050,25 +1053,29 @@ class Mochitest(MochitestUtilsMixin):
     log.info("TEST-UNEXPECTED-FAIL | %s | application timed out after %d seconds with no output", self.lastTestSeen, int(timeout))
     browserProcessId = browserProcessId or proc.pid
     self.killAndGetStack(browserProcessId, utilityPath, debuggerInfo, dump_screen=not debuggerInfo)
 
   ### output processing
 
   class OutputHandler(object):
     """line output handler for mozrunner"""
-    def __init__(self, harness, utilityPath, symbolsPath=None, dump_screen_on_timeout=True, shutdownLeaks=None):
+    def __init__(self, harness, utilityPath, symbolsPath=None, dump_screen_on_timeout=True,
+                 hide_subtests=False, shutdownLeaks=None):
       """
       harness -- harness instance
       dump_screen_on_timeout -- whether to dump the screen on timeout
       """
       self.harness = harness
+      self.output_buffer = []
+      self.running_test = False
       self.utilityPath = utilityPath
       self.symbolsPath = symbolsPath
       self.dump_screen_on_timeout = dump_screen_on_timeout
+      self.hide_subtests = hide_subtests
       self.shutdownLeaks = shutdownLeaks
 
       # perl binary to use
       self.perl = which('perl')
 
       # With metro browser runs this script launches the metro test harness which launches the browser.
       # The metro test harness hands back the real browser process id via log output which we need to
       # pick up on and parse out. This variable tracks the real browser process id if we find it.
@@ -1082,21 +1089,22 @@ class Mochitest(MochitestUtilsMixin):
       for handler in self.outputHandlers():
         line = handler(line)
     __call__ = processOutputLine
 
     def outputHandlers(self):
       """returns ordered list of output handlers"""
       return [self.fix_stack,
               self.format,
-              self.record_last_test,
               self.dumpScreenOnTimeout,
               self.metro_subprocess_id,
               self.trackShutdownLeaks,
+              self.check_test_failure,
               self.log,
+              self.record_last_test,
               ]
 
     def stackFixer(self):
       """
       return 2-tuple, (stackFixerFunction, StackFixerProcess),
       if any, to use on the output lines
       """
 
@@ -1136,37 +1144,36 @@ class Mochitest(MochitestUtilsMixin):
         self.stackFixerProcess.communicate()
         status = self.stackFixerProcess.returncode
         if status and not didTimeout:
           log.info("TEST-UNEXPECTED-FAIL | runtests.py | Stack fixer process exited with code %d during test run", status)
 
       if self.shutdownLeaks:
         self.shutdownLeaks.process()
 
+    def log_output_buffer(self):
+        if self.output_buffer:
+            lines = ['  %s' % line for line in self.output_buffer]
+            log.info("Buffered test output:\n%s" % '\n'.join(lines))
 
     # output line handlers:
     # these take a line and return a line
 
     def fix_stack(self, line):
       if self.stackFixerFunction:
         return self.stackFixerFunction(line)
       return line
 
     def format(self, line):
       """format the line"""
       return line.rstrip().decode("UTF-8", "ignore")
 
-    def record_last_test(self, line):
-      """record last test on harness"""
-      if "TEST-START" in line and "|" in line:
-        self.harness.lastTestSeen = line.split("|")[1].strip()
-      return line
-
     def dumpScreenOnTimeout(self, line):
       if self.dump_screen_on_timeout and "TEST-UNEXPECTED-FAIL" in line and "Test timed out" in line:
+        self.log_output_buffer()
         self.harness.dumpScreen(self.utilityPath)
       return line
 
     def metro_subprocess_id(self, line):
       """look for metro browser subprocess id"""
       if "METRO_BROWSER_PROCESS" in line:
         index = line.find("=")
         if index != -1:
@@ -1174,18 +1181,40 @@ class Mochitest(MochitestUtilsMixin):
           log.info("INFO | runtests.py | metro browser sub process id detected: %s", self.browserProcessId)
       return line
 
     def trackShutdownLeaks(self, line):
       if self.shutdownLeaks:
         self.shutdownLeaks.log(line)
       return line
 
+    def check_test_failure(self, line):
+      if 'TEST-END' in line:
+        self.running_test = False
+        if any('TEST-UNEXPECTED' in l for l in self.output_buffer):
+          self.log_output_buffer()
+      return line
+
     def log(self, line):
-      log.info(line)
+      if self.hide_subtests and self.running_test:
+        self.output_buffer.append(line)
+      else:
+        # hack to make separators align nicely, remove when we use mozlog
+        if self.hide_subtests and 'TEST-END' in line:
+            index = line.index('TEST-END') + len('TEST-END')
+            line = line[:index] + ' ' * (len('TEST-START')-len('TEST-END')) + line[index:]
+        log.info(line)
+      return line
+
+    def record_last_test(self, line):
+      """record last test on harness"""
+      if "TEST-START" in line and "|" in line:
+        self.output_buffer = []
+        self.running_test = True
+        self.harness.lastTestSeen = line.split("|")[1].strip()
       return line
 
 
   def makeTestConfig(self, options):
     "Creates a test configuration file for customizing test execution."
     def jsonString(val):
       if isinstance(val, bool):
         if val: