Skip to content

C
cpython
Commit 49615395 authored by Vinay Sajip's avatar Vinay Sajip
Browse files
Options

Updated information on logging contextual information.

parent 912443c8
Show whitespace changes
Inline Side-by-side
Showing with 283 additions and 20 deletions
Doc/library/logging.rst
View file @ 49615395
......@@ -246,16 +246,16 @@ With the logger object configured, the following methods create log messages:
methods listed above, but this is how to log at custom log levels.
:func:`getLogger` returns a reference to a logger instance with the specified
if it it is provided, or ``root`` if not. The names are period-separated
name if it is provided, or ``root`` if not. The names are period-separated
hierarchical structures. Multiple calls to :func:`getLogger` with the same name
will return a reference to the same logger object. Loggers that are further
down in the hierarchical list are children of loggers higher up in the list.
For example, given a logger with a name of ``foo``, loggers with names of
``foo.bar``, ``foo.bar.baz``, and ``foo.bam`` are all children of ``foo``.
Child loggers propagate messages up to their parent loggers. Because of this,
it is unnecessary to define and configure all the loggers an application uses.
It is sufficient to configure a top-level logger and create child loggers as
needed.
``foo.bar``, ``foo.bar.baz``, and ``foo.bam`` are all descendants of ``foo``.
Child loggers propagate messages up to the handlers associated with their
ancestor loggers. Because of this, it is unnecessary to define and configure
handlers for all the loggers an application uses. It is sufficient to
configure handlers for a top-level logger and create child loggers as needed.
Handlers
......@@ -283,15 +283,16 @@ custom handlers) are the following configuration methods:
are there two :func:`setLevel` methods? The level set in the logger
determines which severity of messages it will pass to its handlers. The level
set in each handler determines which messages that handler will send on.
:func:`setFormatter` selects a Formatter object for this handler to use.
* :func:`setFormatter` selects a Formatter object for this handler to use.
* :func:`addFilter` and :func:`removeFilter` respectively configure and
deconfigure filter objects on handlers.
Application code should not directly instantiate and use handlers. Instead, the
:class:`Handler` class is a base class that defines the interface that all
Handlers should have and establishes some default behavior that child classes
can use (or override).
Application code should not directly instantiate and use instances of
:class:`Handler`. Instead, the :class:`Handler` class is a base class that
defines the interface that all handlers should have and establishes some
default behavior that child classes can use (or override).
Formatters
......@@ -318,6 +319,14 @@ order::
"%(asctime)s - %(levelname)s - %(message)s"
Formatters use a user-configurable function to convert the creation time of a
record to a tuple. By default, :func:`time.localtime` is used; to change this
for a particular formatter instance, set the ``converter`` attribute of the
instance to a function with the same signature as :func:`time.localtime` or
:func:`time.gmtime`. To change it for all formatters, for example if you want
all logging times to be shown in GMT, set the ``converter`` attribute in the
Formatter class (to ``time.gmtime`` for GMT display).
Configuring Logging
^^^^^^^^^^^^^^^^^^^
......@@ -464,9 +473,8 @@ libraries, then the logger name specified can be "orgname.foo" rather than
just "foo".
.. versionadded:: 3.1
The :class:`NullHandler` class was not present in previous versions, but is now
included, so that it need not be defined in library code.
The :class:`NullHandler` class was not present in previous versions, but is
now included, so that it need not be defined in library code.
......@@ -516,7 +524,9 @@ support desk staff, system administrators, developers). Handlers are passed
can have zero, one or more handlers associated with it (via the
:meth:`addHandler` method of :class:`Logger`). In addition to any handlers
directly associated with a logger, *all handlers associated with all ancestors
of the logger* are called to dispatch the message.
of the logger* are called to dispatch the message (unless the *propagate* flag
for a logger is set to a false value, at which point the passing to ancestor
handlers stops).
Just as for loggers, handlers can have levels associated with them. A handler's
level acts as a filter in the same way as a logger's level does. If a handler
......@@ -729,7 +739,11 @@ functions.
Provides an overriding level *lvl* for all loggers which takes precedence over
the logger's own level. When the need arises to temporarily throttle logging
output down across the whole application, this function can be useful.
output down across the whole application, this function can be useful. Its
effect is to disable all logging calls of severity *lvl* and below, so that
if you call it with a value of INFO, then all INFO and DEBUG events would be
discarded, whereas those of severity WARNING and above would be processed
according to the logger's effective level.
.. function:: addLevelName(lvl, levelName)
......@@ -765,11 +779,13 @@ functions.
Does basic configuration for the logging system by creating a
:class:`StreamHandler` with a default :class:`Formatter` and adding it to the
root logger. The function does nothing if any handlers have been defined for
the root logger. The functions :func:`debug`, :func:`info`, :func:`warning`,
root logger. The functions :func:`debug`, :func:`info`, :func:`warning`,
:func:`error` and :func:`critical` will call :func:`basicConfig` automatically
if no handlers are defined for the root logger.
This function does nothing if the root logger already has handlers
configured for it.
The following keyword arguments are supported.
+--------------+---------------------------------------------+
......@@ -838,8 +854,8 @@ instantiated directly, but always through the module-level function
.. attribute:: Logger.propagate
If this evaluates to false, logging messages are not passed by this logger or by
child loggers to higher level (ancestor) loggers. The constructor sets this
attribute to 1.
its child loggers to the handlers of higher level (ancestor) loggers. The
constructor sets this attribute to 1.
.. method:: Logger.setLevel(lvl)
......@@ -1195,6 +1211,28 @@ are sent to both destinations.
This example uses console and file handlers, but you can use any number and
combination of handlers you choose.
.. _logging-exceptions:
Exceptions raised during logging
--------------------------------
The logging package is designed to swallow exceptions which occur while logging
in production. This is so that errors which occur while handling logging events
- such as logging misconfiguration, network or other similar errors - do not
cause the application using logging to terminate prematurely.
:class:`SystemExit` and :class:`KeyboardInterrupt` exceptions are never
swallowed. Other exceptions which occur during the :meth:`emit` method of a
:class:`Handler` subclass are passed to its :meth:`handleError` method.
The default implementation of :meth:`handleError` in :class:`Handler` checks
to see if a module-level variable, :data:`raiseExceptions`, is set. If set, a
traceback is printed to :data:`sys.stderr`. If not set, the exception is swallowed.
**Note:** The default value of :data:`raiseExceptions` is ``True``. This is because
during development, you typically want to be notified of any exceptions that
occur. It's advised that you set :data:`raiseExceptions` to ``False`` for production
usage.
.. _context-info:
......@@ -1214,6 +1252,10 @@ 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.
Using LoggerAdapters to impart contextual information
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
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
......@@ -1318,6 +1360,104 @@ When this script is run, the output should look something like this::
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
Using Filters to impart contextual information
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
You can also add contextual information to log output using a user-defined
:class:`Filter`. ``Filter`` instances are allowed to modify the ``LogRecords``
passed to them, including adding additional attributes which can then be output
using a suitable format string, or if needed a custom :class:`Formatter`.
For example in a web application, the request being processed (or at least,
the interesting parts of it) can be stored in a threadlocal
(:class:`threading.local`) variable, and then accessed from a ``Filter`` to
add, say, information from the request - say, the remote IP address and remote
user's username - to the ``LogRecord``, using the attribute names 'ip' and
'user' as in the ``LoggerAdapter`` example above. In that case, the same format
string can be used to get similar output to that shown above. Here's an example
script::
import logging
from random import choice
class ContextFilter(logging.Filter):
"""
This is a filter which injects contextual information into the log.
Rather than use actual contextual information, we just use random
data in this demo.
"""
USERS = ['jim', 'fred', 'sheila']
IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']
def filter(self, record):
record.ip = choice(ContextFilter.IPS)
record.user = choice(ContextFilter.USERS)
return True
if __name__ == "__main__":
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 = logging.getLogger("a.b.c")
a2 = logging.getLogger("d.e.f")
f = ContextFilter()
a1.addFilter(f)
a2.addFilter(f)
a1.debug("A debug message")
a1.info("An info message with %s", "some parameters")
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")
which, when run, produces something like::
2010-09-06 22:38:15,292 a.b.c DEBUG IP: 123.231.231.123 User: fred A debug message
2010-09-06 22:38:15,300 a.b.c INFO IP: 192.168.0.1 User: sheila An info message with some parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR IP: 127.0.0.1 User: jim A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG IP: 127.0.0.1 User: sheila A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR IP: 123.231.231.123 User: fred A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1 User: jim A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG IP: 192.168.0.1 User: jim A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f ERROR IP: 127.0.0.1 User: sheila A message at ERROR level with 2 parameters
2010-09-06 22:38:15,301 d.e.f DEBUG IP: 123.231.231.123 User: fred A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f INFO IP: 123.231.231.123 User: fred A message at INFO level with 2 parameters
.. _multiple-processes:
Logging to a single file from multiple processes
------------------------------------------------
Although logging is thread-safe, and logging to a single file from multiple
threads in a single process *is* supported, logging to a single file from
*multiple processes* is *not* supported, because there is no standard way to
serialize access to a single file across multiple processes in Python. If you
need to log to a single file from multiple processes, the best way of doing
this is to have all the processes log to a :class:`SocketHandler`, and have a
separate process which implements a socket server which reads from the socket
and logs to file. (If you prefer, you can dedicate one thread in one of the
existing processes to perform this function.) The following section documents
this approach in more detail and includes a working socket receiver which can
be used as a starting point for you to adapt in your own applications.
If you are using a recent version of Python which includes the
:mod:`multiprocessing` module, you can write your own handler which uses the
:class:`Lock` class from this module to serialize access to the file from
your processes. The existing :class:`FileHandler` and subclasses do not make
use of :mod:`multiprocessing` at present, though they may do so in the future.
Note that at present, the :mod:`multiprocessing` module does not provide
working lock functionality on all platforms (see
http://bugs.python.org/issue3770).
.. _network-logging:
......@@ -1449,6 +1589,11 @@ printed on the console; on the server side, you should see something like::
69 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.
69 myapp.area2 ERROR The five boxing wizards jump quickly.
Note that there are some security issues with pickle in some scenarios. If
these affect you, you can use an alternative serialization scheme by overriding
the :meth:`makePickle` method and implementing your alternative there, as
well as adapting the above script to use your alternative serialization.
Using arbitrary objects as messages
-----------------------------------
......@@ -1604,6 +1749,8 @@ subclasses. However, the :meth:`__init__` method in subclasses needs to call
:exc:`NotImplementedError`.
.. _stream-handler:
StreamHandler
^^^^^^^^^^^^^
......@@ -1637,6 +1784,8 @@ and :meth:`flush` methods).
no output, so an explicit :meth:`flush` call may be needed at times.
.. _file-handler:
FileHandler
^^^^^^^^^^^
......@@ -1663,6 +1812,7 @@ sends logging output to a disk file. It inherits the output functionality from
Outputs the record to the file.
.. _null-handler:
NullHandler
^^^^^^^^^^^
......@@ -1686,6 +1836,8 @@ for use by library developers.
See :ref:`library-config` for more information on how to use
:class:`NullHandler`.
.. _watched-file-handler:
WatchedFileHandler
^^^^^^^^^^^^^^^^^^
......@@ -1724,6 +1876,7 @@ this value.
changed. If it has, the existing stream is flushed and closed and the
file opened again, before outputting the record to the file.
.. _rotating-file-handler:
RotatingFileHandler
^^^^^^^^^^^^^^^^^^^
......@@ -1764,6 +1917,7 @@ module, supports rotation of disk log files.
Outputs the record to the file, catering for rollover as described
previously.
.. _timed-rotating-file-handler:
TimedRotatingFileHandler
^^^^^^^^^^^^^^^^^^^^^^^^
......@@ -1811,6 +1965,9 @@ timed intervals.
one is deleted. The deletion logic uses the interval to determine which
files to delete, so changing the interval may leave old files lying around.
If *delay* is true, then file opening is deferred until the first call to
:meth:`emit`.
.. method:: doRollover()
......@@ -1822,6 +1979,8 @@ timed intervals.
Outputs the record to the file, catering for rollover as described above.
.. _socket-handler:
SocketHandler
^^^^^^^^^^^^^
......@@ -1868,6 +2027,11 @@ sends logging output to a network socket. The base class uses a TCP socket.
Pickles the record's attribute dictionary in binary format with a length
prefix, and returns it ready for transmission across the socket.
Note that pickles aren't completely secure. If you are concerned about
security, you may want to override this method to implement a more secure
mechanism. For example, you can sign pickles using HMAC and then verify
them on the receiving end, or alternatively you can disable unpickling of
global objects on the receiving end.
.. method:: send(packet)
......@@ -1875,6 +2039,8 @@ sends logging output to a network socket. The base class uses a TCP socket.
partial sends which can happen when the network is busy.
.. _datagram-handler:
DatagramHandler
^^^^^^^^^^^^^^^
......@@ -1908,6 +2074,8 @@ over UDP sockets.
Send a pickled string to a socket.
.. _syslog-handler:
SysLogHandler
^^^^^^^^^^^^^
......@@ -1944,6 +2112,87 @@ supports sending logging messages to a remote or local Unix syslog.
or integers - if strings are passed, internal mapping dictionaries are
used to convert them to integers.
The symbolic ``LOG_`` values are defined in :class:`SysLogHandler` and
mirror the values defined in the ``sys/syslog.h`` header file.
**Priorities**
+--------------------------+---------------+
| Name (string) | Symbolic value|
+==========================+===============+
| ``alert`` | LOG_ALERT |
+--------------------------+---------------+
| ``crit`` or ``critical`` | LOG_CRIT |
+--------------------------+---------------+
| ``debug`` | LOG_DEBUG |
+--------------------------+---------------+
| ``emerg`` or ``panic`` | LOG_EMERG |
+--------------------------+---------------+
| ``err`` or ``error`` | LOG_ERR |
+--------------------------+---------------+
| ``info`` | LOG_INFO |
+--------------------------+---------------+
| ``notice`` | LOG_NOTICE |
+--------------------------+---------------+
| ``warn`` or ``warning`` | LOG_WARNING |
+--------------------------+---------------+
**Facilities**
+---------------+---------------+
| Name (string) | Symbolic value|
+===============+===============+
| ``auth`` | LOG_AUTH |
+---------------+---------------+
| ``authpriv`` | LOG_AUTHPRIV |
+---------------+---------------+
| ``cron`` | LOG_CRON |
+---------------+---------------+
| ``daemon`` | LOG_DAEMON |
+---------------+---------------+
| ``ftp`` | LOG_FTP |
+---------------+---------------+
| ``kern`` | LOG_KERN |
+---------------+---------------+
| ``lpr`` | LOG_LPR |
+---------------+---------------+
| ``mail`` | LOG_MAIL |
+---------------+---------------+
| ``news`` | LOG_NEWS |
+---------------+---------------+
| ``syslog`` | LOG_SYSLOG |
+---------------+---------------+
| ``user`` | LOG_USER |
+---------------+---------------+
| ``uucp`` | LOG_UUCP |
+---------------+---------------+
| ``local0`` | LOG_LOCAL0 |
+---------------+---------------+
| ``local1`` | LOG_LOCAL1 |
+---------------+---------------+
| ``local2`` | LOG_LOCAL2 |
+---------------+---------------+
| ``local3`` | LOG_LOCAL3 |
+---------------+---------------+
| ``local4`` | LOG_LOCAL4 |
+---------------+---------------+
| ``local5`` | LOG_LOCAL5 |
+---------------+---------------+
| ``local6`` | LOG_LOCAL6 |
+---------------+---------------+
| ``local7`` | LOG_LOCAL7 |
+---------------+---------------+
.. method:: mapPriority(levelname)
Maps a logging level name to a syslog priority name.
You may need to override this if you are using custom levels, or
if the default algorithm is not suitable for your needs. The
default algorithm maps ``DEBUG``, ``INFO``, ``WARNING``, ``ERROR`` and
``CRITICAL`` to the equivalent syslog names, and all other level
names to "warning".
.. _nt-eventlog-handler:
NTEventLogHandler
^^^^^^^^^^^^^^^^^
......@@ -2010,6 +2259,7 @@ extensions for Python installed.
lookup to get the message ID. This version returns 1, which is the base
message ID in :file:`win32service.pyd`.
.. _smtp-handler:
SMTPHandler
^^^^^^^^^^^
......@@ -2038,6 +2288,7 @@ supports sending logging messages to an email address via SMTP.
If you want to specify a subject line which is record-dependent, override
this method.
.. _memory-handler:
MemoryHandler
^^^^^^^^^^^^^
......@@ -2108,6 +2359,8 @@ should, then :meth:`flush` is expected to do the needful.
Checks for buffer full or a record at the *flushLevel* or higher.
.. _http-handler:
HTTPHandler
^^^^^^^^^^^
......@@ -2250,6 +2503,7 @@ Currently, the useful mapping keys in a :class:`LogRecord` are:
just uses :func:`traceback.print_exception`. The resulting string is
returned.
.. _filter:
Filter Objects
--------------
......@@ -2275,6 +2529,14 @@ initialized with the empty string, all events are passed.
yes. If deemed appropriate, the record may be modified in-place by this
method.
Note that filters attached to handlers are consulted whenever an event is
emitted by the handler, whereas filters attached to loggers are consulted
whenever an event is logged to the handler (using :meth:`debug`, :meth:`info`,
etc.) This means that events which have been generated by descendant loggers
will not be filtered by a logger's filter setting, unless the filter has also
been applied to those descendant loggers.
.. _log-record:
LogRecord Objects
-----------------
......@@ -2306,6 +2568,7 @@ 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.
.. _logger-adapter:
LoggerAdapter Objects
---------------------
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7