Bug 777231 - Add skeleton for mozbuild package; r=vlad

build/virtualenv/packages.txt

@@ -7,5 +7,6 @@ setup.py:testing/mozbase/mozprocess:develop
 setup.py:testing/mozbase/mozprofile:develop
 setup.py:testing/mozbase/mozrunner:develop
 setup.py:python/blessings:develop
+setup.py:python/mozbuild:develop
 mozilla.pth:build
 mozilla.pth:config

python/mozbuild/README.rst

@@ -0,0 +1,99 @@
+========
+mozbuild
+========
+
+mozbuild is a Python package providing functionality used by Mozilla's
+build system.
+
+Modules Overview
+================
+
+* mozbuild.logging -- Defines mozbuild's logging infrastructure.
+  mozbuild uses a structured logging backend.
+
+Structured Logging
+==================
+
+One of the features of mozbuild is structured logging. Instead of
+conventional logging where simple strings are logged, the internal
+logging mechanism logs all events with the following pieces of
+information:
+
+* A string *action*
+* A dict of log message fields
+* A formatting string
+
+Essentially, instead of assembling a human-readable string at
+logging-time, you create an object holding all the pieces of data that
+will constitute your logged event. For each unique type of logged event,
+you assign an *action* name.
+
+Depending on how logging is configured, your logged event could get
+written a couple of different ways.
+
+JSON Logging
+------------
+
+Where machines are the intended target of the logging data, a JSON
+logger is configured. The JSON logger assembles an array consisting of
+the following elements:
+
+* Decimal wall clock time in seconds since UNIX epoch
+* String *action* of message
+* Object with structured message data
+
+The JSON-serialized array is written to a configured file handle.
+Consumers of this logging stream can just perform a readline() then feed
+that into a JSON deserializer to reconstruct the original logged
+message. They can key off the *action* element to determine how to
+process individual events. There is no need to invent a parser.
+Convenient, isn't it?
+
+Logging for Humans
+------------------
+
+Where humans are the intended consumer of a log message, the structured
+log message are converted to more human-friendly form. This is done by
+utilizing the *formatting* string provided at log time. The logger
+simply calls the *format* method of the formatting string, passing the
+dict containing the message's fields.
+
+When *mach* is used in a terminal that supports it, the logging facility
+also supports terminal features such as colorization. This is done
+automatically in the logging layer - there is no need to control this at
+logging time.
+
+In addition, messages intended for humans typically prepends every line
+with the time passed since the application started.
+
+Logging HOWTO
+-------------
+
+Structured logging piggybacks on top of Python's built-in logging
+infrastructure provided by the *logging* package. We accomplish this by
+taking advantage of *logging.Logger.log()*'s *extra* argument. To this
+argument, we pass a dict with the fields *action* and *params*. These
+are the string *action* and dict of message fields, respectively. The
+formatting string is passed as the *msg* argument, like normal.
+
+If you were logging to a logger directly, you would do something like:
+
+    logger.log(logging.INFO, 'My name is {name}',
+        extra={'action': 'my_name', 'params': {'name': 'Gregory'}})
+
+The JSON logging would produce something like:
+
+    [1339985554.306338, "my_name", {"name": "Gregory"}]
+
+Human logging would produce something like:
+
+     0.52 My name is Gregory
+
+Since there is a lot of complexity using logger.log directly, it is
+recommended to go through a wrapping layer that hides part of the
+complexity for you. e.g.
+
+    def log(self, level, action, params, format_str):
+        self.logger.log(level, format_str,
+            extra={'action': action, 'params': params)
+

python/mozbuild/mozbuild/logger.py

@@ -0,0 +1,202 @@
+# 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/.
+
+# This file contains logging functionality for mozbuild. This functionality
+# could likely be split out of mozbuild. For now, mozbuild is the only
+# consumer and thus it lives here.
+
+try:
+    import blessings
+except ImportError:
+    blessings = None
+
+import json
+import logging
+import sys
+import time
+
+
+class ConvertToStructuredFilter(logging.Filter):
+    """Filter that converts unstructured records into structured ones."""
+    def filter(self, record):
+        if hasattr(record, 'action') and hasattr(record, 'params'):
+            return True
+
+        record.action = 'unstructured'
+        record.params = {'msg': record.msg}
+        record.msg = '{msg}'
+
+        return True
+
+
+class StructuredJSONFormatter(logging.Formatter):
+    """Log formatter that writes a structured JSON entry."""
+
+    def format(self, record):
+        action = getattr(record, 'action', 'UNKNOWN')
+        params = getattr(record, 'params', {})
+
+        return json.dumps([record.created, action, params])
+
+
+class StructuredHumanFormatter(logging.Formatter):
+    """Log formatter that writes structured messages for humans.
+
+    It is important that this formatter never be added to a logger that
+    produces unstructured/classic log messages. If it is, the call to format()
+    could fail because the string could contain things (like JSON) that look
+    like formatting character sequences.
+
+    Because of this limitation, format() will fail with a KeyError if an
+    unstructured record is passed or if the structured message is malformed.
+    """
+    def __init__(self, start_time, write_interval=False):
+        self.start_time = start_time
+        self.write_interval = write_interval
+        self.last_time = None
+
+    def format(self, record):
+        elapsed = self._time(record)
+
+        return u'%4.2f %s' % (elapsed, record.msg.format(**record.params))
+
+    def _time(self, record):
+        t = record.created - self.start_time
+
+        if self.write_interval and self.last_time is not None:
+            t = record.created - self.last_time
+
+        self.last_time = record.created
+
+        return t
+
+
+class StructuredTerminalFormatter(StructuredHumanFormatter):
+    """Log formatter for structured messages writing to a terminal."""
+
+    def set_terminal(self, terminal):
+        self.terminal = terminal
+
+    def format(self, record):
+        t = self.terminal.blue('%4.2f' % self._time(record))
+        f = record.msg.format(**record.params)
+
+        return u'%s %s' % (t, self._colorize(f))
+
+    def _colorize(self, s):
+        if not self.terminal:
+            return s
+
+        result = s
+
+        if s.startswith('TEST-PASS'):
+            result = self.terminal.green(s[0:9]) + s[9:]
+        elif s.startswith('TEST-UNEXPECTED'):
+            result = self.terminal.red(s[0:20]) + s[21:]
+
+        return result.decode('UTF-8', 'ignore')
+
+
+class LoggingManager(object):
+    """Holds and controls global logging state.
+
+    A mozbuild application should instantiate one of these and configure it
+    as needed.
+
+    This class provides a mechanism to configure the output of logging data
+    both from mozbuild and from the overall logging system (e.g. from other
+    modules).
+    """
+
+    def __init__(self):
+        self.start_time = time.time()
+
+        self.json_handlers = []
+        self.terminal_handler = None
+        self.terminal_formatter = None
+
+        self.root_logger = logging.getLogger()
+        self.root_logger.setLevel(logging.DEBUG)
+
+        self.mozbuild_logger = logging.getLogger('mozbuild')
+        self.mozbuild_logger.setLevel(logging.DEBUG)
+
+        self.structured_filter = ConvertToStructuredFilter()
+
+        self._terminal = None
+
+    @property
+    def terminal(self):
+        if not self._terminal and blessings:
+            terminal = blessings.Terminal(stream=sys.stdout)
+
+            if terminal.is_a_tty:
+                self._terminal = terminal
+
+        return self._terminal
+
+    def add_json_handler(self, fh):
+        """Enable JSON logging on the specified file object."""
+
+        # Configure the consumer of structured messages.
+        handler = logging.StreamHandler(stream=fh)
+        handler.setFormatter(StructuredJSONFormatter())
+        handler.setLevel(logging.DEBUG)
+
+        # And hook it up.
+        self.mozbuild_logger.addHandler(handler)
+
+        self.json_handlers.append(handler)
+
+    def add_terminal_logging(self, fh=sys.stdout, level=logging.INFO,
+            write_interval=False):
+        """Enable logging to the terminal."""
+
+        formatter = StructuredHumanFormatter(self.start_time,
+            write_interval=write_interval)
+
+        if self.terminal:
+            formatter = StructuredTerminalFormatter(self.start_time,
+                write_interval=write_interval)
+            formatter.set_terminal(self.terminal)
+
+        handler = logging.StreamHandler(stream=fh)
+        handler.setFormatter(formatter)
+        handler.setLevel(level)
+
+        self.mozbuild_logger.addHandler(handler)
+
+        self.terminal_handler = handler
+        self.terminal_formatter = formatter
+
+    def replace_terminal_handler(self, handler):
+        """Replace the installed terminal handler.
+
+        Returns the old handler or None if none was configured.
+        If the new handler is None, removes any existing handler and disables
+        logging to the terminal.
+        """
+        old = self.terminal_handler
+
+        if old:
+            self.mozbuild_logger.removeHandler(old)
+
+        if handler:
+            self.mozbuild_logger.addHandler(handler)
+
+        self.terminal_handler = handler
+
+        return old
+
+    def enable_unstructured(self):
+        """Enable logging of unstructured messages."""
+        if self.terminal_handler:
+            self.terminal_handler.addFilter(self.structured_filter)
+            self.root_logger.addHandler(self.terminal_handler)
+
+    def disable_unstructured(self):
+        """Disable logging of unstructured messages."""
+        if self.terminal_handler:
+            self.terminal_handler.removeFilter(self.structured_filter)
+            self.root_logger.removeHandler(self.terminal_handler)

python/mozbuild/setup.py

@@ -0,0 +1,15 @@
+# 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 setuptools import setup
+
+VERSION = '0.1'
+
+setup(
+    name='mozbuild',
+    description='Mozilla build system functionality.',
+    license='MPL 2.0',
+    packages=['mozbuild'],
+    version=VERSION
+)