1 files changed, 100 insertions, 0 deletions
diff --git a/python/mach/docs/logging.rst b/python/mach/docs/logging.rst
new file mode 100644
index 000000000..ff245cf03
--- /dev/null
+++ b/python/mach/docs/logging.rst
@@ -0,0 +1,100 @@
+.. _mach_logging:
+
+=======
+Logging
+=======
+
+Mach configures a built-in logging facility so commands can easily log
+data.
+
+What sets the logging facility apart from most loggers you've seen is
+that it encourages 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:
+
+.. code-block:: python
+
+   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. The easiest way to do this is by utilizing the
+LoggingMixin:
+
+.. code-block:: python
+
+   import logging
+   from mach.mixin.logging import LoggingMixin
+
+   class MyClass(LoggingMixin):
+       def foo(self):
+            self.log(logging.INFO, 'foo_start', {'bar': True},
+                'Foo performed. Bar: {bar}')