Merge lp:~jml/zope.testing/subunit-output-formatter into lp:~vcs-imports/zope.testing/trunk

Proposed by Jonathan Lange
Status: Merged
Merge reported by: Jonathan Lange
Merged at revision: not available
Proposed branch: lp:~jml/zope.testing/subunit-output-formatter
Merge into: lp:~vcs-imports/zope.testing/trunk
Diff against target: 1378 lines (+1270/-5)
8 files modified
.bzrignore (+6/-0)
src/zope/testing/testrunner/formatter.py (+405/-0)
src/zope/testing/testrunner/options.py (+24/-2)
src/zope/testing/testrunner/testrunner-leaks.txt (+3/-3)
src/zope/testing/testrunner/testrunner-subunit-err.txt (+20/-0)
src/zope/testing/testrunner/testrunner-subunit-leaks.txt (+107/-0)
src/zope/testing/testrunner/testrunner-subunit.txt (+678/-0)
src/zope/testing/testrunner/tests.py (+27/-0)
To merge this branch: bzr merge lp:~jml/zope.testing/subunit-output-formatter

Commit message

Add a subunit output formatter to zope.testing.

To post a comment you must log in.
Revision history for this message
Robert Collins (lifeless) wrote :
Download full text (4.0 KiB)

Broad issues:
content and content_type are testtools modules; don't import from subunit, it only has them for compatibility glue.

Perhaps tag tests in layer foo with zope:layer:foo, not zope:testing:foo. In fact it looks like they are, and its simply a docstring bug to claim otherwise.

As subunit has a progress abstraction, the 'cannot support progress' statement confused me. Perhaps say 'cannot support zopes concept of progress because xxx'.

I see you've worked around the bug in subunit where there isn't a tag method on the test result; perhaps you could submit a patch for that ? the contract is(I think) clear, just 'not done'.

194 + Since subunit is a stream protocol format, it has no summary.
perhaps 'no need for a summary - when the stream is displayed a summary can be created then.

What is this?
+ def import_errors(self, import_errors):
221 + """Report test-module import errors (if any)."""
222 + # FIXME: Implement this.
... there is code here

235 + def _exc_info_to_details(self, exc_info):
236 + """Translate 'exc_info' into a details dictionary usable with subunit.
237 + """
238 + import subunit
239 + content_type = subunit.content_type.ContentType(
240 + 'text', 'x-traceback', dict(language='python', charset='utf8'))
241 + formatter = OutputFormatter(None)
242 + traceback = formatter.format_traceback(exc_info)
243 + return {
244 + 'traceback': subunit.content.Content(
245 + content_type, lambda: [traceback.encode('utf8')])}

This might be better as
import testtools.content
test = unittest.TestCase()
content = TracebackContent(exc_info, test)
return {'traceback': content}

