| [3] | 1 | """ | 
|---|
|  | 2 | This plugin captures logging statements issued during test execution. When an | 
|---|
|  | 3 | error or failure occurs, the captured log messages are attached to the running | 
|---|
|  | 4 | test in the test.capturedLogging attribute, and displayed with the error failure | 
|---|
|  | 5 | output. It is enabled by default but can be turned off with the option | 
|---|
|  | 6 | ``--nologcapture``. | 
|---|
|  | 7 |  | 
|---|
|  | 8 | You can filter captured logging statements with the ``--logging-filter`` option. | 
|---|
|  | 9 | If set, it specifies which logger(s) will be captured; loggers that do not match | 
|---|
|  | 10 | will be passed. Example: specifying ``--logging-filter=sqlalchemy,myapp`` | 
|---|
|  | 11 | will ensure that only statements logged via sqlalchemy.engine, myapp | 
|---|
|  | 12 | or myapp.foo.bar logger will be logged. | 
|---|
|  | 13 |  | 
|---|
|  | 14 | You can remove other installed logging handlers with the | 
|---|
|  | 15 | ``--logging-clear-handlers`` option. | 
|---|
|  | 16 | """ | 
|---|
|  | 17 |  | 
|---|
|  | 18 | import logging | 
|---|
|  | 19 | from logging.handlers import BufferingHandler | 
|---|
|  | 20 |  | 
|---|
|  | 21 | from nose.plugins.base import Plugin | 
|---|
|  | 22 | from nose.util import ln, safe_str | 
|---|
|  | 23 |  | 
|---|
|  | 24 | try: | 
|---|
|  | 25 | from cStringIO import StringIO | 
|---|
|  | 26 | except ImportError: | 
|---|
|  | 27 | from StringIO import StringIO | 
|---|
|  | 28 |  | 
|---|
|  | 29 | log = logging.getLogger(__name__) | 
|---|
|  | 30 |  | 
|---|
|  | 31 |  | 
|---|
|  | 32 | class MyMemoryHandler(BufferingHandler): | 
|---|
|  | 33 | def __init__(self, capacity, logformat, logdatefmt, filters): | 
|---|
|  | 34 | BufferingHandler.__init__(self, capacity) | 
|---|
|  | 35 | fmt = logging.Formatter(logformat, logdatefmt) | 
|---|
|  | 36 | self.setFormatter(fmt) | 
|---|
|  | 37 | self.filters = filters | 
|---|
|  | 38 | def flush(self): | 
|---|
|  | 39 | pass # do nothing | 
|---|
|  | 40 | def truncate(self): | 
|---|
|  | 41 | self.buffer = [] | 
|---|
|  | 42 | def filter(self, record): | 
|---|
|  | 43 | """Our custom record filtering logic. | 
|---|
|  | 44 |  | 
|---|
|  | 45 | Built-in filtering logic (via logging.Filter) is too limiting. | 
|---|
|  | 46 | """ | 
|---|
|  | 47 | if not self.filters: | 
|---|
|  | 48 | return True | 
|---|
|  | 49 | matched = False | 
|---|
|  | 50 | rname = record.name # shortcut | 
|---|
|  | 51 | for name in self.filters: | 
|---|
|  | 52 | if rname == name or rname.startswith(name+'.'): | 
|---|
|  | 53 | matched = True | 
|---|
|  | 54 | return matched | 
|---|
|  | 55 |  | 
|---|
|  | 56 |  | 
|---|
|  | 57 | class LogCapture(Plugin): | 
|---|
|  | 58 | """ | 
|---|
|  | 59 | Log capture plugin. Enabled by default. Disable with --nologcapture. | 
|---|
|  | 60 | This plugin captures logging statements issued during test execution, | 
|---|
|  | 61 | appending any output captured to the error or failure output, | 
|---|
|  | 62 | should the test fail or raise an error. | 
|---|
|  | 63 | """ | 
|---|
|  | 64 | enabled = True | 
|---|
|  | 65 | env_opt = 'NOSE_NOLOGCAPTURE' | 
|---|
|  | 66 | name = 'logcapture' | 
|---|
|  | 67 | score = 500 | 
|---|
|  | 68 | logformat = '%(name)s: %(levelname)s: %(message)s' | 
|---|
|  | 69 | logdatefmt = None | 
|---|
|  | 70 | clear = False | 
|---|
|  | 71 | filters = [] | 
|---|
|  | 72 |  | 
|---|
|  | 73 | def options(self, parser, env): | 
|---|
|  | 74 | """Register commandline options. | 
|---|
|  | 75 | """ | 
|---|
|  | 76 | parser.add_option( | 
|---|
|  | 77 | "--nologcapture", action="store_false", | 
|---|
|  | 78 | default=not env.get(self.env_opt), dest="logcapture", | 
|---|
|  | 79 | help="Disable logging capture plugin. " | 
|---|
|  | 80 | "Logging configurtion will be left intact." | 
|---|
|  | 81 | " [NOSE_NOLOGCAPTURE]") | 
|---|
|  | 82 | parser.add_option( | 
|---|
|  | 83 | "--logging-format", action="store", dest="logcapture_format", | 
|---|
|  | 84 | default=env.get('NOSE_LOGFORMAT') or self.logformat, | 
|---|
|  | 85 | metavar="FORMAT", | 
|---|
|  | 86 | help="Specify custom format to print statements. " | 
|---|
|  | 87 | "Uses the same format as used by standard logging handlers." | 
|---|
|  | 88 | " [NOSE_LOGFORMAT]") | 
|---|
|  | 89 | parser.add_option( | 
|---|
|  | 90 | "--logging-datefmt", action="store", dest="logcapture_datefmt", | 
|---|
|  | 91 | default=env.get('NOSE_LOGDATEFMT') or self.logdatefmt, | 
|---|
|  | 92 | metavar="FORMAT", | 
|---|
|  | 93 | help="Specify custom date/time format to print statements. " | 
|---|
|  | 94 | "Uses the same format as used by standard logging handlers." | 
|---|
|  | 95 | " [NOSE_LOGDATEFMT]") | 
|---|
|  | 96 | parser.add_option( | 
|---|
|  | 97 | "--logging-filter", action="store", dest="logcapture_filters", | 
|---|
|  | 98 | default=env.get('NOSE_LOGFILTER'), | 
|---|
|  | 99 | metavar="FILTER", | 
|---|
|  | 100 | help="Specify which statements to filter in/out. " | 
|---|
|  | 101 | "By default, everything is captured. If the output is too" | 
|---|
|  | 102 | " verbose,\nuse this option to filter out needless output.\n" | 
|---|
|  | 103 | "Example: filter=foo will capture statements issued ONLY to\n" | 
|---|
|  | 104 | " foo or foo.what.ever.sub but not foobar or other logger.\n" | 
|---|
|  | 105 | "Specify multiple loggers with comma: filter=foo,bar,baz." | 
|---|
|  | 106 | " [NOSE_LOGFILTER]\n") | 
|---|
|  | 107 | parser.add_option( | 
|---|
|  | 108 | "--logging-clear-handlers", action="store_true", | 
|---|
|  | 109 | default=False, dest="logcapture_clear", | 
|---|
|  | 110 | help="Clear all other logging handlers") | 
|---|
|  | 111 |  | 
|---|
|  | 112 | def configure(self, options, conf): | 
|---|
|  | 113 | """Configure plugin. | 
|---|
|  | 114 | """ | 
|---|
|  | 115 | self.conf = conf | 
|---|
|  | 116 | # Disable if explicitly disabled, or if logging is | 
|---|
|  | 117 | # configured via logging config file | 
|---|
|  | 118 | if not options.logcapture or conf.loggingConfig: | 
|---|
|  | 119 | self.enabled = False | 
|---|
|  | 120 | self.logformat = options.logcapture_format | 
|---|
|  | 121 | self.logdatefmt = options.logcapture_datefmt | 
|---|
|  | 122 | self.clear = options.logcapture_clear | 
|---|
|  | 123 | if options.logcapture_filters: | 
|---|
|  | 124 | self.filters = options.logcapture_filters.split(',') | 
|---|
|  | 125 |  | 
|---|
|  | 126 | def setupLoghandler(self): | 
|---|
|  | 127 | # setup our handler with root logger | 
|---|
|  | 128 | root_logger = logging.getLogger() | 
|---|
|  | 129 | if self.clear: | 
|---|
|  | 130 | for logger in logging.Logger.manager.loggerDict.values(): | 
|---|
|  | 131 | if hasattr(logger, "handlers"): | 
|---|
|  | 132 | for handler in logger.handlers: | 
|---|
|  | 133 | logger.removeHandler(handler) | 
|---|
|  | 134 | # make sure there isn't one already | 
|---|
|  | 135 | # you can't simply use "if self.handler not in root_logger.handlers" | 
|---|
|  | 136 | # since at least in unit tests this doesn't work -- | 
|---|
|  | 137 | # LogCapture() is instantiated for each test case while root_logger | 
|---|
|  | 138 | # is module global | 
|---|
|  | 139 | # so we always add new MyMemoryHandler instance | 
|---|
|  | 140 | for handler in root_logger.handlers[:]: | 
|---|
|  | 141 | if isinstance(handler, MyMemoryHandler): | 
|---|
|  | 142 | root_logger.handlers.remove(handler) | 
|---|
|  | 143 | root_logger.addHandler(self.handler) | 
|---|
|  | 144 | # to make sure everything gets captured | 
|---|
|  | 145 | root_logger.setLevel(logging.NOTSET) | 
|---|
|  | 146 |  | 
|---|
|  | 147 | def begin(self): | 
|---|
|  | 148 | """Set up logging handler before test run begins. | 
|---|
|  | 149 | """ | 
|---|
|  | 150 | self.start() | 
|---|
|  | 151 |  | 
|---|
|  | 152 | def start(self): | 
|---|
|  | 153 | self.handler = MyMemoryHandler(1000, self.logformat, self.logdatefmt, | 
|---|
|  | 154 | self.filters) | 
|---|
|  | 155 | self.setupLoghandler() | 
|---|
|  | 156 |  | 
|---|
|  | 157 | def end(self): | 
|---|
|  | 158 | pass | 
|---|
|  | 159 |  | 
|---|
|  | 160 | def beforeTest(self, test): | 
|---|
|  | 161 | """Clear buffers and handlers before test. | 
|---|
|  | 162 | """ | 
|---|
|  | 163 | self.setupLoghandler() | 
|---|
|  | 164 |  | 
|---|
|  | 165 | def afterTest(self, test): | 
|---|
|  | 166 | """Clear buffers after test. | 
|---|
|  | 167 | """ | 
|---|
|  | 168 | self.handler.truncate() | 
|---|
|  | 169 |  | 
|---|
|  | 170 | def formatFailure(self, test, err): | 
|---|
|  | 171 | """Add captured log messages to failure output. | 
|---|
|  | 172 | """ | 
|---|
|  | 173 | return self.formatError(test, err) | 
|---|
|  | 174 |  | 
|---|
|  | 175 | def formatError(self, test, err): | 
|---|
|  | 176 | """Add captured log messages to error output. | 
|---|
|  | 177 | """ | 
|---|
|  | 178 | # logic flow copied from Capture.formatError | 
|---|
|  | 179 | test.capturedLogging = records = self.formatLogRecords() | 
|---|
|  | 180 | if not records: | 
|---|
|  | 181 | return err | 
|---|
|  | 182 | ec, ev, tb = err | 
|---|
|  | 183 | return (ec, self.addCaptureToErr(ev, records), tb) | 
|---|
|  | 184 |  | 
|---|
|  | 185 | def formatLogRecords(self): | 
|---|
|  | 186 | format = self.handler.format | 
|---|
|  | 187 | return [safe_str(format(r)) for r in self.handler.buffer] | 
|---|
|  | 188 |  | 
|---|
|  | 189 | def addCaptureToErr(self, ev, records): | 
|---|
|  | 190 | return '\n'.join([safe_str(ev), ln('>> begin captured logging <<')] + \ | 
|---|
|  | 191 | records + \ | 
|---|
|  | 192 | [ln('>> end captured logging <<')]) | 
|---|