|
Package ipapython ::
Module log_manager
|
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 '''
20
21 Quick Start Guide For Using This Module
22 =======================================
23
24 This module implements a Log Manager class which wraps the Python
25 logging module and provides some utility functions for use with
26 logging. All logging operations should be done through the
27 `LogManager` where available. *DO NOT create objects using the
28 Python logging module, the log manager will be unaware of them.*
29
30 This module was designed for ease of use while preserving advanced
31 functionality and performance. You must perform the following steps.
32
33 1. Import the log_manger module and instantiate *one* `LogManager`
34 instance for your application or library. The `LogManager` is
35 configured via `LogManager.configure()` whose values are
36 easily populated from command line options or a config file. You
37 can modify the configuration again at any point.
38
39 2. Create one or more output handlers via
40 `LogManager.create_log_handlers()` an easy to use yet powerful
41 interface.
42
43 3. In your code create loggers via `LogManager.get_logger()`. Since
44 loggers are normally bound to a class this method is optimized for
45 that case, all you need to do in the call ``__init__()`` is::
46
47 log_mgr.get_logger(self, True)
48
49 Then emitting messages is as simple as ``self.debug()`` or ``self.error()``
50
51 Example:
52 --------
53
54 ::
55
56 # Step 1, Create log manager and configure it
57 prog_name = 'my_app'
58 log_mgr = LogManager(prog_name)
59 log_mgr.configure(dict(verbose=True))
60
61 # Step 2, Create handlers
62 log_mgr.create_log_handlers([dict(name='my_app stdout',
63 stream=sys.stdout,
64 level=logging.INFO),
65 dict(name='my_app file',
66 filename='my_app.log',
67 level=logging.DEBUG)])
68
69 # Step 3, Create and use a logger in your code
70 class FooBar:
71 def __init__(self, name):
72 log_mgr.get_logger(self, True)
73 self.info("I'm alive! %s", name)
74
75 foobar = FooBar('Dr. Frankenstein')
76
77 # Dump the log manager state for illustration
78 print
79 print log_mgr
80
81
82 Running the above code would produce::
83
84 <INFO>: I'm alive! Dr. Frankenstein
85
86 root_logger_name: my_app
87 configure_state: None
88 default_level: INFO
89 debug: False
90 verbose: True
91 number of loggers: 2
92 "my_app" [level=INFO]
93 "my_app.__main__.FooBar" [level=INFO]
94 number of handlers: 2
95 "my_app file" [level=DEBUG]
96 "my_app stdout" [level=INFO]
97 number of logger regexps: 0
98
99 *Note, Steps 1 & 2 were broken out for expository purposes.* You can
100 pass your handler configuration into `LogManager.configure()`. The above
101 could have been simpler and more compact.::
102
103 # Step 1 & 2, Create log manager, and configure it and handlers
104 prog_name = 'my_app'
105 log_mgr = LogManager(prog_name)
106 log_mgr.configure(dict(verbose=True,
107 handlers = [dict(name='my_app stdout',
108 stream=sys.stdout,
109 level=logging.INFO),
110 dict(name='my_app file',
111 filename='my_app.log',
112 level=logging.DEBUG)])
113
114
115 FAQ (Frequently Asked Questions)
116 ================================
117
118 #. **Why is this better than logging.basicConfig? The short example
119 for the LogManager doesn't seem much different in complexity from
120 basicConfig?**
121
122 * You get independent logging namespaces. You can instantiate
123 multiple logging namespaces. If you use this module you'll be
124 isolated from other users of the Python logging module avoiding
125 conflicts.
126
127 * Creating and initializing loggers for classes is trivial. One
128 simple call creates the logger, configures it, and sets logging
129 methods on the class instance.
130
131 * You can easily configure individual loggers to different
132 levels. For example turn on debuging for just the part of the
133 code you're working on.
134
135 * The configuration is both simple and powerful. You get many more
136 options than with basicConfig.
137
138 * You can dynamically reset the logging configuration during
139 execution, you're not forced to live with the config established
140 during program initialization.
141
142 * The manager optimizes the use of the logging objects, you'll
143 spend less time executing pointless logging code for messages
144 that won't be emitted.
145
146 * You can see the state of all the logging objects in your
147 namespace from one centrally managed location.
148
149 * You can configure a LogManager to use the standard logging root
150 logger and get all the benefits of this API.
151
152 #. **How do I turn on debug logging for a specific class without
153 affecting the rest of the logging configuration?**
154
155 Use a logger regular expression to bind a custom level to loggers
156 whose name matches the regexp. See `LogManager.configure()`
157 for details.
158
159 Lets say you want to set your Foo.Bar class to debug, then do
160 this::
161
162 log_mgr.configure(dict(logger_regexps=[(r'Foo\.Bar', 'debug')]))
163
164 #. **I set the default_level but all my loggers are configured
165 with a higher level, what happened?**
166
167 You probably don't have any handlers defined at or below the
168 default_level. The level set on a logger will never be
169 lower than the lowest level handler available to that logger.
170
171 #. **My logger's all have their level set to a huge integer, why?**
172
173 See above. Logger's will never have a level less than the level of
174 the handlers visible to the logger. If there are no handlers then
175 loggers can't output anything so their level is set to maxint.
176
177 #. **I set the default_level but all the loggers are configured
178 at INFO or DEBUG, what happened?**
179
180 The verbose and debug config flags set the default_level to
181 INFO and DEBUG respectively as a convenience.
182
183 #. **I'm not seeing messages output when I expect them to be, what's
184 wrong?**
185
186 For a message to be emitted the following 3 conditions must hold:
187
188 * Message level >= logger's level
189 * Message level >= handler's level
190 * The message was not elided by a filter
191
192 To verify the above conditions hold print out the log manager state
193 (e.g. print log_mgr). Locate your logger, what level is at? Locate
194 the handler you expected to see the message appear on, what level
195 is it?
196
197 A General Discussion of Python Logging
198 ======================================
199
200 The design of this module is driven by how the Python logging module
201 works. The following discussion complements the Python Logging Howto,
202 fills in some missing information and covers strategies for
203 implementing different functionality along with the trade-offs
204 involved.
205
206 Understanding when & how log messages are emitted:
207 --------------------------------------------------
208
209 Loggers provide the application interface for logging. Every logger
210 object has the following methods debug(), info(), warning(), error(),
211 critical(), exception() and log() all of which can accept a format
212 string and arguments. Applications generate logging messages by
213 calling one of these methods to produce a formatted message.
214
215 A logger's effective level is the first explicitly set level found
216 when searching from the logger through it's ancestors terminating at
217 the root logger. The root logger always has an explicit level
218 (defaults to WARNING).
219
220 For a message to be emitted by a handler the following must be true:
221
222 The logger's effective level must >= message level and it must not
223 be filtered by a filter attached to the logger, otherwise the
224 message is discarded.
225
226 If the message survives the logger check it is passed to a list of
227 handlers. A handler will emit the message if the handler's level >=
228 message level and its not filtered by a filter attached to the
229 handler.
230
231 The list of handlers is determined thusly: Each logger has a list of
232 handlers (which may be empty). Starting with the logger the message
233 was bound to the message is passed to each of it's handlers. Then
234 the process repeats itself by traversing the chain of loggers
235 through all of it's ancestors until it reaches the root logger. The
236 logger traversal will be terminated if the propagate flag on a logger
237 is False (by default propagate is True).
238
239 Let's look at a hypothetical logger hierarchy (tree)::
240
241 A
242 / \\
243 B D
244 /
245 C
246
247
248 There are 4 loggers and 3 handlers
249
250 Loggers:
251
252 +-------+---------+---------+-----------+----------+
253 |Logger | Level | Filters | Propagate | Handlers |
254 +=======+=========+=========+===========+==========+
255 | A | WARNING | [] | False | [h1,h2] |
256 +-------+---------+---------+-----------+----------+
257 | A.B | ERROR | [] | False | [h3] |
258 +-------+---------+---------+-----------+----------+
259 | A.B.C | DEBUG | [] | True | |
260 +-------+---------+---------+-----------+----------+
261 | A.D | | [] | True | |
262 +-------+---------+---------+-----------+----------+
263
264 Handlers:
265
266 +---------+---------+---------+
267 | Handler | Level | Filters |
268 +=========+=========+=========+
269 | h1 | ERROR | [] |
270 +---------+---------+---------+
271 | h2 | WARNING | [] |
272 +---------+---------+---------+
273 | h3 | DEBUG | [] |
274 +---------+---------+---------+
275
276 Each of the loggers and handlers have empty filter lists in this
277 example thus the filter checks will always pass.
278
279 If a debug message is posted logger A.B.C the following would
280 happen. The effective level is determined. Since it does not have a
281 level set it's parent (A.B) is examined which has ERROR set,
282 therefore the effective level of A.B.C is ERROR. Processing
283 immediately stops because the logger's level of ERROR does not
284 permit debug messages.
285
286 If an error message is posted on logger A.B.C it passes the logger
287 level check and filter check therefore the message is passed along
288 to the handlers. The list of handlers on A.B.C is empty so no
289 handlers are called at this position in the logging hierarchy. Logger
290 A.B.C's propagate flag is True so parent logger A.B handlers are
291 invoked. Handler h3's level is DEBUG, it passes both the level and
292 filter check thus h3 emits the message. Processing now stops because
293 logger A.B's propagate flag is False.
294
295 Now let's see what would happen if a warning message was posted on
296 logger A.D. It's effective level is WARNING because logger A.D does
297 not have a level set, it's only ancestor is logger A, the root
298 logger which has a level of WARNING, thus logger's A.D effective
299 level is WARNING. Logger A.D has no handlers, it's propagate flag is
300 True so the message is passed to it's parent logger A, the root
301 logger. Logger A has two handlers h1 and h2. The level of h1 is
302 ERROR so the warning message is discarded by h1, nothing is emitted
303 by h1. Next handler h2 is invoked, it's level is WARNING so it
304 passes both the level check and the filter check, thus h2 emits the
305 warning message.
306
307 How to configure independent logging spaces:
308 --------------------------------------------
309
310 A common idiom is to hang all handlers off the root logger and set
311 the root loggers level to the desired verbosity. But this simplistic
312 approach runs afoul of several problems, in particular who controls
313 logging (accomplished by configuring the root logger). The usual
314 advice is to check and see if the root logger has any handlers set,
315 if so someone before you has configured logging and you should
316 inherit their configuration, all you do is add your own loggers
317 without any explicitly set level. If the root logger doesn't have
318 handlers set then you go ahead and configure the root logger to your
319 preference. The idea here is if your code is being loaded by another
320 application you want to defer to that applications logging
321 configuration but if your code is running stand-alone you need to
322 set up logging yourself.
323
324 But sometimes your code really wants it's own logging configuration
325 managed only by yourself completely independent of any logging
326 configuration by someone who may have loaded your code. Even if you
327 code is not designed to be loaded as a package or module you may be
328 faced with this problem. A trivial example of this is running your
329 code under a unit test framework which itself uses the logging
330 facility (remember there is only ever one root logger in any Python
331 process).
332
333 Fortunately there is a simple way to accommodate this. All you need
334 to do is create a "fake" root in the logging hierarchy which belongs
335 to you. You set your fake root's propagate flag to False, set a
336 level on it and you'll hang your handlers off this fake root. Then
337 when you create your loggers each should be a descendant of this
338 fake root. Now you've completely isolated yourself in the logging
339 hierarchy and won't be influenced by any other logging
340 configuration. As an example let's say your your code is called
341 'foo' and so you name your fake root logger 'foo'.::
342
343 my_root = logging.getLogger('foo') # child of the root logger
344 my_root.propagate = False
345 my_root.setLevel(logging.DEBUG)
346 my_root.addHandler(my_handler)
347
348 Then every logger you create should have 'foo.' prepended to it's
349 name. If you're logging my module your module's logger would be
350 created like this::
351
352 module_logger = logging.getLogger('foo.%s' % __module__)
353
354 If you're logging by class then your class logger would be::
355
356 class_logger = logging.getLogger('foo.%s.%s' % (self.__module__, self.__class__.__name__))
357
358 How to set levels:
359 ------------------
360
361 An instinctive or simplistic assumption is to set the root logger to a
362 high logging level, for example ERROR. After all you don't want to be
363 spamming users with debug and info messages. Let's also assume you've
364 got two handlers, one for a file and one for the console, both
365 attached to the root logger (a common configuration) and you haven't
366 set the level on either handler (in which case the handler will emit
367 all levels).
368
369 But now let's say you want to turn on debugging, but just to the file,
370 the console should continue to only emit error messages.
371
372 You set the root logger's level to DEBUG. The first thing you notice is
373 that you're getting debug message both in the file and on the console
374 because the console's handler does not have a level set. Not what you
375 want.
376
377 So you go back restore the root loggers level back to it's original
378 ERROR level and set the file handler's level to DEBUG and the console
379 handler's level to ERROR. Now you don't get any debug messages because
380 the root logger is blocking all messages below the level of ERROR and
381 doesn't invoke any handlers. The file handler attached to the root
382 logger even though it's level is set to DEBUG never gets a chance to
383 process the message.
384
385 *IMPORTANT:* You have to set the logger's level to the minimum of all
386 the attached handler's levels, otherwise the logger may block the
387 message from ever reaching any handler.
388
389 In this example the root logger's level must be set to DEBUG, the file
390 handler's level to DEBUG, and the console handler's level set to
391 ERROR.
392
393 Now let's take a more real world example which is a bit more
394 complicated. It's typical to assign loggers to every major class. In
395 fact this is the design strategy of Java logging from which the Python
396 logging is modeled. In a large complex application or library that
397 means dozens or possibly hundreds of loggers. Now lets say you need to
398 trace what is happening with one class. If you use the simplistic
399 configuration outlined above you'll set the log level of the root
400 logger and one of the handlers to debug. Now you're flooded with debug
401 message from every logger in the system when all you wanted was the
402 debug messages from just one class.
403
404 How can you get fine grained control over which loggers emit debug
405 messages? Here are some possibilities:
406
407 (1) Set a filter.
408 .................
409
410 When a message is propagated to a logger in the hierarchy first the
411 loggers level is checked. If logger level passes then the logger
412 iterates over every handler attached to the logger first checking the
413 handler level. If the handler level check passes then the filters
414 attached to the handler are run.
415
416 Filters are passed the record (i.e. the message), it does not have
417 access to either the logger or handler it's executing within. You
418 can't just set the filter to only pass the records of the classes you
419 want to debug because that would block other important info, warning,
420 error and critical messages from other classes. The filter would have
421 to know about the "global" log level which is in effect and also pass
422 any messages at that level or higher. It's unfortunate the filter
423 cannot know the level of the logger or handler it's executing inside
424 of.
425
426 Also logger filters only are applied to the logger they are attached
427 to, i.e. the logger the message was generated on. They do not get
428 applied to any ancestor loggers. That means you can't just set a
429 filter on the root logger. You have to either set the filters on the
430 handlers or on every logger created.
431
432 The filter first checks the level of the message record. If it's
433 greater than debug it passes it. For debug messages it checks the set
434 of loggers which have debug messages enabled, if the message record
435 was generated on one of those loggers it passes the record, otherwise
436 it blocks it.
437
438 The only question is whether you attach the filter to every logger or
439 to a handful of handlers. The advantage of attaching the filter to
440 every logger is efficiency, the time spent handling the message can be
441 short circuited much sooner if the message is filtered earlier in the
442 process. The advantage of attaching the filter to a handler is
443 simplicity, you only have to do that when a handler is created, not
444 every place in the code where a logger is created.
445
446 (2) Conditionally set the level of each logger.
447 ...............................................
448
449 When loggers are created a check is performed to see if the logger is
450 in the set of loggers for which debug information is desired, if so
451 it's level is set to DEBUG, otherwise it's set to the global
452 level. One has to recall there really isn't a single global level if
453 you want some handlers to emit info and above, some handlers error and
454 above, etc. In this case if the logger is not in the set of logger's
455 emitting debug the logger level should be set to the next increment
456 above debug level.
457
458 A good question to ask would be why not just leave the logger's level
459 unset if it's not in the set of loggers to be debugged? After all it
460 will just inherit the root level right? There are two problems with
461 that. 1) It wold actually inherit the level any ancestor logger and if
462 an ancestor was set to debug you've effectively turned on debugging
463 for all children of that ancestor logger. There are times you might
464 want that behavior, where all your children inherit your level, but
465 there are many cases where that's not the behavior you want. 2) A more
466 pernicious problem exists. The logger your handlers are attached to
467 MUST be set to debug level, otherwise your debug messages will never
468 reach the handlers for output. Thus if you leave a loggers level unset
469 and let it inherit it's effective level from an ancestor it might very
470 well inherit the debug level from the root logger. That means you've
471 completely negated your attempt to selectively set debug logging on
472 specific loggers. Bottom line, you really have to set the level on
473 every logger created if you want fine grained control.
474
475 Approach 2 has some distinct performance advantages. First of all
476 filters are not used, this avoids a whole processing step and extra
477 filter function calls on every message. Secondly a logger level check
478 is a simple integer compare which is very efficient. Thirdly the
479 processing of a message can be short circuited very early in the
480 processing pipeline, no ancestor loggers will be invoked and no
481 handlers will be invoked.
482
483 The downside is some added complexity at logger creation time. But
484 this is easily mitigated by using a utility function or method to
485 create the logger instead of just calling logger.getLogger().
486
487 Like every thing else in computer science which approach you take boils
488 down to a series of trade offs, most around how your code is
489 organized. You might find it easier to set a filter on just one or two
490 handlers. It might be easier to modify the configuration during
491 execution if the logic is centralized in just a filter function, but
492 don't let that sway you too much because it's trivial to iterate over
493 every logger and dynamically reset it's log level.
494
495 Now at least you've got a basic understanding of how this stuff hangs
496 together and what your options are. That's not insignificant, when I
497 was first introduced to logging in Java and Python I found it
498 bewildering difficult to get it do what I wanted.
499
500 John Dennis <jdennis@redhat.com>
501
502 '''
503
504
505 import sys
506 import os
507 import pwd
508 import logging
509 import re
510 import time
511
512
513
514 LOGGING_DEFAULT_FORMAT = '%(levelname)s %(message)s'
515
516
517 log_level_name_map = {
518 'notset' : logging.NOTSET,
519 'debug' : logging.DEBUG,
520 'info' : logging.INFO,
521 'warn' : logging.WARNING,
522 'warning' : logging.WARNING,
523 'error' : logging.ERROR,
524 'critical' : logging.CRITICAL
525 }
526
527 log_levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
528
529 logger_method_names = ('debug', 'info', 'warning', 'error', 'exception', 'critical')
530
531
532
534 '''
535 Given a iterable of objects containing a logging level return a
536 ordered list (min to max) of unique levels.
537
538 :parameters:
539 iterable
540 Iterable yielding objects with a logging level attribute.
541 :returns:
542 Ordered list (min to max) of unique levels.
543 '''
544 levels = set()
545
546 for obj in iterable:
547 level = getattr(obj, 'level', sys.maxint)
548 if level != logging.NOTSET:
549 levels.add(level)
550 levels = list(levels)
551 levels.sort()
552 return levels
553
555 '''
556 Given a iterable of objects containing a logging level return the
557 minimum level. If no levels are defined return maxint.
558 set of unique levels.
559
560 :parameters:
561 iterable
562 Iterable yielding objects with a logging level attribute.
563 :returns:
564 Ordered list (min to max) of unique levels.
565 '''
566 min_level = sys.maxint
567
568 for obj in iterable:
569 level = getattr(obj, 'level', sys.maxint)
570 if level != logging.NOTSET:
571 if level < min_level:
572 min_level = level
573 return min_level
574
576 '''
577 Given a log level either as a string or integer
578 return a numeric logging level. The following case insensitive
579 names are recognized::
580
581 * notset
582 * debug
583 * info
584 * warn
585 * warning
586 * error
587 * critical
588
589 A string containing an integer is also recognized, for example
590 ``"10"`` would map to ``logging.DEBUG``
591
592 The integer value must be the range [``logging.NOTSET``,
593 ``logging.CRITICAL``] otherwise a value exception will be raised.
594
595 :parameters:
596 level
597 basestring or integer, level value to convert
598 :returns:
599 integer level value
600 '''
601
602
603 if isinstance(level, basestring):
604 try:
605 level = int(level)
606 except:
607 pass
608
609
610
611 if isinstance(level, basestring):
612 result = log_level_name_map.get(level.lower())
613 if result is None:
614 raise ValueError('unknown log level (%s)' % level)
615 return result
616 elif isinstance(level, int):
617 if level < logging.NOTSET or level > logging.CRITICAL:
618 raise ValueError('log level (%d) out of range' % level)
619 return level
620 else:
621 raise TypeError('log level must be basestring or int, got (%s)' % type(level))
622
623
625 '''
626 Unfortunately the logging Logger and Handler classes do not have a
627 custom __str__() function which converts the object into a human
628 readable string representation. This function takes any object
629 with a level attribute and outputs the objects name with it's
630 associated level. If a name was never set for the object then it's
631 repr is used instead.
632
633 :parameters:
634 obj
635 Object with a logging level attribute
636 :returns:
637 string describing the object
638 '''
639 name = getattr(obj, 'name', repr(obj))
640 text = '"%s" [level=%s]' % (name, logging.getLevelName(obj.level))
641 if isinstance(obj, logging.FileHandler):
642 text += ' filename="%s"' % obj.baseFilename
643 return text
644
646 '''
647 This class wraps the functionality in the logging module to
648 provide an easier to use API for logging while providing advanced
649 features including a independent namespace. Each application or
650 library wishing to have it's own logging namespace should instantiate
651 exactly one instance of this class and use it to manage all it's
652 logging.
653
654 Traditionally (or simplistically) logging was set up with a single
655 global root logger with output handlers bound to it. The global
656 root logger (whose name is the empty string) was shared by all
657 code in a loaded process. The only the global unamed root logger
658 had a level set on it, all other loggers created inherited this
659 global level. This can cause conflicts in more complex scenarios
660 where loaded code wants to maintain it's own logging configuration
661 independent of whomever loaded it's code. By using only a single
662 logger level set on the global root logger it was not possible to
663 have fine grained control over individual logger output. The
664 pattern seen with this simplistic setup has been frequently copied
665 despite being clumsy and awkward. The logging module has the tools
666 available to support a more sophisitcated and useful model, but it
667 requires an overarching framework to manage. This class provides
668 such a framework.
669
670 The features of this logging manager are:
671
672 * Independent logging namespace.
673
674 * Simplifed method to create handlers.
675
676 * Simple setup for applications with command line args.
677
678 * Sophisitcated handler configuration
679 (e.g. file ownership & permissions)
680
681 * Easy fine grained control of logger output
682 (e.g. turning on debug for just 1 or 2 loggers)
683
684 * Holistic management of the interrelationships between
685 logging components.
686
687 * Ability to dynamically adjust logging configuration in
688 a running process.
689
690 An independent namespace is established by creating a independent
691 root logger for this manager (root_logger_name). This root logger
692 is a direct child of the global unamed root logger. All loggers
693 created by this manager will be descendants of this managers root
694 logger. The managers root logger has it's propagate flag set
695 to False which means all loggers and handlers created by this
696 manager will be isolated in the global logging tree.
697
698 Log level management:
699 ---------------------
700
701 Traditionally loggers inherited their logging level from the root
702 logger. This was simple but made it impossible to independently
703 control logging output from different loggers. If you set the root
704 level to DEBUG you got DEBUG output from every logger in the
705 system, often overwhelming in it's voluminous output. Many times
706 you want to turn on debug for just one class (a common idom is to
707 have one logger per class). To achieve the fine grained control
708 you can either use filters or set a logging level on every logger
709 (see the module documentation for the pros and cons). This manager
710 sets a log level on every logger instead of using level
711 inheritence because it's more efficient at run time.
712
713 Global levels are supported via the verbose and debug flags
714 setting every logger level to INFO and DEBUG respectively. Fine
715 grained level control is provided via regular expression matching
716 on logger names (see `configure()` for the details. For
717 example if you want to set a debug level for the foo.bar logger
718 set a regular expression to match it and bind it to the debug
719 level. Note, the global verbose and debug flags always override
720 the regular expression level configuration. Do not set these
721 global flags if you want fine grained control.
722
723 The manager maintains the minimum level for all loggers under it's
724 control and the minimum level for all handlers under it's
725 control. The reason it does this is because there is no point in
726 generating debug messages on a logger if there is no handler
727 defined which will output a debug message. Thus when the level is
728 set on a logger it takes into consideration the set of handlers
729 that logger can emit to.
730
731 IMPORTANT: Because the manager maintains knowledge about all the
732 loggers and handlers under it's control it is essential you use
733 only the managers interface to modify a logger or handler and not
734 set levels on the objects directly, otherwise the manger will not
735 know to visit every object under it's control when a configuraiton
736 changes (see '`LogManager.apply_configuration()`).
737
738 Example Usage::
739
740 # Create a log managers for use by 'my_app'
741 log_mgr = LogManager('my_app')
742
743 # Create a handler to send error messages to stderr
744 log_mgr.create_log_handlers([dict(stream=sys.stdout,
745 level=logging.ERROR)])
746
747 # Create logger for a class
748 class Foo(object):
749 def __init__(self):
750 self.log = log_mgr.get_logger(self)
751
752 '''
753 - def __init__(self, root_logger_name='', configure_state=None):
754 '''
755 Create a new LogManager instance using root_logger_name as the
756 parent of all loggers maintained by the manager.
757
758 Only one log manger should be created for each logging namespace.
759
760 :parameters:
761 root_logger_name
762 The name of the root logger. All loggers will be prefixed
763 by this name.
764 configure_state
765 Used by clients of the log manager to track the
766 configuration state, may be any object.
767
768 :return:
769 LogManager instance
770
771 '''
772 self.loggers = {}
773 self.handlers = {}
774
775 self.configure_state = configure_state
776 self.root_logger_name = root_logger_name
777 self.default_level = 'error'
778 self.debug = False
779 self.verbose = False
780 self.logger_regexps = []
781
782 self.root_logger = self.get_logger(self.root_logger_name)
783
784 self.root_logger.propagate = False
785
786
788 return self._default_level
789
794
795 default_level = property(_get_default_level, _set_default_level,
796 doc='see log_manager.parse_log_level()` for details on how the level can be specified during assignement.')
797
799 '''
800 Reset the default logger level, updates all loggers.
801 Note, the default_level may also be set by assigning to the
802 default_level attribute but that does not update the configure_state,
803 this method is provided as a convenience to simultaneously set the
804 configure_state if so desired.
805
806 :parameters:
807 level
808 The new default level for the log manager. See
809 `log_manager.parse_log_level()` for details on how the
810 level can be specified.
811 configure_state
812 If other than None update the log manger's configure_state
813 variable to this object. Clients of the log manager can
814 use configure_state to track the state of the log manager.
815
816 '''
817 level = parse_log_level(level)
818 self._default_level = level
819 self.apply_configuration(configure_state)
820
821
823 '''
824 When str() is called on the LogManager output it's state.
825 '''
826 text = ''
827 text += 'root_logger_name: %s\n' % (self.root_logger_name)
828 text += 'configure_state: %s\n' % (self.configure_state)
829 text += 'default_level: %s\n' % (logging.getLevelName(self.default_level))
830 text += 'debug: %s\n' % (self.debug)
831 text += 'verbose: %s\n' % (self.verbose)
832
833 text += 'number of loggers: %d\n' % (len(self.loggers))
834 loggers = [logging_obj_str(x) for x in self.loggers.values()]
835 loggers.sort()
836 for logger in loggers:
837 text += ' %s\n' % (logger)
838
839 text += 'number of handlers: %d\n' % (len(self.handlers))
840 handlers = [logging_obj_str(x) for x in self.handlers.values()]
841 handlers.sort()
842 for handler in handlers:
843 text += ' %s\n' % (handler)
844
845 text += 'number of logger regexps: %d\n' % (len(self.logger_regexps))
846 for regexp, level in self.logger_regexps:
847 text += ' "%s" => %s\n' % (regexp, logging.getLevelName(level))
848
849 return text
850
977
979 '''
980 Create new handlers and attach them to a logger (log mangers
981 root logger by default).
982
983 *Note, you may also pass the handler configs to `LogManager.configure()`.*
984
985 configs is an iterable yielding a dict. Each dict configures a
986 handler. Currently two types of handlers are supported:
987
988 * stream
989 * file
990
991 Which type of handler is created is determined by the presence of
992 the ``stream`` or ``filename`` in the dict.
993
994 Configuration keys:
995 ===================
996
997 Handler type keys:
998 ------------------
999
1000 Exactly of the following must present in the config dict:
1001
1002 stream
1003 Use the specified stream to initialize the StreamHandler.
1004
1005 filename
1006 Specifies that a FileHandler be created, using the specified
1007 filename.
1008
1009 Common keys:
1010 ------------
1011
1012 name
1013 Set the name of the handler. This is optional but can be
1014 useful when examining the logging configuration.
1015 For files defaults to ``'file:absolute_path'`` and for streams
1016 it defaults to ``'stream:stream_name'``
1017
1018 format
1019 Use the specified format string for the handler.
1020
1021 time_zone_converter
1022 Log record timestamps are seconds since the epoch in the UTC
1023 time zone stored as floating point values. When the formatter
1024 inserts a timestamp via the %(asctime)s format substitution it
1025 calls a time zone converter on the timestamp which returns a
1026 time.struct_time value to pass to the time.strftime function
1027 along with the datefmt format conversion string. The time
1028 module provides two functions with this signature,
1029 time.localtime and time.gmtime which performs a conversion to
1030 local time and UTC respectively. time.localtime is the default
1031 converter. Setting the time zone converter to time.gmtime is
1032 appropriate for date/time strings in UTC. The
1033 time_zone_converter attribute may be any function with the
1034 correct signature. Or as a convenience you may also pass a
1035 string which will select either the time.localtime or the
1036 time.gmtime converter. The case insenstive string mappings
1037 are::
1038
1039 'local' => time.localtime
1040 'localtime' => time.localtime
1041 'gmt' => time.gmtime
1042 'gmtime' => time.gmtime
1043 'utc' => time.gmtime
1044
1045 datefmt
1046 Use the specified time.strftime date/time format when
1047 formatting a timestamp via the %(asctime)s format
1048 substitution. The timestamp is first converted using the
1049 time_zone_converter to either local or UTC
1050
1051 level
1052 Set the handler logger level to the specified level. May be
1053 one of the following strings: 'debug', 'info', 'warn',
1054 'warning', 'error', 'critical' or any of the logging level
1055 constants. Thus level='debug' is equivalent to
1056 level=logging.DEBUG. Defaults to self.default_level.
1057
1058
1059 File handler keys:
1060 ------------------
1061
1062 filemode
1063 Specifies the mode to open the file. Defaults to 'a' for
1064 append, use 'w' for write.
1065
1066 permission
1067 Set the permission bits on the file (i.e. chmod).
1068 Must be a valid integer (e.g. 0660 for rw-rw----)
1069
1070 user
1071 Set the user owning the file. May be either a numeric uid or a
1072 basestring with a user name in the passwd file.
1073
1074 group
1075 Set the group associated with the file, May be either a
1076 numeric gid or a basestring with a group name in the groups
1077 file.
1078
1079 Examples:
1080 ---------
1081
1082 The following shows how to set two handlers, one for a file
1083 (ipa.log) at the debug log level and a second handler set to
1084 stdout (e.g. console) at the info log level. (One handler sets it
1085 level with a simple name, the other with a logging constant just
1086 to illustrate the flexibility) ::
1087
1088 # Get a root logger
1089 log_mgr = LogManger('my_app')
1090
1091 # Create the handlers
1092 log_mgr.create_log_handlers([dict(filename='my_app.log',
1093 level='info',
1094 user='root',
1095 group='root',
1096 permission=0600,
1097 time_zone_converter='utc',
1098 datefmt='%Y-%m-%dT%H:%M:%SZ', # ISO 8601
1099 format='<%(levelname)s> [%(asctime)s] module=%(name)s "%(message)s"'),
1100 dict(stream=sys.stdout,
1101 level=logging.ERROR,
1102 format='%(levelname)s: %(message)s')])
1103
1104 # Create a logger for my_app.foo.bar
1105 foo_bar_log = log_mgr.get_logger('foo.bar')
1106
1107 root_logger.info("Ready to process requests")
1108 foo_bar_log.error("something went boom")
1109
1110 In the file my_app.log you would see::
1111
1112 <INFO> [2011-10-26T01:39:00Z] module=my_app "Ready to process requests"
1113 <ERROR> [2011-10-26T01:39:00Z] module=may_app.foo.bar "something went boom"
1114
1115 On the console you would see::
1116
1117 ERROR: something went boom
1118
1119 :parameters:
1120 configs
1121 Sequence of dicts (any iterable yielding a dict). Each
1122 dict creates one handler and contains the configuration
1123 parameters used to create that handler.
1124 logger
1125 If unspecified the handlers will be attached to the
1126 LogManager.root_logger, otherwise the handlers will be
1127 attached to the specified logger.
1128 configure_state
1129 If other than None update the log manger's configure_state
1130 variable to this object. Clients of the log manager can
1131 use configure_state to track the state of the log manager.
1132
1133 :return:
1134 The list of created handers.
1135 '''
1136 if logger is None:
1137 logger = self.root_logger
1138
1139 handlers = []
1140
1141
1142 for cfg in configs:
1143
1144 filename = cfg.get('filename')
1145 if filename:
1146 if cfg.has_key("stream"):
1147 raise ValueError("both filename and stream are specified, must be one or the other, config: %s" % cfg)
1148 path = os.path.abspath(filename)
1149 filemode = cfg.get('filemode', 'a')
1150 handler = logging.FileHandler(path, filemode)
1151
1152
1153 name = cfg.get("name")
1154 if name is None:
1155 name = 'file:%s' % (path)
1156 handler.name = name
1157
1158
1159
1160
1161 uid = gid = None
1162 user = cfg.get('user')
1163 group = cfg.get('group')
1164 if user is not None:
1165 if isinstance(user, basestring):
1166 pw = pwd.getpwnam(user)
1167 uid = pw.pw_uid
1168 elif isinstance(user, int):
1169 uid = user
1170 else:
1171 raise TypeError("user (%s) is not int or basestring" % user)
1172 if group is not None:
1173 if isinstance(group, basestring):
1174 pw = pwd.getpwnam(group)
1175 gid = pw.pw_gid
1176 elif isinstance(group, int):
1177 gid = group
1178 else:
1179 raise TypeError("group (%s) is not int or basestring" % group)
1180 if uid is not None or gid is not None:
1181 if uid is None:
1182 uid = -1
1183 if gid is None:
1184 gid = -1
1185 os.chown(path, uid, gid)
1186
1187
1188 permission = cfg.get('permission')
1189 if permission is not None:
1190 os.chmod(path, permission)
1191 else:
1192 stream = cfg.get("stream")
1193 if stream is None:
1194 raise ValueError("neither file nor stream specified in config: %s" % cfg)
1195
1196 handler = logging.StreamHandler(stream)
1197
1198
1199 name = cfg.get("name")
1200 if name is None:
1201 name = 'stream:%s' % (stream)
1202 handler.name = name
1203
1204
1205 handlers.append(handler)
1206
1207
1208 format = cfg.get("format", LOGGING_DEFAULT_FORMAT)
1209 datefmt = cfg.get("datefmt", None)
1210 formatter = logging.Formatter(format, datefmt)
1211 time_zone_converter = cfg.get('time_zone_converter', time.localtime)
1212 if isinstance(time_zone_converter, basestring):
1213 converter = {'local' : time.localtime,
1214 'localtime' : time.localtime,
1215 'gmt' : time.gmtime,
1216 'gmtime' : time.gmtime,
1217 'utc' : time.gmtime}.get(time_zone_converter.lower())
1218 if converter is None:
1219 raise ValueError("invalid time_zone_converter name (%s)" % \
1220 time_zone_converter)
1221 elif callable(time_zone_converter):
1222 converter = time_zone_converter
1223 else:
1224 raise ValueError("time_zone_converter must be basestring or callable, not %s" % \
1225 type(time_zone_converter))
1226
1227 formatter.converter = converter
1228 handler.setFormatter(formatter)
1229
1230
1231 level = cfg.get('level')
1232 if level is not None:
1233 try:
1234 level = parse_log_level(level)
1235 except Exception, e:
1236 print >>sys.stderr, 'could not set handler log level "%s" (%s)' % (level, e)
1237 level = None
1238 if level is None:
1239 level = self.default_level
1240 handler.setLevel(level)
1241
1242 for handler in handlers:
1243 if handler.name in self.handlers:
1244 raise ValueError('handler "%s" already exists' % handler.name)
1245 logger.addHandler(handler)
1246 self.handlers[handler.name] = handler
1247 self.apply_configuration(configure_state)
1248 return handlers
1249
1251 '''
1252 Given a handler name return the handler object associated with
1253 it.
1254
1255 :parameters:
1256 handler_name
1257 Name of the handler to look-up.
1258
1259 :returns:
1260 The handler object associated with the handler name.
1261 '''
1262 handler = self.handlers.get(handler_name)
1263 if handler is None:
1264 raise KeyError('handler "%s" is not defined' % handler_name)
1265 return handler
1266
1268 '''
1269 Given a handler name, set the handler's level, return previous level.
1270
1271 :parameters:
1272 handler_name
1273 Name of the handler to look-up.
1274 level
1275 The new level for the handler. See
1276 `log_manager.parse_log_level()` for details on how the
1277 level can be specified.
1278 configure_state
1279 If other than None update the log manger's configure_state
1280 variable to this object. Clients of the log manager can
1281 use configure_state to track the state of the log manager.
1282
1283 :returns:
1284 The handler's previous level
1285 '''
1286 handler = self.get_handler(handler_name)
1287 level = parse_log_level(level)
1288 prev_level = handler.level
1289 handler.setLevel(level)
1290 self.apply_configuration(configure_state)
1291 return prev_level
1292
1294 '''
1295 Given a handler return a list of loggers that hander is bound to.
1296
1297
1298 :parameters:
1299 handler
1300 The name of a handler or a handler object.
1301
1302 :returns:
1303 List of loggers with the handler is bound to.
1304 '''
1305
1306 if isinstance(handler, basestring):
1307 handler = self.get_handler(handler)
1308 elif isinstance(handler, logging.Handler):
1309 if not handler in self.handlers.values():
1310 raise ValueError('handler "%s" is not managed by this log manager' % \
1311 logging_obj_str(handler))
1312 else:
1313 raise TypeError('handler must be basestring or Handler object, got %s' % type(handler))
1314
1315 loggers = []
1316 for logger in self.loggers.values():
1317 if handler in logger.handlers:
1318 loggers.append(logger)
1319
1320 return loggers
1321
1322 - def remove_handler(self, handler, logger=None, configure_state=None):
1323 '''
1324 Remove the named handler. If logger is unspecified the handler
1325 will be removed from all managed loggers, otherwise it will be
1326 removed from only the specified logger.
1327
1328 :parameters:
1329 handler
1330 The name of the handler to be removed or the handler object.
1331 logger
1332 If unspecified the handler is removed from all loggers,
1333 otherwise the handler is removed from only this logger.
1334 configure_state
1335 If other than None update the log manger's configure_state
1336 variable to this object. Clients of the log manager can
1337 use configure_state to track the state of the log manager.
1338 '''
1339
1340 if isinstance(handler, basestring):
1341 handler = self.get_handler(handler)
1342 elif not isinstance(handler, logging.Handler):
1343 raise TypeError('handler must be basestring or Handler object, got %s' % type(handler))
1344
1345 handler_name = handler.name
1346 if handler_name is None:
1347 raise ValueError('handler "%s" does not have a name' % logging_obj_str(handler))
1348
1349 loggers = self.get_loggers_with_handler(handler)
1350
1351 if logger is None:
1352 for logger in loggers:
1353 logger.removeHandler(handler)
1354 del self.handlers[handler_name]
1355 else:
1356 if not logger in loggers:
1357 raise ValueError('handler "%s" is not bound to logger "%s"' % \
1358 (handler_name, logging_obj_str(logger)))
1359 logger.removeHandler(handler)
1360 if len(loggers) == 1:
1361 del self.handlers[handler_name]
1362
1363 self.apply_configuration(configure_state)
1364
1366 '''
1367 Using the log manager's internal configuration state apply the
1368 configuration to all the objects managed by the log manager.
1369
1370 :parameters:
1371 configure_state
1372 If other than None update the log manger's configure_state
1373 variable to this object. Clients of the log manager can
1374 use configure_state to track the state of the log manager.
1375
1376 '''
1377 if configure_state is not None:
1378 self.configure_state = configure_state
1379 for logger in self.loggers.values():
1380 self._set_configured_logger_level(logger)
1381
1401
1403 '''
1404 Return the set of unique handlers visible to this logger.
1405
1406 :parameters:
1407 logger
1408 The logger whose visible and enabled handlers will be returned.
1409
1410 :return:
1411 Set of handlers
1412 '''
1413 handlers = set()
1414
1415 while logger:
1416 for handler in logger.handlers:
1417 handlers.add(handler)
1418 if logger.propagate:
1419 logger = logger.parent
1420 else:
1421 logger = None
1422 return handlers
1423
1425 '''
1426 Return the minimum handler level of all the handlers the
1427 logger is exposed to.
1428
1429 :parameters:
1430 logger
1431 The logger whose handlers will be examined.
1432
1433 :return:
1434 The minimum of all the handler's levels. If no
1435 handlers are defined sys.maxint will be returned.
1436 '''
1437
1438 handlers = self.get_logger_handlers(logger)
1439 min_level = get_minimum_level(handlers)
1440 return min_level
1441
1467
1468 - def get_logger(self, who, bind_logger_names=False):
1469 '''
1470 Return the logger for an object or a name. If the logger
1471 already exists return the existing instance otherwise create
1472 the logger.
1473
1474 The who parameter may be either a name or an object.
1475 Loggers are identified by a name but because loggers are
1476 usually bound to a class this method is optimized to handle
1477 that case. If who is an object:
1478
1479 * The name object's module name (dot seperated) and the
1480 object's class name.
1481
1482 * Optionally the logging output methods can be bound to the
1483 object if bind_logger_names is True.
1484
1485 Otherwise if who is a basestring it is used as the logger
1486 name.
1487
1488 In all instances the root_logger_name is prefixed to every
1489 logger created by the manager.
1490
1491 :parameters:
1492 who
1493 If a basestring then use this as the logger name,
1494 prefixed with the root_logger_name. Otherwise who is treated
1495 as a class instance. The logger name is formed by prepending
1496 the root_logger_name to the module name and then appending the
1497 class name. All name components are dot seperated. Thus if the
1498 root_logger_name is 'my_app', the class is ParseFileConfig
1499 living in the config.parsers module the logger name will be:
1500 ``my_app.config.parsers.ParseFileConfig``.
1501 bind_logger_names
1502 If true the class instance will have the following bound
1503 to it: ``log``, ``debug()``, ``info()``, ``warning()``,
1504 ``error()``, ``exception()``, ``critical()``. Where log is
1505 the logger object and the others are the loggers output
1506 methods. This is a convenience which allows you emit
1507 logging messages directly, for example::
1508
1509 self.debug('%d names defined', self.num_names).
1510
1511 :return:
1512 The logger matching the name indicated by who. If the
1513 logger pre-existed return that instance otherwise create the
1514 named logger return it.
1515 '''
1516
1517 is_object = False
1518 if isinstance(who, basestring):
1519 obj_name = who
1520 else:
1521 is_object = True
1522 obj_name = '%s.%s' % (who.__module__, who.__class__.__name__)
1523
1524 if obj_name == self.root_logger_name:
1525 logger_name = obj_name
1526 else:
1527 logger_name = self.root_logger_name + '.' + obj_name
1528
1529
1530 logger = self.loggers.get(logger_name)
1531 if logger is None:
1532 logger = logging.getLogger(logger_name)
1533 self.loggers[logger_name] = logger
1534 self._set_configured_logger_level(logger)
1535
1536 if bind_logger_names and is_object and getattr(who, '__log_manager', None) is None:
1537 setattr(who, '__log_manager', self)
1538 method = 'log'
1539 if hasattr(who, method):
1540 raise ValueError('%s is already bound to %s' % (method, repr(who)))
1541 setattr(who, method, logger)
1542
1543 for method in logger_method_names:
1544 if hasattr(who, method):
1545 raise ValueError('%s is already bound to %s' % (method, repr(who)))
1546 setattr(who, method, getattr(logger, method))
1547
1548 return logger
1549