unless the formatter.format_traceback(exc_info) is doing something nonobvious (and if it is, perhaps you should mention that. If its doing something nonobvious, then I suggest subclassing testtools.content.Content similarly to testtools.content.TracebackContent.

Also, you might want a global import rather than a scope local.

270 + # XXX: Since the subunit stream is designed for machine reading, we
271 + # should really dump the binary profiler stats here. Sadly, the
272 + # "content" API doesn't support this yet. Instead, we dump the
273 + # stringified version of the stats dict, which is functionally the
274 + # same thing. -- jml, 2010-02-14.
275 + plain_text = subunit.content_type.ContentType(
276 + 'text', 'plain', {'charset': 'utf8'})
277 + details = {
278 + 'profiler-stats': subunit.content.Content(
279 + plain_text, lambda: [unicode(stats.stats).encode('utf8')])}

meta: where some dependency is insufficient, it might be nice to file a bug saying 'please provide X', and then reference the bug in this patch. That way, when your later self returns, they have something to prompt the memory.
That said, I'm not sure what subunit is missing here:
(see application/octet-stream in http://www.rfc-editor.org/rfc/rfc2046.txt for details)
cprofile_type = testtools.content_type.ContentType('application', 'octet-stream', {'type':'cProfile'})
content = testtools.content.Content(cprofile_type, lambda: [bpickle(stats)])
return {'profiler-stats': content}

You can also make the content types attributes on self to avoid calculating them every time; they are 'Value Objec...

Read more...

Revision history for this message
Robert Collins (lifeless) wrote :

Oh, I forgot to mention; for profiling, using bzrlib.lsprof.profile you can get kcachegrind output out really easily; I love it much more than the damaged cProfile output, and it is actually plain text anyway :).

Revision history for this message
Jonathan Lange (jml) wrote :
Download full text (5.0 KiB)

> Broad issues:
...
> As subunit has a progress abstraction, the 'cannot support progress' statement
> confused me. Perhaps say 'cannot support zopes concept of progress because
> xxx'.
>

Changed to:
    # subunit output is designed for computers, so displaying a progress bar
    # isn't helpful.

Which isn't _strictly_ true, since displaying a progress bar might help the humans running the process. The real reason is it's too hard.

> I see you've worked around the bug in subunit where there isn't a tag method
> on the test result; perhaps you could submit a patch for that ? the contract
> is(I think) clear, just 'not done'.
>

...

> 194 + Since subunit is a stream protocol format, it has no summary.
> perhaps 'no need for a summary - when the stream is displayed a summary can be
> created then.
...

Now says:
        Since subunit is a stream protocol format, it has no need for a
        summary. When the stream is finished other tools can generate a
        summary if so desired.

> 235 + def _exc_info_to_details(self, exc_info):
> 236 + """Translate 'exc_info' into a details dictionary usable with
> subunit.
> 237 + """
> 238 + import subunit
> 239 + content_type = subunit.content_type.ContentType(
> 240 + 'text', 'x-traceback', dict(language='python', charset='utf8'))
> 241 + formatter = OutputFormatter(None)
> 242 + traceback = formatter.format_traceback(exc_info)
> 243 + return {
> 244 + 'traceback': subunit.content.Content(
> 245 + content_type, lambda: [traceback.encode('utf8')])}
>
> This might be better as
> import testtools.content
> test = unittest.TestCase()
> content = TracebackContent(exc_info, test)
> return {'traceback': content}
>
> unless the formatter.format_traceback(exc_info) is doing something nonobvious
> (and if it is, perhaps you should mention that. If its doing something
> nonobvious, then I suggest subclassing testtools.content.Content similarly to
> testtools.content.TracebackContent.
>

It's the non-obvious thing. Added this comment:
        # In an ideal world, we'd use the pre-bundled 'TracebackContent' class
        # from testtools. However, 'OutputFormatter' contains special logic to
        # handle errors from doctests, so we have to use that and manually
        # create an object equivalent to an instance of 'TracebackContent'.

> Also, you might want a global import rather than a scope local.
>

Yeah, good point.

I've changed it to be a global import. Note that it's still a soft dependency.

>
> 270 + # XXX: Since the subunit stream is designed for machine reading, we
> 271 + # should really dump the binary profiler stats here. Sadly, the
> 272 + # "content" API doesn't support this yet. Instead, we dump the
> 273 + # stringified version of the stats dict, which is functionally the
> 274 + # same thing. -- jml, 2010-02-14.
> 275 + plain_text = subunit.content_type.ContentType(
> 276 + 'text', 'plain', {'charset': 'utf8'})
> 277 + details = {
> 278 + 'profiler-stats': subunit.content.Content(
> 279 + plain_text, lambda: [unicode(stats.stats).encode('utf8')])}
>
> meta: where some dependency is insuffic...

Read more...

Revision history for this message
Jonathan Lange (jml) wrote :

OK, I think this is ready for landing into trunk. Would appreciate a review and guidance through whatever hoops I must jump through to get this landed.

Revision history for this message
Robert Collins (lifeless) wrote :

On Thu, 2010-03-11 at 20:31 +0000, Jonathan Lange wrote:
> > Broad issues:
> ...
> > As subunit has a progress abstraction, the 'cannot support progress' statement
> > confused me. Perhaps say 'cannot support zopes concept of progress because
> > xxx'.
> >
>
> Changed to:
> # subunit output is designed for computers, so displaying a progress bar
> # isn't helpful.
>
> Which isn't _strictly_ true, since displaying a progress bar might
> help the humans running the process. The real reason is it's too hard.

This still leaves me confused: subunit can fairly easily do a progress
bar, in-process or out-of-process. I was guessing that zopes concept of
progress was strange or something.

> > I think its great you've written docs/tests for this. I worry that they will
> > be fragile because they encode the subunit stream representation, but thats
> > not what you wrote: you wrote some object calls against subunit. I suggest you
> > use the guts from things like subunit-ls, subunit2pyunit, subunit-stats to
> > make your tests be done at the same level as the code wrote: to the object
> > API. This will prevent you having to e.g. include multipart MIME or http
> > chunking in the tests. Specifically I suspect you are really writing smoke
> > tests, and just a stats output will do great for your needs [most of the
> > time].
> >
>
> I suspect you are right. However, at this point I can't be bothered making that change. :)

It's your dime ;)

Let me know of anything I can do to help.

-Rob

377. By Jonathan Lange

Correct versions for testtools and subunit

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== added file '.bzrignore'
2--- .bzrignore 1970-01-01 00:00:00 +0000
3+++ .bzrignore 2010-03-11 22:36:30 +0000
4@@ -0,0 +1,6 @@
5+.installed.cfg
6+bin
7+develop-eggs
8+documentation.txt
9+src/zope.testing.egg-info
10+parts
11
12=== modified file 'src/zope/testing/testrunner/formatter.py'
13--- src/zope/testing/testrunner/formatter.py 2009-12-23 21:21:53 +0000
14+++ src/zope/testing/testrunner/formatter.py 2010-03-11 22:36:30 +0000
15@@ -16,9 +16,12 @@
16 $Id: __init__.py 86207 2008-05-03 13:25:02Z ctheune $
17 """
18
19+from datetime import datetime, timedelta
20 import doctest
21+import os
22 import sys
23 import re
24+import tempfile
25 import traceback
26
27 from zope.testing.exceptions import DocTestFailureException
28@@ -647,3 +650,405 @@
29 else:
30 print self.colorize('exception', line)
31 print
32+
33+
34+class FakeTest(object):
35+ """A fake test object that only has an id."""
36+
37+ failureException = None
38+
39+ def __init__(self, test_id):
40+ self._id = test_id
41+
42+ def id(self):
43+ return self._id
44+
45+
46+# Conditional imports, we don't want zope.testing to have a hard dependency on
47+# subunit.
48+try:
49+ import subunit
50+ from subunit.iso8601 import Utc
51+except ImportError:
52+ subunit = None
53+
54+
55+# testtools is a hard dependency of subunit itself, guarding separately for
56+# richer error messages.
57+try:
58+ from testtools import content
59+except ImportError:
60+ content = None
61+
62+
63+class SubunitOutputFormatter(object):
64+ """A subunit output formatter.
65+
66+ This output formatter generates subunit compatible output (see
67+ https://launchpad.net/subunit). Subunit output is essentially a stream of
68+ results of unit tests. In this formatter, non-test events (such as layer
69+ set up) are encoded as specially tagged tests and summary-generating
70+ methods (such as modules_with_import_problems) deliberately do nothing.
71+
72+ In particular, for a layer 'foo', the fake tests related to layer set up
73+ and tear down are tagged with 'zope:layer' and are called 'foo:setUp' and
74+ 'foo:tearDown'. Any tests within layer 'foo' are tagged with
75+ 'zope:layer:foo'.
76+
77+ Note that all tags specific to this formatter begin with 'zope:'
78+ """
79+
80+ # subunit output is designed for computers, so displaying a progress bar
81+ # isn't helpful.
82+ progress = False
83+ verbose = property(lambda self: self.options.verbose)
84+
85+ TAG_INFO_SUBOPTIMAL = 'zope:info_suboptimal'
86+ TAG_ERROR_WITH_BANNER = 'zope:error_with_banner'
87+ TAG_LAYER = 'zope:layer'
88+ TAG_IMPORT_ERROR = 'zope:import_error'
89+ TAG_PROFILER_STATS = 'zope:profiler_stats'
90+ TAG_GARBAGE = 'zope:garbage'
91+ TAG_THREADS = 'zope:threads'
92+ TAG_REFCOUNTS = 'zope:refcounts'
93+
94+ def __init__(self, options):
95+ if subunit is None:
96+ raise Exception("Requires subunit 0.0.5 or better")
97+ if content is None:
98+ raise Exception("Requires testtools 0.9.2 or better")
99+ self.options = options
100+ self._stream = sys.stdout
101+ self._subunit = subunit.TestProtocolClient(self._stream)
102+ # Used to track the last layer that was set up or torn down. Either
103+ # None or (layer_name, last_touched_time).
104+ self._last_layer = None
105+ self.UTC = Utc()
106+ # Content types used in the output.
107+ self.TRACEBACK_CONTENT_TYPE = content.ContentType(
108+ 'text', 'x-traceback', dict(language='python', charset='utf8'))
109+ self.PROFILE_CONTENT_TYPE = content.ContentType(
110+ 'application', 'x-binary-profile')
111+ self.PLAIN_TEXT = content.ContentType(
112+ 'text', 'plain', {'charset': 'utf8'})
113+
114+ @property
115+ def _time_tests(self):
116+ return self.verbose > 2
117+
118+ def _emit_timestamp(self, now=None):
119+ """Emit a timestamp to the subunit stream.
120+
121+ If 'now' is not specified, use the current time on the system clock.
122+ """
123+ if now is None:
124+ now = datetime.now(self.UTC)
125+ self._subunit.time(now)
126+ return now
127+
128+ def _emit_tag(self, tag):
129+ self._stream.write('tags: %s\n' % (tag,))
130+
131+ def _stop_tag(self, tag):
132+ self._stream.write('tags: -%s\n' % (tag,))
133+
134+ def _emit_fake_test(self, message, tag, details=None):
135+ """Emit a successful fake test to the subunit stream.
136+
137+ Use this to print tagged informative messages.
138+ """
139+ test = FakeTest(message)
140+ self._subunit.startTest(test)
141+ self._emit_tag(tag)
142+ self._subunit.addSuccess(test, details)
143+
144+ def _emit_error(self, error_id, tag, exc_info):
145+ """Emit an error to the subunit stream.
146+
147+ Use this to pass on information about errors that occur outside of
148+ tests.
149+ """
150+ test = FakeTest(error_id)
151+ self._subunit.startTest(test)
152+ self._emit_tag(tag)
153+ self._subunit.addError(test, exc_info)
154+
155+ def info(self, message):
156+ """Print an informative message, but only if verbose."""
157+ # info() output is not relevant to actual test results. It only says
158+ # things like "Running tests" or "Tearing down left over layers",
159+ # things that are communicated already by the subunit stream. Just
160+ # suppress the info() output.
161+ pass
162+
163+ def info_suboptimal(self, message):
164+ """Print an informative message about losing some of the features.
165+
166+ For example, when you run some tests in a subprocess, you lose the
167+ ability to use the debugger.
168+ """
169+ # Used _only_ to indicate running in a subprocess.
170+ self._emit_fake_test(message.strip(), self.TAG_INFO_SUBOPTIMAL)
171+
172+ def error(self, message):
173+ """Report an error."""
174+ # XXX: Mostly used for user errors, sometimes used for errors in the
175+ # test framework, sometimes used to record layer setUp failure (!!!).
176+ # How should this be encoded?
177+ raise NotImplementedError(self.error)
178+
179+ def error_with_banner(self, message):
180+ """Report an error with a big ASCII banner."""
181+ # Either "Could not communicate with subprocess"
182+ # Or "Can't post-mortem debug when running a layer as a subprocess!"
183+ self._emit_fake_test(message, self.TAG_ERROR_WITH_BANNER)
184+
185+ def _enter_layer(self, layer_name):
186+ """Signal in the subunit stream that we are entering a layer."""
187+ self._emit_tag('zope:layer:%s' % (layer_name,))
188+
189+ def _exit_layer(self, layer_name):
190+ """Signal in the subunit stream that we are leaving a layer."""
191+ self._stop_tag('zope:layer:%s' % (layer_name,))
192+
193+ def start_set_up(self, layer_name):
194+ """Report that we're setting up a layer.
195+
196+ We do this by emitting a tag of the form 'layer:$LAYER_NAME'.
197+ """
198+ now = self._emit_timestamp()
199+ self._subunit.startTest(FakeTest('%s:setUp' % (layer_name,)))
200+ self._emit_tag(self.TAG_LAYER)
201+ self._last_layer = (layer_name, now)
202+
203+ def stop_set_up(self, seconds):
204+ layer_name, start_time = self._last_layer
205+ self._last_layer = None
206+ self._emit_timestamp(start_time + timedelta(seconds=seconds))
207+ self._subunit.addSuccess(FakeTest('%s:setUp' % (layer_name,)))
208+ self._enter_layer(layer_name)
209+
210+ def start_tear_down(self, layer_name):
211+ """Report that we're tearing down a layer.
212+
213+ We do this by removing a tag of the form 'layer:$LAYER_NAME'.
214+ """
215+ self._exit_layer(layer_name)
216+ now = self._emit_timestamp()
217+ self._subunit.startTest(FakeTest('%s:tearDown' % (layer_name,)))
218+ self._emit_tag(self.TAG_LAYER)
219+ self._last_layer = (layer_name, now)
220+
221+ def stop_tear_down(self, seconds):
222+ layer_name, start_time = self._last_layer
223+ self._last_layer = None
224+ self._emit_timestamp(start_time + timedelta(seconds=seconds))
225+ self._subunit.addSuccess(FakeTest('%s:tearDown' % (layer_name,)))
226+
227+ def tear_down_not_supported(self):
228+ """Report that we could not tear down a layer.
229+
230+ Should be called right after start_tear_down().
231+ """
232+ layer_name, start_time = self._last_layer
233+ self._last_layer = None
234+ self._emit_timestamp(datetime.now(self.UTC))
235+ self._subunit.addSkip(
236+ FakeTest('%s:tearDown' % (layer_name,)), "tearDown not supported")
237+
238+ def summary(self, n_tests, n_failures, n_errors, n_seconds):
239+ """Print out a summary.
240+
241+ Since subunit is a stream protocol format, it has no need for a
242+ summary. When the stream is finished other tools can generate a
243+ summary if so desired.
244+ """
245+ pass
246+
247+ def start_test(self, test, tests_run, total_tests):
248+ """Report that we're about to run a test.
249+
250+ The next output operation should be test_success(), test_error(), or
251+ test_failure().
252+ """
253+ if self._time_tests:
254+ self._emit_timestamp()
255+ # Note that this always emits newlines, so it will function as well as
256+ # other start_test implementations if we are running in a subprocess.
257+ self._subunit.startTest(test)
258+
259+ def stop_test(self, test):
260+ """Clean up the output state after a test."""
261+ self._subunit.stopTest(test)
262+ self._stream.flush()
263+
264+ def stop_tests(self):
265+ """Clean up the output state after a collection of tests."""
266+ self._stream.flush()
267+
268+ def test_success(self, test, seconds):
269+ if self._time_tests:
270+ self._emit_timestamp()
271+ self._subunit.addSuccess(test)
272+
273+ def import_errors(self, import_errors):
274+ """Report test-module import errors (if any)."""
275+ if not import_errors:
276+ return
277+ for error in import_errors:
278+ self._emit_error(
279+ error.module, self.TAG_IMPORT_ERROR, error.exc_info)
280+
281+ def modules_with_import_problems(self, import_errors):
282+ """Report names of modules with import problems (if any)."""
283+ # This is simply a summary method, and subunit output doesn't benefit
284+ # from summaries.
285+ pass
286+
287+ def _exc_info_to_details(self, exc_info):
288+ """Translate 'exc_info' into a details dictionary usable with subunit.
289+ """
290+ # In an ideal world, we'd use the pre-bundled 'TracebackContent' class
291+ # from testtools. However, 'OutputFormatter' contains special logic to
292+ # handle errors from doctests, so we have to use that and manually
293+ # create an object equivalent to an instance of 'TracebackContent'.
294+ formatter = OutputFormatter(None)
295+ traceback = formatter.format_traceback(exc_info)
296+ return {
297+ 'traceback': content.Content(
298+ self.TRACEBACK_CONTENT_TYPE, lambda: [traceback.encode('utf8')])}
299+
300+ def test_error(self, test, seconds, exc_info):
301+ """Report that an error occurred while running a test.
302+
303+ Should be called right after start_test().
304+
305+ The next output operation should be stop_test().
306+ """
307+ if self._time_tests:
308+ self._emit_timestamp()
309+ details = self._exc_info_to_details(exc_info)
310+ self._subunit.addError(test, details=details)
311+
312+ def test_failure(self, test, seconds, exc_info):
313+ """Report that a test failed.
314+
315+ Should be called right after start_test().
316+
317+ The next output operation should be stop_test().
318+ """
319+ if self._time_tests:
320+ self._emit_timestamp()
321+ details = self._exc_info_to_details(exc_info)
322+ self._subunit.addFailure(test, details=details)
323+
324+ def profiler_stats(self, stats):
325+ """Report profiler stats."""
326+ ignored, filename = tempfile.mkstemp()
327+ try:
328+ stats.dump_stats(filename)
329+ profile_content = content.Content(
330+ self.PROFILE_CONTENT_TYPE, open(filename).read)
331+ details = {'profiler-stats': profile_content}
332+ finally:
333+ os.unlink(filename)
334+ # Name the test 'zope:profiler_stats' just like its tag.
335+ self._emit_fake_test(
336+ self.TAG_PROFILER_STATS, self.TAG_PROFILER_STATS, details)
337+
338+ def tests_with_errors(self, errors):
339+ """Report tests with errors.
340+
341+ Simply not supported by the subunit formatter. Fancy summary output
342+ doesn't make sense.
343+ """
344+ pass
345+
346+ def tests_with_failures(self, failures):
347+ """Report tests with failures.
348+
349+ Simply not supported by the subunit formatter. Fancy summary output
350+ doesn't make sense.
351+ """
352+ pass
353+
354+ def totals(self, n_tests, n_failures, n_errors, n_seconds):
355+ """Summarize the results of all layers.
356+
357+ Simply not supported by the subunit formatter. Fancy summary output
358+ doesn't make sense.
359+ """
360+ pass
361+
362+ def list_of_tests(self, tests, layer_name):
363+ """Report a list of test names."""
364+ self._enter_layer(layer_name)
365+ for test in tests:
366+ self._subunit.startTest(test)
367+ self._subunit.addSuccess(test)
368+ self._exit_layer(layer_name)
369+
370+ def _get_text_details(self, name, text):
371+ """Get a details dictionary that just has some plain text."""
372+ return {
373+ name: content.Content(
374+ self.PLAIN_TEXT, lambda: [text.encode('utf8')])}
375+
376+ def garbage(self, garbage):
377+ """Report garbage generated by tests."""
378+ # XXX: Really, 'garbage', 'profiler_stats' and the 'refcounts' twins
379+ # ought to add extra details to a fake test that represents the
380+ # summary information for the whole suite. However, there's no event
381+ # on output formatters for "everything is really finished, honest". --
382+ # jml, 2010-02-14
383+ details = self._get_text_details('garbage', unicode(garbage))
384+ self._emit_fake_test(
385+ self.TAG_GARBAGE, self.TAG_GARBAGE, details)
386+
387+ def test_garbage(self, test, garbage):
388+ """Report garbage generated by a test.
389+
390+ Encoded in the subunit stream as a test error. Clients can filter out
391+ these tests based on the tag if they don't think garbage should fail
392+ the test run.
393+ """
394+ # XXX: Perhaps 'test_garbage' and 'test_threads' ought to be within
395+ # the output for the actual test, appended as details to whatever
396+ # result the test gets. Not an option with the present API, as there's
397+ # no event for "no more output for this test". -- jml, 2010-02-14
398+ self._subunit.startTest(test)
399+ self._emit_tag(self.TAG_GARBAGE)
400+ self._subunit.addError(
401+ test, self._get_text_details('garbage', unicode(garbage)))
402+
403+ def test_threads(self, test, new_threads):
404+ """Report threads left behind by a test.
405+
406+ Encoded in the subunit stream as a test error. Clients can filter out
407+ these tests based on the tag if they don't think left-over threads
408+ should fail the test run.
409+ """
410+ self._subunit.startTest(test)
411+ self._emit_tag(self.TAG_THREADS)
412+ self._subunit.addError(
413+ test, self._get_text_details('garbage', unicode(new_threads)))
414+
415+ def refcounts(self, rc, prev):
416+ """Report a change in reference counts."""
417+ details = self._get_text_details('sys-refcounts', str(rc))
418+ details.update(
419+ self._get_text_details('changes', str(rc - prev)))
420+ # XXX: Emit the details dict as JSON?
421+ self._emit_fake_test(
422+ self.TAG_REFCOUNTS, self.TAG_REFCOUNTS, details)
423+
424+ def detailed_refcounts(self, track, rc, prev):
425+ """Report a change in reference counts, with extra detail."""
426+ details = self._get_text_details('sys-refcounts', str(rc))
427+ details.update(
428+ self._get_text_details('changes', str(rc - prev)))
429+ details.update(
430+ self._get_text_details('track', str(track.delta)))
431+
432+ self._emit_fake_test(
433+ self.TAG_REFCOUNTS, self.TAG_REFCOUNTS, details)
434
435=== modified file 'src/zope/testing/testrunner/options.py'
436--- src/zope/testing/testrunner/options.py 2009-12-18 08:23:21 +0000
437+++ src/zope/testing/testrunner/options.py 2010-03-11 22:36:30 +0000
438@@ -22,7 +22,11 @@
439 import sys
440
441 from zope.testing.testrunner.profiling import available_profilers
442-from zope.testing.testrunner.formatter import OutputFormatter, ColorfulOutputFormatter
443+from zope.testing.testrunner.formatter import (
444+ OutputFormatter,
445+ ColorfulOutputFormatter,
446+ SubunitOutputFormatter,
447+ )
448 from zope.testing.testrunner.formatter import terminal_has_colors
449
450
451@@ -192,6 +196,12 @@
452 """)
453
454 reporting.add_option(
455+ '--subunit', action="store_true", dest='subunit',
456+ help="""\
457+Use subunit output. Will not be colorized.
458+""")
459+
460+reporting.add_option(
461 '--slow-test', type='float', dest='slow_test_threshold', metavar='N',
462 help="""\
463 With -c and -vvv, highlight tests that take longer than N seconds (default:
464@@ -531,7 +541,19 @@
465 options, positional = parser.parse_args(args[1:], defaults)
466 options.original_testrunner_args = args
467
468- if options.color:
469+ if options.subunit:
470+ try:
471+ import subunit
472+ except ImportError:
473+ print """\
474+ Subunit is not installed. Please install Subunit
475+ to generate subunit output.
476+ """
477+ options.fail = True
478+ return options
479+ else:
480+ options.output = SubunitOutputFormatter(options)
481+ elif options.color:
482 options.output = ColorfulOutputFormatter(options)
483 options.output.slow_test_threshold = options.slow_test_threshold
484 else:
485
486=== modified file 'src/zope/testing/testrunner/testrunner-leaks.txt'
487--- src/zope/testing/testrunner/testrunner-leaks.txt 2008-05-05 18:50:48 +0000
488+++ src/zope/testing/testrunner/testrunner-leaks.txt 2010-03-11 22:36:30 +0000
489@@ -16,7 +16,7 @@
490 >>> from zope.testing import testrunner
491
492 >>> sys.argv = 'test --layer Layer11$ --layer Layer12$ -N4 -r'.split()
493- >>> _ = testrunner.run(defaults)
494+ >>> _ = testrunner.run_internal(defaults)
495 Running samplelayers.Layer11 tests:
496 Set up samplelayers.Layer1 in 0.000 seconds.
497 Set up samplelayers.Layer11 in 0.000 seconds.
498@@ -60,7 +60,7 @@
499 Let's look at an example test that leaks:
500
501 >>> sys.argv = 'test --tests-pattern leak -N4 -r'.split()
502- >>> _ = testrunner.run(defaults)
503+ >>> _ = testrunner.run_internal(defaults)
504 Running zope.testing.testrunner.layer.UnitTests tests:...
505 Iteration 1
506 Ran 1 tests with 0 failures and 0 errors in 0.000 seconds.
507@@ -81,7 +81,7 @@
508 type (or class):
509
510 >>> sys.argv = 'test --tests-pattern leak -N5 -r -v'.split()
511- >>> _ = testrunner.run(defaults)
512+ >>> _ = testrunner.run_internal(defaults)
513 Running tests at level 1
514 Running zope.testing.testrunner.layer.UnitTests tests:...
515 Iteration 1
516
517=== added file 'src/zope/testing/testrunner/testrunner-subunit-err.txt'
518--- src/zope/testing/testrunner/testrunner-subunit-err.txt 1970-01-01 00:00:00 +0000
519+++ src/zope/testing/testrunner/testrunner-subunit-err.txt 2010-03-11 22:36:30 +0000
520@@ -0,0 +1,20 @@
521+Using subunit output without subunit installed
522+==============================================
523+
524+To use the --subunit reporting option, you must have subunit installed. If you
525+do not, you will get an error message:
526+
527+ >>> import os.path, sys
528+ >>> directory_with_tests = os.path.join(this_directory, 'testrunner-ex')
529+ >>> defaults = [
530+ ... '--path', directory_with_tests,
531+ ... '--tests-pattern', '^sampletestsf?$',
532+ ... ]
533+
534+ >>> from zope.testing import testrunner
535+
536+ >>> sys.argv = 'test --subunit'.split()
537+ >>> _ = testrunner.run_internal(defaults)
538+ Subunit is not installed. Please install Subunit
539+ to generate subunit output.
540+ <BLANKLINE>
541
542=== added file 'src/zope/testing/testrunner/testrunner-subunit-leaks.txt'
543--- src/zope/testing/testrunner/testrunner-subunit-leaks.txt 1970-01-01 00:00:00 +0000
544+++ src/zope/testing/testrunner/testrunner-subunit-leaks.txt 2010-03-11 22:36:30 +0000
545@@ -0,0 +1,107 @@
546+Debugging Memory Leaks with subunit output
547+==========================================
548+
549+The --report-refcounts (-r) option can be used with the --repeat (-N)
550+option to detect and diagnose memory leaks. To use this option, you
551+must configure Python with the --with-pydebug option. (On Unix, pass
552+this option to configure and then build Python.)
553+
554+For more detailed documentation, see testrunner-leaks.txt.
555+
556+ >>> import os.path, sys
557+ >>> directory_with_tests = os.path.join(this_directory, 'testrunner-ex')
558+ >>> defaults = [
559+ ... '--path', directory_with_tests,
560+ ... '--tests-pattern', '^sampletestsf?$',
561+ ... ]
562+
563+ >>> from zope.testing import testrunner
564+
565+Each layer is repeated the requested number of times. For each
566+iteration after the first, the system refcount and change in system
567+refcount is shown. The system refcount is the total of all refcount in
568+the system. When a refcount on any object is changed, the system
569+refcount is changed by the same amount. Tests that don't leak show
570+zero changes in system refcount.
571+
572+Let's look at an example test that leaks:
573+
574+ >>> sys.argv = 'test --subunit --tests-pattern leak -N2 -r'.split()
575+ >>> _ = testrunner.run_internal(defaults)
576+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
577+ test: zope.testing.testrunner.layer.UnitTests:setUp
578+ tags: zope:layer
579+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
580+ successful: zope.testing.testrunner.layer.UnitTests:setUp
581+ tags: zope:layer:zope.testing.testrunner.layer.UnitTests
582+ test: leak.TestSomething.testleak
583+ successful: leak.TestSomething.testleak
584+ test: leak.TestSomething.testleak
585+ successful: leak.TestSomething.testleak
586+ test: zope:refcounts
587+ tags: zope:refcounts
588+ successful: zope:refcounts [ multipart
589+ Content-Type: text/plain;charset=utf8
590+ ...
591+ ...\r
592+ <BLANKLINE>
593+ ...\r
594+ <BLANKLINE>
595+ Content-Type: text/plain;charset=utf8
596+ ...
597+ ...\r
598+ <BLANKLINE>
599+ ...\r
600+ <BLANKLINE>
601+ ]
602+ tags: -zope:layer:zope.testing.testrunner.layer.UnitTests
603+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
604+ test: zope.testing.testrunner.layer.UnitTests:tearDown
605+ tags: zope:layer
606+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
607+ successful: zope.testing.testrunner.layer.UnitTests:tearDown
608+
609+Here we see that the system refcount is increasing. If we specify a
610+verbosity greater than one, we can get details broken out by object
611+type (or class):
612+
613+ >>> sys.argv = 'test --subunit --tests-pattern leak -N2 -v -r'.split()
614+ >>> _ = testrunner.run_internal(defaults)
615+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
616+ test: zope.testing.testrunner.layer.UnitTests:setUp
617+ tags: zope:layer
618+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
619+ successful: zope.testing.testrunner.layer.UnitTests:setUp
620+ tags: zope:layer:zope.testing.testrunner.layer.UnitTests
621+ test: leak.TestSomething.testleak
622+ successful: leak.TestSomething.testleak
623+ test: leak.TestSomething.testleak
624+ successful: leak.TestSomething.testleak
625+ test: zope:refcounts
626+ tags: zope:refcounts
627+ successful: zope:refcounts [ multipart
628+ Content-Type: text/plain;charset=utf8
629+ ...
630+ ...\r
631+ <BLANKLINE>
632+ ...\r
633+ <BLANKLINE>
634+ Content-Type: text/plain;charset=utf8
635+ ...
636+ ...\r
637+ <BLANKLINE>
638+ ...\r
639+ <BLANKLINE>
640+ Content-Type: text/plain;charset=utf8
641+ ...
642+ ...\r
643+ <BLANKLINE>
644+ ...
645+ <BLANKLINE>
646+ ]
647+ tags: -zope:layer:zope.testing.testrunner.layer.UnitTests
648+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
649+ test: zope.testing.testrunner.layer.UnitTests:tearDown
650+ tags: zope:layer
651+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
652+ successful: zope.testing.testrunner.layer.UnitTests:tearDown
653
654=== added file 'src/zope/testing/testrunner/testrunner-subunit.txt'
655--- src/zope/testing/testrunner/testrunner-subunit.txt 1970-01-01 00:00:00 +0000
656+++ src/zope/testing/testrunner/testrunner-subunit.txt 2010-03-11 22:36:30 +0000
657@@ -0,0 +1,678 @@
658+Subunit Output
659+==============
660+
661+Subunit is a streaming protocol for interchanging test results. More
662+information can be found at https://launchpad.net/subunit.
663+
664+ >>> import os.path, sys
665+ >>> directory_with_tests = os.path.join(this_directory, 'testrunner-ex')
666+ >>> defaults = [
667+ ... '--path', directory_with_tests,
668+ ... '--tests-pattern', '^sampletestsf?$',
669+ ... ]
670+
671+ >>> from zope.testing import testrunner
672+
673+
674+Basic output
675+------------
676+
677+Subunit output is line-based, with a 'test:' line for the start of each test
678+and a 'successful:' line for each successful test.
679+
680+Zope layer set up and tear down events are represented as tests tagged with
681+'zope:layer'. This allows them to be distinguished from actual tests, provides
682+a place for the layer timing information in the subunit stream and allows us
683+to include error information if necessary.
684+
685+Once the layer is set up, all future tests are tagged with
686+'zope:layer:LAYER_NAME'.
687+
688+ >>> sys.argv = 'test --layer 122 --subunit -t TestNotMuch'.split()
689+ >>> testrunner.run_internal(defaults)
690+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
691+ test: samplelayers.Layer1:setUp
692+ tags: zope:layer
693+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
694+ successful: samplelayers.Layer1:setUp
695+ tags: zope:layer:samplelayers.Layer1
696+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
697+ test: samplelayers.Layer12:setUp
698+ tags: zope:layer
699+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
700+ successful: samplelayers.Layer12:setUp
701+ tags: zope:layer:samplelayers.Layer12
702+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
703+ test: samplelayers.Layer122:setUp
704+ tags: zope:layer
705+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
706+ successful: samplelayers.Layer122:setUp
707+ tags: zope:layer:samplelayers.Layer122
708+ test: sample1.sampletests.test122.TestNotMuch.test_1
709+ successful: sample1.sampletests.test122.TestNotMuch.test_1
710+ test: sample1.sampletests.test122.TestNotMuch.test_2
711+ successful: sample1.sampletests.test122.TestNotMuch.test_2
712+ test: sample1.sampletests.test122.TestNotMuch.test_3
713+ successful: sample1.sampletests.test122.TestNotMuch.test_3
714+ test: sampletests.test122.TestNotMuch.test_1
715+ successful: sampletests.test122.TestNotMuch.test_1
716+ test: sampletests.test122.TestNotMuch.test_2
717+ successful: sampletests.test122.TestNotMuch.test_2
718+ test: sampletests.test122.TestNotMuch.test_3
719+ successful: sampletests.test122.TestNotMuch.test_3
720+ tags: -zope:layer:samplelayers.Layer122
721+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
722+ test: samplelayers.Layer122:tearDown
723+ tags: zope:layer
724+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
725+ successful: samplelayers.Layer122:tearDown
726+ tags: -zope:layer:samplelayers.Layer12
727+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
728+ test: samplelayers.Layer12:tearDown
729+ tags: zope:layer
730+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
731+ successful: samplelayers.Layer12:tearDown
732+ tags: -zope:layer:samplelayers.Layer1
733+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
734+ test: samplelayers.Layer1:tearDown
735+ tags: zope:layer
736+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
737+ successful: samplelayers.Layer1:tearDown
738+ False
739+
740+
741+Timing tests
742+------------
743+
744+When verbosity is high enough, the subunit stream includes timing information
745+for the actual tests, as well as for the layers.
746+
747+ >>> sys.argv = 'test --layer 122 -vvv --subunit -t TestNotMuch'.split()
748+ >>> testrunner.run_internal(defaults)
749+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
750+ test: samplelayers.Layer1:setUp
751+ tags: zope:layer
752+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
753+ successful: samplelayers.Layer1:setUp
754+ tags: zope:layer:samplelayers.Layer1
755+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
756+ test: samplelayers.Layer12:setUp
757+ tags: zope:layer
758+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
759+ successful: samplelayers.Layer12:setUp
760+ tags: zope:layer:samplelayers.Layer12
761+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
762+ test: samplelayers.Layer122:setUp
763+ tags: zope:layer
764+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
765+ successful: samplelayers.Layer122:setUp
766+ tags: zope:layer:samplelayers.Layer122
767+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
768+ test: sample1.sampletests.test122.TestNotMuch.test_1
769+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
770+ successful: sample1.sampletests.test122.TestNotMuch.test_1
771+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
772+ test: sample1.sampletests.test122.TestNotMuch.test_2
773+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
774+ successful: sample1.sampletests.test122.TestNotMuch.test_2
775+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
776+ test: sample1.sampletests.test122.TestNotMuch.test_3
777+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
778+ successful: sample1.sampletests.test122.TestNotMuch.test_3
779+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
780+ test: sampletests.test122.TestNotMuch.test_1
781+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
782+ successful: sampletests.test122.TestNotMuch.test_1
783+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
784+ test: sampletests.test122.TestNotMuch.test_2
785+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
786+ successful: sampletests.test122.TestNotMuch.test_2
787+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
788+ test: sampletests.test122.TestNotMuch.test_3
789+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
790+ successful: sampletests.test122.TestNotMuch.test_3
791+ tags: -zope:layer:samplelayers.Layer122
792+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
793+ test: samplelayers.Layer122:tearDown
794+ tags: zope:layer
795+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
796+ successful: samplelayers.Layer122:tearDown
797+ tags: -zope:layer:samplelayers.Layer12
798+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
799+ test: samplelayers.Layer12:tearDown
800+ tags: zope:layer
801+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
802+ successful: samplelayers.Layer12:tearDown
803+ tags: -zope:layer:samplelayers.Layer1
804+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
805+ test: samplelayers.Layer1:tearDown
806+ tags: zope:layer
807+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
808+ successful: samplelayers.Layer1:tearDown
809+ False
810+
811+
812+Listing tests
813+-------------
814+
815+A subunit stream is a stream of test results, more or less, so the most
816+natural way of listing tests in subunit is to simply emit successful test
817+results without actually running the tests.
818+
819+Note that in this stream, we don't emit fake tests for the layer set up and
820+tear down, because it simply doesn't happen.
821+
822+We also don't include the dependent layers in the stream (in this case Layer1
823+and Layer12), since they are not provided to the reporter.
824+
825+ >>> sys.argv = (
826+ ... 'test --layer 122 --list-tests --subunit -t TestNotMuch').split()
827+ >>> testrunner.run_internal(defaults)
828+ tags: zope:layer:samplelayers.Layer122
829+ test: sample1.sampletests.test122.TestNotMuch.test_1
830+ successful: sample1.sampletests.test122.TestNotMuch.test_1
831+ test: sample1.sampletests.test122.TestNotMuch.test_2
832+ successful: sample1.sampletests.test122.TestNotMuch.test_2
833+ test: sample1.sampletests.test122.TestNotMuch.test_3
834+ successful: sample1.sampletests.test122.TestNotMuch.test_3
835+ test: sampletests.test122.TestNotMuch.test_1
836+ successful: sampletests.test122.TestNotMuch.test_1
837+ test: sampletests.test122.TestNotMuch.test_2
838+ successful: sampletests.test122.TestNotMuch.test_2
839+ test: sampletests.test122.TestNotMuch.test_3
840+ successful: sampletests.test122.TestNotMuch.test_3
841+ tags: -zope:layer:samplelayers.Layer122
842+ False
843+
844+
845+Profiling tests
846+---------------
847+
848+Test suites often cover a lot of code, and the performance of test suites
849+themselves is often a critical part of the development process. Thus, it's
850+good to be able to profile a test run.
851+
852+ >>> sys.argv = (
853+ ... 'test --layer 122 --profile=cProfile --subunit '
854+ ... '-t TestNotMuch').split()
855+ >>> testrunner.run_internal(defaults)
856+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
857+ test: samplelayers.Layer1:setUp
858+ ...
859+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
860+ successful: samplelayers.Layer1:tearDown
861+ test: zope:profiler_stats
862+ tags: zope:profiler_stats
863+ successful: zope:profiler_stats [ multipart
864+ Content-Type: application/x-binary-profile
865+ profiler-stats
866+ ...\r
867+ <BLANKLINE>
868+ ...
869+ <BLANKLINE>
870+ ]
871+ False
872+
873+
874+Errors
875+------
876+
877+Errors are recorded in the subunit stream as MIME-encoded chunks of text.
878+
879+ >>> sys.argv = [
880+ ... 'test', '--subunit' , '--tests-pattern', '^sampletests_e$',
881+ ... ]
882+ >>> testrunner.run_internal(defaults)
883+ time: 2010-02-05 15:27:05.113541Z
884+ test: zope.testing.testrunner.layer.UnitTests:setUp
885+ tags: zope:layer
886+ time: 2010-02-05 15:27:05.113545Z
887+ successful: zope.testing.testrunner.layer.UnitTests:setUp
888+ tags: zope:layer:zope.testing.testrunner.layer.UnitTests
889+ test: sample2.sampletests_e.eek
890+ failure: sample2.sampletests_e.eek [ multipart
891+ Content-Type: text/x-traceback;charset=utf8,language=python
892+ traceback
893+ 4B6\r
894+ <BLANKLINE>
895+ Failed doctest test for sample2.sampletests_e.eek
896+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 29, in eek
897+ <BLANKLINE>
898+ ----------------------------------------------------------------------
899+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 31, in sample2.sampletests_e.eek
900+ Failed example:
901+ f()
902+ Exception raised:
903+ Traceback (most recent call last):
904+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/doctest/__init__.py", line 1355, in __run
905+ compileflags, 1) in test.globs
906+ File "<doctest sample2.sampletests_e.eek[line 2, example 0]>", line 1, in <module>
907+ f()
908+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 19, in f
909+ g()
910+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 25, in g
911+ x = y + 1
912+ - __traceback_info__: I don't know what Y should be.
913+ NameError: global name 'y' is not defined
914+ 0\r
915+ <BLANKLINE>
916+ ]
917+ test: sample2.sampletests_e.Test.test1
918+ successful: sample2.sampletests_e.Test.test1
919+ test: sample2.sampletests_e.Test.test2
920+ successful: sample2.sampletests_e.Test.test2
921+ test: sample2.sampletests_e.Test.test3
922+ error: sample2.sampletests_e.Test.test3 [ multipart
923+ Content-Type: text/x-traceback;charset=utf8,language=python
924+ traceback
925+ 29F\r
926+ <BLANKLINE>
927+ Traceback (most recent call last):
928+ File "/usr/lib/python2.6/unittest.py", line 279, in run
929+ testMethod()
930+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 44, in test3
931+ f()
932+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 19, in f
933+ g()
934+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/sampletests_e.py", line 25, in g
935+ x = y + 1
936+ - __traceback_info__: I don't know what Y should be.
937+ NameError: global name 'y' is not defined
938+ 0\r
939+ <BLANKLINE>
940+ ]
941+ test: sample2.sampletests_e.Test.test4
942+ successful: sample2.sampletests_e.Test.test4
943+ test: sample2.sampletests_e.Test.test5
944+ successful: sample2.sampletests_e.Test.test5
945+ test: e_txt
946+ failure: e_txt [
947+ multipart
948+ Content-Type: text/x-traceback;charset=utf8,language=python
949+ traceback
950+ 329\r
951+ <BLANKLINE>
952+ Failed doctest test for e.txt
953+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/e.txt", line 0
954+ <BLANKLINE>
955+ ----------------------------------------------------------------------
956+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample2/e.txt", line 4, in e.txt
957+ Failed example:
958+ f()
959+ Exception raised:
960+ Traceback (most recent call last):
961+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/doctest/__init__.py", line 1355, in __run
962+ compileflags, 1) in test.globs
963+ File "<doctest e.txt[line 4, example 1]>", line 1, in <module>
964+ f()
965+ File "<doctest e.txt[line 1, example 0]>", line 2, in f
966+ return x
967+ NameError: global name 'x' is not defined
968+ 0\r
969+ <BLANKLINE>
970+ ]
971+ tags: -zope:layer:zope.testing.testrunner.layer.UnitTests
972+ time: 2010-02-05 15:27:05.147082Z
973+ test: zope.testing.testrunner.layer.UnitTests:tearDown
974+ tags: zope:layer
975+ time: 2010-02-05 15:27:05.147088Z
976+ successful: zope.testing.testrunner.layer.UnitTests:tearDown
977+ True
978+
979+
980+Layers that can't be torn down
981+------------------------------
982+
983+A layer can have a tearDown method that raises NotImplementedError. If this is
984+the case and there are no remaining tests to run, the subunit stream will say
985+that the layer skipped its tearDown.
986+
987+ >>> import os.path, sys
988+ >>> directory_with_tests = os.path.join(this_directory, 'testrunner-ex')
989+ >>> from zope.testing import testrunner
990+ >>> defaults = [
991+ ... '--subunit',
992+ ... '--path', directory_with_tests,
993+ ... '--tests-pattern', '^sampletestsf?$',
994+ ... ]
995+
996+ >>> sys.argv = 'test -ssample2 --tests-pattern sampletests_ntd$'.split()
997+ >>> testrunner.run_internal(defaults)
998+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
999+ test: sample2.sampletests_ntd.Layer:setUp
1000+ tags: zope:layer
1001+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1002+ successful: sample2.sampletests_ntd.Layer:setUp
1003+ tags: zope:layer:sample2.sampletests_ntd.Layer
1004+ test: sample2.sampletests_ntd.TestSomething.test_something
1005+ successful: sample2.sampletests_ntd.TestSomething.test_something
1006+ tags: -zope:layer:sample2.sampletests_ntd.Layer
1007+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1008+ test: sample2.sampletests_ntd.Layer:tearDown
1009+ tags: zope:layer
1010+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1011+ skip: sample2.sampletests_ntd.Layer:tearDown [
1012+ tearDown not supported
1013+ ]
1014+ False
1015+
1016+
1017+Module import errors
1018+--------------------
1019+
1020+We report module import errors too. They get encoded as tests with errors. The
1021+name of the test is the module that could not be imported, the test's result
1022+is an error containing the traceback. These "tests" are tagged with
1023+zope:import_error.
1024+
1025+Let's create a module with some bad syntax:
1026+
1027+ >>> badsyntax_path = os.path.join(directory_with_tests,
1028+ ... "sample2", "sampletests_i.py")
1029+ >>> f = open(badsyntax_path, "w")
1030+ >>> print >> f, "importx unittest" # syntax error
1031+ >>> f.close()
1032+
1033+And then run the tests:
1034+
1035+ >>> sys.argv = (
1036+ ... 'test --subunit --tests-pattern ^sampletests(f|_i)?$ --layer 1 '
1037+ ... ).split()
1038+ >>> testrunner.run_internal(defaults)
1039+ test: sample2.sampletests_i
1040+ tags: zope:import_error
1041+ error: sample2.sampletests_i [
1042+ Traceback (most recent call last):
1043+ testrunner-ex/sample2/sampletests_i.py", line 1
1044+ importx unittest
1045+ ^
1046+ SyntaxError: invalid syntax
1047+ ]
1048+ test: sample2.sample21.sampletests_i
1049+ tags: zope:import_error
1050+ error: sample2.sample21.sampletests_i [
1051+ Traceback (most recent call last):
1052+ testrunner-ex/sample2/sample21/sampletests_i.py", Line NNN, in ?
1053+ import zope.testing.huh
1054+ ImportError: No module named huh
1055+ ]
1056+ test: sample2.sample23.sampletests_i
1057+ tags: zope:import_error
1058+ error: sample2.sample23.sampletests_i [
1059+ Traceback (most recent call last):
1060+ testrunner-ex/sample2/sample23/sampletests_i.py", Line NNN, in ?
1061+ class Test(unittest.TestCase):
1062+ testrunner-ex/sample2/sample23/sampletests_i.py", Line NNN, in Test
1063+ raise TypeError('eek')
1064+ TypeError: eek
1065+ ]
1066+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1067+ test: samplelayers.Layer1:setUp
1068+ tags: zope:layer
1069+ ...
1070+ True
1071+
1072+Of course, because we care deeply about test isolation, we're going to have to
1073+delete the module with bad syntax now, lest it contaminate other tests or even
1074+future test runs.
1075+
1076+ >>> os.unlink(badsyntax_path)
1077+
1078+
1079+Tests in subprocesses
1080+---------------------
1081+
1082+If the tearDown method raises NotImplementedError and there are remaining
1083+layers to run, the test runner will restart itself as a new process,
1084+resuming tests where it left off:
1085+
1086+ >>> sys.argv = [testrunner_script, '--tests-pattern', 'sampletests_ntd$']
1087+ >>> testrunner.run_internal(defaults)
1088+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1089+ test: sample1.sampletests_ntd.Layer:setUp
1090+ tags: zope:layer
1091+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1092+ successful: sample1.sampletests_ntd.Layer:setUp
1093+ tags: zope:layer:sample1.sampletests_ntd.Layer
1094+ test: sample1.sampletests_ntd.TestSomething.test_something
1095+ successful: sample1.sampletests_ntd.TestSomething.test_something
1096+ tags: -zope:layer:sample1.sampletests_ntd.Layer
1097+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1098+ test: sample1.sampletests_ntd.Layer:tearDown
1099+ tags: zope:layer
1100+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1101+ skip: sample1.sampletests_ntd.Layer:tearDown [
1102+ tearDown not supported
1103+ ]
1104+ test: Running in a subprocess.
1105+ tags: zope:info_suboptimal
1106+ successful: Running in a subprocess.
1107+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1108+ test: sample2.sampletests_ntd.Layer:setUp
1109+ tags: zope:layer
1110+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1111+ successful: sample2.sampletests_ntd.Layer:setUp
1112+ tags: zope:layer:sample2.sampletests_ntd.Layer
1113+ test: sample2.sampletests_ntd.TestSomething.test_something
1114+ successful: sample2.sampletests_ntd.TestSomething.test_something
1115+ tags: -zope:layer:sample2.sampletests_ntd.Layer
1116+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1117+ test: sample2.sampletests_ntd.Layer:tearDown
1118+ tags: zope:layer
1119+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1120+ skip: sample2.sampletests_ntd.Layer:tearDown [
1121+ tearDown not supported
1122+ ]
1123+ test: Running in a subprocess.
1124+ tags: zope:info_suboptimal
1125+ successful: Running in a subprocess.
1126+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1127+ test: sample3.sampletests_ntd.Layer:setUp
1128+ tags: zope:layer
1129+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1130+ successful: sample3.sampletests_ntd.Layer:setUp
1131+ tags: zope:layer:sample3.sampletests_ntd.Layer
1132+ test: sample3.sampletests_ntd.TestSomething.test_error1
1133+ error: sample3.sampletests_ntd.TestSomething.test_error1 [ multipart
1134+ Content-Type: text/x-traceback;charset=utf8,language=python
1135+ traceback
1136+ 14F\r
1137+ <BLANKLINE>
1138+ Traceback (most recent call last):
1139+ testrunner-ex/sample3/sampletests_ntd.py", Line NNN, in test_error1
1140+ raise TypeError("Can we see errors")
1141+ TypeError: Can we see errors
1142+ 0\r
1143+ <BLANKLINE>
1144+ ]
1145+ test: sample3.sampletests_ntd.TestSomething.test_error2
1146+ error: sample3.sampletests_ntd.TestSomething.test_error2 [ multipart
1147+ Content-Type: text/x-traceback;charset=utf8,language=python
1148+ traceback
1149+ 13F\r
1150+ <BLANKLINE>
1151+ Traceback (most recent call last):
1152+ testrunner-ex/sample3/sampletests_ntd.py", Line NNN, in test_error2
1153+ raise TypeError("I hope so")
1154+ TypeError: I hope so
1155+ 0\r
1156+ <BLANKLINE>
1157+ ]
1158+ test: sample3.sampletests_ntd.TestSomething.test_fail1
1159+ failure: sample3.sampletests_ntd.TestSomething.test_fail1 [ multipart
1160+ Content-Type: text/x-traceback;charset=utf8,language=python
1161+ traceback
1162+ 1AA\r
1163+ <BLANKLINE>
1164+ Traceback (most recent call last):
1165+ testrunner-ex/sample3/sampletests_ntd.py", Line NNN, in test_fail1
1166+ self.assertEqual(1, 2)
1167+ AssertionError: 1 != 2
1168+ 0\r
1169+ <BLANKLINE>
1170+ ]
1171+ test: sample3.sampletests_ntd.TestSomething.test_fail2
1172+ failure: sample3.sampletests_ntd.TestSomething.test_fail2 [ multipart
1173+ Content-Type: text/x-traceback;charset=utf8,language=python
1174+ traceback
1175+ 1AA\r
1176+ <BLANKLINE>
1177+ Traceback (most recent call last):
1178+ testrunner-ex/sample3/sampletests_ntd.py", Line NNN, in test_fail2
1179+ self.assertEqual(1, 3)
1180+ AssertionError: 1 != 3
1181+ 0\r
1182+ <BLANKLINE>
1183+ ]
1184+ test: sample3.sampletests_ntd.TestSomething.test_something
1185+ successful: sample3.sampletests_ntd.TestSomething.test_something
1186+ test: sample3.sampletests_ntd.TestSomething.test_something_else
1187+ successful: sample3.sampletests_ntd.TestSomething.test_something_else
1188+ tags: -zope:layer:sample3.sampletests_ntd.Layer
1189+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1190+ test: sample3.sampletests_ntd.Layer:tearDown
1191+ tags: zope:layer
1192+ time: YYYY-MM-DD HH:MM:SS.mmmmmmZ
1193+ skip: sample3.sampletests_ntd.Layer:tearDown [
1194+ tearDown not supported
1195+ ]
1196+ True
1197+
1198+Note that debugging doesn't work when running tests in a subprocess:
1199+
1200+ >>> sys.argv = [testrunner_script, '--tests-pattern', 'sampletests_ntd$',
1201+ ... '-D', ]
1202+ >>> testrunner.run_internal(defaults)
1203+ time: 2010-02-10 22:41:25.279692Z
1204+ test: sample1.sampletests_ntd.Layer:setUp
1205+ tags: zope:layer
1206+ time: 2010-02-10 22:41:25.279695Z
1207+ successful: sample1.sampletests_ntd.Layer:setUp
1208+ tags: zope:layer:sample1.sampletests_ntd.Layer
1209+ test: sample1.sampletests_ntd.TestSomething.test_something
1210+ successful: sample1.sampletests_ntd.TestSomething.test_something
1211+ tags: -zope:layer:sample1.sampletests_ntd.Layer
1212+ time: 2010-02-10 22:41:25.310078Z
1213+ test: sample1.sampletests_ntd.Layer:tearDown
1214+ tags: zope:layer
1215+ time: 2010-02-10 22:41:25.310171Z
1216+ skip: sample1.sampletests_ntd.Layer:tearDown [
1217+ tearDown not supported
1218+ ]
1219+ test: Running in a subprocess.
1220+ tags: zope:info_suboptimal
1221+ successful: Running in a subprocess.
1222+ time: 2010-02-10 22:41:25.753076Z
1223+ test: sample2.sampletests_ntd.Layer:setUp
1224+ tags: zope:layer
1225+ time: 2010-02-10 22:41:25.753079Z
1226+ successful: sample2.sampletests_ntd.Layer:setUp
1227+ tags: zope:layer:sample2.sampletests_ntd.Layer
1228+ test: sample2.sampletests_ntd.TestSomething.test_something
1229+ successful: sample2.sampletests_ntd.TestSomething.test_something
1230+ tags: -zope:layer:sample2.sampletests_ntd.Layer
1231+ time: 2010-02-10 22:41:25.779256Z
1232+ test: sample2.sampletests_ntd.Layer:tearDown
1233+ tags: zope:layer
1234+ time: 2010-02-10 22:41:25.779326Z
1235+ skip: sample2.sampletests_ntd.Layer:tearDown [
1236+ tearDown not supported
1237+ ]
1238+ test: Running in a subprocess.
1239+ tags: zope:info_suboptimal
1240+ successful: Running in a subprocess.
1241+ time: 2010-02-10 22:41:26.310296Z
1242+ test: sample3.sampletests_ntd.Layer:setUp
1243+ tags: zope:layer
1244+ time: 2010-02-10 22:41:26.310299Z
1245+ successful: sample3.sampletests_ntd.Layer:setUp
1246+ tags: zope:layer:sample3.sampletests_ntd.Layer
1247+ test: sample3.sampletests_ntd.TestSomething.test_error1
1248+ error: sample3.sampletests_ntd.TestSomething.test_error1 [ multipart
1249+ Content-Type: text/x-traceback;charset=utf8,language=python
1250+ traceback
1251+ 16A\r
1252+ <BLANKLINE>
1253+ Traceback (most recent call last):
1254+ File "/usr/lib/python2.6/unittest.py", line 305, in debug
1255+ getattr(self, self._testMethodName)()
1256+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample3/sampletests_ntd.py", line 42, in test_error1
1257+ raise TypeError("Can we see errors")
1258+ TypeError: Can we see errors
1259+ 0\r
1260+ <BLANKLINE>
1261+ ]
1262+ test: Can't post-mortem debug when running a layer as a subprocess!
1263+ tags: zope:error_with_banner
1264+ successful: Can't post-mortem debug when running a layer as a subprocess!
1265+ test: sample3.sampletests_ntd.TestSomething.test_error2
1266+ error: sample3.sampletests_ntd.TestSomething.test_error2 [ multipart
1267+ Content-Type: text/x-traceback;charset=utf8,language=python
1268+ traceback
1269+ 15A\r
1270+ <BLANKLINE>
1271+ Traceback (most recent call last):
1272+ File "/usr/lib/python2.6/unittest.py", line 305, in debug
1273+ getattr(self, self._testMethodName)()
1274+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample3/sampletests_ntd.py", line 45, in test_error2
1275+ raise TypeError("I hope so")
1276+ TypeError: I hope so
1277+ 0\r
1278+ <BLANKLINE>
1279+ ]
1280+ test: Can't post-mortem debug when running a layer as a subprocess!
1281+ tags: zope:error_with_banner
1282+ successful: Can't post-mortem debug when running a layer as a subprocess!
1283+ test: sample3.sampletests_ntd.TestSomething.test_fail1
1284+ error: sample3.sampletests_ntd.TestSomething.test_fail1 [ multipart
1285+ Content-Type: text/x-traceback;charset=utf8,language=python
1286+ traceback
1287+ 1C5\r
1288+ <BLANKLINE>
1289+ Traceback (most recent call last):
1290+ File "/usr/lib/python2.6/unittest.py", line 305, in debug
1291+ getattr(self, self._testMethodName)()
1292+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample3/sampletests_ntd.py", line 48, in test_fail1
1293+ self.assertEqual(1, 2)
1294+ File "/usr/lib/python2.6/unittest.py", line 350, in failUnlessEqual
1295+ (msg or '%r != %r' % (first, second))
1296+ AssertionError: 1 != 2
1297+ 0\r
1298+ <BLANKLINE>
1299+ ]
1300+ test: Can't post-mortem debug when running a layer as a subprocess!
1301+ tags: zope:error_with_banner
1302+ successful: Can't post-mortem debug when running a layer as a subprocess!
1303+ test: sample3.sampletests_ntd.TestSomething.test_fail2
1304+ error: sample3.sampletests_ntd.TestSomething.test_fail2 [ multipart
1305+ Content-Type: text/x-traceback;charset=utf8,language=python
1306+ traceback
1307+ 1C5\r
1308+ <BLANKLINE>
1309+ Traceback (most recent call last):
1310+ File "/usr/lib/python2.6/unittest.py", line 305, in debug
1311+ getattr(self, self._testMethodName)()
1312+ File "/home/jml/src/zope.testing/subunit-output-formatter/src/zope/testing/testrunner/testrunner-ex/sample3/sampletests_ntd.py", line 51, in test_fail2
1313+ self.assertEqual(1, 3)
1314+ File "/usr/lib/python2.6/unittest.py", line 350, in failUnlessEqual
1315+ (msg or '%r != %r' % (first, second))
1316+ AssertionError: 1 != 3
1317+ 0\r
1318+ <BLANKLINE>
1319+ ]
1320+ test: Can't post-mortem debug when running a layer as a subprocess!
1321+ tags: zope:error_with_banner
1322+ successful: Can't post-mortem debug when running a layer as a subprocess!
1323+ test: sample3.sampletests_ntd.TestSomething.test_something
1324+ successful: sample3.sampletests_ntd.TestSomething.test_something
1325+ test: sample3.sampletests_ntd.TestSomething.test_something_else
1326+ successful: sample3.sampletests_ntd.TestSomething.test_something_else
1327+ tags: -zope:layer:sample3.sampletests_ntd.Layer
1328+ time: 2010-02-10 22:41:26.340878Z
1329+ test: sample3.sampletests_ntd.Layer:tearDown
1330+ tags: zope:layer
1331+ time: 2010-02-10 22:41:26.340945Z
1332+ skip: sample3.sampletests_ntd.Layer:tearDown [
1333+ tearDown not supported
1334+ ]
1335+ True
1336
1337=== modified file 'src/zope/testing/testrunner/tests.py'
1338--- src/zope/testing/testrunner/tests.py 2009-12-18 08:23:21 +0000
1339+++ src/zope/testing/testrunner/tests.py 2010-03-11 22:36:30 +0000
1340@@ -103,6 +103,8 @@
1341 (re.compile(r'\d+[.]\d\d\d seconds'), 'N.NNN seconds'),
1342 (re.compile(r'\d+[.]\d\d\d s'), 'N.NNN s'),
1343 (re.compile(r'\d+[.]\d\d\d{'), 'N.NNN{'),
1344+ (re.compile(r'\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\.\d+'),
1345+ 'YYYY-MM-DD HH:MM:SS.mmmmmm'),
1346 (re.compile('( |")[^\n]+testrunner-ex'), r'\1testrunner-ex'),
1347 (re.compile('( |")[^\n]+testrunner.py'), r'\1testrunner.py'),
1348 (re.compile(r'> [^\n]*(doc|unit)test[.]py\(\d+\)'),
1349@@ -251,4 +253,29 @@
1350 checker=checker,
1351 )
1352 )
1353+
1354+ try:
1355+ import subunit
1356+ except ImportError:
1357+ suites.append(
1358+ doctest.DocFileSuite(
1359+ 'testrunner-subunit-err.txt',
1360+ setUp=setUp, tearDown=tearDown,
1361+ optionflags=doctest.ELLIPSIS + doctest.NORMALIZE_WHITESPACE,
1362+ checker=checker))
1363+ else:
1364+ suites.append(
1365+ doctest.DocFileSuite(
1366+ 'testrunner-subunit.txt',
1367+ setUp=setUp, tearDown=tearDown,
1368+ optionflags=doctest.ELLIPSIS + doctest.NORMALIZE_WHITESPACE,
1369+ checker=checker))
1370+ if hasattr(sys, 'gettotalrefcount'):
1371+ suites.append(
1372+ doctest.DocFileSuite(
1373+ 'testrunner-subunit-leaks.txt',
1374+ setUp=setUp, tearDown=tearDown,
1375+ optionflags=doctest.ELLIPSIS + doctest.NORMALIZE_WHITESPACE,
1376+ checker=checker))
1377+
1378 return unittest.TestSuite(suites)

Subscribers

People subscribed via source and target branches

to all changes: