Bug 977071 - Add run_info to structured log suite_start message and fix some small bugs. r=ahal
authorJames Graham <james@hoppipolla.co.uk>
Mon, 10 Feb 2014 20:21:18 +0000
changeset 171095 9adf062bc5a344d2314498ce168d915632367c75
parent 171094 4a3f182f06c0105874b0859bf87ea9c34740e701
child 171096 b89988fc261d6f63f59d7d98f1c25bc1b425f20e
push id270
push userpvanderbeken@mozilla.com
push dateThu, 06 Mar 2014 09:24:21 +0000
reviewersahal
bugs977071
milestone30.0a1
Bug 977071 - Add run_info to structured log suite_start message and fix some small bugs. r=ahal
testing/mozbase/mozlog/mozlog/__init__.py
testing/mozbase/mozlog/mozlog/structured/commandline.py
testing/mozbase/mozlog/mozlog/structured/formatters/__init__.py
testing/mozbase/mozlog/mozlog/structured/formatters/html/html.py
testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
testing/mozbase/mozlog/mozlog/structured/handlers/__init__.py
testing/mozbase/mozlog/mozlog/structured/structuredlog.py
--- a/testing/mozbase/mozlog/mozlog/__init__.py
+++ b/testing/mozbase/mozlog/mozlog/__init__.py
@@ -4,21 +4,21 @@
 
 """
 Mozlog aims to standardize log formatting within Mozilla.
 
 It simply wraps Python's logging_ module and adds a few convenience methods
 for logging test results and events.
 
 The structured submodule takes a different approach and implements a
-JSON-based logging protocol designed for recording test results.
-"""
+JSON-based logging protocol designed for recording test results."""
 
 from logger import *
 from loglistener import LogMessageServer
 from loggingmixin import LoggingMixin
 
 try:
     import structured
 except ImportError:
     # Structured logging doesn't work on python 2.6 which is still used on some
     # legacy test machines; https://bugzilla.mozilla.org/show_bug.cgi?id=864866
     pass
+
--- a/testing/mozbase/mozlog/mozlog/structured/commandline.py
+++ b/testing/mozbase/mozlog/mozlog/structured/commandline.py
@@ -10,16 +10,17 @@ import handlers
 import formatters
 
 log_formatters = {
     'raw': (formatters.JSONFormatter, "Raw structured log messages"),
     'unittest': (formatters.UnittestFormatter, "Unittest style output"),
     'xunit': (formatters.XUnitFormatter, "xUnit compatible XML"),
     'html': (formatters.HTMLFormatter, "HTML report"),
     'mach': (formatters.MachFormatter, "Uncolored mach-like output"),
+    'mach_terminal': (formatters.MachTerminalFormatter, "Colored mach-like output for use in a tty"),
 }
 
 
 def log_file(name):
     if name == "-":
         return sys.stdout
     else:
         return open(name, "w")
@@ -37,44 +38,45 @@ def add_logging_group(parser):
                    options added.
     """
     group = parser.add_argument_group("Output Logging",
                                       description="Options for logging output.\n"
                                       "Each option represents a possible logging format "
                                       "and takes a filename to write that format to, "
                                       "or '-' to write to stdout.")
     for name, (cls, help_str) in log_formatters.iteritems():
