Bug 1209463 - [test] Use a common logger across suites from |mach test| and other test commands, r=gbrown
authorAndrew Halberstadt <ahalberstadt@mozilla.com>
Thu, 23 Nov 2017 13:04:19 -0500
changeset 447975 d3afe2be86851ca2114b177cfb801c63cdec793c
parent 447974 6aae83bee604e538345806ff1c0cc330b7f355ab
child 447976 bdecf757602bfd20403325444bce8910c38d5a3e
push id8527
push userCallek@gmail.com
push dateThu, 11 Jan 2018 21:05:50 +0000
treeherdermozilla-beta@95342d212a7a [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersgbrown
bugs1209463
milestone59.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 1209463 - [test] Use a common logger across suites from |mach test| and other test commands, r=gbrown In order for |mach test| and |mach mochitest| to log an overall summary, every test harness invocation they make needs to use the same structured logger (otherwise the affected suite will be missing from the summary). MozReview-Commit-ID: 8LJw7r8SItk
layout/tools/reftest/runreftest.py
testing/mach_commands.py
testing/marionette/mach_commands.py
testing/mochitest/mach_commands.py
testing/mochitest/runrobocop.py
testing/mochitest/runtests.py
testing/mochitest/runtestsremote.py
testing/web-platform/tests/tools/wptrunner/wptrunner/wptlogging.py
testing/xpcshell/mach_commands.py
--- a/layout/tools/reftest/runreftest.py
+++ b/layout/tools/reftest/runreftest.py
@@ -236,16 +236,20 @@ class RefTest(object):
         self.haveDumpedScreen = False
         self.resolver = self.resolver_cls()
         self.log = None
 
     def _populate_logger(self, options):
         if self.log:
             return
 
+        self.log = getattr(options, 'log', None)
+        if self.log:
+            return
+
         mozlog.commandline.log_formatters["tbpl"] = (ReftestFormatter,
                                                      "Reftest specific formatter for the"
                                                      "benefit of legacy log parsers and"
                                                      "tools such as the reftest analyzer")
         fmt_options = {}
         if not options.log_tbpl_level and os.environ.get('MOZ_REFTEST_VERBOSE'):
             options.log_tbpl_level = fmt_options['level'] = 'debug'
         self.log = mozlog.commandline.setup_logging(
--- a/testing/mach_commands.py
+++ b/testing/mach_commands.py
@@ -12,16 +12,17 @@ import sys
 import tempfile
 import subprocess
 import shutil
 
 from mach.decorators import (
     CommandArgument,
     CommandProvider,
     Command,
+    SettingsProvider,
 )
 
 from mozbuild.base import MachCommandBase, MachCommandConditions as conditions
 from moztest.resolve import TEST_SUITES
 from argparse import ArgumentParser
 
 UNKNOWN_TEST = '''
 I was unable to find tests from the given argument(s).
@@ -46,16 +47,33 @@ TEST_HELP = '''
 Test or tests to run. Tests can be specified by filename, directory, suite
 name or suite alias.
 
 The following test suites and aliases are supported: %s
 ''' % ', '.join(sorted(TEST_SUITES))
 TEST_HELP = TEST_HELP.strip()
 
 
+@SettingsProvider
+class TestConfig(object):
+
+    @classmethod
+    def config_settings(cls):
+        from mozlog.commandline import log_formatters
+        from mozlog.structuredlog import log_levels
+        format_desc = "The default format to use when running tests with `mach test`."
+        format_choices = log_formatters.keys()
+        level_desc = "The default log level to use when running tests with `mach test`."
+        level_choices = [l.lower() for l in log_levels]
+        return [
+            ('test.format', 'string', format_desc, 'tbpl', {'choices': format_choices}),
+            ('test.level', 'string', level_desc, 'info', {'choices': level_choices}),
+        ]
+
+
 @CommandProvider
 class Test(MachCommandBase):
     @Command('test', category='testing',
              description='Run tests (detects the kind of test and runs it).')
     @CommandArgument('what', default=None, nargs='*', help=TEST_HELP)
     @CommandArgument('extra_args', default=None, nargs=argparse.REMAINDER,
                      help="Extra arguments to pass to the underlying test command(s). "
                           "If an underlying command doesn't recognize the argument, it "
@@ -79,32 +97,45 @@ class Test(MachCommandBase):
         When paths or directories are given, they are first resolved to test
         files known to the build system.
 
         If resolved tests belong to more than one test type/flavor/harness,
         the harness for each relevant type/flavor will be invoked. e.g. if
         you specify a directory with xpcshell and browser chrome mochitests,
         both harnesses will be invoked.
         """
+        from mozlog.commandline import log_formatters
+        from mozlog.handlers import StreamHandler, LogLevelFilter
+        from mozlog.structuredlog import StructuredLogger
         from moztest.resolve import TestResolver, TEST_FLAVORS, TEST_SUITES
+
         resolver = self._spawn(TestResolver)
         run_suites, run_tests = resolver.resolve_metadata(what)
 
         if not run_suites and not run_tests:
             print(UNKNOWN_TEST)
             return 1
 
+        # Create shared logger
+        formatter = log_formatters[self._mach_context.settings['test']['format']][0]()
+
+        level = self._mach_context.settings['test']['level']
+        log = StructuredLogger('mach-test')
+        log.add_handler(StreamHandler(sys.stdout, LogLevelFilter(formatter, level)))
+
         status = None
         for suite_name in run_suites:
             suite = TEST_SUITES[suite_name]
+            kwargs = suite['kwargs']
+            kwargs['log'] = log
 
             if 'mach_command' in suite:
                 res = self._mach_context.commands.dispatch(
                     suite['mach_command'], self._mach_context,
-                    argv=extra_args, **suite['kwargs'])
+                    argv=extra_args, **kwargs)
                 if res:
                     status = res
 
         buckets = {}
         for test in run_tests:
             key = (test['flavor'], test.get('subsuite', ''))
             buckets.setdefault(key, []).append(test)
 
@@ -116,40 +147,45 @@ class Test(MachCommandBase):
 
             m = TEST_FLAVORS[flavor]
             if 'mach_command' not in m:
                 print(UNKNOWN_FLAVOR % flavor)
                 status = 1
                 continue
 
             kwargs = dict(m['kwargs'])
+            kwargs['log'] = log
             kwargs['subsuite'] = subsuite
 
             res = self._mach_context.commands.dispatch(
                 m['mach_command'], self._mach_context,
                 argv=extra_args, test_objects=tests, **kwargs)
             if res:
                 status = res
 
+        log.shutdown()
         return status
 
 
 @CommandProvider
 class MachCommands(MachCommandBase):
     @Command('cppunittest', category='testing',
              description='Run cpp unit tests (C++ tests).')
     @CommandArgument('test_files', nargs='*', metavar='N',
                      help='Test to run. Can be specified as one or more files or '
                      'directories, or omitted. If omitted, the entire test suite is '
                      'executed.')
     def run_cppunit_test(self, **params):
         from mozlog import commandline
-        log = commandline.setup_logging("cppunittest",
-                                        {},
-                                        {"tbpl": sys.stdout})
+
+        log = params.get('log')
+        if not log:
+            log = commandline.setup_logging("cppunittest",
+                                            {},
+                                            {"tbpl": sys.stdout})
 
         # See if we have crash symbols
         symbols_path = os.path.join(self.distdir, 'crashreporter-symbols')
         if not os.path.isdir(symbols_path):
             symbols_path = None
 
         # If no tests specified, run all tests in main manifest
         tests = params['test_files']
--- a/testing/marionette/mach_commands.py
+++ b/testing/marionette/mach_commands.py
@@ -52,19 +52,21 @@ def run_marionette(tests, binary=None, t
 
     args.binary = binary
 
     for k, v in kwargs.iteritems():
         setattr(args, k, v)
 
     parser.verify_usage(args)
 
-    args.logger = commandline.setup_logging("Marionette Unit Tests",
-                                            args,
-                                            {"mach": sys.stdout})
+    args.logger = kwargs.get('log')
+    if not args.logger:
+        args.logger = commandline.setup_logging("Marionette Unit Tests",
+                                                args,
+                                                {"mach": sys.stdout})
     failed = MarionetteHarness(MarionetteTestRunner, args=vars(args)).run()
     if failed > 0:
         return 1
     else:
         return 0
 
 
 @CommandProvider
--- a/testing/mochitest/mach_commands.py
+++ b/testing/mochitest/mach_commands.py
@@ -281,16 +281,19 @@ def verify_host_bin():
 @CommandProvider
 class MachCommands(MachCommandBase):
     @Command('mochitest', category='testing',
              conditions=[is_buildapp_in(*SUPPORTED_APPS)],
              description='Run any flavor of mochitest (integration test).',
              parser=setup_argument_parser)
     def run_mochitest_general(self, flavor=None, test_objects=None, resolve_tests=True, **kwargs):
         from mochitest_options import ALL_FLAVORS
+        from mozlog.commandline import log_formatters
+        from mozlog.handlers import StreamHandler, LogLevelFilter
+        from mozlog.structuredlog import StructuredLogger
 
         buildapp = None
         for app in SUPPORTED_APPS:
             if is_buildapp_in(app)(self):
                 buildapp = app
                 break
 
         flavors = None
@@ -299,16 +302,23 @@ class MachCommands(MachCommandBase):
                 if flavor in fobj['aliases']:
                     if buildapp not in fobj['enabled_apps']:
                         continue
                     flavors = [fname]
                     break
         else:
             flavors = [f for f, v in ALL_FLAVORS.iteritems() if buildapp in v['enabled_apps']]
 
+        if not kwargs.get('log'):
+            # Create shared logger
+            formatter = log_formatters[self._mach_context.settings['test']['format']][0]()
+            level = self._mach_context.settings['test']['level']
+            kwargs['log'] = StructuredLogger('mach-mochitest')
+            kwargs['log'].add_handler(StreamHandler(sys.stdout, LogLevelFilter(formatter, level)))
+
         from mozbuild.controller.building import BuildDriver
         self._ensure_state_subdir_exists('.')
 
         test_paths = kwargs['test_paths']
         kwargs['test_paths'] = []
 
         mochitest = self._spawn(MochitestRunner)
         tests = []
@@ -414,17 +424,20 @@ class MachCommands(MachCommandBase):
 
             if result:
                 overall = result
 
             # Halt tests on keyboard interrupt
             if result == -1:
                 break
 
-        # TODO consolidate summaries from all suites
+        # Only shutdown the logger if we created it
+        if kwargs['log'].name == 'mach-mochitest':
+            kwargs['log'].shutdown()
+
         return overall
 
 
 @CommandProvider
 class RobocopCommands(MachCommandBase):
 
     @Command('robocop', category='testing',
              conditions=[conditions.is_android],
--- a/testing/mochitest/runrobocop.py
+++ b/testing/mochitest/runrobocop.py
@@ -37,17 +37,17 @@ class RobocopTestRunner(MochitestDesktop
     dm = None
     # Some robocop tests run for >60 seconds without generating any output.
     NO_OUTPUT_TIMEOUT = 180
 
     def __init__(self, automation, devmgr, options):
         """
            Simple one-time initialization.
         """
-        MochitestDesktop.__init__(self, options.flavor, options)
+        MochitestDesktop.__init__(self, options.flavor, vars(options))
 
         self.auto = automation
         self.dm = devmgr
         self.dm.default_timeout = 320
         self.options = options
         self.options.logFile = "robocop.log"
         self.environment = self.auto.environment
         self.deviceRoot = self.dm.getDeviceRoot()
--- a/testing/mochitest/runtests.py
+++ b/testing/mochitest/runtests.py
@@ -855,20 +855,23 @@ class MochitestDesktop(object):
         self._locations = None
 
         self.marionette = None
         self.start_script = None
         self.mozLogs = None
         self.start_script_kwargs = {}
         self.urlOpts = []
 
-        commandline.log_formatters["tbpl"] = (
-            MochitestFormatter,
-            "Mochitest specific tbpl formatter")
-        self.log = commandline.setup_logging("mochitest", logger_options, {"tbpl": sys.stdout})
+        if logger_options.get('log'):
+            self.log = logger_options['log']
+        else:
+            commandline.log_formatters["tbpl"] = (
+                MochitestFormatter,
+                "Mochitest specific tbpl formatter")
+            self.log = commandline.setup_logging("mochitest", logger_options, {"tbpl": sys.stdout})
 
         self.message_logger = MessageLogger(
                 logger=self.log, buffering=quiet, structured=True)
 
         # Max time in seconds to wait for server startup before tests will fail -- if
         # this seems big, it's mostly for debug machines where cold startup
         # (particularly after a build) takes forever.
         self.SERVER_STARTUP_TIMEOUT = 180 if mozinfo.info.get('debug') else 90
--- a/testing/mochitest/runtestsremote.py
+++ b/testing/mochitest/runtestsremote.py
@@ -24,17 +24,17 @@ SCRIPT_DIR = os.path.abspath(os.path.rea
 
 class MochiRemote(MochitestDesktop):
     _automation = None
     _dm = None
     localProfile = None
     logMessages = []
 
     def __init__(self, automation, devmgr, options):
-        MochitestDesktop.__init__(self, options.flavor, options)
+        MochitestDesktop.__init__(self, options.flavor, vars(options))
 
         self._automation = automation
         self._dm = devmgr
         self.environment = self._automation.environment
         self.remoteProfile = os.path.join(options.remoteTestRoot, "profile/")
         self.remoteModulesDir = os.path.join(options.remoteTestRoot, "modules/")
         self.remoteCache = os.path.join(options.remoteTestRoot, "cache/")
         self._automation.setRemoteProfile(self.remoteProfile)
--- a/testing/web-platform/tests/tools/wptrunner/wptrunner/wptlogging.py
+++ b/testing/web-platform/tests/tools/wptrunner/wptrunner/wptlogging.py
@@ -1,18 +1,24 @@
 import logging
 import sys
 import threading
 from StringIO import StringIO
 from multiprocessing import Queue
 
-from mozlog import commandline, stdadapter
+from mozlog import commandline, stdadapter, set_default_logger
+from mozlog.structuredlog import StructuredLogger
 
 def setup(args, defaults):
-    logger = commandline.setup_logging("web-platform-tests", args, defaults)
+    logger = args.pop('log', None)
+    if logger:
+        set_default_logger(logger)
+        StructuredLogger._logger_states["web-platform-tests"] = logger._state
+    else:
+        logger = commandline.setup_logging("web-platform-tests", args, defaults)
     setup_stdlib_logger()
 
     for name in args.keys():
         if name.startswith("log_"):
             args.pop(name)
 
     return logger
 
--- a/testing/xpcshell/mach_commands.py
+++ b/testing/xpcshell/mach_commands.py
@@ -243,20 +243,21 @@ class MachCommands(MachCommandBase):
         driver = self._spawn(BuildDriver)
         driver.install_tests(test_objects)
 
         # We should probably have a utility function to ensure the tree is
         # ready to run tests. Until then, we just create the state dir (in
         # case the tree wasn't built with mach).
         self._ensure_state_subdir_exists('.')
 
-        params['log'] = structured.commandline.setup_logging("XPCShellTests",
-                                                             params,
-                                                             {"mach": sys.stdout},
-                                                             {"verbose": True})
+        if not params.get('log'):
+            params['log'] = structured.commandline.setup_logging("XPCShellTests",
+                                                                 params,
+                                                                 {"mach": sys.stdout},
+                                                                 {"verbose": True})
 
         if not params['threadCount']:
             params['threadCount'] = int((cpu_count() * 3) / 2)
 
         if conditions.is_android(self):
             from mozrunner.devices.android_device import verify_android_device, get_adb_path
             verify_android_device(self)
             if not params['adbPath']: