/brz/remove-bazaar

To get this branch, use:
bzr branch http://gegoxaren.bato24.eu/bzr/brz/remove-bazaar

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_trace.py

  • Committer: Robert Collins
  • Date: 2010-05-06 23:41:35 UTC
  • mto: This revision was merged to the branch mainline in revision 5223.
  • Revision ID: robertc@robertcollins.net-20100506234135-yivbzczw1sejxnxc
Lock methods on ``Tree``, ``Branch`` and ``Repository`` are now
expected to return an object which can be used to unlock them. This reduces
duplicate code when using cleanups. The previous 'tokens's returned by
``Branch.lock_write`` and ``Repository.lock_write`` are now attributes
on the result of the lock_write. ``repository.RepositoryWriteLockResult``
and ``branch.BranchWriteLockResult`` document this. (Robert Collins)

``log._get_info_for_log_files`` now takes an add_cleanup callable.
(Robert Collins)

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/tests/test_trace.py
1
 
# Copyright (C) 2005-2011, 2016 Canonical Ltd
 
1
# Copyright (C) 2005-2010 Canonical Ltd
2
2
#
3
3
# This program is free software; you can redistribute it and/or modify
4
4
# it under the terms of the GNU General Public License as published by
18
18
 
19
19
"""Tests for trace library"""
20
20
 
 
21
from cStringIO import StringIO
21
22
import errno
22
 
import logging
23
23
import os
24
24
import re
25
25
import sys
26
26
import tempfile
27
27
 
28
 
