Added section on passing contextual information to logging and documentation for…

Added section on passing contextual information to logging and documentation for the LoggerAdapter class.

Doc/library/logging.rst

@@ -1155,33 +1155,113 @@ level of granularity you want to use in logging an application, it could
 be hard to manage if the number of :class:`Logger` instances becomes
 effectively unbounded.
 
-There are a number of other ways you can pass contextual information to be
-output along with logging event information.
-
-* Use an adapter class which has access to the contextual information and
-  which defines methods :meth:`debug`, :meth:`info` etc. with the same
-  signatures as used by :class:`Logger`. You instantiate the adapter with a
-  name, which will be used to create an underlying :class:`Logger` with that
-  name. In each adpater method, the passed-in message is modified to include
-  whatever contextual information you want.
-
-* Use something other than a string to pass the message. Although normally
-  the first argument to a logger method such as :meth:`debug`, :meth:`info`
-  etc. is usually a string, it can in fact be any object. This object is the
-  argument to a :func:`str()` call which is made, in
-  :meth:`LogRecord.getMessage`, to obtain the actual message string. You can
-  use this behavior to pass an instance which may be initialized with a
-  logging message, which redefines :meth:__str__ to return a modified version
-  of that message with the contextual information added.
-
-* Use a specialized :class:`Formatter` subclass to add additional information
-  to the formatted output. The subclass could, for instance, merge some thread
-  local contextual information (or contextual information obtained in some
-  other way) with the output generated by the base :class:`Formatter`.
-
-In each of these three approaches, thread locals can sometimes be a useful way
-of passing contextual information without undue coupling between different
-parts of your code.
+An easy way in which you can pass contextual information to be output along
+with logging event information is to use the :class:`LoggerAdapter` class.
+This class is designed to look like a :class:`Logger`, so that you can call
+:meth:`debug`, :meth:`info`, :meth:`warning`, :meth:`error`,
+:meth:`exception`, :meth:`critical` and :meth:`log`. These methods have the
+same signatures as their counterparts in :class:`Logger`, so you can use the
+two types of instances interchangeably.
+
+When you create an instance of :class:`LoggerAdapter`, you pass it a
+:class:`Logger` instance and a dict-like object which contains your contextual
+information. When you call one of the logging methods on an instance of
+:class:`LoggerAdapter`, it delegates the call to the underlying instance of
+:class:`Logger` passed to its constructor, and arranges to pass the contextual
+information in the delegated call. Here's a snippet from the code of
+:class:`LoggerAdapter`::
+
+    def debug(self, msg, *args, **kwargs):
+        """
+        Delegate a debug call to the underlying logger, after adding
+        contextual information from this adapter instance.
+        """
+        msg, kwargs = self.process(msg, kwargs)
+        self.logger.debug(msg, *args, **kwargs)
+
+The :meth:`process` method of :class:`LoggerAdapter` is where the contextual
+information is added to the logging output. It's passed the message and
+keyword arguments of the logging call, and it passes back (potentially)
+modified versions of these to use in the call to the underlying logger. The
+default implementation of this method leaves the message alone, but inserts
+an "extra" key in the keyword argument whose value is the dict-like object
+passed to the constructor. Of course, if you had passed an "extra" keyword
+argument in the call to the adapter, it will be silently overwritten.
+
+The advantage of using "extra" is that the values in the dict-like object are
+merged into the :class:`LogRecord` instance's __dict__, allowing you to use
+customized strings with your :class:`Formatter` instances which know about
+the keys of the dict-like object. If you need a different method, e.g. if you
+want to prepend or append the contextual information to the message string,
+you just need to subclass :class:`LoggerAdapter` and override :meth:`process`
+to do what you need. Here's an example script which uses this class, which
+also illustrates what dict-like behaviour is needed from an arbitrary
+"dict-like" object for use in the constructor::
+
+import logging
+
+class ConnInfo:
+    """
+    An example class which shows how an arbitrary class can be used as
+    the 'extra' context information repository passed to a LoggerAdapter.
+    """
+
+    def __getitem__(self, name):
+        """
+        To allow this instance to look like a dict.
+        """
+        from random import choice
+        if name == "ip":
+            result = choice(["127.0.0.1", "192.168.0.1"])
+        elif name == "user":
+            result = choice(["jim", "fred", "sheila"])
+        else:
+            result = self.__dict__.get(name, "?")
+        return result
+
+    def __iter__(self):
+        """
+        To allow iteration over keys, which will be merged into
+        the LogRecord dict before formatting and output.
+        """
+        keys = ["ip", "user"]
+        keys.extend(self.__dict__.keys())
+        return keys.__iter__()
+
+if __name__ == "__main__":
+    from random import choice
+    levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
+    a1 = logging.LoggerAdapter(logging.getLogger("a.b.c"),
+                               { "ip" : "123.231.231.123", "user" : "sheila" })
+    logging.basicConfig(level=logging.DEBUG,
+                        format="%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s")
+    a1.debug("A debug message")
+    a1.info("An info message with %s", "some parameters")
+    a2 = logging.LoggerAdapter(logging.getLogger("d.e.f"), ConnInfo())
+    for x in range(10):
+        lvl = choice(levels)
+        lvlname = logging.getLevelName(lvl)
+        a2.log(lvl, "A message at %s level with %d %s", lvlname, 2, "parameters")
+
+When this script is run, the output should look something like this::
+
+2008-01-18 14:49:54,023 a.b.c DEBUG    IP: 123.231.231.123 User: sheila   A debug message
+2008-01-18 14:49:54,023 a.b.c INFO     IP: 123.231.231.123 User: sheila   An info message with some parameters
+2008-01-18 14:49:54,023 d.e.f CRITICAL IP: 192.168.0.1     User: jim      A message at CRITICAL level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f INFO     IP: 192.168.0.1     User: jim      A message at INFO level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f WARNING  IP: 192.168.0.1     User: sheila   A message at WARNING level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f ERROR    IP: 127.0.0.1       User: fred     A message at ERROR level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f ERROR    IP: 127.0.0.1       User: sheila   A message at ERROR level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f WARNING  IP: 192.168.0.1     User: sheila   A message at WARNING level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f WARNING  IP: 192.168.0.1     User: jim      A message at WARNING level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f INFO     IP: 192.168.0.1     User: fred     A message at INFO level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f WARNING  IP: 192.168.0.1     User: sheila   A message at WARNING level with 2 parameters
+2008-01-18 14:49:54,033 d.e.f WARNING  IP: 127.0.0.1       User: jim      A message at WARNING level with 2 parameters
+
+.. versionadded:: 2.6
+
+The :class:`LoggerAdapter` class was not present in previous versions.
+
 
 .. _network-logging:
 
