~ubuntu-branches/ubuntu/trusty/python3.4/trusty-proposed

« back to all changes in this revision

Viewing changes to Doc/howto/logging.rst

  • Committer: Package Import Robot
  • Author(s): Matthias Klose
  • Date: 2013-11-25 09:44:27 UTC
  • Revision ID: package-import@ubuntu.com-20131125094427-lzxj8ap5w01lmo7f
Tags: upstream-3.4~b1
ImportĀ upstreamĀ versionĀ 3.4~b1

Show diffs side-by-side

added added

removed removed

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