from .. import (
29
 
    debug,
 
28
from bzrlib import (
30
29
    errors,
31
30
    trace,
32
31
    )
33
 
from ..sixish import (
34
 
    PY3,
35
 
    StringIO,
36
 
    )
37
 
from . import features, TestCaseInTempDir, TestCase, TestSkipped
38
 
from ..trace import (
 
32
from bzrlib.tests import TestCaseInTempDir, TestCase
 
33
from bzrlib.trace import (
39
34
    mutter, mutter_callsite, report_exception,
40
35
    set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
41
36
    pop_log_file,
56
51
 
57
52
    def test_format_sys_exception(self):
58
53
        # Test handling of an internal/unexpected error that probably
59
 
        # indicates a bug in brz.  The details of the message may vary
 
54
        # indicates a bug in bzr.  The details of the message may vary
60
55
        # depending on whether apport is available or not.  See test_crash for
61
56
        # more.
62
57
        try:
63
 
            raise NotImplementedError("time travel")
 
58
            raise NotImplementedError, "time travel"
64
59
        except NotImplementedError:
65
 
            err = _format_exception()
66
 
        self.assertContainsRe(err,
67
 
                              '^brz: ERROR: NotImplementedError: time travel')
68
 
        self.assertContainsRe(err,
69
 
                              'Bazaar has encountered an internal error.')
 
60
            pass
 
61
        err = _format_exception()
 
62
        self.assertEqualDiff(err.splitlines()[0],
 
63
                'bzr: ERROR: exceptions.NotImplementedError: time travel')
 
64
        self.assertContainsRe(err,
 
65
            'Bazaar has encountered an internal error.')
70
66
 
71
67
    def test_format_interrupt_exception(self):
72
68
        try:
73
69
            raise KeyboardInterrupt()
74
70
        except KeyboardInterrupt:
75
71
            # XXX: Some risk that a *real* keyboard interrupt won't be seen
76
 
            msg = _format_exception()
77
 
        self.assertEqual(msg, 'brz: interrupted\n')
 
72
            pass
 
73
        msg = _format_exception()
 
74
        self.assertTrue(len(msg) > 0)
 
75
        self.assertEqualDiff(msg, 'bzr: interrupted\n')
78
76
 
79
77
    def test_format_memory_error(self):
80
78
        try:
81
79
            raise MemoryError()
82
80
        except MemoryError:
83
 
            msg = _format_exception()
84
 
        self.assertEqual(
85
 
            msg,
86
 
            "brz: out of memory\nUse -Dmem_dump to dump memory to a file.\n")
87
 
 
88
 
    def test_format_mem_dump(self):
89
 
        self.requireFeature(features.meliae)
90
 
        debug.debug_flags.add('mem_dump')
91
 
        try:
92
 
            raise MemoryError()
93
 
        except MemoryError:
94
 
            msg = _format_exception()
95
 
        self.assertStartsWith(msg,
96
 
                              "brz: out of memory\nMemory dumped to ")
 
81
            pass
 
82
        msg = _format_exception()
 
83
        self.assertEquals(msg,
 
84
            "bzr: out of memory\n")
97
85
 
98
86
    def test_format_os_error(self):
99
87
        try:
100
88
            os.rmdir('nosuchfile22222')
101
 
        except OSError as e:
 
89
        except OSError, e:
102
90
            e_str = str(e)
103
 
            msg = _format_exception()
 
91
        msg = _format_exception()
104
92
        # Linux seems to give "No such file" but Windows gives "The system
105
93
        # cannot find the file specified".
106
 
        self.assertEqual('brz: ERROR: %s\n' % (e_str,), msg)
 
94
        self.assertEqual('bzr: ERROR: %s\n' % (e_str,), msg)
107
95
 
108
96
    def test_format_io_error(self):
109
97
        try:
110
 
            open('nosuchfile22222')
 
98
            file('nosuchfile22222')
111
99
        except IOError:
112
 
            msg = _format_exception()
 
100
            pass
 
101
        msg = _format_exception()
113
102
        # Even though Windows and Linux differ for 'os.rmdir', they both give
114
103
        # 'No such file' for open()
115
 
        # However it now gets translated so we can not test for a specific
116
 
        # message
117
104
        self.assertContainsRe(msg,
118
 
                              '^brz: ERROR: \\[Errno .*\\] .*nosuchfile')
119
 
 
120
 
    def test_format_pywintypes_error(self):
121
 
        self.requireFeature(features.pywintypes)
122
 
        import pywintypes
123
 
        import win32file
124
 
        try:
125
 
            win32file.RemoveDirectory('nosuchfile22222')
126
 
        except pywintypes.error:
127
 
            msg = _format_exception()
128
 
        # GZ 2010-05-03: Formatting for pywintypes.error is basic, a 3-tuple
129
 
        #                with errno, function name, and locale error message
130
 
        self.assertContainsRe(
131
 
            msg, "^brz: ERROR: \\(2, 'RemoveDirectory[AW]?', .*\\)")
132
 
 
133
 
    def test_format_sockets_error(self):
134
 
        try:
135
 
            import socket
136
 
            sock = socket.socket()
137
 
            sock.send(b"This should fail.")
138
 
        except socket.error:
139
 
            msg = _format_exception()
140
 
 
141
 
        self.assertNotContainsRe(msg,
142
 
                                 "Traceback \\(most recent call last\\):")
 
105
            r'^bzr: ERROR: \[Errno .*\] No such file.*nosuchfile')
143
106
 
144
107
    def test_format_unicode_error(self):
145
108
        try:
146
109
            raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
147
110
        except errors.BzrCommandError:
148
 
            msg = _format_exception()
149
 
        if PY3:
150
 
            expected = 'brz: ERROR: argument foo\xb5 does not exist\n'
151
 
        else:
152
 
            # GZ 2017-06-10: Pretty bogus, should encode per the output stream
153
 
            expected = 'brz: ERROR: argument foo\xc2\xb5 does not exist\n'
154
 
        self.assertEqual(msg, expected)
 
111
            pass
 
112
        msg = _format_exception()
155
113
 
156
114
    def test_format_exception(self):
157
 
        """Short formatting of brz exceptions"""
 
115
        """Short formatting of bzr exceptions"""
158
116
        try:
159
117
            raise errors.NotBranchError('wibble')
160
118
        except errors.NotBranchError:
161
 
            msg = _format_exception()
162
 
        self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
 
119
            pass
 
120
        msg = _format_exception()
 
121
        self.assertTrue(len(msg) > 0)
 
122
        self.assertEqualDiff(msg, 'bzr: ERROR: Not a branch: \"wibble\".\n')
163
123
 
164
124
    def test_report_external_import_error(self):
165
125
        """Short friendly message for missing system modules."""
166
126
        try:
167
127
            import ImaginaryModule
168
 
        except ImportError:
169
 
            msg = _format_exception()
 
128
        except ImportError, e:
 
129
            pass
170
130
        else:
171
131
            self.fail("somehow succeeded in importing %r" % ImaginaryModule)
172
 
        self.assertContainsRe(
173
 
            msg,
174
 
            "^brz: ERROR: No module named '?ImaginaryModule'?\n"
175
 
            "You may need to install this Python library separately.\n$")
 
132
        msg = _format_exception()
 
133
        self.assertEqual(msg,
 
134
            'bzr: ERROR: No module named ImaginaryModule\n'
 
135
            'You may need to install this Python library separately.\n')
176
136
 
177
137
    def test_report_import_syntax_error(self):
178
138
        try:
179
139
            raise ImportError("syntax error")
180
 
        except ImportError:
181
 
            msg = _format_exception()
 
140
        except ImportError, e:
 
141
            pass
 
142
        msg = _format_exception()
182
143
        self.assertContainsRe(msg,
183
 
                              'Bazaar has encountered an internal error')
 
144
            r'Bazaar has encountered an internal error')
184
145
 
185
146
    def test_trace_unicode(self):
186
147
        """Write Unicode to trace log"""
201
162
        log = self.get_log()
202
163
        self.assertContainsRe(log, 'the unicode character')
203
164
 
204
 
    def test_trace_argument_exception(self):
205
 
        err = Exception('an error')
206
 
        mutter(u'can format stringable classes %s', err)
207
 
        log = self.get_log()
208
 
        self.assertContainsRe(log, 'can format stringable classes an error')
209
 
 
210
165
    def test_report_broken_pipe(self):
211
166
        try:
212
167
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
213
 
        except IOError:
 
168
        except IOError, e:
214
169
            msg = _format_exception()
215
 
            self.assertEqual(msg, "brz: broken pipe\n")
 
170
            self.assertEquals(msg, "bzr: broken pipe\n")
216
171
        else:
217
172
            self.fail("expected error not raised")
218
173
 
219
 
    def assertLogContainsLine(self, log, string):
220
 
        """Assert log contains a line including log timestamp."""
221
 
        # Does not check absolute position in log as there may be kipple.
 
174
    def assertLogStartsWith(self, log, string):
 
175
        """Like assertStartsWith, but skips the log timestamp."""
222
176
        self.assertContainsRe(log,
223
 
                              '(?m)^\\d+\\.\\d+  ' + re.escape(string))
 
177
            '^\\d+\\.\\d+  ' + re.escape(string))
