1
2
3
4
5
6 """
7 Logging module.
8
9 Five levels of log information are defined.
10 These are, in order of decreasing verbosity: log, debug, info, warning, error.
11
12 This module provides a Loggable class for objects, as well as various
13 convenience methods for logging in general, and for logging with Twisted
14 and failures in particular.
15
16 Maintainer: U{Thomas Vander Stichele <thomas at apestaart dot org>}
17 """
18
19 import errno
20 import sys
21 import os
22 import fnmatch
23 import time
24 import types
25 import traceback
26
27
28 _DEBUG = "*:1"
29
30 _ENV_VAR_NAME = None
31
32 _PACKAGE_SCRUB_LIST = []
33
34
35 _categories = {}
36
37
38 _log_handlers = []
39 _log_handlers_limited = []
40
41 _initialized = False
42
43 _stdout = None
44 _stderr = None
45 _old_hup_handler = None
46
47
48
49 (ERROR,
50 WARN,
51 INFO,
52 DEBUG,
53 LOG) = range(1, 6)
54
55 COLORS = {ERROR: 'RED',
56 WARN: 'YELLOW',
57 INFO: 'GREEN',
58 DEBUG: 'BLUE',
59 LOG: 'CYAN'
60 }
61
62 _FORMATTED_LEVELS = []
63
65 """
66 Return the name of a log level.
67 """
68 assert isinstance(level, int) and level > 0 and level < 6, \
69 "Bad debug level"
70 return ('ERROR', 'WARN', 'INFO', 'DEBUG', 'LOG')[level - 1]
71
76
78 """
79 Register a given category in the debug system.
80 A level will be assigned to it based on previous calls to setDebug.
81 """
82
83
84 global _DEBUG
85 global _levels
86 global _categories
87
88 level = 0
89 chunks = _DEBUG.split(',')
90 for chunk in chunks:
91 if not chunk:
92 continue
93 if ':' in chunk:
94 spec, value = chunk.split(':')
95 else:
96 spec = '*'
97 value = chunk
98
99
100
101 if category in fnmatch.filter((category, ), spec):
102
103 if not value:
104 continue
105 try:
106 level = int(value)
107 except ValueError:
108 level = 5
109
110 _categories[category] = level
111
113 """
114 @param category: string
115
116 Get the debug level at which this category is being logged, adding it
117 if it wasn't registered yet.
118 """
119 global _categories
120 if not _categories.has_key(category):
121 registerCategory(category)
122 return _categories[category]
123
142
144 """Fetches the current log settings.
145 The returned object can be sent to setLogSettings to restore the
146 returned settings
147 @returns: the current settings
148 """
149 return (_DEBUG,
150 _categories,
151 _log_handlers,
152 _log_handlers_limited)
153
161
173
175 """
176 Return the filename and line number for the given location.
177
178 If where is a negative integer, look for the code entry in the current
179 stack that is the given number of frames above this module.
180 If where is a function, look for the code entry of the function.
181
182 @param where: how many frames to go back up, or function
183 @type where: int (negative) or function
184
185 @return: tuple of (file, line)
186 @rtype: tuple of (str, int)
187 """
188 co = None
189 lineno = None
190
191 if isinstance(where, types.FunctionType):
192 co = where.func_code
193 lineno = co.co_firstlineno
194 elif isinstance(where, types.MethodType):
195 co = where.im_func.func_code
196 lineno = co.co_firstlineno
197 else:
198 stackFrame = sys._getframe()
199 while stackFrame:
200 co = stackFrame.f_code
201 if not co.co_filename.endswith('log.py'):
202
203 while where < -1:
204 stackFrame = stackFrame.f_back
205 where += 1
206 co = stackFrame.f_code
207 lineno = stackFrame.f_lineno
208 break
209 stackFrame = stackFrame.f_back
210
211 if not co:
212 return "<unknown file>", 0
213
214 return scrubFilename(co.co_filename), lineno
215
217 """
218 Ellipsize the representation of the given object.
219 """
220 r = repr(o)
221 if len(r) < 800:
222 return r
223
224 r = r[:60] + ' ... ' + r[-15:]
225 return r
226
245
246 -def doLog(level, object, category, format, args, where=-1,
247 filePath=None, line=None):
248 """
249 @param where: what to log file and line number for;
250 -1 for one frame above log.py; -2 and down for higher up;
251 a function for a (future) code object
252 @type where: int or callable
253 @param filePath: file to show the message as coming from, if caller
254 knows best
255 @type filePath: str
256 @param line: line to show the message as coming from, if caller
257 knows best
258 @type line: int
259
260 @return: dict of calculated variables, if they needed calculating.
261 currently contains file and line; this prevents us from
262 doing this work in the caller when it isn't needed because
263 of the debug level
264 """
265 ret = {}
266
267 if args:
268 message = format % args
269 else:
270 message = format
271
272
273 if _log_handlers:
274 if filePath is None and line is None:
275 (filePath, line) = getFileLine(where=where)
276 ret['filePath'] = filePath
277 ret['line'] = line
278 for handler in _log_handlers:
279 try:
280 handler(level, object, category, file, line, message)
281 except TypeError:
282 raise SystemError, "handler %r raised a TypeError" % handler
283
284 if level > getCategoryLevel(category):
285 return ret
286
287 for handler in _log_handlers_limited:
288
289
290 if filePath is None and line is None:
291 (filePath, line) = getFileLine(where=where)
292 ret['filePath'] = filePath
293 ret['line'] = line
294 try:
295 handler(level, object, category, filePath, line, message)
296 except TypeError:
297 raise SystemError, "handler %r raised a TypeError" % handler
298
299 return ret
300
302 """
303 Log a fatal error message in the given category.
304 This will also raise a L{SystemExit}.
305 """
306 doLog(ERROR, object, cat, format, args)
307
308
309
310
311 if args:
312 raise SystemExit(format % args)
313 else:
314 raise SystemExit(format)
315
317 """
318 Log a warning message in the given category.
319 This is used for non-fatal problems.
320 """
321 doLog(WARN, object, cat, format, args)
322
324 """
325 Log an informational message in the given category.
326 """
327 doLog(INFO, object, cat, format, args)
328
330 """
331 Log a debug message in the given category.
332 """
333 doLog(DEBUG, object, cat, format, args)
334
336 """
337 Log a log message. Used for debugging recurring events.
338 """
339 doLog(LOG, object, cat, format, args)
340
342 """Write to a file object, ignoring errors.
343 """
344 try:
345 if args:
346 file.write(format % args)
347 else:
348 file.write(format)
349 except IOError, e:
350 if e.errno == errno.EPIPE:
351
352
353 os._exit(os.EX_OSERR)
354
355
357 """
358 A log handler that writes to stderr.
359
360 @type level: string
361 @type object: string (or None)
362 @type category: string
363 @type message: string
364 """
365
366 o = ""
367 if object:
368 o = '"' + object + '"'
369
370 where = "(%s:%d)" % (file, line)
371
372
373
374 safeprintf(sys.stderr, '%s [%5d] %-32s %-17s %-15s ',
375 getFormattedLevelName(level), os.getpid(), o, category,
376 time.strftime("%b %d %H:%M:%S"))
377 safeprintf(sys.stderr, '%-4s %s %s\n', "", message, where)
378
379 sys.stderr.flush()
380
405
406
407
408
409 -def init(envVarName, enableColorOutput=False):
434
447
449 """
450 Returns the currently active DEBUG string.
451 @rtype: str
452 """
453 global _DEBUG
454 return _DEBUG
455
457 """
458 Set the package names to scrub from filenames.
459 Filenames from these paths in log messages will be scrubbed to their
460 relative file path instead of the full absolute path.
461
462 @type packages: list of str
463 """
464 global _PACKAGE_SCRUB_LIST
465 _PACKAGE_SCRUB_LIST = packages
466
476
478 """
479 Add a custom log handler.
480
481 @param func: a function object with prototype (level, object, category,
482 message) where level is either ERROR, WARN, INFO, DEBUG, or
483 LOG, and the rest of the arguments are strings or None. Use
484 getLevelName(level) to get a printable name for the log level.
485 @type func: a callable function
486
487 @raises TypeError: if func is not a callable
488 """
489
490 if not callable(func):
491 raise TypeError, "func must be callable"
492
493 if func not in _log_handlers:
494 _log_handlers.append(func)
495
497 """
498 Add a custom log handler.
499
500 @param func: a function object with prototype (level, object, category,
501 message) where level is either ERROR, WARN, INFO, DEBUG, or
502 LOG, and the rest of the arguments are strings or None. Use
503 getLevelName(level) to get a printable name for the log level.
504 @type func: a callable function
505
506 @raises TypeError: TypeError if func is not a callable
507 """
508 if not callable(func):
509 raise TypeError, "func must be callable"
510
511 if func not in _log_handlers_limited:
512 _log_handlers_limited.append(func)
513
515 """
516 Remove a registered log handler.
517
518 @param func: a function object with prototype (level, object, category,
519 message) where level is either ERROR, WARN, INFO, DEBUG, or
520 LOG, and the rest of the arguments are strings or None. Use
521 getLevelName(level) to get a printable name for the log level.
522 @type func: a callable function
523
524 @raises ValueError: if func is not registered
525 """
526 _log_handlers.remove(func)
527
528
530 """
531 Remove a registered limited log handler.
532
533 @param func: a function object with prototype (level, object, category,
534 message) where level is either ERROR, WARN, INFO, DEBUG, or
535 LOG, and the rest of the arguments are strings or None. Use
536 getLevelName(level) to get a printable name for the log level.
537 @type func: a callable function
538
539 @raises ValueError: if func is not registered
540 """
541 _log_handlers_limited.remove(func)
542
543
544 -def error(cat, format, *args):
546
549
550 -def info(cat, format, *args):
552
553 -def debug(cat, format, *args):
555
556 -def log(cat, format, *args):
558
559
561 """
562 Return a short message based on an exception, useful for debugging.
563 Tries to find where the exception was triggered.
564 """
565 stack = traceback.extract_tb(sys.exc_info()[2])
566 if filename:
567 stack = [f for f in stack if f[0].find(filename) > -1]
568
569 (filename, line, func, text) = stack[frame]
570 filename = scrubFilename(filename)
571 exc = exception.__class__.__name__
572 msg = ""
573
574
575 if str(exception):
576 msg = ": %s" % str(exception)
577 return "exception %(exc)s at %(filename)s:%(line)s: %(func)s()%(msg)s" \
578 % locals()
579
581 """
582 Reopens the stdout and stderr output files, as set by
583 L{outputToFiles}.
584 """
585 if not _stdout and not _stderr:
586 debug('log', 'told to reopen log files, but log files not set')
587 return
588
589 def reopen(name, fileno, *args):
590 oldmask = os.umask(0026)
591 try:
592 f = open(name, 'a+', *args)
593 finally:
594 os.umask(oldmask)
595
596 os.dup2(f.fileno(), fileno)
597
598 if _stdout:
599 reopen(_stdout, sys.stdout.fileno())
600
601 if _stderr:
602 reopen(_stderr, sys.stderr.fileno(), 0)
603 debug('log', 'opened log %r', _stderr)
604
606 """
607 Redirect stdout and stderr to named files.
608
609 Records the file names so that a future call to reopenOutputFiles()
610 can open the same files. Installs a SIGHUP handler that will reopen
611 the output files.
612
613 Note that stderr is opened unbuffered, so if it shares a file with
614 stdout then interleaved output may not appear in the order that you
615 expect.
616 """
617 global _stdout, _stderr, _old_hup_handler
618 _stdout, _stderr = stdout, stderr
619 reopenOutputFiles()
620
621 def sighup(signum, frame):
622 info('log', "Received SIGHUP, reopening logs")
623 reopenOutputFiles()
624 if _old_hup_handler:
625 info('log', "Calling old SIGHUP hander")
626 _old_hup_handler(signum, frame)
627
628 debug('log', 'installing SIGHUP handler')
629 import signal
630 handler = signal.signal(signal.SIGHUP, sighup)
631 if handler == signal.SIG_DFL or handler == signal.SIG_IGN:
632 _old_hup_handler = None
633 else:
634 _old_hup_handler = handler
635
636
637
639 """
640 Base class for objects that want to be able to log messages with
641 different level of severity. The levels are, in order from least
642 to most: log, debug, info, warning, error.
643
644 @cvar logCategory: Implementors can provide a category to log their
645 messages under.
646 """
647
648 logCategory = 'default'
649
656
663
664 - def info(self, *args):
670
677
678 - def log(self, *args):
684
685 - def doLog(self, level, where, format, *args, **kwargs):
686 """
687 Log a message at the given level, with the possibility of going
688 higher up in the stack.
689
690 @param level: log level
691 @type level: int
692 @param where: how many frames to go back from the last log frame;
693 or a function (to log for a future call)
694 @type where: int (negative), or function
695
696 @param kwargs: a dict of pre-calculated values from a previous
697 doLog call
698
699 @return: a dict of calculated variables, to be reused in a
700 call to doLog that should show the same location
701 @rtype: dict
702 """
703 if _canShortcutLogging(self.logCategory, level):
704 return {}
705 args = self.logFunction(*args)
706 return doLog(level, self.logObjectName(), self.logCategory,
707 format, args, where=where, **kwargs)
708
725
727 """Overridable log function. Default just returns passed message."""
728 return args
729
731 """Overridable object name function."""
732
733 for name in ['logName', 'name']:
734 if hasattr(self, name):
735 return getattr(self, name)
736
737 return None
738
739
740
741
742 _initializedTwisted = False
743
744
745 __theTwistedLogObserver = None
746
755
756
757
759 """
760 Return a short message based on L{twisted.python.failure.Failure}.
761 Tries to find where the exception was triggered.
762 """
763 exc = str(failure.type)
764 msg = failure.getErrorMessage()
765 if len(failure.frames) == 0:
766 return "failure %(exc)s: %(msg)s" % locals()
767
768 (func, filename, line, some, other) = failure.frames[-1]
769 filename = scrubFilename(filename)
770 return "failure %(exc)s at %(filename)s:%(line)s: %(func)s(): %(msg)s" \
771 % locals()
772
774 """
775 Log a warning about a Failure. Useful as an errback handler:
776 d.addErrback(warningFailure)
777
778 @param swallow: whether to swallow the failure or not
779 @type swallow: bool
780 """
781 warning('', getFailureMessage(failure))
782 if not swallow:
783 return failure
784
814
815
816
817
819 """
820 Twisted log observer that integrates with our logging.
821 """
822 logCategory = "logobserver"
823
825 self._ignoreErrors = []
826
827 - def emit(self, eventDict):
828 method = log
829 edm = eventDict['message']
830 if not edm:
831 if eventDict['isError'] and eventDict.has_key('failure'):
832 f = eventDict['failure']
833 for failureType in self._ignoreErrors:
834 r = f.check(failureType)
835 if r:
836 self.debug("Failure of type %r, ignoring" % failureType)
837 return
838
839 self.log("Failure %r" % f)
840
841 method = debug
842 msg = "A twisted traceback occurred."
843 if getCategoryLevel("twisted") < WARN:
844 msg += " Run with debug level >= 2 to see the traceback."
845
846 warning('twisted', msg)
847 text = f.getTraceback()
848 safeprintf(sys.stderr, "\nTwisted traceback:\n")
849 safeprintf(sys.stderr, text + '\n')
850 elif eventDict.has_key('format'):
851 text = eventDict['format'] % eventDict
852 else:
853
854 return
855 else:
856 text = ' '.join(map(str, edm))
857
858 fmtDict = { 'system': eventDict['system'],
859 'text': text.replace("\n", "\n\t")
860 }
861 msgStr = " [%(system)s] %(text)s\n" % fmtDict
862
863
864 method('twisted', msgStr)
865
867 for failureType in types:
868 self._ignoreErrors.append(failureType)
869
871 self._ignoreErrors = []
872