[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 <<')]) |
---|