Bug 1285299 - Add pytest_mozlog plugin to mozlog; r?jgraham draft
authorAnjana Vakil <anjanavakil@gmail.com>
Thu, 08 Sep 2016 11:43:11 +0200
changeset 411597 07bdd0d18463de5ec22355f60f9b9a167874ab51
parent 411217 dea2ba419ad7fe37f29905844ba36fd76abfc76c
child 411598 6af4d9c3737450b6c7af950e0bc5605c35d4293c
push id28936
push userbmo:anjanavakil@gmail.com
push dateThu, 08 Sep 2016 09:45:30 +0000
reviewersjgraham
bugs1285299
milestone51.0a1
Bug 1285299 - Add pytest_mozlog plugin to mozlog; r?jgraham Add the `pytest_mozlog` module (from https://github.com/davehunt/pytest-mozlog) to mozbase/mozlog/mozlog, so that we can use it in the logging of the Marionette harness tests. Add an entry point for the plugin to mozlog/setup.py so that when mozlog is installed, pytest will register the pytest_mozlog plugin.py module as the plugin 'mozlog'. Make the following modifications to pytest_mozlog/plugin.py: - Disable stdout logging by default in pytest-mozlog In the pytest-mozlog plugin, disable logging to stdout by default when setting up the mozlog logger, so that the default output seen when using the plugin is just the Pytest terminal output. The user can specify a mozlog logger to write to stdout by using the '--log-* -' option, in which case both Pytest and pytest-mozlog will log to stdout. - Record error msg and lineno in pytest-mozlog logs Extract the error message and line number for tests with failures/ errors from the Pytest test report, and pass these to the Mozlog logs output by the pytest-mozlog plugin. For skipped tests, pass the skip reason, and for unexpected passes allow Mozlog to report its default message "expected FAIL". - Report collected item count in pytest-mozlog Add/modify Pytest hooks in the pytest-mozlog plugin so that the suite_start event sent to the logger contains the correct list of tests to be run, i.e. items collected by Pytest, instead of an empty list. This allows mozlog to log the correct number of tests to be run. - Log skipped/xfailed tests with corresponding status (not 'PASS') Log skipped tests with status 'SKIP' and expected failures that do indeed fail with status 'FAIL'/expected 'FAIL' so that these can be distinguished from true passing tests. - Pass parsed arguments directly to mozlog.commandline.setup_logging Pass the entire Pytest config's argument namespace to `setup_logging` instead of copying over only the non-None formatters/formatter option arguments. Use the new `allow_unused_options` parameter to stop Mozlog from raising an error about options for unused formatters. MozReview-Commit-ID: 4WpprytS5cI
testing/mozbase/mozlog/mozlog/pytest_mozlog/__init__.py
testing/mozbase/mozlog/mozlog/pytest_mozlog/plugin.py
testing/mozbase/mozlog/setup.py
new file mode 100644
new file mode 100644
--- /dev/null
+++ b/testing/mozbase/mozlog/mozlog/pytest_mozlog/plugin.py
@@ -0,0 +1,92 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# 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 mozlog
+import os
+import time
+
+def pytest_addoption(parser):
+    # We can't simply use mozlog.commandline.add_logging_group(parser) here because
+    # Pytest's parser doesn't have the add_argument_group method Mozlog expects.
+    group = parser.getgroup('mozlog')
+
+    for name, (_class, _help) in mozlog.commandline.log_formatters.iteritems():
+        group.addoption('--log-{0}'.format(name), action='append', help=_help)
+
+    formatter_options = mozlog.commandline.fmt_options.iteritems()
+    for name, (_class, _help, formatters, action) in formatter_options:
+        for formatter in formatters:
+            if formatter in mozlog.commandline.log_formatters:
+                group.addoption(
+                    '--log-{0}-{1}'.format(formatter, name),
+                    action=action,
+                    help=_help)
+
+
+def pytest_configure(config):
+    # If using pytest-xdist for parallelization, only register plugin on master process
+    if not hasattr(config, 'slaveinput'):
+        config.pluginmanager.register(MozLog())
+
+
+class MozLog(object):
+    def __init__(self):
+        self.results = {}
+        self.start_time = int(time.time() * 1000)  # in ms for Mozlog compatibility
+
+    def format_nodeid(self, nodeid):
+        '''Helper to Reformat/shorten a "::"-separated pytest test nodeid'''
+        testfile, testname = nodeid.split("::")
+        return " ".join([os.path.basename(testfile), testname])
+
+    def pytest_configure(self, config):
+        mozlog.commandline.setup_logging('pytest', config.known_args_namespace,
+                                         defaults={}, allow_unused_options=True)
+        self.logger = mozlog.get_default_logger(component='pytest')
+
+    def pytest_sessionstart(self, session):
+        '''Called before test collection; records suite start time to log later'''
+        self.start_time = int(time.time() * 1000)  # in ms for Mozlog compatibility
+
+    def pytest_collection_modifyitems(self, items):
+        '''Called after test collection is completed, just before tests are run (suite start)'''
+        self.logger.suite_start(tests=items, time=self.start_time)
+
+    def pytest_sessionfinish(self, session, exitstatus):
+        self.logger.suite_end()
+
+    def pytest_runtest_logstart(self, nodeid, location):
+        self.logger.test_start(test=self.format_nodeid(nodeid))
+
+    def pytest_runtest_logreport(self, report):
+        '''Called 3 times per test (setup, call, teardown), indicated by report.when'''
+        test = report.nodeid
+        status = expected = 'PASS'
+        message = stack = None
+        if hasattr(report, 'wasxfail'):
+            # Pytest reporting for xfail tests is somewhat counterinutitive:
+            # If an xfail test fails as expected, its 'call' report has .skipped,
+            # so we record status FAIL (== expected) and log an expected result.
+            # If an xfail unexpectedly passes, the 'call' report has .failed (Pytest 2)
+            # or .passed (Pytest 3), so we leave status as PASS (!= expected)
+            # to log an unexpected result.
+            expected = 'FAIL'
+            if report.skipped:  # indicates expected failure (passing test)
+                status = 'FAIL'
+        elif report.failed:
+            status = 'FAIL' if report.when == 'call' else 'ERROR'
+            crash = report.longrepr.reprcrash  # here longrepr is a ReprExceptionInfo
+            message = "{0} (line {1})".format(crash.message, crash.lineno)
+            stack = report.longrepr.reprtraceback
+        elif report.skipped:  # indicates true skip
+            status = expected = 'SKIP'
+            message = report.longrepr[-1]  # here longrepr is a tuple (file, lineno, reason)
+        if status != expected or expected != 'PASS':
+            self.results[test] = (status, expected, message, stack)
+        if report.when == 'teardown':
+            defaults = ('PASS', 'PASS', None, None)
+            status, expected, message, stack = self.results.get(test, defaults)
+            self.logger.test_end(test=self.format_nodeid(test),
+                                 status=status, expected=expected,
+                                 message=message, stack=stack)
--- a/testing/mozbase/mozlog/setup.py
+++ b/testing/mozbase/mozlog/setup.py
@@ -27,10 +27,13 @@ setup(name=PACKAGE_NAME,
                    'Operating System :: OS Independent',
                    'Topic :: Software Development :: Libraries :: Python Modules',
                   ],
       package_data={"mozlog": ["formatters/html/main.js",
                                "formatters/html/style.css"]},
       entry_points={
           "console_scripts": [
               "structlog = mozlog.scripts:main"
+          ],
+          'pytest11': [
+            'mozlog = mozlog.pytest_mozlog.plugin',
           ]}
      )