mirror of
https://github.com/mozilla/gecko-dev.git
synced 2025-11-04 02:09:05 +02:00
e6f5b57c9e
The main mach docs page is a bit long. Let's split it into multiple articles to increase readability going forward. --HG-- rename : python/mach/docs/index.rst => python/mach/docs/commands.rst rename : python/mach/docs/index.rst => python/mach/docs/driver.rst rename : python/mach/docs/index.rst => python/mach/docs/logging.rst extra : rebase_source : 484d60327568333fcb0069e1f3444dc6db4322c0 extra : histedit_source : 18d09ac2e2e93565661763b6567f7a46226735f5
100 lines
3.4 KiB
ReStructuredText
100 lines
3.4 KiB
ReStructuredText
.. _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}')
|