224
178
 
225
179
    def test_mutter_callsite_1(self):
226
180
        """mutter_callsite can capture 1 level of stack frame."""
227
181
        mutter_callsite(1, "foo %s", "a string")
228
182
        log = self.get_log()
229
183
        # begin with the message
230
 
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
184
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
231
185
        # should show two frame: this frame and the one above
232
 
        self.assertContainsRe(
233
 
            log, 'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
 
186
        self.assertContainsRe(log,
 
187
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
234
188
        # this frame should be the final one
235
189
        self.assertEndsWith(log, ' "a string")\n')
236
190
 
239
193
        mutter_callsite(2, "foo %s", "a string")
240
194
        log = self.get_log()
241
195
        # begin with the message
242
 
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
196
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
243
197
        # should show two frame: this frame and the one above
244
 
        self.assertContainsRe(
245
 
            log, 'test_trace.py", line \\d+, in test_mutter_callsite_2\n')
 
198
        self.assertContainsRe(log,
 
199
            'test_trace.py", line \d+, in test_mutter_callsite_2\n')
246
200
        # this frame should be the final one
247
201
        self.assertEndsWith(log, ' "a string")\n')
248
202
 
249
203
    def test_mutter_never_fails(self):
250
 
        """Even with unencodable input mutter should not raise errors."""
251
 
        mutter(u'can write unicode \xa7')
252
 
        mutter('can interpolate unicode %s', u'\xa7')
253
 
        mutter(b'can write bytes \xa7')
254
 
        mutter('can repr bytes %r', b'\xa7')
255
 
        mutter('can interpolate bytes %s', b'\xa7')
256
 
        # Log will always be written as utf-8
 
204
        # Even if the decode/encode stage fails, mutter should not
 
205
        # raise an exception
 
206
        # This test checks that mutter doesn't fail; the current behaviour
 
207
        # is that it doesn't fail *and writes non-utf8*.
 
208
        mutter(u'Writing a greek mu (\xb5) works in a unicode string')
 
209
        mutter('But fails in an ascii string \xb5')
 
210
        mutter('and in an ascii argument: %s', '\xb5')
257
211
        log = self.get_log()
258
 
        self.assertContainsRe(
259
 
            log,
260
 
            u'.* +can write unicode \xa7\n'
261
 
            u'.* +can interpolate unicode \xa7\n'
262
 
            u'.* +can write bytes \ufffd\n'
263
 
            u'.* +can repr bytes b\'\\\\xa7\'\n'
264
 
            u'.* +can interpolate bytes (?:\ufffd|b\'\\\\xa7\')\n')
265
 
 
 
212
        self.assertContainsRe(log, 'Writing a greek mu')
 
213
        self.assertContainsRe(log, "But fails in an ascii string")
 
214
        # However, the log content object does unicode replacement on reading
 
215
        # to let it get unicode back where good data has been written. So we
 
216
        # have to do a replaceent here as well.
 
217
        self.assertContainsRe(log, "ascii argument: \xb5".decode('utf8',
 
218
            'replace'))
 
219
        
266
220
    def test_show_error(self):
267
221
        show_error('error1')
268
222
        show_error(u'error2 \xb5 blah')
269
223
        show_error('arg: %s', 'blah')
270
 
        show_error('arg2: %(key)s', {'key': 'stuff'})
 
224
        show_error('arg2: %(key)s', {'key':'stuff'})
271
225
        try:
272
226
            raise Exception("oops")
273
 
        except BaseException:
 
227
        except:
274
228
            show_error('kwarg', exc_info=True)
275
229
        log = self.get_log()
276
230
        self.assertContainsRe(log, 'error1')
279
233
        self.assertContainsRe(log, 'arg2: stuff')
280
234
        self.assertContainsRe(log, 'kwarg')
281
235
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
282
 
        self.assertContainsRe(
283
 
            log, 'File ".*test_trace.py", line .*, in test_show_error')
 
236
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
284
237
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
285
238
        self.assertContainsRe(log, 'Exception: oops')
286
239
 
309
262
            # as there's a timestamp at the front.
310
263
            tmp1.seek(0)
311
264
            self.assertContainsRe(tmp1.read(),
312
 
                                  b"\\d+\\.\\d+  comment to file1\n"
313
 
                                  b"\\d+\\.\\d+  again to file1\n")
 
265
                r"\d+\.\d+  comment to file1\n\d+\.\d+  again to file1\n")
314
266
            tmp2.seek(0)
315
267
            self.assertContainsRe(tmp2.read(),
316
 
                                  b"\\d+\\.\\d+  comment to file2\n")
 
268
                r"\d+\.\d+  comment to file2\n")
