Merge lp:~bac/zope.testing/1012171 into lp:~launchpad/zope.testing/3.9.4-fork

Proposed by Brad Crittenden on 2012-06-19
Status: Merged
Approved by: Brad Crittenden on 2012-06-19
Approved revision: 43
Merged at revision: 41
Proposed branch: lp:~bac/zope.testing/1012171
Merge into: lp:~launchpad/zope.testing/3.9.4-fork
Diff against target: 257 lines (+129/-9)
5 files modified
.bzrignore (+1/-0)
setup.py (+1/-1)
src/zope/testing/testrunner/formatter.py (+30/-2)
src/zope/testing/testrunner/options.py (+4/-2)
src/zope/testing/testrunner/test_subunit.py (+93/-4)
To merge this branch: bzr merge lp:~bac/zope.testing/1012171
Reviewer Review Type Date Requested Status
Benji York (community) code 2012-06-19 Approve on 2012-06-19
Review via email: mp+111093@code.launchpad.net

Commit message

Include data written to stdout or stderr by tests into the subunit output stream.

Description of the change

Include data written to stdout or stderr by tests into the subunit output stream.

Test:

bin/test -vvt test_subunit

To post a comment you must log in.
Benji York (benji) wrote :

This looks great.

I'm disappointed in the hoops you had to jump through to build the content.Content objects.

review: Approve (code)
Robert Collins (lifeless) wrote :

This:
+ if msg:
+ details['STDOUT:'] = content.Content(
+ self.PLAIN_TEXT, partial(lambda x: x, msg))

Would be simpler as:
if msg:
    details['STDOUT:'] = content.text_content(msg)

(assuming msg is a unicode object, not a bytestring). If msg is a
bytestring, then:
if msg:
    details['STDOUT:'] = content.Content(content_type.UTF8_TEXT, lambda:[msg])

would be appropriate.

As it is, you're generating content objects that iterate bytes of
length 1, which will be pathologically slow, so you should change this
one way or another. Happy to chat on IRC or wherever if you need more
pointers.

-Rob

Gavin Panella (allenap) wrote :

On 19 June 2012 21:46, Robert Collins <email address hidden> wrote:
...
> (assuming msg is a unicode object, not a bytestring). If msg is a
> bytestring, then:
> if msg:
>    details['STDOUT:'] = content.Content(content_type.UTF8_TEXT, lambda:[msg])

This will keep a reference to msg in the enclosing scope. A quick look
at the code shows that msg is changed later in the function, so this
will break, hence the need for the partial() I think.

Robert Collins (lifeless) wrote :

On Wed, Jun 20, 2012 at 10:28 AM, Gavin Panella
<email address hidden> wrote:
> On 19 June 2012 21:46, Robert Collins <email address hidden> wrote:
> ...
>> (assuming msg is a unicode object, not a bytestring). If msg is a
>> bytestring, then:
>> if msg:
>>    details['STDOUT:'] = content.Content(content_type.UTF8_TEXT, lambda:[msg])
>
> This will keep a reference to msg in the enclosing scope. A quick look
> at the code shows that msg is changed later in the function, so this
> will break, hence the need for the partial() I think.

Oh! So, I'd wrap the two lines in a helper, that will break the
scoping problem and be shorter overall:

def attach(label, msg):
    if msg:
        details[label] = content.Content(content_type.UTF8_TEXT, lambda:[msg])
