mirror of
https://github.com/python/cpython
synced 2024-09-05 00:05:39 +00:00
gh-98731: Improvements to the logging documentation (GH-101618)
Co-authored-by: Vinay Sajip <vinay_sajip@yahoo.co.uk>
This commit is contained in:
parent
8e2aab7ad5
commit
7f418fb111
|
@ -25,10 +25,12 @@ or *severity*.
|
|||
When to use logging
|
||||
^^^^^^^^^^^^^^^^^^^
|
||||
|
||||
Logging provides a set of convenience functions for simple logging usage. These
|
||||
are :func:`debug`, :func:`info`, :func:`warning`, :func:`error` and
|
||||
:func:`critical`. To determine when to use logging, see the table below, which
|
||||
states, for each of a set of common tasks, the best tool to use for it.
|
||||
You can access logging functionality by creating a logger via ``logger =
|
||||
getLogger(__name__)``, and then calling the logger's :meth:`~Logger.debug`,
|
||||
:meth:`~Logger.info`, :meth:`~Logger.warning`, :meth:`~Logger.error` and
|
||||
:meth:`~Logger.critical` methods. To determine when to use logging, and to see
|
||||
which logger methods to use when, see the table below. It states, for each of a
|
||||
set of common tasks, the best tool to use for that task.
|
||||
|
||||
+-------------------------------------+--------------------------------------+
|
||||
| Task you want to perform | The best tool for the task |
|
||||
|
@ -37,8 +39,8 @@ states, for each of a set of common tasks, the best tool to use for it.
|
|||
| usage of a command line script or | |
|
||||
| program | |
|
||||
+-------------------------------------+--------------------------------------+
|
||||
| Report events that occur during | :func:`logging.info` (or |
|
||||
| normal operation of a program (e.g. | :func:`logging.debug` for very |
|
||||
| Report events that occur during | A logger's :meth:`~Logger.info` (or |
|
||||
| normal operation of a program (e.g. | :meth:`~Logger.debug` method for very|
|
||||
| for status monitoring or fault | detailed output for diagnostic |
|
||||
| investigation) | purposes) |
|
||||
+-------------------------------------+--------------------------------------+
|
||||
|
@ -47,22 +49,23 @@ states, for each of a set of common tasks, the best tool to use for it.
|
|||
| | the client application should be |
|
||||
| | modified to eliminate the warning |
|
||||
| | |
|
||||
| | :func:`logging.warning` if there is |
|
||||
| | nothing the client application can do|
|
||||
| | about the situation, but the event |
|
||||
| | should still be noted |
|
||||
| | A logger's :meth:`~Logger.warning` |
|
||||
| | method if there is nothing the client|
|
||||
| | application can do about the |
|
||||
| | situation, but the event should still|
|
||||
| | be noted |
|
||||
+-------------------------------------+--------------------------------------+
|
||||
| Report an error regarding a | Raise an exception |
|
||||
| particular runtime event | |
|
||||
+-------------------------------------+--------------------------------------+
|
||||
| Report suppression of an error | :func:`logging.error`, |
|
||||
| without raising an exception (e.g. | :func:`logging.exception` or |
|
||||
| error handler in a long-running | :func:`logging.critical` as |
|
||||
| Report suppression of an error | A logger's :meth:`~Logger.error`, |
|
||||
| without raising an exception (e.g. | :meth:`~Logger.exception` or |
|
||||
| error handler in a long-running | :meth:`~Logger.critical` method as |
|
||||
| server process) | appropriate for the specific error |
|
||||
| | and application domain |
|
||||
+-------------------------------------+--------------------------------------+
|
||||
|
||||
The logging functions are named after the level or severity of the events
|
||||
The logger methods are named after the level or severity of the events
|
||||
they are used to track. The standard levels and their applicability are
|
||||
described below (in increasing order of severity):
|
||||
|
||||
|
@ -115,12 +118,18 @@ If you type these lines into a script and run it, you'll see:
|
|||
WARNING:root:Watch out!
|
||||
|
||||
printed out on the console. The ``INFO`` message doesn't appear because the
|
||||
default level is ``WARNING``. The printed message includes the indication of
|
||||
the level and the description of the event provided in the logging call, i.e.
|
||||
'Watch out!'. Don't worry about the 'root' part for now: it will be explained
|
||||
later. The actual output can be formatted quite flexibly if you need that;
|
||||
formatting options will also be explained later.
|
||||
default level is ``WARNING``. The printed message includes the indication of the
|
||||
level and the description of the event provided in the logging call, i.e.
|
||||
'Watch out!'. The actual output can be formatted quite flexibly if you need
|
||||
that; formatting options will also be explained later.
|
||||
|
||||
Notice that in this example, we use functions directly on the ``logging``
|
||||
module, like ``logging.debug``, rather than creating a logger and calling
|
||||
functions on it. These functions operation on the root logger, but can be useful
|
||||
as they will call :func:`~logging.basicConfig` for you if it has not been called yet, like in
|
||||
this example. In larger programs you'll usually want to control the logging
|
||||
configuration explicitly however - so for that reason as well as others, it's
|
||||
better to create loggers and call their methods.
|
||||
|
||||
Logging to a file
|
||||
^^^^^^^^^^^^^^^^^
|
||||
|
@ -130,11 +139,12 @@ look at that next. Be sure to try the following in a newly started Python
|
|||
interpreter, and don't just continue from the session described above::
|
||||
|
||||
import logging
|
||||
logger = logging.getLogger(__name__)
|
||||
logging.basicConfig(filename='example.log', encoding='utf-8', level=logging.DEBUG)
|
||||
logging.debug('This message should go to the log file')
|
||||
logging.info('So should this')
|
||||
logging.warning('And this, too')
|
||||
logging.error('And non-ASCII stuff, too, like Øresund and Malmö')
|
||||
logger.debug('This message should go to the log file')
|
||||
logger.info('So should this')
|
||||
logger.warning('And this, too')
|
||||
logger.error('And non-ASCII stuff, too, like Øresund and Malmö')
|
||||
|
||||
.. versionchanged:: 3.9
|
||||
The *encoding* argument was added. In earlier Python versions, or if not
|
||||
|
@ -148,10 +158,10 @@ messages:
|
|||
|
||||
.. code-block:: none
|
||||
|
||||
DEBUG:root:This message should go to the log file
|
||||
INFO:root:So should this
|
||||
WARNING:root:And this, too
|
||||
ERROR:root:And non-ASCII stuff, too, like Øresund and Malmö
|
||||
DEBUG:__main__:This message should go to the log file
|
||||
INFO:__main__:So should this
|
||||
WARNING:__main__:And this, too
|
||||
ERROR:__main__:And non-ASCII stuff, too, like Øresund and Malmö
|
||||
|
||||
This example also shows how you can set the logging level which acts as the
|
||||
threshold for tracking. In this case, because we set the threshold to
|
||||
|
@ -180,11 +190,9 @@ following example::
|
|||
raise ValueError('Invalid log level: %s' % loglevel)
|
||||
logging.basicConfig(level=numeric_level, ...)
|
||||
|
||||
The call to :func:`basicConfig` should come *before* any calls to
|
||||
:func:`debug`, :func:`info`, etc. Otherwise, those functions will call
|
||||
:func:`basicConfig` for you with the default options. As it's intended as a
|
||||
one-off simple configuration facility, only the first call will actually do
|
||||
anything: subsequent calls are effectively no-ops.
|
||||
The call to :func:`basicConfig` should come *before* any calls to a logger's
|
||||
methods such as :meth:`~Logger.debug`, :meth:`~Logger.info`, etc. Otherwise,
|
||||
that logging event may not be handled in the desired manner.
|
||||
|
||||
If you run the above script several times, the messages from successive runs
|
||||
are appended to the file *example.log*. If you want each run to start afresh,
|
||||
|
@ -197,50 +205,6 @@ The output will be the same as before, but the log file is no longer appended
|
|||
to, so the messages from earlier runs are lost.
|
||||
|
||||
|
||||
Logging from multiple modules
|
||||
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
|
||||
|
||||
If your program consists of multiple modules, here's an example of how you
|
||||
could organize logging in it::
|
||||
|
||||
# myapp.py
|
||||
import logging
|
||||
import mylib
|
||||
|
||||
def main():
|
||||
logging.basicConfig(filename='myapp.log', level=logging.INFO)
|
||||
logging.info('Started')
|
||||
mylib.do_something()
|
||||
logging.info('Finished')
|
||||
|
||||
if __name__ == '__main__':
|
||||
main()
|
||||
|
||||
::
|
||||
|
||||
# mylib.py
|
||||
import logging
|
||||
|
||||
def do_something():
|
||||
logging.info('Doing something')
|
||||
|
||||
If you run *myapp.py*, you should see this in *myapp.log*:
|
||||
|
||||
.. code-block:: none
|
||||
|
||||
INFO:root:Started
|
||||
INFO:root:Doing something
|
||||
INFO:root:Finished
|
||||
|
||||
which is hopefully what you were expecting to see. You can generalize this to
|
||||
multiple modules, using the pattern in *mylib.py*. Note that for this simple
|
||||
usage pattern, you won't know, by looking in the log file, *where* in your
|
||||
application your messages came from, apart from looking at the event
|
||||
description. If you want to track the location of your messages, you'll need
|
||||
to refer to the documentation beyond the tutorial level -- see
|
||||
:ref:`logging-advanced-tutorial`.
|
||||
|
||||
|
||||
Logging variable data
|
||||
^^^^^^^^^^^^^^^^^^^^^
|
||||
|
||||
|
|
|
@ -30,13 +30,53 @@ is that all Python modules can participate in logging, so your application log
|
|||
can include your own messages integrated with messages from third-party
|
||||
modules.
|
||||
|
||||
The simplest example:
|
||||
Here's a simple example of idiomatic usage: ::
|
||||
|
||||
# myapp.py
|
||||
import logging
|
||||
import mylib
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
def main():
|
||||
logging.basicConfig(filename='myapp.log', level=logging.INFO)
|
||||
logger.info('Started')
|
||||
mylib.do_something()
|
||||
logger.info('Finished')
|
||||
|
||||
if __name__ == '__main__':
|
||||
main()
|
||||
|
||||
::
|
||||
|
||||
# mylib.py
|
||||
import logging
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
def do_something():
|
||||
logger.info('Doing something')
|
||||
|
||||
If you run *myapp.py*, you should see this in *myapp.log*:
|
||||
|
||||
.. code-block:: none
|
||||
|
||||
>>> import logging
|
||||
>>> logging.warning('Watch out!')
|
||||
WARNING:root:Watch out!
|
||||
INFO:__main__:Started
|
||||
INFO:mylib:Doing something
|
||||
INFO:__main__:Finished
|
||||
|
||||
The key features of this idiomatic usage is that the majority of code is simply
|
||||
creating a module level logger with ``getLogger(__name__)``, and using that
|
||||
logger to do any needed logging. This is concise while allowing downstream code
|
||||
fine grained control if needed. Logged messages to the module-level logger get
|
||||
forwarded up to handlers of loggers in higher-level modules, all the way up to
|
||||
the root logger; for this reason this approach is known as hierarchical logging.
|
||||
|
||||
For logging to be useful, it needs to be configured: setting the levels and
|
||||
destinations for each logger, potentially changing how specific modules log,
|
||||
often based on command-line arguments or application configuration. In most
|
||||
cases, like the one above, only the root logger needs to be so configured, since
|
||||
all the lower level loggers at module level eventually forward their messages to
|
||||
its handlers. :func:`~logging.basicConfig` provides a quick way to configure
|
||||
the root logger that handles many use cases.
|
||||
|
||||
The module provides a lot of functionality and flexibility. If you are
|
||||
unfamiliar with logging, the best way to get to grips with it is to view the
|
||||
|
@ -1151,89 +1191,31 @@ functions.
|
|||
|
||||
.. function:: debug(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`DEBUG` on the root logger. The *msg* is the
|
||||
message format string, and the *args* are the arguments which are merged into
|
||||
*msg* using the string formatting operator. (Note that this means that you can
|
||||
use keywords in the format string, together with a single dictionary argument.)
|
||||
This is a convenience function that calls :meth:`Logger.debug`, on the root
|
||||
logger. The handling of the arguments is in every way identical
|
||||
to what is described in that method.
|
||||
|
||||
There are three keyword arguments in *kwargs* which are inspected: *exc_info*
|
||||
which, if it does not evaluate as false, causes exception information to be
|
||||
added to the logging message. If an exception tuple (in the format returned by
|
||||
:func:`sys.exc_info`) or an exception instance is provided, it is used;
|
||||
otherwise, :func:`sys.exc_info` is called to get the exception information.
|
||||
The only difference is that if the root logger has no handlers, then
|
||||
:func:`basicConfig` is called, prior to calling ``debug`` on the root logger.
|
||||
|
||||
The second optional keyword argument is *stack_info*, which defaults to
|
||||
``False``. If true, stack information is added to the logging
|
||||
message, including the actual logging call. Note that this is not the same
|
||||
stack information as that displayed through specifying *exc_info*: The
|
||||
former is stack frames from the bottom of the stack up to the logging call
|
||||
in the current thread, whereas the latter is information about stack frames
|
||||
which have been unwound, following an exception, while searching for
|
||||
exception handlers.
|
||||
For very short scripts or quick demonstrations of ``logging`` facilities,
|
||||
``debug`` and the other module-level functions may be convenient. However,
|
||||
most programs will want to carefully and explicitly control the logging
|
||||
configuration, and should therefore prefer creating a module-level logger and
|
||||
calling :meth:`Logger.debug` (or other level-specific methods) on it, as
|
||||
described at the beginnning of this documentation.
|
||||
|
||||
You can specify *stack_info* independently of *exc_info*, e.g. to just show
|
||||
how you got to a certain point in your code, even when no exceptions were
|
||||
raised. The stack frames are printed following a header line which says:
|
||||
|
||||
.. code-block:: none
|
||||
|
||||
Stack (most recent call last):
|
||||
|
||||
This mimics the ``Traceback (most recent call last):`` which is used when
|
||||
displaying exception frames.
|
||||
|
||||
The third optional keyword argument is *extra* which can be used to pass a
|
||||
dictionary which is used to populate the __dict__ of the LogRecord created for
|
||||
the logging event with user-defined attributes. These custom attributes can then
|
||||
be used as you like. For example, they could be incorporated into logged
|
||||
messages. For example::
|
||||
|
||||
FORMAT = '%(asctime)s %(clientip)-15s %(user)-8s %(message)s'
|
||||
logging.basicConfig(format=FORMAT)
|
||||
d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
|
||||
logging.warning('Protocol problem: %s', 'connection reset', extra=d)
|
||||
|
||||
would print something like:
|
||||
|
||||
.. code-block:: none
|
||||
|
||||
2006-02-08 22:20:02,165 192.168.0.1 fbloggs Protocol problem: connection reset
|
||||
|
||||
The keys in the dictionary passed in *extra* should not clash with the keys used
|
||||
by the logging system. (See the :class:`Formatter` documentation for more
|
||||
information on which keys are used by the logging system.)
|
||||
|
||||
If you choose to use these attributes in logged messages, you need to exercise
|
||||
some care. In the above example, for instance, the :class:`Formatter` has been
|
||||
set up with a format string which expects 'clientip' and 'user' in the attribute
|
||||
dictionary of the LogRecord. If these are missing, the message will not be
|
||||
logged because a string formatting exception will occur. So in this case, you
|
||||
always need to pass the *extra* dictionary with these keys.
|
||||
|
||||
While this might be annoying, this feature is intended for use in specialized
|
||||
circumstances, such as multi-threaded servers where the same code executes in
|
||||
many contexts, and interesting conditions which arise are dependent on this
|
||||
context (such as remote client IP address and authenticated user name, in the
|
||||
above example). In such circumstances, it is likely that specialized
|
||||
:class:`Formatter`\ s would be used with particular :class:`Handler`\ s.
|
||||
|
||||
This function (as well as :func:`info`, :func:`warning`, :func:`error` and
|
||||
:func:`critical`) will call :func:`basicConfig` if the root logger doesn't
|
||||
have any handler attached.
|
||||
|
||||
.. versionchanged:: 3.2
|
||||
The *stack_info* parameter was added.
|
||||
|
||||
.. function:: info(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`INFO` on the root logger. The arguments are
|
||||
interpreted as for :func:`debug`.
|
||||
Logs a message with level :const:`INFO` on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`.
|
||||
|
||||
|
||||
.. function:: warning(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`WARNING` on the root logger. The arguments
|
||||
are interpreted as for :func:`debug`.
|
||||
Logs a message with level :const:`WARNING` on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`.
|
||||
|
||||
.. note:: There is an obsolete function ``warn`` which is functionally
|
||||
identical to ``warning``. As ``warn`` is deprecated, please do not use
|
||||
|
@ -1246,26 +1228,26 @@ functions.
|
|||
|
||||
.. function:: error(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`ERROR` on the root logger. The arguments are
|
||||
interpreted as for :func:`debug`.
|
||||
Logs a message with level :const:`ERROR` on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`.
|
||||
|
||||
|
||||
.. function:: critical(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`CRITICAL` on the root logger. The arguments
|
||||
are interpreted as for :func:`debug`.
|
||||
Logs a message with level :const:`CRITICAL` on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`.
|
||||
|
||||
|
||||
.. function:: exception(msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level :const:`ERROR` on the root logger. The arguments are
|
||||
interpreted as for :func:`debug`. Exception info is added to the logging
|
||||
Logs a message with level :const:`ERROR` on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`. Exception info is added to the logging
|
||||
message. This function should only be called from an exception handler.
|
||||
|
||||
.. function:: log(level, msg, *args, **kwargs)
|
||||
|
||||
Logs a message with level *level* on the root logger. The other arguments are
|
||||
interpreted as for :func:`debug`.
|
||||
Logs a message with level *level* on the root logger. The arguments and behavior
|
||||
are otherwise the same as for :func:`debug`.
|
||||
|
||||
.. function:: disable(level=CRITICAL)
|
||||
|
||||
|
|
Loading…
Reference in a new issue