Package flumotion :: Package extern :: Package log :: Module log
[hide private]

Source Code for Module flumotion.extern.log.log

   1  # -*- Mode: Python; test-case-name: test_log -*- 
   2  # vi:si:et:sw=4:sts=4:ts=4 
   3   
   4  # This file is released under the standard PSF license. 
   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. It is written such a way that it can be reused in 
  15  different projects to provide a controllable logging mechanism. 
  16   
  17  Maintainer: U{Thomas Vander Stichele <thomas at apestaart dot org>} 
  18  """ 
  19   
  20  import errno 
  21  import sys 
  22  import os 
  23  import fnmatch 
  24  import time 
  25  import types 
  26  import logging 
  27  import traceback 
  28   
  29  # environment variables controlling levels for each category 
  30  _DEBUG = "*:1" 
  31  # name of the environment variable controlling our logging 
  32  _ENV_VAR_NAME = None 
  33  # package names we should scrub filenames for 
  34  _PACKAGE_SCRUB_LIST = [] 
  35   
  36  # dynamic dictionary of categories already seen and their level 
  37  _categories = {} 
  38   
  39  # log handlers registered 
  40  _log_handlers = [] 
  41  _log_handlers_limited = [] 
  42   
  43  _initialized = False 
  44   
  45  _stdout = None 
  46  _stderr = None 
  47  _old_hup_handler = None 
  48   
  49   
  50  # public log levels 
  51  (ERROR, 
  52   WARN, 
  53   INFO, 
  54   DEBUG, 
  55   LOG) = range(1, 6) 
  56   
  57  COLORS = {ERROR: 'RED', 
  58            WARN: 'YELLOW', 
  59            INFO: 'GREEN', 
  60            DEBUG: 'BLUE', 
  61            LOG: 'CYAN'} 
  62   
  63  _FORMATTED_LEVELS = [] 
  64  _LEVEL_NAMES = ['ERROR', 'WARN', 'INFO', 'DEBUG', 'LOG'] 
  65   
  66   
67 -def getLevelName(level):
68 """ 69 Return the name of a log level. 70 @param level: The level we want to know the name 71 @type level: int 72 @return: The name of the level 73 @rtype: str 74 """ 75 assert isinstance(level, int) and level > 0 and level < 6, \ 76 TypeError("Bad debug level") 77 return getLevelNames()[level - 1]
78 79
80 -def getLevelNames():
81 """ 82 Return a list with the level names 83 @return: A list with the level names 84 @rtype: list of str 85 """ 86 return _LEVEL_NAMES
87 88
89 -def getLevelInt(levelName):
90 """ 91 Return the integer value of the levelName. 92 @param levelName: The string value of the level name 93 @type levelName: str 94 @return: The value of the level name we are interested in. 95 @rtype: int 96 """ 97 assert isinstance(levelName, str) and levelName in getLevelNames(), \ 98 "Bad debug level name" 99 return getLevelNames().index(levelName)+1
100 101
102 -def getFormattedLevelName(level):
103 assert isinstance(level, int) and level > 0 and level < 6, \ 104 TypeError("Bad debug level") 105 return _FORMATTED_LEVELS[level - 1]
106 107
108 -def registerCategory(category):
109 """ 110 Register a given category in the debug system. 111 A level will be assigned to it based on previous calls to setDebug. 112 """ 113 # parse what level it is set to based on _DEBUG 114 # example: *:2,admin:4 115 global _DEBUG 116 global _levels 117 global _categories 118 119 level = 0 120 chunks = _DEBUG.split(',') 121 for chunk in chunks: 122 if not chunk: 123 continue 124 if ':' in chunk: 125 spec, value = chunk.split(':') 126 else: 127 spec = '*' 128 value = chunk 129 130 # our glob is unix filename style globbing, so cheat with fnmatch 131 # fnmatch.fnmatch didn't work for this, so don't use it 132 if category in fnmatch.filter((category, ), spec): 133 # we have a match, so set level based on string or int 134 if not value: 135 continue 136 try: 137 level = int(value) 138 except ValueError: # e.g. *; we default to most 139 level = 5 140 # store it 141 _categories[category] = level
142 143
144 -def getCategoryLevel(category):
145 """ 146 @param category: string 147 148 Get the debug level at which this category is being logged, adding it 149 if it wasn't registered yet. 150 """ 151 global _categories 152 if not category in _categories: 153 registerCategory(category) 154 return _categories[category]
155 156
157 -def setLogSettings(state):
158 """Update the current log settings. 159 This can restore an old saved log settings object returned by 160 getLogSettings 161 @param state: the settings to set 162 """ 163 164 global _DEBUG 165 global _log_handlers 166 global _log_handlers_limited 167 168 (_DEBUG, 169 categories, 170 _log_handlers, 171 _log_handlers_limited) = state 172 173 for category in categories: 174 registerCategory(category)
175 176
177 -def getLogSettings():
178 """Fetches the current log settings. 179 The returned object can be sent to setLogSettings to restore the 180 returned settings 181 @returns: the current settings 182 """ 183 return (_DEBUG, 184 _categories, 185 _log_handlers, 186 _log_handlers_limited)
187 188
189 -def _canShortcutLogging(category, level):
190 if _log_handlers: 191 # we have some loggers operating without filters, have to do 192 # everything 193 return False 194 else: 195 return level > getCategoryLevel(category)
196 197
198 -def scrubFilename(filename):
199 ''' 200 Scrub the filename to a relative path for all packages in our scrub list. 201 ''' 202 global _PACKAGE_SCRUB_LIST 203 for package in _PACKAGE_SCRUB_LIST: 204 i = filename.rfind(package) 205 if i > -1: 206 return filename[i:] 207 208 return filename
209 210
211 -def getFileLine(where=-1, targetModule=None):
212 """ 213 Return the filename and line number for the given location. 214 215 If where is a negative integer, look for the code entry in the current 216 stack that is the given number of frames above this module. 217 If where is a function, look for the code entry of the function. 218 219 @param where: how many frames to go back up, or function 220 @type where: int (negative) or function 221 222 @param targetModule: continue going up the stack until that module is seen 223 @type targetModule: str or None 224 225 @return: tuple of (file, line) 226 @rtype: tuple of (str, int) 227 """ 228 co = None 229 lineno = None 230 231 if isinstance(where, types.FunctionType): 232 co = where.func_code 233 lineno = co.co_firstlineno 234 elif isinstance(where, types.MethodType): 235 co = where.im_func.func_code 236 lineno = co.co_firstlineno 237 else: 238 stackFrame = sys._getframe() 239 while stackFrame: 240 co = stackFrame.f_code 241 if not co.co_filename.endswith('log.py'): 242 # wind up the stack according to frame 243 while where < -1: 244 stackFrame = stackFrame.f_back 245 where += 1 246 co = stackFrame.f_code 247 lineno = stackFrame.f_lineno 248 break 249 stackFrame = stackFrame.f_back 250 251 if not co: 252 return "<unknown file>", 0 253 254 if targetModule: 255 while stackFrame: 256 co = stackFrame.f_code 257 lineno = stackFrame.f_lineno 258 if targetModule in co.co_filename: 259 break 260 stackFrame = stackFrame.f_back 261 262 return scrubFilename(co.co_filename), lineno
263 264
265 -def ellipsize(o):
266 """ 267 Ellipsize the representation of the given object. 268 """ 269 r = repr(o) 270 if len(r) < 800: 271 return r 272 273 r = r[:60] + ' ... ' + r[-15:] 274 return r
275 276
277 -def getFormatArgs(startFormat, startArgs, endFormat, endArgs, args, kwargs):
278 """ 279 Helper function to create a format and args to use for logging. 280 This avoids needlessly interpolating variables. 281 """ 282 debugArgs = startArgs[:] 283 for a in args: 284 debugArgs.append(ellipsize(a)) 285 286 for items in kwargs.items(): 287 debugArgs.extend(items) 288 debugArgs.extend(endArgs) 289 debugFormat = startFormat \ 290 + ', '.join(('%s', ) * len(args)) \ 291 + (kwargs and ', ' or '') \ 292 + ', '.join(('%s=%r', ) * len(kwargs)) \ 293 + endFormat 294 return debugFormat, debugArgs
295 296
297 -def doLog(level, object, category, format, args, where=-1, 298 filePath=None, line=None):
299 """ 300 @param where: what to log file and line number for; 301 -1 for one frame above log.py; -2 and down for higher up; 302 a function for a (future) code object 303 @type where: int or callable 304 @param filePath: file to show the message as coming from, if caller 305 knows best 306 @type filePath: str 307 @param line: line to show the message as coming from, if caller 308 knows best 309 @type line: int 310 311 @return: dict of calculated variables, if they needed calculating. 312 currently contains file and line; this prevents us from 313 doing this work in the caller when it isn't needed because 314 of the debug level 315 """ 316 ret = {} 317 318 if args: 319 message = format % args 320 else: 321 message = format 322 323 # first all the unlimited ones 324 if _log_handlers: 325 if filePath is None and line is None: 326 (filePath, line) = getFileLine(where=where) 327 ret['filePath'] = filePath 328 ret['line'] = line 329 for handler in _log_handlers: 330 try: 331 handler(level, object, category, file, line, message) 332 except TypeError, e: 333 raise SystemError("handler %r raised a TypeError: %s" % ( 334 handler, getExceptionMessage(e))) 335 336 if level > getCategoryLevel(category): 337 return ret 338 339 if _log_handlers_limited: 340 if filePath is None and line is None: 341 (filePath, line) = getFileLine(where=where) 342 ret['filePath'] = filePath 343 ret['line'] = line 344 for handler in _log_handlers_limited: 345 # set this a second time, just in case there weren't unlimited 346 # loggers there before 347 try: 348 handler(level, object, category, filePath, line, message) 349 except TypeError: 350 raise SystemError("handler %r raised a TypeError" % handler) 351 352 return ret
353 354
355 -def errorObject(object, cat, format, *args):
356 """ 357 Log a fatal error message in the given category. 358 This will also raise a L{SystemExit}. 359 """ 360 doLog(ERROR, object, cat, format, args) 361 362 # we do the import here because having it globally causes weird import 363 # errors if our gstreactor also imports .log, which brings in errors 364 # and pb stuff 365 if args: 366 raise SystemExit(format % args) 367 else: 368 raise SystemExit(format)
369 370
371 -def warningObject(object, cat, format, *args):
372 """ 373 Log a warning message in the given category. 374 This is used for non-fatal problems. 375 """ 376 doLog(WARN, object, cat, format, args)
377 378
379 -def infoObject(object, cat, format, *args):
380 """ 381 Log an informational message in the given category. 382 """ 383 doLog(INFO, object, cat, format, args)
384 385
386 -def debugObject(object, cat, format, *args):
387 """ 388 Log a debug message in the given category. 389 """ 390 doLog(DEBUG, object, cat, format, args)
391 392
393 -def logObject(object, cat, format, *args):
394 """ 395 Log a log message. Used for debugging recurring events. 396 """ 397 doLog(LOG, object, cat, format, args)
398 399
400 -def safeprintf(file, format, *args):
401 """Write to a file object, ignoring errors. 402 """ 403 try: 404 if args: 405 file.write(format % args) 406 else: 407 file.write(format) 408 except IOError, e: 409 if e.errno == errno.EPIPE: 410 # if our output is closed, exit; e.g. when logging over an 411 # ssh connection and the ssh connection is closed 412 os._exit(os.EX_OSERR)
413 # otherwise ignore it, there's nothing you can do 414 415
416 -def stderrHandler(level, object, category, file, line, message):
417 """ 418 A log handler that writes to stderr. 419 420 @type level: string 421 @type object: string (or None) 422 @type category: string 423 @type message: string 424 """ 425 426 o = "" 427 if object: 428 o = '"' + object + '"' 429 430 where = "(%s:%d)" % (file, line) 431 432 # level pid object cat time 433 # 5 + 1 + 7 + 1 + 32 + 1 + 17 + 1 + 15 == 80 434 safeprintf(sys.stderr, '%s [%5d] %-32s %-17s %-15s ', 435 getFormattedLevelName(level), os.getpid(), o, category, 436 time.strftime("%b %d %H:%M:%S")) 437 438 try: 439 safeprintf(sys.stderr, '%-4s %s %s\n', "", message, where) 440 except UnicodeEncodeError: 441 # this can happen if message is a unicode object, convert it back into 442 # a string using the UTF-8 encoding 443 message = message.encode('UTF-8') 444 safeprintf(sys.stderr, '%-4s %s %s\n', "", message, where) 445 446 sys.stderr.flush()
447 448
449 -def _preformatLevels(noColorEnvVarName):
450 format = '%-5s' 451 452 try: 453 import termcolor 454 except ImportError: 455 # we don't need to catch this if termcolor is in same package as 456 # log.py 457 termcolor = None 458 459 if (noColorEnvVarName is not None 460 and termcolor is not None 461 and (noColorEnvVarName not in os.environ 462 or not os.environ[noColorEnvVarName])): 463 464 t = termcolor.TerminalController() 465 formatter = lambda level: ''.join((t.BOLD, getattr(t, COLORS[level]), 466 format % (_LEVEL_NAMES[level-1], ), t.NORMAL)) 467 else: 468 formatter = lambda level: format % (_LEVEL_NAMES[level-1], ) 469 470 for level in ERROR, WARN, INFO, DEBUG, LOG: 471 _FORMATTED_LEVELS.append(formatter(level))
472 473 ### "public" useful API 474 475 # setup functions 476 477
478 -def init(envVarName, enableColorOutput=False):
479 """ 480 Initialize the logging system and parse the environment variable 481 of the given name. 482 Needs to be called before starting the actual application. 483 """ 484 global _initialized 485 486 if _initialized: 487 return 488 489 global _ENV_VAR_NAME 490 _ENV_VAR_NAME = envVarName 491 492 if enableColorOutput: 493 _preformatLevels(envVarName + "_NO_COLOR") 494 else: 495 _preformatLevels(None) 496 497 if envVarName in os.environ: 498 # install a log handler that uses the value of the environment var 499 setDebug(os.environ[envVarName]) 500 addLimitedLogHandler(stderrHandler) 501 502 _initialized = True
503 504
505 -def setDebug(string):
506 """Set the DEBUG string. This controls the log output.""" 507 global _DEBUG 508 global _ENV_VAR_NAME 509 global _categories 510 511 _DEBUG = string 512 debug('log', "%s set to %s" % (_ENV_VAR_NAME, _DEBUG)) 513 514 # reparse all already registered category levels 515 for category in _categories: 516 registerCategory(category)
517 518
519 -def getDebug():
520 """ 521 Returns the currently active DEBUG string. 522 @rtype: str 523 """ 524 global _DEBUG 525 return _DEBUG
526 527
528 -def setPackageScrubList(*packages):
529 """ 530 Set the package names to scrub from filenames. 531 Filenames from these paths in log messages will be scrubbed to their 532 relative file path instead of the full absolute path. 533 534 @type packages: list of str 535 """ 536 global _PACKAGE_SCRUB_LIST 537 _PACKAGE_SCRUB_LIST = packages
538 539
540 -def reset():
541 """ 542 Resets the logging system, removing all log handlers. 543 """ 544 global _log_handlers, _log_handlers_limited, _initialized 545 546 _log_handlers = [] 547 _log_handlers_limited = [] 548 _initialized = False
549 550
551 -def addLogHandler(func):
552 """ 553 Add a custom log handler. 554 555 @param func: a function object with prototype (level, object, category, 556 message) where level is either ERROR, WARN, INFO, DEBUG, or 557 LOG, and the rest of the arguments are strings or None. Use 558 getLevelName(level) to get a printable name for the log level. 559 @type func: a callable function 560 561 @raises TypeError: if func is not a callable 562 """ 563 564 if not callable(func): 565 raise TypeError("func must be callable") 566 567 if func not in _log_handlers: 568 _log_handlers.append(func)
569 570
571 -def addLimitedLogHandler(func):
572 """ 573 Add a custom log handler. 574 575 @param func: a function object with prototype (level, object, category, 576 message) where level is either ERROR, WARN, INFO, DEBUG, or 577 LOG, and the rest of the arguments are strings or None. Use 578 getLevelName(level) to get a printable name for the log level. 579 @type func: a callable function 580 581 @raises TypeError: TypeError if func is not a callable 582 """ 583 if not callable(func): 584 raise TypeError("func must be callable") 585 586 if func not in _log_handlers_limited: 587 _log_handlers_limited.append(func)
588 589
590 -def removeLogHandler(func):
591 """ 592 Remove a registered log handler. 593 594 @param func: a function object with prototype (level, object, category, 595 message) where level is either ERROR, WARN, INFO, DEBUG, or 596 LOG, and the rest of the arguments are strings or None. Use 597 getLevelName(level) to get a printable name for the log level. 598 @type func: a callable function 599 600 @raises ValueError: if func is not registered 601 """ 602 _log_handlers.remove(func)
603 604
605 -def removeLimitedLogHandler(func):
606 """ 607 Remove a registered limited log handler. 608 609 @param func: a function object with prototype (level, object, category, 610 message) where level is either ERROR, WARN, INFO, DEBUG, or 611 LOG, and the rest of the arguments are strings or None. Use 612 getLevelName(level) to get a printable name for the log level. 613 @type func: a callable function 614 615 @raises ValueError: if func is not registered 616 """ 617 _log_handlers_limited.remove(func)
618 619 # public log functions 620 621
622 -def error(cat, format, *args):
623 errorObject(None, cat, format, *args)
624 625
626 -def warning(cat, format, *args):
627 warningObject(None, cat, format, *args)
628 629
630 -def info(cat, format, *args):
631 infoObject(None, cat, format, *args)
632 633
634 -def debug(cat, format, *args):
635 debugObject(None, cat, format, *args)
636 637
638 -def log(cat, format, *args):
639 logObject(None, cat, format, *args)
640 641 # public utility functions 642 643
644 -def getExceptionMessage(exception, frame=-1, filename=None):
645 """ 646 Return a short message based on an exception, useful for debugging. 647 Tries to find where the exception was triggered. 648 """ 649 stack = traceback.extract_tb(sys.exc_info()[2]) 650 if filename: 651 stack = [f for f in stack if f[0].find(filename) > -1] 652 653 # badly raised exceptions can come without a stack 654 if stack: 655 (filename, line, func, text) = stack[frame] 656 else: 657 (filename, line, func, text) = ('no stack', 0, 'none', '') 658 659 filename = scrubFilename(filename) 660 exc = exception.__class__.__name__ 661 msg = "" 662 # a shortcut to extract a useful message out of most exceptions 663 # for now 664 if str(exception): 665 msg = ": %s" % str(exception) 666 return "exception %(exc)s at %(filename)s:%(line)s: %(func)s()%(msg)s" \ 667 % locals()
668 669
670 -def reopenOutputFiles():
671 """ 672 Reopens the stdout and stderr output files, as set by 673 L{outputToFiles}. 674 """ 675 if not _stdout and not _stderr: 676 debug('log', 'told to reopen log files, but log files not set') 677 return 678 679 def reopen(name, fileno, *args): 680 oldmask = os.umask(0026) 681 try: 682 f = open(name, 'a+', *args) 683 finally: 684 os.umask(oldmask) 685 686 os.dup2(f.fileno(), fileno)
687 688 if _stdout: 689 reopen(_stdout, sys.stdout.fileno()) 690 691 if _stderr: 692 reopen(_stderr, sys.stderr.fileno(), 0) 693 debug('log', 'opened log %r', _stderr) 694 695
696 -def outputToFiles(stdout=None, stderr=None):
697 """ 698 Redirect stdout and stderr to named files. 699 700 Records the file names so that a future call to reopenOutputFiles() 701 can open the same files. Installs a SIGHUP handler that will reopen 702 the output files. 703 704 Note that stderr is opened unbuffered, so if it shares a file with 705 stdout then interleaved output may not appear in the order that you 706 expect. 707 """ 708 global _stdout, _stderr, _old_hup_handler 709 _stdout, _stderr = stdout, stderr 710 reopenOutputFiles() 711 712 def sighup(signum, frame): 713 info('log', "Received SIGHUP, reopening logs") 714 reopenOutputFiles() 715 if _old_hup_handler: 716 info('log', "Calling old SIGHUP hander") 717 _old_hup_handler(signum, frame)
718 719 try: 720 import signal 721 except ImportError: 722 debug('log', 'POSIX signals not supported, unable to install' 723 ' SIGHUP handler') 724 else: 725 debug('log', 'installing SIGHUP handler') 726 handler = signal.signal(signal.SIGHUP, sighup) 727 if handler == signal.SIG_DFL or handler == signal.SIG_IGN: 728 _old_hup_handler = None 729 else: 730 _old_hup_handler = handler 731 732 733 # base class for loggable objects 734 735
736 -class Loggable:
737 """ 738 Base class for objects that want to be able to log messages with 739 different level of severity. The levels are, in order from least 740 to most: log, debug, info, warning, error. 741 742 @cvar logCategory: Implementors can provide a category to log their 743 messages under. 744 """ 745 746 logCategory = 'default' 747
748 - def writeMarker(self, marker, level):
749 """ 750 Sets a marker that written to the logs. Setting this 751 marker to multiple elements at a time helps debugging. 752 @param marker: A string write to the log. 753 @type marker: str 754 @param level: The log level. It can be log.WARN, log.INFO, 755 log.DEBUG, log.ERROR or log.LOG. 756 @type level: int 757 """ 758 # errorObject specifically raises, so treat it specially 759 if level == ERROR: 760 self.error('%s', marker) 761 762 doLog(level, self.logObjectName(), self.logCategory, '%s', marker)
763
764 - def error(self, *args):
765 """Log an error. By default this will also raise an exception.""" 766 if _canShortcutLogging(self.logCategory, ERROR): 767 return 768 errorObject(self.logObjectName(), self.logCategory, 769 *self.logFunction(*args))
770
771 - def warning(self, *args):
772 """Log a warning. Used for non-fatal problems.""" 773 if _canShortcutLogging(self.logCategory, WARN): 774 return 775 warningObject(self.logObjectName(), self.logCategory, 776 *self.logFunction(*args))
777
778 - def info(self, *args):
779 """Log an informational message. Used for normal operation.""" 780 if _canShortcutLogging(self.logCategory, INFO): 781 return 782 infoObject(self.logObjectName(), self.logCategory, 783 *self.logFunction(*args))
784
785 - def debug(self, *args):
786 """Log a debug message. Used for debugging.""" 787 if _canShortcutLogging(self.logCategory, DEBUG): 788 return 789 debugObject(self.logObjectName(), self.logCategory, 790 *self.logFunction(*args))
791
792 - def log(self, *args):
793 """Log a log message. Used for debugging recurring events.""" 794 if _canShortcutLogging(self.logCategory, LOG): 795 return 796 logObject(self.logObjectName(), self.logCategory, 797 *self.logFunction(*args))
798
799 - def doLog(self, level, where, format, *args, **kwargs):
800 """ 801 Log a message at the given level, with the possibility of going 802 higher up in the stack. 803 804 @param level: log level 805 @type level: int 806 @param where: how many frames to go back from the last log frame; 807 or a function (to log for a future call) 808 @type where: int (negative), or function 809 810 @param kwargs: a dict of pre-calculated values from a previous 811 doLog call 812 813 @return: a dict of calculated variables, to be reused in a 814 call to doLog that should show the same location 815 @rtype: dict 816 """ 817 if _canShortcutLogging(self.logCategory, level): 818 return {} 819 args = self.logFunction(*args) 820 return doLog(level, self.logObjectName(), self.logCategory, 821 format, args, where=where, **kwargs)
822
823 - def warningFailure(self, failure, swallow=True):
824 """ 825 Log a warning about a Twisted Failure. Useful as an errback handler: 826 d.addErrback(self.warningFailure) 827 828 @param swallow: whether to swallow the failure or not 829 @type swallow: bool 830 """ 831 if _canShortcutLogging(self.logCategory, WARN): 832 if swallow: 833 return 834 return failure 835 warningObject(self.logObjectName(), self.logCategory, 836 *self.logFunction(getFailureMessage(failure))) 837 if not swallow: 838 return failure
839
840 - def logFunction(self, *args):
841 """Overridable log function. Default just returns passed message.""" 842 return args
843
844 - def logObjectName(self):
845 """Overridable object name function.""" 846 # cheat pychecker 847 for name in ['logName', 'name']: 848 if hasattr(self, name): 849 return getattr(self, name) 850 851 return None
852 853 # Twisted helper stuff 854 855 # private stuff 856 _initializedTwisted = False 857 858 # make a singleton 859 __theTwistedLogObserver = None 860 861
862 -def _getTheTwistedLogObserver():
863 # used internally and in test 864 global __theTwistedLogObserver 865 866 if not __theTwistedLogObserver: 867 __theTwistedLogObserver = TwistedLogObserver() 868 869 return __theTwistedLogObserver
870 871 872 # public helper methods 873 874
875 -def getFailureMessage(failure):
876 """ 877 Return a short message based on L{twisted.python.failure.Failure}. 878 Tries to find where the exception was triggered. 879 """ 880 exc = str(failure.type) 881 msg = failure.getErrorMessage() 882 if len(failure.frames) == 0: 883 return "failure %(exc)s: %(msg)s" % locals() 884 885 (func, filename, line, some, other) = failure.frames[-1] 886 filename = scrubFilename(filename) 887 return "failure %(exc)s at %(filename)s:%(line)s: %(func)s(): %(msg)s" \ 888 % locals()
889 890
891 -def warningFailure(failure, swallow=True):
892 """ 893 Log a warning about a Failure. Useful as an errback handler: 894 d.addErrback(warningFailure) 895 896 @param swallow: whether to swallow the failure or not 897 @type swallow: bool 898 """ 899 warning('', getFailureMessage(failure)) 900 if not swallow: 901 return failure
902 903
904 -def logTwisted():
905 """ 906 Integrate twisted's logger with our logger. 907 908 This is done in a separate method because calling this imports and sets 909 up a reactor. Since we want basic logging working before choosing a 910 reactor, we need to separate these. 911 """ 912 global _initializedTwisted 913 914 if _initializedTwisted: 915 return 916 917 debug('log', 'Integrating twisted logger') 918 919 # integrate twisted's logging with us 920 from twisted.python import log as tlog 921 922 # this call imports the reactor 923 # that is why we do this in a separate method 924 from twisted.spread import pb 925 926 # we don't want logs for pb.Error types since they 927 # are specifically raised to be handled on the other side 928 observer = _getTheTwistedLogObserver() 929 observer.ignoreErrors([pb.Error, ]) 930 tlog.startLoggingWithObserver(observer.emit, False) 931 932 _initializedTwisted = True
933 934 935 # we need an object as the observer because startLoggingWithObserver 936 # expects a bound method 937 938
939 -class TwistedLogObserver(Loggable):
940 """ 941 Twisted log observer that integrates with our logging. 942 """ 943 logCategory = "logobserver" 944
945 - def __init__(self):
946 self._ignoreErrors = [] # Failure types
947
948 - def emit(self, eventDict):
949 method = log # by default, lowest level 950 edm = eventDict['message'] 951 if not edm: 952 if eventDict['isError'] and 'failure' in eventDict: 953 f = eventDict['failure'] 954 for failureType in self._ignoreErrors: 955 r = f.check(failureType) 956 if r: 957 self.debug("Failure of type %r, ignoring" % 958 failureType) 959 return 960 961 self.log("Failure %r" % f) 962 963 method = debug # tracebacks from errors at debug level 964 msg = "A twisted traceback occurred." 965 if getCategoryLevel("twisted") < WARN: 966 msg += " Run with debug level >= 2 to see the traceback." 967 # and an additional warning 968 warning('twisted', msg) 969 text = f.getTraceback() 970 safeprintf(sys.stderr, "\nTwisted traceback:\n") 971 safeprintf(sys.stderr, text + '\n') 972 elif 'format' in eventDict: 973 text = eventDict['format'] % eventDict 974 else: 975 # we don't know how to log this 976 return 977 else: 978 text = ' '.join(map(str, edm)) 979 980 msgStr = " [%(system)s] %(text)s\n" % { 981 'system': eventDict['system'], 982 'text': text.replace("\n", "\n\t")} 983 # because msgstr can contain %, as in a backtrace, make sure we 984 # don't try to splice it 985 method('twisted', msgStr)
986
987 - def ignoreErrors(self, *types):
988 for failureType in types: 989 self._ignoreErrors.append(failureType)
990
991 - def clearIgnores(self):
992 self._ignoreErrors = []
993 994
995 -def logLevelToStdLevel(level):
996 t = {ERROR: logging.CRITICAL, 997 WARN: logging.ERROR, 998 INFO: logging.WARNING, 999 DEBUG: logging.INFO, 1000 LOG: logging.DEBUG} 1001 return t.get(level, logging.NOTSET)
1002 1003
1004 -def stdLevelToLogLevel(level):
1005 t = {logging.CRITICAL: ERROR, 1006 logging.ERROR: WARN, 1007 logging.WARNING: INFO, 1008 logging.INFO: DEBUG, 1009 logging.DEBUG: LOG} 1010 return t.get(level, None)
1011 1012
1013 -def adaptStandardLogging(loggerName, logCategory, targetModule):
1014 """ 1015 Make a logger from the standard library log through the Flumotion logging 1016 system. 1017 1018 @param loggerName: The standard logger to adapt, e.g. 'library.module' 1019 @type loggerName: str 1020 @param logCategory: The Flumotion log category to use when reporting output 1021 from the standard logger, e.g. 'librarymodule' 1022 @type logCategory: str 1023 @param targetModule: The name of the module that the logging should look 1024 like it's coming from. Use this if you don't want to 1025 see the file names and line numbers of the library 1026 who's logger you are adapting. 1027 @type targetModule: str or None 1028 """ 1029 logger = logging.getLogger(loggerName) 1030 # if there is already a FluHandler, exit 1031 if map(lambda h: isinstance(h, LogHandler), logger.handlers): 1032 return 1033 logger.setLevel(logLevelToStdLevel(getCategoryLevel(logCategory))) 1034 logger.addHandler(LogHandler(logCategory, targetModule))
1035 1036
1037 -class LogHandler(logging.Handler):
1038 """ 1039 A standard library logging handler that logs through the log system of this 1040 module. 1041 """ 1042
1043 - def __init__(self, logCategory, targetModule):
1044 logging.Handler.__init__(self) 1045 self.logCategory = logCategory 1046 self.targetModule = targetModule
1047
1048 - def emit(self, record):
1049 level = stdLevelToLogLevel(record.levelno) 1050 if _canShortcutLogging(self.logCategory, level): 1051 return 1052 1053 filename, lineno = getFileLine(-1, self.targetModule) 1054 doLog(level, None, self.logCategory, 1055 self.format(record), None, 0, 1056 scrubFilename(filename), lineno)
1057