317
269
        finally:
318
270
            tmp1.close()
319
271
            tmp2.close()
320
272
 
321
 
    def test__open_brz_log_uses_stderr_for_failures(self):
322
 
        # If _open_brz_log cannot open the file, then we should write the
 
273
    def test__open_bzr_log_uses_stderr_for_failures(self):
 
274
        # If _open_bzr_log cannot open the file, then we should write the
323
275
        # warning to stderr. Since this is normally happening before logging is
324
276
        # set up.
325
277
        self.overrideAttr(sys, 'stderr', StringIO())
326
278
        # Set the log file to something that cannot exist
327
 
        self.overrideEnv('BRZ_LOG', '/no-such-dir/brz.log')
328
 
        self.overrideAttr(trace, '_brz_log_filename')
329
 
        logf = trace._open_brz_log()
330
 
        if os.path.isdir('/no-such-dir'):
331
 
            raise TestSkipped('directory creation succeeded')
332
 
        self.assertIs(None, logf)
333
 
        self.assertContainsRe(
334
 
            sys.stderr.getvalue(),
335
 
            "failed to open trace file: .* '/no-such-dir/brz.log'$")
336
 
 
337
 
    def test__open_brz_log_ignores_cache_dir_error(self):
338
 
        # If the cache directory can not be created and _open_brz_log can thus
339
 
        # not open the file, then we should write the warning to stderr. Since
340
 
        # this is normally happening before logging is set up.
341
 
        self.overrideAttr(sys, 'stderr', StringIO())
342
 
        # Set the cache directory to something that cannot exist
343
 
        self.overrideEnv('BRZ_LOG', None)
344
 
        self.overrideEnv('BRZ_HOME', '/no-such-dir')
345
 
        self.overrideEnv('XDG_CACHE_HOME', '/no-such-dir')
346
 
        self.overrideAttr(trace, '_brz_log_filename')
347
 
        logf = trace._open_brz_log()
348
 
        if os.path.isdir('/no-such-dir'):
349
 
            raise TestSkipped('directory creation succeeded')
350
 
        self.assertIs(None, logf)
351
 
        self.assertContainsRe(
352
 
            sys.stderr.getvalue(),
353
 
            "failed to open trace file: .* '/no-such-dir'$")
 
279
        # FIXME: A bit dangerous: we are not in an isolated dir here -- vilajam
 
280
        # 20100125
 
281
        os.environ['BZR_LOG'] = os.getcwd() + '/no-dir/bzr.log'
 
282
        self.overrideAttr(trace, '_bzr_log_filename')
 
283
        logf = trace._open_bzr_log()
 
284
        self.assertIs(None, logf)
 