@@ -2077,6 +2157,33 @@ made, and any exception information to be logged.
    Returns the message for this :class:`LogRecord` instance after merging any
    user-supplied arguments with the message.
 
+LoggerAdapter Objects
+---------------------
+
+.. versionadded:: 2.6
+
+:class:`LoggerAdapter` instances are used to conveniently pass contextual
+information into logging calls. For a usage example , see context-info_.
+
+.. class:: LoggerAdapter(logger, extra)
+
+  Returns an instance of :class:`LoggerAdapter` initialized with an
+  underlying :class:`Logger` instance and a dict-like object.
+
+.. method:: LoggerAdapter.process(msg, kwargs)
+
+  Modifies the message and/or keyword arguments passed to a logging call in
+  order to insert contextual information. This implementation takes the
+  object passed as *extra* to the constructor and adds it to *kwargs* using
+  key 'extra'. The return value is a (*msg*, *kwargs*) tuple which has the
+  (possibly modified) versions of the arguments passed in.
+
+In addition to the above, :class:`LoggerAdapter` supports all the logging
+methods of :class:`Logger`, i.e. :meth:`debug`, :meth:`info`, :meth:`warning`,
+:meth:`error`, :meth:`exception`, :meth:`critical` and :meth:`log`. These
+methods have the same signatures as their counterparts in :class:`Logger`, so
+you can use the two types of instances interchangeably.
+
 
 Thread Safety
 -------------