~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/selftest/__init__.py

[merge] trace improvements

 - shorter error messages on exceptions

 - shorter display of status and time in selftest output

 - send debug output direct to file to reduce cost of going
   through Python logging

 - always send exception tracebacks to trace file

Show diffs side-by-side

added added

removed removed

Lines of Context:
27
27
import unittest
28
28
import time
29
29
 
30
 
from logging import debug, warning, error
31
 
 
32
30
import bzrlib.commands
33
31
import bzrlib.trace
34
32
import bzrlib.osutils as osutils
 
33
from bzrlib.trace import mutter
35
34
from bzrlib.selftest import TestUtil
36
35
from bzrlib.selftest.TestUtil import TestLoader, TestSuite
37
36
from bzrlib.selftest.treeshape import build_tree_contents
66
65
 
67
66
 
68
67
class _MyResult(unittest._TextTestResult):
69
 
    """
70
 
    Custom TestResult.
 
68
    """Custom TestResult.
71
69
 
72
70
    No special behaviour for now.
73
71
    """
74
72
 
 
73
    # assumes 80-column window, less 'ERROR 99999ms' = 13ch
75
74
    def _elapsedTime(self):
76
 
        return "(Took %.3fs)" % (time.time() - self._start_time)
 
75
        return "%5dms" % (1000 * (time.time() - self._start_time))
77
76
 
78
77
    def startTest(self, test):
79
78
        unittest.TestResult.startTest(self, test)
80
79
        # TODO: Maybe show test.shortDescription somewhere?
81
80
        what = test.shortDescription() or test.id()        
 
81
        pref = 'bzrlib.selftest.'
 
82
        if what.startswith(pref):
 
83
            what = what[len(pref):]
82
84
        if self.showAll:
83
 
            self.stream.write('%-70.70s' % what)
 
85
            self.stream.write('%-65.65s' % what)
84
86
        self.stream.flush()
85
87
        self._start_time = time.time()
86
88
 
95
97
    def addFailure(self, test, err):
96
98
        unittest.TestResult.addFailure(self, test, err)
97
99
        if self.showAll:
98
 
            self.stream.writeln("FAIL %s" % self._elapsedTime())
 
100
            self.stream.writeln(" FAIL %s" % self._elapsedTime())
99
101
        elif self.dots:
100
102
            self.stream.write('F')
101
103
        self.stream.flush()
102
104
 
103
105
    def addSuccess(self, test):
104
106
        if self.showAll:
105
 
            self.stream.writeln('OK %s' % self._elapsedTime())
 
107
            self.stream.writeln('   OK %s' % self._elapsedTime())
106
108
        elif self.dots:
107
109
            self.stream.write('~')
108
110
        self.stream.flush()
224
226
        fileno, name = tempfile.mkstemp(suffix='.log', prefix='testbzr')
225
227
        self._log_file = os.fdopen(fileno, 'w+')
226
228
        bzrlib.trace.enable_test_log(self._log_file)
227
 
        debug('opened log file %s', name)
228
229
        self._log_file_name = name
229
230
        self.addCleanup(self._finishLogFile)
230
231
 
298
299
            callable()
299
300
 
300
301
    def log(self, *args):
301
 
        logging.debug(*args)
 
302
        mutter(*args)
302
303
 
303
304
    def _get_log(self):
304
305
        """Return as a string the log for this test"""
306
307
            return open(self._log_file_name).read()
307
308
        else:
308
309
            return self._log_contents
 
310
        # TODO: Delete the log after it's been read in
309
311
 
310
312
    def capture(self, cmd, retcode=0):
311
313
        """Shortcut that splits cmd into words, runs, and returns stdout"""
334
336
        stdout = StringIO()
335
337
        stderr = StringIO()
336
338
        self.log('run bzr: %s', ' '.join(argv))
 
339
        # FIXME: don't call into logging here
337
340
        handler = logging.StreamHandler(stderr)
338
341
        handler.setFormatter(bzrlib.trace.QuietFormatter())
339
342
        handler.setLevel(logging.INFO)
528
531
    def test_logging(self):
529
532
        """Test logs are captured when a test fails."""
530
533
        self.log('a test message')
 
534
        self._log_file.flush()
531
535
        self.assertContainsRe(self._get_log(), 'a test message\n')
532
536
 
533
537