-        group.add_argument("--log-" + name, type=log_file,
+        group.add_argument("--log-" + name, action="append", type=log_file,
                            help=help_str)
 
 
 def setup_logging(suite, args, defaults):
     """
     Configure a structuredlogger based on command line arguments.
 
     :param suite: The name of the testsuite being run
-    :param args: The Namespace object produced by argparse from parsing
-                 command line arguments from a parser with logging arguments.
+    :param args: A dictionary of {argument_name:value} produced from
+                 parsing the command line arguments for the application
     :param defaults: A dictionary of {formatter name: output stream} to apply
                      when there is no logging supplied on the command line.
 
     :rtype: StructuredLogger
     """
     logger = StructuredLogger(suite)
     prefix = "log_"
     found = False
     found_stdout_logger = False
-    for name, value in args.iteritems():
-        if name.startswith(prefix) and value is not None:
-            found = True
-            if value == sys.stdout:
-                found_stdout_logger = True
-            formatter_cls = log_formatters[name[len(prefix):]][0]
-            logger.add_handler(handlers.StreamHandler(stream=value,
-                                                      formatter=formatter_cls()))
+    for name, values in args.iteritems():
+        if name.startswith(prefix) and values is not None:
+            for value in values:
+                found = True
+                if value == sys.stdout:
+                    found_stdout_logger = True
+                formatter_cls = log_formatters[name[len(prefix):]][0]
+                logger.add_handler(handlers.StreamHandler(stream=value,
+                                                          formatter=formatter_cls()))
 
     #If there is no user-specified logging, go with the default options
     if not found:
         for name, value in defaults.iteritems():
             formatter_cls = log_formatters[name][0]
             logger.add_handler(handlers.StreamHandler(stream=value,
                                                       formatter=formatter_cls()))
 
--- a/testing/mozbase/mozlog/mozlog/structured/formatters/__init__.py
+++ b/testing/mozbase/mozlog/mozlog/structured/formatters/__init__.py
@@ -3,9 +3,10 @@
 # file, You can obtain one at http://mozilla.org/MPL/2.0/.
 
 import json
 from unittest import UnittestFormatter
 from xunit import XUnitFormatter
 from html import HTMLFormatter
 from machformatter import MachFormatter, MachTerminalFormatter
 
-JSONFormatter = lambda: json.dumps
+def JSONFormatter():
+    return lambda x: json.dumps(x) + "\n"
--- a/testing/mozbase/mozlog/mozlog/structured/formatters/html/html.py
+++ b/testing/mozbase/mozlog/mozlog/structured/formatters/html/html.py
@@ -1,14 +1,15 @@
 #!/usr/bin/env python
 # 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 sys
+import json
 import datetime
 import os
 
 from .. import base
 
 from collections import defaultdict
 
 html = None
--- a/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
+++ b/testing/mozbase/mozlog/mozlog/structured/formatters/machformatter.py
@@ -24,17 +24,17 @@ class BaseMachFormatter(base.BaseFormatt
         self.last_time = None
 
     def __call__(self, data):
         s = base.BaseFormatter.__call__(self, data)
         if s is not None:
             return "%s %s\n" % (self.generic_formatter(data), s)
 
     def _get_test_id(self, data):
-        test_id = data["test"]
+        test_id = data.get("test")
         if isinstance(test_id, list):
             test_id = tuple(test_id)
         return test_id
 
     def generic_formatter(self, data):
         return "%s: %s" % (data["action"].upper(), data["thread"])
 
     def suite_start(self, data):
@@ -57,22 +57,23 @@ class BaseMachFormatter(base.BaseFormatt
 
         return "Harness status %s%s. Subtests passed %i/%i. Unexpected %i" % (
             data["status"], expected_str, subtests["pass"],
             subtests["count"], unexpected)
 
     def test_status(self, data):
         test = self._get_test_id(data)
         if test not in self.status_buffer:
-            self.buffer[test] = {"count": 0, "unexpected": 0, "pass": 0}
-        self.buffer[test]["count"] += 1
+            self.status_buffer[test] = {"count": 0, "unexpected": 0, "pass": 0}
+        self.status_buffer[test]["count"] += 1
+
         if "expected" in data:
-            self.buffer[test]["unexpected"] += 1
+            self.status_buffer[test]["unexpected"] += 1
         if data["status"] == "PASS":
-            self.buffer[test]["pass"] += 1
+            self.status_buffer[test]["pass"] += 1
 
     def process_output(self, data):
         return '"%s" (pid:%s command:%s)' % (data["data"],
                                              data["process"],
                                              data["command"])
 
     def log(self, data):
         return "%s %s" % (data["level"], data["message"])
@@ -127,19 +128,19 @@ class MachTerminalFormatter(BaseMachForm
         BaseMachFormatter.__init__(self,
                                    start_time=start_time,
                                    write_interval=write_interval,
                                    write_times=write_times)
 
     def __call__(self, data):
         s = BaseMachFormatter.__call__(self, data)
         if s is not None:
-            t = self.terminal.blue(format_seconds(self._time(entry)))
+            t = self.terminal.blue(format_seconds(self._time(data)))
 
-            return '%s %s' % (t, self._colorize(entry, s))
+            return '%s %s' % (t, self._colorize(data, s))
 
     def _colorize(self, data, s):
         if self.terminal is None:
             return s
 
         subtests = self._get_subtest_data(data)
 
         color = None
@@ -150,15 +151,17 @@ class MachTerminalFormatter(BaseMachForm
                 color = self.terminal.green
             else:
                 color = self.terminal.red
         elif data["action"] in ("suite_start", "suite_end", "test_start"):
             color = self.terminal.yellow
 
         if color is not None:
             result = color(s[:len_action]) + s[len_action:]
+        else:
+            result = s
 
         return result
 
 if __name__ == "__main__":
     base.format_file(sys.stdin,
                      handlers.StreamHandler(stream=sys.stdout,
                                             formatter=MachFormatter()))
--- a/testing/mozbase/mozlog/mozlog/structured/handlers/__init__.py
+++ b/testing/mozbase/mozlog/mozlog/structured/handlers/__init__.py
@@ -1,14 +1,16 @@
 # 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/.
 
 from threading import Lock
 
+from ..structuredlog import log_levels
+
 
 class BaseHandler(object):
     def __init__(self, formatter=str):
         self.formatter = formatter
         self.filters = []
 
     def add_filter(self, filter_func):
         self.filters.append(filter_func)
--- a/testing/mozbase/mozlog/mozlog/structured/structuredlog.py
+++ b/testing/mozbase/mozlog/mozlog/structured/structuredlog.py
@@ -99,22 +99,25 @@ class StructuredLogger(object):
         all_data = {"action": action,
                     "time": int(time.time() * 1000),
                     "thread": current_thread().name,
                     "pid": current_process().pid,
                     "source": self.name}
         all_data.update(data)
         return all_data
 
-    def suite_start(self, tests):
+    def suite_start(self, tests, run_info=None):
         """Log a suite_start message
 
         :param tests: List of test identifiers that will be run in the suite.
         """
-        self._log_data("suite_start", {"tests": tests})
+        data = {"tests": tests}
+        if run_info is not None:
+            data["run_info"] = run_info
+        self._log_data("suite_start", data)
 
     def suite_end(self):
         """Log a suite_end message"""
         self._log_data("suite_end")
 
     def test_start(self, test):
         """Log a test_start message
 
@@ -166,18 +169,17 @@ class StructuredLogger(object):
             data["message"] = message
         if expected != data["status"]:
             data["expected"] = expected
         if extra is not None:
             data["extra"] = extra
         self._log_data("test_end", data)
 
     def process_output(self, process, data, command=None):
-        """
-        Log output from a managed process.
+        """Log output from a managed process.
 
         :param process: A unique identifier for the process producing the output
                         (typically the pid)
         :param data: The output to log
         :param command: A string representing the full command line used to start
                         the process.
         """
         data = {"process": process, "data": data}