285
        self.assertContainsRe(sys.stderr.getvalue(),
 
286
                              'failed to open trace file: .*/no-dir/bzr.log')
354
287
 
355
288
 
356
289
class TestVerbosityLevel(TestCase):
377
310
        self.assertEqual(0, get_verbosity_level())
378
311
 
379
312
 
380
 
class TestLogging(TestCase):
381
 
    """Check logging functionality robustly records information"""
382
 
 
383
 
    def test_note(self):
384
 
        trace.note("Noted")
385
 
        self.assertEqual("    INFO  Noted\n", self.get_log())
386
 
 
387
 
    def test_warning(self):
388
 
        trace.warning("Warned")
389
 
        self.assertEqual(" WARNING  Warned\n", self.get_log())
390
 
 
391
 
    def test_log(self):
392
 
        logging.getLogger("brz").error("Errored")
393
 
        self.assertEqual("   ERROR  Errored\n", self.get_log())
394
 
 
395
 
    def test_log_sub(self):
396
 
        logging.getLogger("brz.test_log_sub").debug("Whispered")
397
 
        self.assertEqual("   DEBUG  Whispered\n", self.get_log())
398
 
 
399
 
    def test_log_unicode_msg(self):
400
 
        logging.getLogger("brz").debug(u"\xa7")
401
 
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
402
 
 
403
 
    def test_log_unicode_arg(self):
404
 
        logging.getLogger("brz").debug("%s", u"\xa7")
405
 
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
406
 
 
407
 
    def test_log_utf8_msg(self):
408
 
        logging.getLogger("brz").debug(b"\xc2\xa7")
409
 
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
410
 
 
411
 
    def test_log_utf8_arg(self):
412
 
        logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
413
 
        if PY3:
414
 
            expected = u"   DEBUG  b'\\xc2\\xa7'\n"
415
 
        else:
416
 
            expected = u"   DEBUG  \xa7\n"
417
 
        self.assertEqual(expected, self.get_log())
418
 
 
419
 
    def test_log_bytes_msg(self):
420
 
        logging.getLogger("brz").debug(b"\xa7")
421
 
        log = self.get_log()
422
 
        self.assertContainsString(log, "UnicodeDecodeError: ")
423
 
        self.assertContainsRe(
424
 
            log, "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
425
 
 
426
 
    def test_log_bytes_arg(self):
427
 
        logging.getLogger("brz").debug(b"%s", b"\xa7")
428
 
        log = self.get_log()
429
 
        if PY3:
430
 
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
431
 
        else:
432
 
            self.assertContainsString(log, "UnicodeDecodeError: ")
433
 
            self.assertContainsRe(
434
 
                log,
435
 
                "Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
436
 
 
437
 
    def test_log_mixed_strings(self):
438
 
        logging.getLogger("brz").debug(u"%s", b"\xa7")
439
 
        log = self.get_log()
440
 
        if PY3:
441
 
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
442
 
        else:
443
 
            self.assertContainsString(log, "UnicodeDecodeError: ")
444
 
            self.assertContainsRe(
445
 
                log,
446
 
                "Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
447
 
 
448
 
    def test_log_repr_broken(self):
449
 
        class BadRepr(object):
450
 
            def __repr__(self):
451
 
                raise ValueError("Broken object")
452
 
        logging.getLogger("brz").debug("%s", BadRepr())
453
 
        log = self.get_log()
454
 
        self.assertContainsRe(log, "ValueError: Broken object\n")
455
 
        self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
456
 
 
457
 
 
458
313
class TestBzrLog(TestCaseInTempDir):
459
314
 
460
315
    def test_log_rollover(self):
465
320
        _rollover_trace_maybe(temp_log_name)
466
321
        # should have been rolled over
467
322
        self.assertFalse(os.access(temp_log_name, os.R_OK))
468
 
 
469
 
 
470
 
class TestTraceConfiguration(TestCaseInTempDir):
471
 
 
472
 
    def test_default_config(self):
473
 
        config = trace.DefaultConfig()
474
 
        self.overrideAttr(trace, "_brz_log_filename", None)
475
 
        trace._brz_log_filename = None
476
 
        expected_filename = trace._get_brz_log_filename()
477
 
        self.assertEqual(None, trace._brz_log_filename)
478
 
        config.__enter__()
479
 
        try:
480
 
            # Should have entered and setup a default filename.
481
 
            self.assertEqual(expected_filename, trace._brz_log_filename)
482
 
        finally:
483
 
            config.__exit__(None, None, None)
484
 
            # Should have exited and cleaned up.
485
 
            self.assertEqual(None, trace._brz_log_filename)