134
139
SUBUNIT_SEEK_SET = 0
135
140
SUBUNIT_SEEK_CUR = 1
137
# These are intentionally brought into this namespace. That way plugins, etc
138
# can just "from bzrlib.tests import TestCase, TestLoader, etc"
139
TestSuite = TestUtil.TestSuite
140
TestLoader = TestUtil.TestLoader
142
class ExtendedTestResult(testtools.TextTestResult):
143
class ExtendedTestResult(unittest._TextTestResult):
143
144
"""Accepts, reports and accumulates the results of running tests.
145
146
Compared to the unittest version this class adds support for
166
167
:param bench_history: Optionally, a writable file object to accumulate
167
168
benchmark results.
169
testtools.TextTestResult.__init__(self, stream)
170
unittest._TextTestResult.__init__(self, stream, descriptions, verbosity)
170
171
if bench_history is not None:
171
172
from bzrlib.version import _get_bzr_source_tree
172
173
src_tree = _get_bzr_source_tree()
194
195
self._overall_start_time = time.time()
195
196
self._strict = strict
196
self._first_thread_leaker_id = None
197
self._tests_leaking_threads_count = 0
199
198
def stopTestRun(self):
200
199
run = self.testsRun
201
200
actionTaken = "Ran"
202
201
stopTime = time.time()
203
202
timeTaken = stopTime - self.startTime
204
# GZ 2010-07-19: Seems testtools has no printErrors method, and though
205
# the parent class method is similar have to duplicate
206
self._show_list('ERROR', self.errors)
207
self._show_list('FAIL', self.failures)
208
self.stream.write(self.sep2)
209
self.stream.write("%s %d test%s in %.3fs\n\n" % (actionTaken,
204
self.stream.writeln(self.separator2)
205
self.stream.writeln("%s %d test%s in %.3fs" % (actionTaken,
210
206
run, run != 1 and "s" or "", timeTaken))
207
self.stream.writeln()
211
208
if not self.wasSuccessful():
212
209
self.stream.write("FAILED (")
213
210
failed, errored = map(len, (self.failures, self.errors))
220
217
if failed or errored: self.stream.write(", ")
221
218
self.stream.write("known_failure_count=%d" %
222
219
self.known_failure_count)
223
self.stream.write(")\n")
220
self.stream.writeln(")")
225
222
if self.known_failure_count:
226
self.stream.write("OK (known_failures=%d)\n" %
223
self.stream.writeln("OK (known_failures=%d)" %
227
224
self.known_failure_count)
229
self.stream.write("OK\n")
226
self.stream.writeln("OK")
230
227
if self.skip_count > 0:
231
228
skipped = self.skip_count
232
self.stream.write('%d test%s skipped\n' %
229
self.stream.writeln('%d test%s skipped' %
233
230
(skipped, skipped != 1 and "s" or ""))
234
231
if self.unsupported:
235
232
for feature, count in sorted(self.unsupported.items()):
236
self.stream.write("Missing feature '%s' skipped %d tests.\n" %
233
self.stream.writeln("Missing feature '%s' skipped %d tests." %
237
234
(feature, count))
239
236
ok = self.wasStrictlySuccessful()
241
238
ok = self.wasSuccessful()
242
if self._first_thread_leaker_id:
239
if TestCase._first_thread_leaker_id:
243
240
self.stream.write(
244
241
'%s is leaking threads among %d leaking tests.\n' % (
245
self._first_thread_leaker_id,
246
self._tests_leaking_threads_count))
242
TestCase._first_thread_leaker_id,
243
TestCase._leaking_threads_tests))
247
244
# We don't report the main thread as an active one.
248
245
self.stream.write(
249
246
'%d non-main threads were left active in the end.\n'
250
% (len(self._active_threads) - 1))
247
% (TestCase._active_threads - 1))
252
249
def getDescription(self, test):
278
275
def _shortened_test_description(self, test):
280
what = re.sub(r'^bzrlib\.tests\.', '', what)
277
what = re.sub(r'^bzrlib\.(tests|benchmarks)\.', '', what)
283
280
def startTest(self, test):
284
super(ExtendedTestResult, self).startTest(test)
281
unittest.TestResult.startTest(self, test)
285
282
if self.count == 0:
286
283
self.startTests()
288
284
self.report_test_start(test)
289
285
test.number = self.count
290
286
self._recordTestStartTime()
291
# Only check for thread leaks if the test case supports cleanups
292
addCleanup = getattr(test, "addCleanup", None)
293
if addCleanup is not None:
294
addCleanup(self._check_leaked_threads, test)
296
288
def startTests(self):
297
self.report_tests_starting()
298
self._active_threads = threading.enumerate()
300
def _check_leaked_threads(self, test):
301
"""See if any threads have leaked since last call
303
A sample of live threads is stored in the _active_threads attribute,
304
when this method runs it compares the current live threads and any not
305
in the previous sample are treated as having leaked.
307
now_active_threads = set(threading.enumerate())
308
threads_leaked = now_active_threads.difference(self._active_threads)
310
self._report_thread_leak(test, threads_leaked, now_active_threads)
311
self._tests_leaking_threads_count += 1
312
if self._first_thread_leaker_id is None:
313
self._first_thread_leaker_id = test.id()
314
self._active_threads = now_active_threads
290
if getattr(sys, 'frozen', None) is None:
291
bzr_path = osutils.realpath(sys.argv[0])
293
bzr_path = sys.executable
295
'bzr selftest: %s\n' % (bzr_path,))
298
bzrlib.__path__[0],))
300
' bzr-%s python-%s %s\n' % (
301
bzrlib.version_string,
302
bzrlib._format_version_tuple(sys.version_info),
303
platform.platform(aliased=1),
305
self.stream.write('\n')
316
307
def _recordTestStartTime(self):
317
308
"""Record that a test has started."""
318
309
self._start_time = time.time()
311
def _cleanupLogFile(self, test):
312
# We can only do this if we have one of our TestCases, not if
314
setKeepLogfile = getattr(test, 'setKeepLogfile', None)
315
if setKeepLogfile is not None:
320
318
def addError(self, test, err):
321
319
"""Tell result that test finished with an error.
324
322
fails with an unexpected error.
326
324
self._post_mortem()
327
super(ExtendedTestResult, self).addError(test, err)
325
unittest.TestResult.addError(self, test, err)
328
326
self.error_count += 1
329
327
self.report_error(test, err)
330
328
if self.stop_early:
330
self._cleanupLogFile(test)
333
332
def addFailure(self, test, err):
334
333
"""Tell result that test failed.
337
336
fails because e.g. an assert() method failed.
339
338
self._post_mortem()
340
super(ExtendedTestResult, self).addFailure(test, err)
339
unittest.TestResult.addFailure(self, test, err)
341
340
self.failure_count += 1
342
341
self.report_failure(test, err)
343
342
if self.stop_early:
344
self._cleanupLogFile(test)
346
346
def addSuccess(self, test, details=None):
347
347
"""Tell result that test completed successfully.
355
355
self._formatTime(benchmark_time),
357
357
self.report_success(test)
358
super(ExtendedTestResult, self).addSuccess(test)
358
self._cleanupLogFile(test)
359
unittest.TestResult.addSuccess(self, test)
359
360
test._log_contents = ''
361
362
def addExpectedFailure(self, test, err):
399
400
raise errors.BzrError("Unknown whence %r" % whence)
401
def report_tests_starting(self):
402
"""Display information before the test run begins"""
403
if getattr(sys, 'frozen', None) is None:
404
bzr_path = osutils.realpath(sys.argv[0])
406
bzr_path = sys.executable
408
'bzr selftest: %s\n' % (bzr_path,))
411
bzrlib.__path__[0],))
413
' bzr-%s python-%s %s\n' % (
414
bzrlib.version_string,
415
bzrlib._format_version_tuple(sys.version_info),
416
platform.platform(aliased=1),
418
self.stream.write('\n')
420
def report_test_start(self, test):
421
"""Display information on the test just about to be run"""
423
def _report_thread_leak(self, test, leaked_threads, active_threads):
424
"""Display information on a test that leaked one or more threads"""
425
# GZ 2010-09-09: A leak summary reported separately from the general
426
# thread debugging would be nice. Tests under subunit
427
# need something not using stream, perhaps adding a
428
# testtools details object would be fitting.
429
if 'threads' in selftest_debug_flags:
430
self.stream.write('%s is leaking, active is now %d\n' %
431
(test.id(), len(active_threads)))
402
def report_cleaning_up(self):
433
405
def startTestRun(self):
434
406
self.startTime = time.time()
471
443
self.pb.finished()
472
444
super(TextTestResult, self).stopTestRun()
474
def report_tests_starting(self):
475
super(TextTestResult, self).report_tests_starting()
446
def startTestRun(self):
447
super(TextTestResult, self).startTestRun()
476
448
self.pb.update('[test 0/%d] Starting' % (self.num_tests))
450
def printErrors(self):
451
# clear the pb to make room for the error listing
453
super(TextTestResult, self).printErrors()
478
455
def _progress_prefix_text(self):
479
456
# the longer this text, the less space we have to show the test
534
512
def report_unsupported(self, test, feature):
535
513
"""test cannot be run because feature is missing."""
515
def report_cleaning_up(self):
516
self.pb.update('Cleaning up')
538
519
class VerboseTestResult(ExtendedTestResult):
539
520
"""Produce long output, with one line per test run plus times"""
546
527
result = a_string
547
528
return result.ljust(final_width)
549
def report_tests_starting(self):
530
def startTestRun(self):
531
super(VerboseTestResult, self).startTestRun()
550
532
self.stream.write('running %d tests...\n' % self.num_tests)
551
super(VerboseTestResult, self).report_tests_starting()
553
534
def report_test_start(self, test):
554
536
name = self._shortened_test_description(test)
555
537
width = osutils.terminal_width()
556
538
if width is not None:
568
550
return '%s%s' % (indent, err[1])
570
552
def report_error(self, test, err):
571
self.stream.write('ERROR %s\n%s\n'
553
self.stream.writeln('ERROR %s\n%s'
572
554
% (self._testTimeString(test),
573
555
self._error_summary(err)))
575
557
def report_failure(self, test, err):
576
self.stream.write(' FAIL %s\n%s\n'
558
self.stream.writeln(' FAIL %s\n%s'
577
559
% (self._testTimeString(test),
578
560
self._error_summary(err)))
580
562
def report_known_failure(self, test, err):
581
self.stream.write('XFAIL %s\n%s\n'
563
self.stream.writeln('XFAIL %s\n%s'
582
564
% (self._testTimeString(test),
583
565
self._error_summary(err)))
585
567
def report_success(self, test):
586
self.stream.write(' OK %s\n' % self._testTimeString(test))
568
self.stream.writeln(' OK %s' % self._testTimeString(test))
587
569
for bench_called, stats in getattr(test, '_benchcalls', []):
588
self.stream.write('LSProf output for %s(%s, %s)\n' % bench_called)
570
self.stream.writeln('LSProf output for %s(%s, %s)' % bench_called)
589
571
stats.pprint(file=self.stream)
590
572
# flush the stream so that we get smooth output. This verbose mode is
591
573
# used to show the output in PQM.
592
574
self.stream.flush()
594
576
def report_skip(self, test, reason):
595
self.stream.write(' SKIP %s\n%s\n'
577
self.stream.writeln(' SKIP %s\n%s'
596
578
% (self._testTimeString(test), reason))
598
580
def report_not_applicable(self, test, reason):
599
self.stream.write(' N/A %s\n %s\n'
581
self.stream.writeln(' N/A %s\n %s'
600
582
% (self._testTimeString(test), reason))
602
584
def report_unsupported(self, test, feature):
603
585
"""test cannot be run because feature is missing."""
604
self.stream.write("NODEP %s\n The feature '%s' is not available.\n"
586
self.stream.writeln("NODEP %s\n The feature '%s' is not available."
605
587
%(self._testTimeString(test), feature))
806
788
routine, and to build and check bzr trees.
808
790
In addition to the usual method of overriding tearDown(), this class also
809
allows subclasses to register cleanup functions via addCleanup, which are
791
allows subclasses to register functions into the _cleanups list, which is
810
792
run in order as the object is torn down. It's less likely this will be
811
793
accidentally overlooked.
796
_active_threads = None
797
_leaking_threads_tests = 0
798
_first_thread_leaker_id = None
799
_log_file_name = None
815
800
# record lsprof data when performing benchmark calls.
816
801
_gather_lsprof_in_benchmarks = False
818
803
def __init__(self, methodName='testMethod'):
819
804
super(TestCase, self).__init__(methodName)
820
806
self._directory_isolation = True
821
807
self.exception_handlers.insert(0,
822
808
(UnavailableFeature, self._do_unsupported_or_skip))
840
826
self._track_transports()
841
827
self._track_locks()
842
828
self._clear_debug_flags()
829
TestCase._active_threads = threading.activeCount()
830
self.addCleanup(self._check_leaked_threads)
845
833
# debug a frame up.
847
835
pdb.Pdb().set_trace(sys._getframe().f_back)
849
def discardDetail(self, name):
850
"""Extend the addDetail, getDetails api so we can remove a detail.
852
eg. bzr always adds the 'log' detail at startup, but we don't want to
853
include it for skipped, xfail, etc tests.
855
It is safe to call this for a detail that doesn't exist, in case this
856
gets called multiple times.
858
# We cheat. details is stored in __details which means we shouldn't
859
# touch it. but getDetails() returns the dict directly, so we can
861
details = self.getDetails()
837
def _check_leaked_threads(self):
838
active = threading.activeCount()
839
leaked_threads = active - TestCase._active_threads
840
TestCase._active_threads = active
841
# If some tests make the number of threads *decrease*, we'll consider
842
# that they are just observing old threads dieing, not agressively kill
843
# random threads. So we don't report these tests as leaking. The risk
844
# is that we have false positives that way (the test see 2 threads
845
# going away but leak one) but it seems less likely than the actual
846
# false positives (the test see threads going away and does not leak).
847
if leaked_threads > 0:
848
TestCase._leaking_threads_tests += 1
849
if TestCase._first_thread_leaker_id is None:
850
TestCase._first_thread_leaker_id = self.id()
865
852
def _clear_debug_flags(self):
866
853
"""Prevent externally set debug flags affecting tests.
1468
1455
The file is removed as the test is torn down.
1470
self._log_file = StringIO()
1457
fileno, name = tempfile.mkstemp(suffix='.log', prefix='testbzr')
1458
self._log_file = os.fdopen(fileno, 'w+')
1471
1459
self._log_memento = bzrlib.trace.push_log_file(self._log_file)
1460
self._log_file_name = name
1472
1461
self.addCleanup(self._finishLogFile)
1474
1463
def _finishLogFile(self):
1497
1486
debug.debug_flags.discard('strict_locks')
1488
def addCleanup(self, callable, *args, **kwargs):
1489
"""Arrange to run a callable when this case is torn down.
1491
Callables are run in the reverse of the order they are registered,
1492
ie last-in first-out.
1494
self._cleanups.append((callable, args, kwargs))
1499
1496
def overrideAttr(self, obj, attr_name, new=_unitialized_attr):
1500
1497
"""Overrides an object attribute restoring it after the test.
1585
1582
"""This test has failed for some known reason."""
1586
1583
raise KnownFailure(reason)
1588
def _suppress_log(self):
1589
"""Remove the log info from details."""
1590
self.discardDetail('log')
1592
1585
def _do_skip(self, result, reason):
1593
self._suppress_log()
1594
1586
addSkip = getattr(result, 'addSkip', None)
1595
1587
if not callable(addSkip):
1596
1588
result.addSuccess(result)
1621
1611
self._do_skip(result, reason)
1624
def _report_skip(self, result, err):
1625
"""Override the default _report_skip.
1627
We want to strip the 'log' detail. If we waint until _do_skip, it has
1628
already been formatted into the 'reason' string, and we can't pull it
1631
self._suppress_log()
1632
super(TestCase, self)._report_skip(self, result, err)
1635
def _report_expected_failure(self, result, err):
1638
See _report_skip for motivation.
1640
self._suppress_log()
1641
super(TestCase, self)._report_expected_failure(self, result, err)
1644
1614
def _do_unsupported_or_skip(self, result, e):
1645
1615
reason = e.args[0]
1646
self._suppress_log()
1647
1616
addNotSupported = getattr(result, 'addNotSupported', None)
1648
1617
if addNotSupported is not None:
1649
1618
result.addNotSupported(self, reason)
1696
1665
unicodestr = self._log_contents.decode('utf8', 'replace')
1697
1666
self._log_contents = unicodestr.encode('utf8')
1698
1667
return self._log_contents
1699
if self._log_file is not None:
1700
log_contents = self._log_file.getvalue()
1669
if bzrlib.trace._trace_file:
1670
# flush the log file, to get all content
1671
bzrlib.trace._trace_file.flush()
1672
if self._log_file_name is not None:
1673
logfile = open(self._log_file_name)
1675
log_contents = logfile.read()
1702
1679
log_contents.decode('utf8')
1703
1680
except UnicodeDecodeError:
1704
1681
unicodestr = log_contents.decode('utf8', 'replace')
1705
1682
log_contents = unicodestr.encode('utf8')
1706
1683
if not keep_log_file:
1685
max_close_attempts = 100
1686
first_close_error = None
1687
while close_attempts < max_close_attempts:
1690
self._log_file.close()
1691
except IOError, ioe:
1692
if ioe.errno is None:
1693
# No errno implies 'close() called during
1694
# concurrent operation on the same file object', so
1695
# retry. Probably a thread is trying to write to
1697
if first_close_error is None:
1698
first_close_error = ioe
1703
if close_attempts > 1:
1705
'Unable to close log file on first attempt, '
1706
'will retry: %s\n' % (first_close_error,))
1707
if close_attempts == max_close_attempts:
1709
'Unable to close log file after %d attempts.\n'
1710
% (max_close_attempts,))
1707
1711
self._log_file = None
1708
1712
# Permit multiple calls to get_log until we clean it up in
1709
1713
# finishLogFile
1710
1714
self._log_contents = log_contents
1716
os.remove(self._log_file_name)
1718
if sys.platform == 'win32' and e.errno == errno.EACCES:
1719
sys.stderr.write(('Unable to delete log file '
1720
' %r\n' % self._log_file_name))
1723
self._log_file_name = None
1711
1724
return log_contents
1713
return "No log file content."
1726
return "No log file content and no log file name."
1715
1728
def get_log(self):
1716
1729
"""Get a unicode string containing the log from bzrlib.trace.
1931
1944
variables. A value of None will unset the env variable.
1932
1945
The values must be strings. The change will only occur in the
1933
1946
child, so you don't need to fix the environment after running.
1934
:param skip_if_plan_to_signal: raise TestSkipped when true and system
1935
doesn't support signalling subprocesses.
1947
:param skip_if_plan_to_signal: raise TestSkipped when true and os.kill
1936
1949
:param allow_plugins: If False (default) pass --no-plugins to bzr.
1938
1951
:returns: Popen object for the started process.
1940
1953
if skip_if_plan_to_signal:
1941
if os.name != "posix":
1942
raise TestSkipped("Sending signals not supported")
1954
if not getattr(os, 'kill', None):
1955
raise TestSkipped("os.kill not available.")
1944
1957
if env_changes is None:
1945
1958
env_changes = {}
2424
2437
def setUp(self):
2425
2438
super(TestCaseWithMemoryTransport, self).setUp()
2426
# Ensure that ConnectedTransport doesn't leak sockets
2427
def get_transport_with_cleanup(*args, **kwargs):
2428
t = orig_get_transport(*args, **kwargs)
2429
if isinstance(t, _mod_transport.ConnectedTransport):
2430
self.addCleanup(t.disconnect)
2433
orig_get_transport = self.overrideAttr(_mod_transport, 'get_transport',
2434
get_transport_with_cleanup)
2435
2439
self._make_test_root()
2436
2440
self.addCleanup(os.chdir, os.getcwdu())
2437
2441
self.makeAndChdirToTestDir()
3197
3198
def partition_tests(suite, count):
3198
3199
"""Partition suite into count lists of tests."""
3199
# This just assigns tests in a round-robin fashion. On one hand this
3200
# splits up blocks of related tests that might run faster if they shared
3201
# resources, but on the other it avoids assigning blocks of slow tests to
3202
# just one partition. So the slowest partition shouldn't be much slower
3204
partitions = [list() for i in range(count)]
3205
tests = iter_suite_tests(suite)
3206
for partition, test in itertools.izip(itertools.cycle(partitions), tests):
3207
partition.append(test)
3201
tests = list(iter_suite_tests(suite))
3202
tests_per_process = int(math.ceil(float(len(tests)) / count))
3203
for block in range(count):
3204
low_test = block * tests_per_process
3205
high_test = low_test + tests_per_process
3206
process_tests = tests[low_test:high_test]
3207
result.append(process_tests)
3211
3211
def workaround_zealous_crypto_random():
3647
3642
'bzrlib.tests.blackbox',
3648
3643
'bzrlib.tests.commands',
3649
'bzrlib.tests.doc_generate',
3650
3644
'bzrlib.tests.per_branch',
3651
3645
'bzrlib.tests.per_bzrdir',
3652
'bzrlib.tests.per_controldir',
3653
'bzrlib.tests.per_controldir_colo',
3646
'bzrlib.tests.per_bzrdir_colo',
3654
3647
'bzrlib.tests.per_foreign_vcs',
3655
3648
'bzrlib.tests.per_interrepository',
3656
3649
'bzrlib.tests.per_intertree',
3669
3662
'bzrlib.tests.per_workingtree',
3670
3663
'bzrlib.tests.test__annotator',
3671
3664
'bzrlib.tests.test__bencode',
3672
'bzrlib.tests.test__btree_serializer',
3673
3665
'bzrlib.tests.test__chk_map',
3674
3666
'bzrlib.tests.test__dirstate_helpers',
3675
3667
'bzrlib.tests.test__groupcompress',
3808
3800
'bzrlib.tests.test_switch',
3809
3801
'bzrlib.tests.test_symbol_versioning',
3810
3802
'bzrlib.tests.test_tag',
3811
'bzrlib.tests.test_test_server',
3812
3803
'bzrlib.tests.test_testament',
3813
3804
'bzrlib.tests.test_textfile',
3814
3805
'bzrlib.tests.test_textmerge',
3820
3811
'bzrlib.tests.test_transport_log',
3821
3812
'bzrlib.tests.test_tree',
3822
3813
'bzrlib.tests.test_treebuilder',
3823
'bzrlib.tests.test_treeshape',
3824
3814
'bzrlib.tests.test_tsort',
3825
3815
'bzrlib.tests.test_tuned_gzip',
3826
3816
'bzrlib.tests.test_ui',
3830
3820
'bzrlib.tests.test_urlutils',
3831
3821
'bzrlib.tests.test_version',
3832
3822
'bzrlib.tests.test_version_info',
3833
'bzrlib.tests.test_versionedfile',
3834
3823
'bzrlib.tests.test_weave',
3835
3824
'bzrlib.tests.test_whitebox',
3836
3825
'bzrlib.tests.test_win32utils',
4061
4050
new_test = copy.copy(test)
4062
4051
new_test.id = lambda: new_id
4063
# XXX: Workaround <https://bugs.launchpad.net/testtools/+bug/637725>, which
4064
# causes cloned tests to share the 'details' dict. This makes it hard to
4065
# read the test output for parameterized tests, because tracebacks will be
4066
# associated with irrelevant tests.
4068
details = new_test._TestCase__details
4069
except AttributeError:
4070
# must be a different version of testtools than expected. Do nothing.
4073
# Reset the '__details' dict.
4074
new_test._TestCase__details = {}
4075
4052
return new_test
4504
4481
from subunit import TestProtocolClient
4505
4482
from subunit.test_results import AutoTimingTestResultDecorator
4506
class SubUnitBzrProtocolClient(TestProtocolClient):
4508
def addSuccess(self, test, details=None):
4509
# The subunit client always includes the details in the subunit
4510
# stream, but we don't want to include it in ours.
4511
if details is not None and 'log' in details:
4513
return super(SubUnitBzrProtocolClient, self).addSuccess(
4516
4483
class SubUnitBzrRunner(TextTestRunner):
4517
4484
def run(self, test):
4518
4485
result = AutoTimingTestResultDecorator(
4519
SubUnitBzrProtocolClient(self.stream))
4486
TestProtocolClient(self.stream))
4520
4487
test.run(result)
4522
4489
except ImportError: