← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/__init__.py

(gz) Cleanup and test selftest thread leak detection (Martin [gz])

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/__init__.py
38
38
import logging
39
39
import math
40
40
import os
 
41
import platform
41
42
import pprint
42
43
import random
43
44
import re
194
195
        self.count = 0
195
196
        self._overall_start_time = time.time()
196
197
        self._strict = strict
 
198
        self._first_thread_leaker_id = None
 
199
        self._tests_leaking_threads_count = 0
197
200
 
198
201
    def stopTestRun(self):
199
202
        run = self.testsRun
238
241
            ok = self.wasStrictlySuccessful()
239
242
        else:
240
243
            ok = self.wasSuccessful()
241
 
        if TestCase._first_thread_leaker_id:
 
244
        if self._first_thread_leaker_id:
242
245
            self.stream.write(
243
246
                '%s is leaking threads among %d leaking tests.\n' % (
244
 
                TestCase._first_thread_leaker_id,
245
 
                TestCase._leaking_threads_tests))
 
247
                self._first_thread_leaker_id,
 
248
                self._tests_leaking_threads_count))
246
249
            # We don't report the main thread as an active one.
247
250
            self.stream.write(
248
251
                '%d non-main threads were left active in the end.\n'
249
 
                % (TestCase._active_threads - 1))
 
252
                % (len(self._active_threads) - 1))
250
253
 
251
254
    def getDescription(self, test):
252
255
        return test.id()
283
286
        super(ExtendedTestResult, self).startTest(test)
284
287
        if self.count == 0:
285
288
            self.startTests()
 
289
        self.count += 1
286
290
        self.report_test_start(test)
287
291
        test.number = self.count
288
292
        self._recordTestStartTime()
 
293
        # Only check for thread leaks if the test case supports cleanups
 
294
        addCleanup = getattr(test, "addCleanup", None)
 
295
        if addCleanup is not None:
 
296
            addCleanup(self._check_leaked_threads, test)
289
297
 
290
298
    def startTests(self):
291
 
        import platform
292
 
        if getattr(sys, 'frozen', None) is None:
293
 
            bzr_path = osutils.realpath(sys.argv[0])
294
 
        else:
295
 
            bzr_path = sys.executable
296
 
        self.stream.write(
297
 
            'bzr selftest: %s\n' % (bzr_path,))
298
 
        self.stream.write(
299
 
            '   %s\n' % (
300
 
                    bzrlib.__path__[0],))
301
 
        self.stream.write(
302
 
            '   bzr-%s python-%s %s\n' % (
303
 
                    bzrlib.version_string,
304
 
                    bzrlib._format_version_tuple(sys.version_info),
305
 
                    platform.platform(aliased=1),
306
 
                    ))
307
 
        self.stream.write('\n')
 
299
        self.report_tests_starting()
 
300
        self._active_threads = threading.enumerate()
 
301
 
 
302
    def _check_leaked_threads(self, test):
 
303
        """See if any threads have leaked since last call
 
304
 
 
305
        A sample of live threads is stored in the _active_threads attribute,
 
306
        when this method runs it compares the current live threads and any not
 
307
        in the previous sample are treated as having leaked.
 
308
        """
 
309
        now_active_threads = set(threading.enumerate())
 
310
        threads_leaked = now_active_threads.difference(self._active_threads)
 
311
        if threads_leaked:
 
312
            self._report_thread_leak(test, threads_leaked, now_active_threads)
 
313
            self._tests_leaking_threads_count += 1
 
314
            if self._first_thread_leaker_id is None:
 
315
                self._first_thread_leaker_id = test.id()
 
316
            self._active_threads = now_active_threads
308
317
 
309
318
    def _recordTestStartTime(self):
310
319
        """Record that a test has started."""
401
410
        else:
402
411
            raise errors.BzrError("Unknown whence %r" % whence)
403
412
 
404
 
    def report_cleaning_up(self):
405
 
        pass
 
413
    def report_tests_starting(self):
 
414
        """Display information before the test run begins"""
 
415
        if getattr(sys, 'frozen', None) is None:
 
416
            bzr_path = osutils.realpath(sys.argv[0])
 