attach('STDOUT:, _get_new_stream_output(sys.stdout))
attach('STDERR:, _get_new_stream_output(sys.stderr))

5 lines vs 6, and less partial gymnastics ;)

-Rob

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file '.bzrignore'
2--- .bzrignore 2012-06-11 18:30:09 +0000
3+++ .bzrignore 2012-06-19 19:31:21 +0000
4@@ -7,3 +7,4 @@
5 Session.vim
6 dist
7 tags
8+.emacs.desktop
9
10=== modified file 'setup.py'
11--- setup.py 2012-06-14 16:56:56 +0000
12+++ setup.py 2012-06-19 19:31:21 +0000
13@@ -85,7 +85,7 @@
14
15 setup(
16 name='zope.testing',
17- version = '3.9.4-p13',
18+ version = '3.9.4-p14',
19 url='http://pypi.python.org/pypi/zope.testing',
20 license='ZPL 2.1',
21 description='Zope testing framework, including the testrunner script.',
22
23=== modified file 'src/zope/testing/testrunner/formatter.py'
24--- src/zope/testing/testrunner/formatter.py 2012-06-12 19:23:43 +0000
25+++ src/zope/testing/testrunner/formatter.py 2012-06-19 19:31:21 +0000
26@@ -24,6 +24,7 @@
27 import traceback
28
29 from datetime import datetime, timedelta
30+from functools import partial
31
32 from zope.testing.exceptions import DocTestFailureException
33
34@@ -713,6 +714,7 @@
35 TAG_THREADS = 'zope:threads'
36 TAG_REFCOUNTS = 'zope:refcounts'
37
38+
39 def __init__(self, options, stream=None):
40 if subunit is None:
41 raise Exception("Requires subunit 0.0.5 or better")
42@@ -907,7 +909,9 @@
43 def test_success(self, test, seconds):
44 if self._time_tests:
45 self._emit_timestamp()
46- self._subunit.addSuccess(test)
47+ details = {}
48+ self._add_test_output(details)
49+ self._subunit.addSuccess(test, details=details)
50
51 def import_errors(self, import_errors):
52 """Report test-module import errors (if any)."""
53@@ -943,7 +947,29 @@
54
55 return {
56 'traceback': content.Content(
57- self.TRACEBACK_CONTENT_TYPE, lambda: [unicode_tb.encode('utf8')])}
58+ self.TRACEBACK_CONTENT_TYPE,
59+ lambda: [unicode_tb.encode('utf8')])}
60+
61+ def _get_new_stream_output(self, stream):
62+ """Get the stream output written since the last time."""
63+ try:
64+ stream.truncate()
65+ msg = stream.getvalue()
66+ stream.seek(0)
67+ except (AttributeError, IOError):
68+ msg = None
69+ return msg
70+
71+ def _add_test_output(self, details):
72+ """If tests write data to stdout or stderr, add it to the details."""
73+ msg = self._get_new_stream_output(sys.stdout)
74+ if msg:
75+ details['STDOUT:'] = content.Content(
76+ self.PLAIN_TEXT, partial(lambda x: x, msg))
77+ msg = self._get_new_stream_output(sys.stderr)
78+ if msg:
79+ details['STDERR:'] = content.Content(
80+ self.PLAIN_TEXT, partial(lambda x: x, msg))
81
82 def test_error(self, test, seconds, exc_info):
83 """Report that an error occurred while running a test.
84@@ -955,6 +981,7 @@
85 if self._time_tests:
86 self._emit_timestamp()
87 details = self._exc_info_to_details(exc_info)
88+ self._add_test_output(details)
89 self._subunit.addError(test, details=details)
90
91 def test_failure(self, test, seconds, exc_info):
92@@ -967,6 +994,7 @@
93 if self._time_tests:
94 self._emit_timestamp()
95 details = self._exc_info_to_details(exc_info)
96+ self._add_test_output(details)
97 self._subunit.addFailure(test, details=details)
98
99 def profiler_stats(self, stats):
100
101=== modified file 'src/zope/testing/testrunner/options.py'
102--- src/zope/testing/testrunner/options.py 2012-06-14 17:27:43 +0000
103+++ src/zope/testing/testrunner/options.py 2012-06-19 19:31:21 +0000
104@@ -19,6 +19,7 @@
105 import optparse
106 import re
107 import os
108+from StringIO import StringIO
109 import sys
110
111 import pkg_resources
112@@ -511,6 +512,7 @@
113 return (lambda s: not pattern(s))
114 return re.compile(pattern).search
115
116+
117 def merge_options(options, defaults):
118 odict = options.__dict__
119 for name, value in defaults.__dict__.items():
120@@ -601,12 +603,12 @@
121 streams_munged = True
122 # Replace stdout (and possibly stderr) with a file-like black hole
123 # so the subunit stream does not get corrupted by test output.
124- sys.stdout = NullStream()
125+ sys.stdout = StringIO()
126 # If we are running in a subprocess then the test runner code will
127 # use stderr as a communication channel back to the spawning
128 # process so we shouldn't touch it.
129 if '--resume-layer' not in sys.argv:
130- sys.__stderr__ = sys.stderr = NullStream()
131+ sys.__stderr__ = sys.stderr = StringIO()
132 # Send subunit output to the real stdout.
133 options.output = SubunitOutputFormatter(options, sys.__stdout__)
134
135
136=== modified file 'src/zope/testing/testrunner/test_subunit.py'
137--- src/zope/testing/testrunner/test_subunit.py 2012-05-30 11:59:41 +0000
138+++ src/zope/testing/testrunner/test_subunit.py 2012-06-19 19:31:21 +0000
139@@ -18,10 +18,14 @@
140 import sys
141 import unittest
142 import formatter
143-import subunit
144 from StringIO import StringIO
145
146
147+class FormatterOptions:
148+ """Simple options class for use with formatter."""
149+ verbose=False
150+
151+
152 class TestSubunitTracebackPrinting(unittest.TestCase):
153
154 def makeByteStringFailure(self, text, encoding):
155@@ -35,8 +39,6 @@
156 return sys.exc_info()
157
158 def setUp(self):
159- class FormatterOptions:
160- verbose=False
161 options = FormatterOptions()
162
163 self.output = StringIO()
164@@ -56,4 +58,91 @@
165 def test_print_failure_containing_latin1_bytestrings(self):
166 exc_info = self.makeByteStringFailure(unichr(241), 'latin1')
167 self.subunit_formatter.test_failure(self, 0, exc_info)
168- assert "AssertionError: \xef\xbf\xbd0" in self.output.getvalue()
169\ No newline at end of file
170+ self.assertIn("\xef\xbf\xbd", self.output.getvalue())
171+
172+
173+class TestSubunitStreamReporting(unittest.TestCase):
174+ """Test capture of stdout and stderr.
175+
176+ The testrunner sets up fake I/O streams for the tests to use for
177+ sys.stdout and sys.stderr. Anything written to those streams is
178+ captured and added as part of the subunit multi-part details output.
179+ """
180+ def setFakeStreams(self):
181+ sys.stdout = StringIO()
182+ sys.stderr = StringIO()
183+
184+ def restoreStreams(self):
185+ sys.stdout = sys.__stdout__
186+ sys.stderr = sys.__stderr__
187+
188+ def makeExcInfo(self):
189+ try:
190+ assert False
191+ except:
192+ return sys.exc_info()
193+
194+ def setUp(self):
195+ class FormatterOptions:
196+ verbose = False
197+ options = FormatterOptions()
198+
199+ self.output = StringIO()
200+ self.setFakeStreams()
201+ self.subunit_formatter = formatter.SubunitOutputFormatter(
202+ options, stream=self.output)
203+ #self.subunit_formatter._set_stream_positions()
204+
205+ def tearDown(self):
206+ self.restoreStreams()
207+
208+ def test_stream_success(self):
209+ sys.stdout.write("Output written to stdout\n")
210+ sys.stderr.write("Output written to stderr\n")
211+ fake_test = formatter.FakeTest('stdout_test')
212+ self.subunit_formatter.test_success(fake_test, 10)
213+ self.restoreStreams()
214+ self.assertIn('STDOUT:', self.output.getvalue())
215+ self.assertIn('STDERR:', self.output.getvalue())
216+
217+
218+ def test_stream_error(self):
219+ sys.stdout.write("Output written to stdout\n")
220+ sys.stderr.write("Output written to stderr\n")
221+ fake_test = formatter.FakeTest('error_test')
222+ exc_info = self.makeExcInfo()
223+ self.subunit_formatter.test_error(fake_test, 10, exc_info)
224+ self.restoreStreams()
225+ self.assertIn('STDOUT:', self.output.getvalue())
226+ self.assertIn('STDERR:', self.output.getvalue())
227+
228+ def test_stream_failure(self):
229+ sys.stdout.write("Output written to stdout\n")
230+ sys.stderr.write("Output written to stderr\n")
231+ fake_test = formatter.FakeTest('error_test')
232+ exc_info = self.makeExcInfo()
233+ self.subunit_formatter.test_failure(fake_test, 10, exc_info)
234+ self.restoreStreams()
235+ self.assertIn('STDOUT:', self.output.getvalue())
236+ self.assertIn('STDERR:', self.output.getvalue())
237+
238+ def test_multiple_messages(self):
239+ # Only never-reported messages should be seen.
240+ fake_test = formatter.FakeTest('stdout_test')
241+ sys.stdout.write("First message written to stdout\n")
242+ sys.stderr.write("First message written to stderr\n")
243+ self.subunit_formatter.test_success(fake_test, 10)
244+ self.assertIn(
245+ "First message written to stdout", self.output.getvalue())
246+ self.assertIn(
247+ "First message written to stderr", self.output.getvalue())
248+ self.output.seek(0)
249+ self.output.truncate()
250+ sys.stdout.write("Second message written to stdout\n")
251+ sys.stderr.write("Second message written to stderr\n")
252+ self.subunit_formatter.test_success(fake_test, 10)
253+ self.restoreStreams()
254+ self.assertNotIn(
255+ "First message written to stdout", self.output.getvalue())
256+ self.assertNotIn(
257+ "First message written to stderr", self.output.getvalue())

Subscribers

People subscribed via source and target branches