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