417
        else:
 
418
            bzr_path = sys.executable
 
419
        self.stream.write(
 
420
            'bzr selftest: %s\n' % (bzr_path,))
 
421
        self.stream.write(
 
422
            '   %s\n' % (
 
423
                    bzrlib.__path__[0],))
 
424
        self.stream.write(
 
425
            '   bzr-%s python-%s %s\n' % (
 
426
                    bzrlib.version_string,
 
427
                    bzrlib._format_version_tuple(sys.version_info),
 
428
                    platform.platform(aliased=1),
 
429
                    ))
 
430
        self.stream.write('\n')
 
431
 
 
432
    def report_test_start(self, test):
 
433
        """Display information on the test just about to be run"""
 
434
 
 
435
    def _report_thread_leak(self, test, leaked_threads, active_threads):
 
436
        """Display information on a test that leaked one or more threads"""
 
437
        # GZ 2010-09-09: A leak summary reported separately from the general
 
438
        #                thread debugging would be nice. Tests under subunit
 
439
        #                need something not using stream, perhaps adding a
 
440
        #                testtools details object would be fitting.
 
441
        if 'threads' in selftest_debug_flags:
 
442
            self.stream.write('%s is leaking, active is now %d\n' %
 
443
                (test.id(), len(active_threads)))
406
444
 
407
445
    def startTestRun(self):
408
446
        self.startTime = time.time()
481
519
        return a
482
520
 
483
521
    def report_test_start(self, test):
484
 
        self.count += 1
485
522
        self.pb.update(
486
523
                self._progress_prefix_text()
487
524
                + ' '
514
551
    def report_unsupported(self, test, feature):
515
552
        """test cannot be run because feature is missing."""
516
553
 
517
 
    def report_cleaning_up(self):
518
 
        self.pb.update('Cleaning up')
519
 
 
520
554
 
521
555
class VerboseTestResult(ExtendedTestResult):
522
556
    """Produce long output, with one line per test run plus times"""
534
568
        self.stream.write('running %d tests...\n' % self.num_tests)
535
569
 
536
570
    def report_test_start(self, test):
537
 
        self.count += 1
538
571
        name = self._shortened_test_description(test)
539
572
        width = osutils.terminal_width()
540
573
        if width is not None:
795
828
    accidentally overlooked.
796
829
    """
797
830
 
798
 
    _active_threads = None
799
 
    _leaking_threads_tests = 0
800
 
    _first_thread_leaker_id = None
801
831
    _log_file = None
802
832
    # record lsprof data when performing benchmark calls.
803
833
    _gather_lsprof_in_benchmarks = False
828
858
        self._track_transports()
829
859
        self._track_locks()
830
860
        self._clear_debug_flags()
831
 
        TestCase._active_threads = threading.activeCount()
832
 
        self.addCleanup(self._check_leaked_threads)
833
861
 
834
862
    def debug(self):
835
863
        # debug a frame up.
836
864
        import pdb
837
865
        pdb.Pdb().set_trace(sys._getframe().f_back)
838
866
 
839
 
    def _check_leaked_threads(self):
840
 
        active = threading.activeCount()
841
 
        leaked_threads = active - TestCase._active_threads
842
 
        TestCase._active_threads = active
843
 
        # If some tests make the number of threads *decrease*, we'll consider
844
 
        # that they are just observing old threads dieing, not agressively kill
845
 
        # random threads. So we don't report these tests as leaking. The risk
846
 
        # is that we have false positives that way (the test see 2 threads
847
 
        # going away but leak one) but it seems less likely than the actual
848
 
        # false positives (the test see threads going away and does not leak).
849
 
        if leaked_threads > 0:
850
 
            if 'threads' in selftest_debug_flags:
851
 
                print '%s is leaking, active is now %d' % (self.id(), active)
852
 
            TestCase._leaking_threads_tests += 1
853
 
            if TestCase._first_thread_leaker_id is None:
854
 
                TestCase._first_thread_leaker_id = self.id()
855
 
 
856
867
    def _clear_debug_flags(self):
857
868
        """Prevent externally set debug flags affecting tests.
858
869