1=============
2Logging HOWTO
3=============
4
5:Author: Vinay Sajip <vinay_sajip at red-dove dot com>
6
7.. _logging-basic-tutorial:
8
9.. currentmodule:: logging
10
11Basic Logging Tutorial
12----------------------
13
14Logging is a means of tracking events that happen when some software runs. The
15software's developer adds logging calls to their code to indicate that certain
16events have occurred. An event is described by a descriptive message which can
17optionally contain variable data (i.e. data that is potentially different for
18each occurrence of the event). Events also have an importance which the
19developer ascribes to the event; the importance can also be called the *level*
20or *severity*.
21
22When to use logging
23^^^^^^^^^^^^^^^^^^^
24
25Logging provides a set of convenience functions for simple logging usage. These
26are :func:`debug`, :func:`info`, :func:`warning`, :func:`error` and
27:func:`critical`. To determine when to use logging, see the table below, which
28states, for each of a set of common tasks, the best tool to use for it.
29
30+-------------------------------------+--------------------------------------+
31| Task you want to perform            | The best tool for the task           |
32+=====================================+======================================+
33| Display console output for ordinary | :func:`print`                        |
34| usage of a command line script or   |                                      |
35| program                             |                                      |
36+-------------------------------------+--------------------------------------+
37| Report events that occur during     | :func:`logging.info` (or             |
38| normal operation of a program (e.g. | :func:`logging.debug` for very       |
39| for status monitoring or fault      | detailed output for diagnostic       |
40| investigation)                      | purposes)                            |
41+-------------------------------------+--------------------------------------+
42| Issue a warning regarding a         | :func:`warnings.warn` in library     |
43| particular runtime event            | code if the issue is avoidable and   |
44|                                     | the client application should be     |
45|                                     | modified to eliminate the warning    |
46|                                     |                                      |
47|                                     | :func:`logging.warning` if there is  |
48|                                     | nothing the client application can do|
49|                                     | about the situation, but the event   |
50|                                     | should still be noted                |
51+-------------------------------------+--------------------------------------+
52| Report an error regarding a         | Raise an exception                   |
53| particular runtime event            |                                      |
54+-------------------------------------+--------------------------------------+
55| Report suppression of an error      | :func:`logging.error`,               |
56| without raising an exception (e.g.  | :func:`logging.exception` or         |
57| error handler in a long-running     | :func:`logging.critical` as          |
58| server process)                     | appropriate for the specific error   |
59|                                     | and application domain               |
60+-------------------------------------+--------------------------------------+
61
62The logging functions are named after the level or severity of the events
63they are used to track. The standard levels and their applicability are
64described below (in increasing order of severity):
65
66.. tabularcolumns:: |l|L|
67
68+--------------+---------------------------------------------+
69| Level        | When it's used                              |
70+==============+=============================================+
71| ``DEBUG``    | Detailed information, typically of interest |
72|              | only when diagnosing problems.              |
73+--------------+---------------------------------------------+
74| ``INFO``     | Confirmation that things are working as     |
75|              | expected.                                   |
76+--------------+---------------------------------------------+
77| ``WARNING``  | An indication that something unexpected     |
78|              | happened, or indicative of some problem in  |
79|              | the near future (e.g. 'disk space low').    |
80|              | The software is still working as expected.  |
81+--------------+---------------------------------------------+
82| ``ERROR``    | Due to a more serious problem, the software |
83|              | has not been able to perform some function. |
84+--------------+---------------------------------------------+
85| ``CRITICAL`` | A serious error, indicating that the program|
86|              | itself may be unable to continue running.   |
87+--------------+---------------------------------------------+
88
89The default level is ``WARNING``, which means that only events of this level
90and above will be tracked, unless the logging package is configured to do
91otherwise.
92
93Events that are tracked can be handled in different ways. The simplest way of
94handling tracked events is to print them to the console. Another common way
95is to write them to a disk file.
96
97
98.. _howto-minimal-example:
99
100A simple example
101^^^^^^^^^^^^^^^^
102
103A very simple example is::
104
105   import logging
106   logging.warning('Watch out!')  # will print a message to the console
107   logging.info('I told you so')  # will not print anything
108
109If you type these lines into a script and run it, you'll see:
110
111.. code-block:: none
112
113   WARNING:root:Watch out!
114
115printed out on the console. The ``INFO`` message doesn't appear because the
116default level is ``WARNING``. The printed message includes the indication of
117the level and the description of the event provided in the logging call, i.e.
118'Watch out!'. Don't worry about the 'root' part for now: it will be explained
119later. The actual output can be formatted quite flexibly if you need that;
120formatting options will also be explained later.
121
122
123Logging to a file
124^^^^^^^^^^^^^^^^^
125
126A very common situation is that of recording logging events in a file, so let's
127look at that next. Be sure to try the following in a newly started Python
128interpreter, and don't just continue from the session described above::
129
130   import logging
131   logging.basicConfig(filename='example.log', encoding='utf-8', level=logging.DEBUG)
132   logging.debug('This message should go to the log file')
133   logging.info('So should this')
134   logging.warning('And this, too')
135   logging.error('And non-ASCII stuff, too, like Øresund and Malmö')
136
137.. versionchanged:: 3.9
138   The *encoding* argument was added. In earlier Python versions, or if not
139   specified, the encoding used is the default value used by :func:`open`. While
140   not shown in the above example, an *errors* argument can also now be passed,
141   which determines how encoding errors are handled. For available values and
142   the default, see the documentation for :func:`open`.
143
144And now if we open the file and look at what we have, we should find the log
145messages:
146
147.. code-block:: none
148
149   DEBUG:root:This message should go to the log file
150   INFO:root:So should this
151   WARNING:root:And this, too
152   ERROR:root:And non-ASCII stuff, too, like Øresund and Malmö
153
154This example also shows how you can set the logging level which acts as the
155threshold for tracking. In this case, because we set the threshold to
156``DEBUG``, all of the messages were printed.
157
158If you want to set the logging level from a command-line option such as:
159
160.. code-block:: none
161
162   --log=INFO
163
164and you have the value of the parameter passed for ``--log`` in some variable
165*loglevel*, you can use::
166
167   getattr(logging, loglevel.upper())
168
169to get the value which you'll pass to :func:`basicConfig` via the *level*
170argument. You may want to error check any user input value, perhaps as in the
171following example::
172
173   # assuming loglevel is bound to the string value obtained from the
174   # command line argument. Convert to upper case to allow the user to
175   # specify --log=DEBUG or --log=debug
176   numeric_level = getattr(logging, loglevel.upper(), None)
177   if not isinstance(numeric_level, int):
178       raise ValueError('Invalid log level: %s' % loglevel)
179   logging.basicConfig(level=numeric_level, ...)
180
181The call to :func:`basicConfig` should come *before* any calls to
182:func:`debug`, :func:`info`, etc. Otherwise, those functions will call
183:func:`basicConfig` for you with the default options. As it's intended as a
184one-off simple configuration facility, only the first call will actually do
185anything: subsequent calls are effectively no-ops.
186
187If you run the above script several times, the messages from successive runs
188are appended to the file *example.log*. If you want each run to start afresh,
189not remembering the messages from earlier runs, you can specify the *filemode*
190argument, by changing the call in the above example to::
191
192   logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)
193
194The output will be the same as before, but the log file is no longer appended
195to, so the messages from earlier runs are lost.
196
197
198Logging from multiple modules
199^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
200
201If your program consists of multiple modules, here's an example of how you
202could organize logging in it::
203
204   # myapp.py
205   import logging
206   import mylib
207
208   def main():
209       logging.basicConfig(filename='myapp.log', level=logging.INFO)
210       logging.info('Started')
211       mylib.do_something()
212       logging.info('Finished')
213
214   if __name__ == '__main__':
215       main()
216
217::
218
219   # mylib.py
220   import logging
221
222   def do_something():
223       logging.info('Doing something')
224
225If you run *myapp.py*, you should see this in *myapp.log*:
226
227.. code-block:: none
228
229   INFO:root:Started
230   INFO:root:Doing something
231   INFO:root:Finished
232
233which is hopefully what you were expecting to see. You can generalize this to
234multiple modules, using the pattern in *mylib.py*. Note that for this simple
235usage pattern, you won't know, by looking in the log file, *where* in your
236application your messages came from, apart from looking at the event
237description. If you want to track the location of your messages, you'll need
238to refer to the documentation beyond the tutorial level -- see
239:ref:`logging-advanced-tutorial`.
240
241
242Logging variable data
243^^^^^^^^^^^^^^^^^^^^^
244
245To log variable data, use a format string for the event description message and
246append the variable data as arguments. For example::
247
248   import logging
249   logging.warning('%s before you %s', 'Look', 'leap!')
250
251will display:
252
253.. code-block:: none
254
255   WARNING:root:Look before you leap!
256
257As you can see, merging of variable data into the event description message
258uses the old, %-style of string formatting. This is for backwards
259compatibility: the logging package pre-dates newer formatting options such as
260:meth:`str.format` and :class:`string.Template`. These newer formatting
261options *are* supported, but exploring them is outside the scope of this
262tutorial: see :ref:`formatting-styles` for more information.
263
264
265Changing the format of displayed messages
266^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
267
268To change the format which is used to display messages, you need to
269specify the format you want to use::
270
271   import logging
272   logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
273   logging.debug('This message should appear on the console')
274   logging.info('So should this')
275   logging.warning('And this, too')
276
277which would print:
278
279.. code-block:: none
280
281   DEBUG:This message should appear on the console
282   INFO:So should this
283   WARNING:And this, too
284
285Notice that the 'root' which appeared in earlier examples has disappeared. For
286a full set of things that can appear in format strings, you can refer to the
287documentation for :ref:`logrecord-attributes`, but for simple usage, you just
288need the *levelname* (severity), *message* (event description, including
289variable data) and perhaps to display when the event occurred. This is
290described in the next section.
291
292
293Displaying the date/time in messages
294^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
295
296To display the date and time of an event, you would place '%(asctime)s' in
297your format string::
298
299   import logging
300   logging.basicConfig(format='%(asctime)s %(message)s')
301   logging.warning('is when this event was logged.')
302
303which should print something like this:
304
305.. code-block:: none
306
307   2010-12-12 11:41:42,612 is when this event was logged.
308
309The default format for date/time display (shown above) is like ISO8601 or
310:rfc:`3339`. If you need more control over the formatting of the date/time, provide
311a *datefmt* argument to ``basicConfig``, as in this example::
312
313   import logging
314   logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
315   logging.warning('is when this event was logged.')
316
317which would display something like this:
318
319.. code-block:: none
320
321   12/12/2010 11:46:36 AM is when this event was logged.
322
323The format of the *datefmt* argument is the same as supported by
324:func:`time.strftime`.
325
326
327Next Steps
328^^^^^^^^^^
329
330That concludes the basic tutorial. It should be enough to get you up and
331running with logging. There's a lot more that the logging package offers, but
332to get the best out of it, you'll need to invest a little more of your time in
333reading the following sections. If you're ready for that, grab some of your
334favourite beverage and carry on.
335
336If your logging needs are simple, then use the above examples to incorporate
337logging into your own scripts, and if you run into problems or don't
338understand something, please post a question on the comp.lang.python Usenet
339group (available at https://groups.google.com/g/comp.lang.python) and you
340should receive help before too long.
341
342Still here? You can carry on reading the next few sections, which provide a
343slightly more advanced/in-depth tutorial than the basic one above. After that,
344you can take a look at the :ref:`logging-cookbook`.
345
346.. _logging-advanced-tutorial:
347
348
349Advanced Logging Tutorial
350-------------------------
351
352The logging library takes a modular approach and offers several categories
353of components: loggers, handlers, filters, and formatters.
354
355* Loggers expose the interface that application code directly uses.
356* Handlers send the log records (created by loggers) to the appropriate
357  destination.
358* Filters provide a finer grained facility for determining which log records
359  to output.
360* Formatters specify the layout of log records in the final output.
361
362Log event information is passed between loggers, handlers, filters and
363formatters in a :class:`LogRecord` instance.
364
365Logging is performed by calling methods on instances of the :class:`Logger`
366class (hereafter called :dfn:`loggers`). Each instance has a name, and they are
367conceptually arranged in a namespace hierarchy using dots (periods) as
368separators. For example, a logger named 'scan' is the parent of loggers
369'scan.text', 'scan.html' and 'scan.pdf'. Logger names can be anything you want,
370and indicate the area of an application in which a logged message originates.
371
372A good convention to use when naming loggers is to use a module-level logger,
373in each module which uses logging, named as follows::
374
375   logger = logging.getLogger(__name__)
376
377This means that logger names track the package/module hierarchy, and it's
378intuitively obvious where events are logged just from the logger name.
379
380The root of the hierarchy of loggers is called the root logger. That's the
381logger used by the functions :func:`debug`, :func:`info`, :func:`warning`,
382:func:`error` and :func:`critical`, which just call the same-named method of
383the root logger. The functions and the methods have the same signatures. The
384root logger's name is printed as 'root' in the logged output.
385
386It is, of course, possible to log messages to different destinations. Support
387is included in the package for writing log messages to files, HTTP GET/POST
388locations, email via SMTP, generic sockets, queues, or OS-specific logging
389mechanisms such as syslog or the Windows NT event log. Destinations are served
390by :dfn:`handler` classes. You can create your own log destination class if
391you have special requirements not met by any of the built-in handler classes.
392
393By default, no destination is set for any logging messages. You can specify
394a destination (such as console or file) by using :func:`basicConfig` as in the
395tutorial examples. If you call the functions  :func:`debug`, :func:`info`,
396:func:`warning`, :func:`error` and :func:`critical`, they will check to see
397if no destination is set; and if one is not set, they will set a destination
398of the console (``sys.stderr``) and a default format for the displayed
399message before delegating to the root logger to do the actual message output.
400
401The default format set by :func:`basicConfig` for messages is:
402
403.. code-block:: none
404
405   severity:logger name:message
406
407You can change this by passing a format string to :func:`basicConfig` with the
408*format* keyword argument. For all options regarding how a format string is
409constructed, see :ref:`formatter-objects`.
410
411Logging Flow
412^^^^^^^^^^^^
413
414The flow of log event information in loggers and handlers is illustrated in the
415following diagram.
416
417.. image:: logging_flow.png
418   :class: invert-in-dark-mode
419
420Loggers
421^^^^^^^
422
423:class:`Logger` objects have a threefold job.  First, they expose several
424methods to application code so that applications can log messages at runtime.
425Second, logger objects determine which log messages to act upon based upon
426severity (the default filtering facility) or filter objects.  Third, logger
427objects pass along relevant log messages to all interested log handlers.
428
429The most widely used methods on logger objects fall into two categories:
430configuration and message sending.
431
432These are the most common configuration methods:
433
434* :meth:`Logger.setLevel` specifies the lowest-severity log message a logger
435  will handle, where debug is the lowest built-in severity level and critical
436  is the highest built-in severity.  For example, if the severity level is
437  INFO, the logger will handle only INFO, WARNING, ERROR, and CRITICAL messages
438  and will ignore DEBUG messages.
439
440* :meth:`Logger.addHandler` and :meth:`Logger.removeHandler` add and remove
441  handler objects from the logger object.  Handlers are covered in more detail
442  in :ref:`handler-basic`.
443
444* :meth:`Logger.addFilter` and :meth:`Logger.removeFilter` add and remove filter
445  objects from the logger object.  Filters are covered in more detail in
446  :ref:`filter`.
447
448You don't need to always call these methods on every logger you create. See the
449last two paragraphs in this section.
450
451With the logger object configured, the following methods create log messages:
452
453* :meth:`Logger.debug`, :meth:`Logger.info`, :meth:`Logger.warning`,
454  :meth:`Logger.error`, and :meth:`Logger.critical` all create log records with
455  a message and a level that corresponds to their respective method names. The
456  message is actually a format string, which may contain the standard string
457  substitution syntax of ``%s``, ``%d``, ``%f``, and so on.  The
458  rest of their arguments is a list of objects that correspond with the
459  substitution fields in the message.  With regard to ``**kwargs``, the
460  logging methods care only about a keyword of ``exc_info`` and use it to
461  determine whether to log exception information.
462
463* :meth:`Logger.exception` creates a log message similar to
464  :meth:`Logger.error`.  The difference is that :meth:`Logger.exception` dumps a
465  stack trace along with it.  Call this method only from an exception handler.
466
467* :meth:`Logger.log` takes a log level as an explicit argument.  This is a
468  little more verbose for logging messages than using the log level convenience
469  methods listed above, but this is how to log at custom log levels.
470
471:func:`getLogger` returns a reference to a logger instance with the specified
472name if it is provided, or ``root`` if not.  The names are period-separated
473hierarchical structures.  Multiple calls to :func:`getLogger` with the same name
474will return a reference to the same logger object.  Loggers that are further
475down in the hierarchical list are children of loggers higher up in the list.
476For example, given a logger with a name of ``foo``, loggers with names of
477``foo.bar``, ``foo.bar.baz``, and ``foo.bam`` are all descendants of ``foo``.
478
479Loggers have a concept of *effective level*. If a level is not explicitly set
480on a logger, the level of its parent is used instead as its effective level.
481If the parent has no explicit level set, *its* parent is examined, and so on -
482all ancestors are searched until an explicitly set level is found. The root
483logger always has an explicit level set (``WARNING`` by default). When deciding
484whether to process an event, the effective level of the logger is used to
485determine whether the event is passed to the logger's handlers.
486
487Child loggers propagate messages up to the handlers associated with their
488ancestor loggers. Because of this, it is unnecessary to define and configure
489handlers for all the loggers an application uses. It is sufficient to
490configure handlers for a top-level logger and create child loggers as needed.
491(You can, however, turn off propagation by setting the *propagate*
492attribute of a logger to ``False``.)
493
494
495.. _handler-basic:
496
497Handlers
498^^^^^^^^
499
500:class:`~logging.Handler` objects are responsible for dispatching the
501appropriate log messages (based on the log messages' severity) to the handler's
502specified destination.  :class:`Logger` objects can add zero or more handler
503objects to themselves with an :meth:`~Logger.addHandler` method.  As an example
504scenario, an application may want to send all log messages to a log file, all
505log messages of error or higher to stdout, and all messages of critical to an
506email address. This scenario requires three individual handlers where each
507handler is responsible for sending messages of a specific severity to a specific
508location.
509
510The standard library includes quite a few handler types (see
511:ref:`useful-handlers`); the tutorials use mainly :class:`StreamHandler` and
512:class:`FileHandler` in its examples.
513
514There are very few methods in a handler for application developers to concern
515themselves with.  The only handler methods that seem relevant for application
516developers who are using the built-in handler objects (that is, not creating
517custom handlers) are the following configuration methods:
518
519* The :meth:`~Handler.setLevel` method, just as in logger objects, specifies the
520  lowest severity that will be dispatched to the appropriate destination.  Why
521  are there two :func:`setLevel` methods?  The level set in the logger
522  determines which severity of messages it will pass to its handlers.  The level
523  set in each handler determines which messages that handler will send on.
524
525* :meth:`~Handler.setFormatter` selects a Formatter object for this handler to
526  use.
527
528* :meth:`~Handler.addFilter` and :meth:`~Handler.removeFilter` respectively
529  configure and deconfigure filter objects on handlers.
530
531Application code should not directly instantiate and use instances of
532:class:`Handler`.  Instead, the :class:`Handler` class is a base class that
533defines the interface that all handlers should have and establishes some
534default behavior that child classes can use (or override).
535
536
537Formatters
538^^^^^^^^^^
539
540Formatter objects configure the final order, structure, and contents of the log
541message.  Unlike the base :class:`logging.Handler` class, application code may
542instantiate formatter classes, although you could likely subclass the formatter
543if your application needs special behavior.  The constructor takes three
544optional arguments -- a message format string, a date format string and a style
545indicator.
546
547.. method:: logging.Formatter.__init__(fmt=None, datefmt=None, style='%')
548
549If there is no message format string, the default is to use the
550raw message.  If there is no date format string, the default date format is:
551
552.. code-block:: none
553
554    %Y-%m-%d %H:%M:%S
555
556with the milliseconds tacked on at the end. The ``style`` is one of ``'%'``,
557``'{'``, or ``'$'``. If one of these is not specified, then ``'%'`` will be used.
558
559If the ``style`` is ``'%'``, the message format string uses
560``%(<dictionary key>)s`` styled string substitution; the possible keys are
561documented in :ref:`logrecord-attributes`. If the style is ``'{'``, the message
562format string is assumed to be compatible with :meth:`str.format` (using
563keyword arguments), while if the style is ``'$'`` then the message format string
564should conform to what is expected by :meth:`string.Template.substitute`.
565
566.. versionchanged:: 3.2
567   Added the ``style`` parameter.
568
569The following message format string will log the time in a human-readable
570format, the severity of the message, and the contents of the message, in that
571order::
572
573    '%(asctime)s - %(levelname)s - %(message)s'
574
575Formatters use a user-configurable function to convert the creation time of a
576record to a tuple. By default, :func:`time.localtime` is used; to change this
577for a particular formatter instance, set the ``converter`` attribute of the
578instance to a function with the same signature as :func:`time.localtime` or
579:func:`time.gmtime`. To change it for all formatters, for example if you want
580all logging times to be shown in GMT, set the ``converter`` attribute in the
581Formatter class (to ``time.gmtime`` for GMT display).
582
583
584Configuring Logging
585^^^^^^^^^^^^^^^^^^^
586
587.. currentmodule:: logging.config
588
589Programmers can configure logging in three ways:
590
5911. Creating loggers, handlers, and formatters explicitly using Python
592   code that calls the configuration methods listed above.
5932. Creating a logging config file and reading it using the :func:`fileConfig`
594   function.
5953. Creating a dictionary of configuration information and passing it
596   to the :func:`dictConfig` function.
597
598For the reference documentation on the last two options, see
599:ref:`logging-config-api`.  The following example configures a very simple
600logger, a console handler, and a simple formatter using Python code::
601
602    import logging
603
604    # create logger
605    logger = logging.getLogger('simple_example')
606    logger.setLevel(logging.DEBUG)
607
608    # create console handler and set level to debug
609    ch = logging.StreamHandler()
610    ch.setLevel(logging.DEBUG)
611
612    # create formatter
613    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
614
615    # add formatter to ch
616    ch.setFormatter(formatter)
617
618    # add ch to logger
619    logger.addHandler(ch)
620
621    # 'application' code
622    logger.debug('debug message')
623    logger.info('info message')
624    logger.warning('warn message')
625    logger.error('error message')
626    logger.critical('critical message')
627
628Running this module from the command line produces the following output:
629
630.. code-block:: shell-session
631
632    $ python simple_logging_module.py
633    2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
634    2005-03-19 15:10:26,620 - simple_example - INFO - info message
635    2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
636    2005-03-19 15:10:26,697 - simple_example - ERROR - error message
637    2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message
638
639The following Python module creates a logger, handler, and formatter nearly
640identical to those in the example listed above, with the only difference being
641the names of the objects::
642
643    import logging
644    import logging.config
645
646    logging.config.fileConfig('logging.conf')
647
648    # create logger
649    logger = logging.getLogger('simpleExample')
650
651    # 'application' code
652    logger.debug('debug message')
653    logger.info('info message')
654    logger.warning('warn message')
655    logger.error('error message')
656    logger.critical('critical message')
657
658Here is the logging.conf file:
659
660.. code-block:: ini
661
662    [loggers]
663    keys=root,simpleExample
664
665    [handlers]
666    keys=consoleHandler
667
668    [formatters]
669    keys=simpleFormatter
670
671    [logger_root]
672    level=DEBUG
673    handlers=consoleHandler
674
675    [logger_simpleExample]
676    level=DEBUG
677    handlers=consoleHandler
678    qualname=simpleExample
679    propagate=0
680
681    [handler_consoleHandler]
682    class=StreamHandler
683    level=DEBUG
684    formatter=simpleFormatter
685    args=(sys.stdout,)
686
687    [formatter_simpleFormatter]
688    format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
689
690The output is nearly identical to that of the non-config-file-based example:
691
692.. code-block:: shell-session
693
694    $ python simple_logging_config.py
695    2005-03-19 15:38:55,977 - simpleExample - DEBUG - debug message
696    2005-03-19 15:38:55,979 - simpleExample - INFO - info message
697    2005-03-19 15:38:56,054 - simpleExample - WARNING - warn message
698    2005-03-19 15:38:56,055 - simpleExample - ERROR - error message
699    2005-03-19 15:38:56,130 - simpleExample - CRITICAL - critical message
700
701You can see that the config file approach has a few advantages over the Python
702code approach, mainly separation of configuration and code and the ability of
703noncoders to easily modify the logging properties.
704
705.. warning:: The :func:`fileConfig` function takes a default parameter,
706   ``disable_existing_loggers``, which defaults to ``True`` for reasons of
707   backward compatibility. This may or may not be what you want, since it
708   will cause any non-root loggers existing before the :func:`fileConfig`
709   call to be disabled unless they (or an ancestor) are explicitly named in
710   the configuration. Please refer to the reference documentation for more
711   information, and specify ``False`` for this parameter if you wish.
712
713   The dictionary passed to :func:`dictConfig` can also specify a Boolean
714   value with key ``disable_existing_loggers``, which if not specified
715   explicitly in the dictionary also defaults to being interpreted as
716   ``True``. This leads to the logger-disabling behaviour described above,
717   which may not be what you want - in which case, provide the key
718   explicitly with a value of ``False``.
719
720
721.. currentmodule:: logging
722
723Note that the class names referenced in config files need to be either relative
724to the logging module, or absolute values which can be resolved using normal
725import mechanisms. Thus, you could use either
726:class:`~logging.handlers.WatchedFileHandler` (relative to the logging module) or
727``mypackage.mymodule.MyHandler`` (for a class defined in package ``mypackage``
728and module ``mymodule``, where ``mypackage`` is available on the Python import
729path).
730
731In Python 3.2, a new means of configuring logging has been introduced, using
732dictionaries to hold configuration information. This provides a superset of the
733functionality of the config-file-based approach outlined above, and is the
734recommended configuration method for new applications and deployments. Because
735a Python dictionary is used to hold configuration information, and since you
736can populate that dictionary using different means, you have more options for
737configuration. For example, you can use a configuration file in JSON format,
738or, if you have access to YAML processing functionality, a file in YAML
739format, to populate the configuration dictionary. Or, of course, you can
740construct the dictionary in Python code, receive it in pickled form over a
741socket, or use whatever approach makes sense for your application.
742
743Here's an example of the same configuration as above, in YAML format for
744the new dictionary-based approach:
745
746.. code-block:: yaml
747
748    version: 1
749    formatters:
750      simple:
751        format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
752    handlers:
753      console:
754        class: logging.StreamHandler
755        level: DEBUG
756        formatter: simple
757        stream: ext://sys.stdout
758    loggers:
759      simpleExample:
760        level: DEBUG
761        handlers: [console]
762        propagate: no
763    root:
764      level: DEBUG
765      handlers: [console]
766
767For more information about logging using a dictionary, see
768:ref:`logging-config-api`.
769
770What happens if no configuration is provided
771^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
772
773If no logging configuration is provided, it is possible to have a situation
774where a logging event needs to be output, but no handlers can be found to
775output the event. The behaviour of the logging package in these
776circumstances is dependent on the Python version.
777
778For versions of Python prior to 3.2, the behaviour is as follows:
779
780* If *logging.raiseExceptions* is ``False`` (production mode), the event is
781  silently dropped.
782
783* If *logging.raiseExceptions* is ``True`` (development mode), a message
784  'No handlers could be found for logger X.Y.Z' is printed once.
785
786In Python 3.2 and later, the behaviour is as follows:
787
788* The event is output using a 'handler of last resort', stored in
789  ``logging.lastResort``. This internal handler is not associated with any
790  logger, and acts like a :class:`~logging.StreamHandler` which writes the
791  event description message to the current value of ``sys.stderr`` (therefore
792  respecting any redirections which may be in effect). No formatting is
793  done on the message - just the bare event description message is printed.
794  The handler's level is set to ``WARNING``, so all events at this and
795  greater severities will be output.
796
797To obtain the pre-3.2 behaviour, ``logging.lastResort`` can be set to ``None``.
798
799.. _library-config:
800
801Configuring Logging for a Library
802^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
803
804When developing a library which uses logging, you should take care to
805document how the library uses logging - for example, the names of loggers
806used. Some consideration also needs to be given to its logging configuration.
807If the using application does not use logging, and library code makes logging
808calls, then (as described in the previous section) events of severity
809``WARNING`` and greater will be printed to ``sys.stderr``. This is regarded as
810the best default behaviour.
811
812If for some reason you *don't* want these messages printed in the absence of
813any logging configuration, you can attach a do-nothing handler to the top-level
814logger for your library. This avoids the message being printed, since a handler
815will always be found for the library's events: it just doesn't produce any
816output. If the library user configures logging for application use, presumably
817that configuration will add some handlers, and if levels are suitably
818configured then logging calls made in library code will send output to those
819handlers, as normal.
820
821A do-nothing handler is included in the logging package:
822:class:`~logging.NullHandler` (since Python 3.1). An instance of this handler
823could be added to the top-level logger of the logging namespace used by the
824library (*if* you want to prevent your library's logged events being output to
825``sys.stderr`` in the absence of logging configuration). If all logging by a
826library *foo* is done using loggers with names matching 'foo.x', 'foo.x.y',
827etc. then the code::
828
829    import logging
830    logging.getLogger('foo').addHandler(logging.NullHandler())
831
832should have the desired effect. If an organisation produces a number of
833libraries, then the logger name specified can be 'orgname.foo' rather than
834just 'foo'.
835
836.. note:: It is strongly advised that you *do not log to the root logger*
837   in your library. Instead, use a logger with a unique and easily
838   identifiable name, such as the ``__name__`` for your library's top-level package
839   or module. Logging to the root logger will make it difficult or impossible for
840   the application developer to configure the logging verbosity or handlers of
841   your library as they wish.
842
843.. note:: It is strongly advised that you *do not add any handlers other
844   than* :class:`~logging.NullHandler` *to your library's loggers*. This is
845   because the configuration of handlers is the prerogative of the application
846   developer who uses your library. The application developer knows their
847   target audience and what handlers are most appropriate for their
848   application: if you add handlers 'under the hood', you might well interfere
849   with their ability to carry out unit tests and deliver logs which suit their
850   requirements.
851
852
853Logging Levels
854--------------
855
856The numeric values of logging levels are given in the following table. These are
857primarily of interest if you want to define your own levels, and need them to
858have specific values relative to the predefined levels. If you define a level
859with the same numeric value, it overwrites the predefined value; the predefined
860name is lost.
861
862+--------------+---------------+
863| Level        | Numeric value |
864+==============+===============+
865| ``CRITICAL`` | 50            |
866+--------------+---------------+
867| ``ERROR``    | 40            |
868+--------------+---------------+
869| ``WARNING``  | 30            |
870+--------------+---------------+
871| ``INFO``     | 20            |
872+--------------+---------------+
873| ``DEBUG``    | 10            |
874+--------------+---------------+
875| ``NOTSET``   | 0             |
876+--------------+---------------+
877
878Levels can also be associated with loggers, being set either by the developer or
879through loading a saved logging configuration. When a logging method is called
880on a logger, the logger compares its own level with the level associated with
881the method call. If the logger's level is higher than the method call's, no
882logging message is actually generated. This is the basic mechanism controlling
883the verbosity of logging output.
884
885Logging messages are encoded as instances of the :class:`~logging.LogRecord`
886class. When a logger decides to actually log an event, a
887:class:`~logging.LogRecord` instance is created from the logging message.
888
889Logging messages are subjected to a dispatch mechanism through the use of
890:dfn:`handlers`, which are instances of subclasses of the :class:`Handler`
891class. Handlers are responsible for ensuring that a logged message (in the form
892of a :class:`LogRecord`) ends up in a particular location (or set of locations)
893which is useful for the target audience for that message (such as end users,
894support desk staff, system administrators, developers). Handlers are passed
895:class:`LogRecord` instances intended for particular destinations. Each logger
896can have zero, one or more handlers associated with it (via the
897:meth:`~Logger.addHandler` method of :class:`Logger`). In addition to any
898handlers directly associated with a logger, *all handlers associated with all
899ancestors of the logger* are called to dispatch the message (unless the
900*propagate* flag for a logger is set to a false value, at which point the
901passing to ancestor handlers stops).
902
903Just as for loggers, handlers can have levels associated with them. A handler's
904level acts as a filter in the same way as a logger's level does. If a handler
905decides to actually dispatch an event, the :meth:`~Handler.emit` method is used
906to send the message to its destination. Most user-defined subclasses of
907:class:`Handler` will need to override this :meth:`~Handler.emit`.
908
909.. _custom-levels:
910
911Custom Levels
912^^^^^^^^^^^^^
913
914Defining your own levels is possible, but should not be necessary, as the
915existing levels have been chosen on the basis of practical experience.
916However, if you are convinced that you need custom levels, great care should
917be exercised when doing this, and it is possibly *a very bad idea to define
918custom levels if you are developing a library*. That's because if multiple
919library authors all define their own custom levels, there is a chance that
920the logging output from such multiple libraries used together will be
921difficult for the using developer to control and/or interpret, because a
922given numeric value might mean different things for different libraries.
923
924.. _useful-handlers:
925
926Useful Handlers
927---------------
928
929In addition to the base :class:`Handler` class, many useful subclasses are
930provided:
931
932#. :class:`StreamHandler` instances send messages to streams (file-like
933   objects).
934
935#. :class:`FileHandler` instances send messages to disk files.
936
937#. :class:`~handlers.BaseRotatingHandler` is the base class for handlers that
938   rotate log files at a certain point. It is not meant to be  instantiated
939   directly. Instead, use :class:`~handlers.RotatingFileHandler` or
940   :class:`~handlers.TimedRotatingFileHandler`.
941
942#. :class:`~handlers.RotatingFileHandler` instances send messages to disk
943   files, with support for maximum log file sizes and log file rotation.
944
945#. :class:`~handlers.TimedRotatingFileHandler` instances send messages to
946   disk files, rotating the log file at certain timed intervals.
947
948#. :class:`~handlers.SocketHandler` instances send messages to TCP/IP
949   sockets. Since 3.4, Unix domain sockets are also supported.
950
951#. :class:`~handlers.DatagramHandler` instances send messages to UDP
952   sockets. Since 3.4, Unix domain sockets are also supported.
953
954#. :class:`~handlers.SMTPHandler` instances send messages to a designated
955   email address.
956
957#. :class:`~handlers.SysLogHandler` instances send messages to a Unix
958   syslog daemon, possibly on a remote machine.
959
960#. :class:`~handlers.NTEventLogHandler` instances send messages to a
961   Windows NT/2000/XP event log.
962
963#. :class:`~handlers.MemoryHandler` instances send messages to a buffer
964   in memory, which is flushed whenever specific criteria are met.
965
966#. :class:`~handlers.HTTPHandler` instances send messages to an HTTP
967   server using either ``GET`` or ``POST`` semantics.
968
969#. :class:`~handlers.WatchedFileHandler` instances watch the file they are
970   logging to. If the file changes, it is closed and reopened using the file
971   name. This handler is only useful on Unix-like systems; Windows does not
972   support the underlying mechanism used.
973
974#. :class:`~handlers.QueueHandler` instances send messages to a queue, such as
975   those implemented in the :mod:`queue` or :mod:`multiprocessing` modules.
976
977#. :class:`NullHandler` instances do nothing with error messages. They are used
978   by library developers who want to use logging, but want to avoid the 'No
979   handlers could be found for logger XXX' message which can be displayed if
980   the library user has not configured logging. See :ref:`library-config` for
981   more information.
982
983.. versionadded:: 3.1
984   The :class:`NullHandler` class.
985
986.. versionadded:: 3.2
987   The :class:`~handlers.QueueHandler` class.
988
989The :class:`NullHandler`, :class:`StreamHandler` and :class:`FileHandler`
990classes are defined in the core logging package. The other handlers are
991defined in a sub-module, :mod:`logging.handlers`. (There is also another
992sub-module, :mod:`logging.config`, for configuration functionality.)
993
994Logged messages are formatted for presentation through instances of the
995:class:`Formatter` class. They are initialized with a format string suitable for
996use with the % operator and a dictionary.
997
998For formatting multiple messages in a batch, instances of
999:class:`~handlers.BufferingFormatter` can be used. In addition to the format
1000string (which is applied to each message in the batch), there is provision for
1001header and trailer format strings.
1002
1003When filtering based on logger level and/or handler level is not enough,
1004instances of :class:`Filter` can be added to both :class:`Logger` and
1005:class:`Handler` instances (through their :meth:`~Handler.addFilter` method).
1006Before deciding to process a message further, both loggers and handlers consult
1007all their filters for permission. If any filter returns a false value, the
1008message is not processed further.
1009
1010The basic :class:`Filter` functionality allows filtering by specific logger
1011name. If this feature is used, messages sent to the named logger and its
1012children are allowed through the filter, and all others dropped.
1013
1014
1015.. _logging-exceptions:
1016
1017Exceptions raised during logging
1018--------------------------------
1019
1020The logging package is designed to swallow exceptions which occur while logging
1021in production. This is so that errors which occur while handling logging events
1022- such as logging misconfiguration, network or other similar errors - do not
1023cause the application using logging to terminate prematurely.
1024
1025:class:`SystemExit` and :class:`KeyboardInterrupt` exceptions are never
1026swallowed. Other exceptions which occur during the :meth:`~Handler.emit` method
1027of a :class:`Handler` subclass are passed to its :meth:`~Handler.handleError`
1028method.
1029
1030The default implementation of :meth:`~Handler.handleError` in :class:`Handler`
1031checks to see if a module-level variable, :data:`raiseExceptions`, is set. If
1032set, a traceback is printed to :data:`sys.stderr`. If not set, the exception is
1033swallowed.
1034
1035.. note:: The default value of :data:`raiseExceptions` is ``True``. This is
1036   because during development, you typically want to be notified of any
1037   exceptions that occur. It's advised that you set :data:`raiseExceptions` to
1038   ``False`` for production usage.
1039
1040.. currentmodule:: logging
1041
1042.. _arbitrary-object-messages:
1043
1044Using arbitrary objects as messages
1045-----------------------------------
1046
1047In the preceding sections and examples, it has been assumed that the message
1048passed when logging the event is a string. However, this is not the only
1049possibility. You can pass an arbitrary object as a message, and its
1050:meth:`~object.__str__` method will be called when the logging system needs to
1051convert it to a string representation. In fact, if you want to, you can avoid
1052computing a string representation altogether - for example, the
1053:class:`~handlers.SocketHandler` emits an event by pickling it and sending it
1054over the wire.
1055
1056
1057Optimization
1058------------
1059
1060Formatting of message arguments is deferred until it cannot be avoided.
1061However, computing the arguments passed to the logging method can also be
1062expensive, and you may want to avoid doing it if the logger will just throw
1063away your event. To decide what to do, you can call the
1064:meth:`~Logger.isEnabledFor` method which takes a level argument and returns
1065true if the event would be created by the Logger for that level of call.
1066You can write code like this::
1067
1068    if logger.isEnabledFor(logging.DEBUG):
1069        logger.debug('Message with %s, %s', expensive_func1(),
1070                                            expensive_func2())
1071
1072so that if the logger's threshold is set above ``DEBUG``, the calls to
1073:func:`expensive_func1` and :func:`expensive_func2` are never made.
1074
1075.. note:: In some cases, :meth:`~Logger.isEnabledFor` can itself be more
1076   expensive than you'd like (e.g. for deeply nested loggers where an explicit
1077   level is only set high up in the logger hierarchy). In such cases (or if you
1078   want to avoid calling a method in tight loops), you can cache the result of a
1079   call to :meth:`~Logger.isEnabledFor` in a local or instance variable, and use
1080   that instead of calling the method each time. Such a cached value would only
1081   need to be recomputed when the logging configuration changes dynamically
1082   while the application is running (which is not all that common).
1083
1084There are other optimizations which can be made for specific applications which
1085need more precise control over what logging information is collected. Here's a
1086list of things you can do to avoid processing during logging which you don't
1087need:
1088
1089+-----------------------------------------------------+---------------------------------------------------+
1090| What you don't want to collect                      | How to avoid collecting it                        |
1091+=====================================================+===================================================+
1092| Information about where calls were made from.       | Set ``logging._srcfile`` to ``None``.             |
1093|                                                     | This avoids calling :func:`sys._getframe`, which  |
1094|                                                     | may help to speed up your code in environments    |
1095|                                                     | like PyPy (which can't speed up code that uses    |
1096|                                                     | :func:`sys._getframe`).                           |
1097+-----------------------------------------------------+---------------------------------------------------+
1098| Threading information.                              | Set ``logging.logThreads`` to ``False``.          |
1099+-----------------------------------------------------+---------------------------------------------------+
1100| Current process ID (:func:`os.getpid`)              | Set ``logging.logProcesses`` to ``False``.        |
1101+-----------------------------------------------------+---------------------------------------------------+
1102| Current process name when using ``multiprocessing`` | Set ``logging.logMultiprocessing`` to ``False``.  |
1103| to manage multiple processes.                       |                                                   |
1104+-----------------------------------------------------+---------------------------------------------------+
1105
1106Also note that the core logging module only includes the basic handlers. If
1107you don't import :mod:`logging.handlers` and :mod:`logging.config`, they won't
1108take up any memory.
1109
1110.. seealso::
1111
1112   Module :mod:`logging`
1113      API reference for the logging module.
1114
1115   Module :mod:`logging.config`
1116      Configuration API for the logging module.
1117
1118   Module :mod:`logging.handlers`
1119      Useful handlers included with the logging module.
1120
1121   :ref:`A logging cookbook <logging-cookbook>`
1122