/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 breezy/tests/test_trace.py

  • Committer: Jelmer Vernooij
  • Date: 2019-10-28 01:38:39 UTC
  • mto: This revision was merged to the branch mainline in revision 7412.
  • Revision ID: jelmer@jelmer.uk-20191028013839-q63zzm4yr0id9b3o
Allow unknown extras in git commits when just inspecting revisions, rather than importing.

Show diffs side-by-side

added added

removed removed

Lines of Context:
breezy/tests/test_trace.py
1
 
# Copyright (C) 2005-2010 Canonical Ltd
 
1
# Copyright (C) 2005-2011, 2016 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
22
21
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 bzrlib import (
 
28
from .. import (
 
29
    debug,
29
30
    errors,
30
31
    trace,
31
32
    )
32
 
from bzrlib.tests import TestCaseInTempDir, TestCase
33
 
from bzrlib.trace import (
 
33
from ..sixish import (
 
34
    PY3,
 
35
    StringIO,
 
36
    )
 
37
from . import features, TestCaseInTempDir, TestCase
 
38
from ..trace import (
34
39
    mutter, mutter_callsite, report_exception,
35
40
    set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
36
41
    pop_log_file,
51
56
 
52
57
    def test_format_sys_exception(self):
53
58
        # Test handling of an internal/unexpected error that probably
54
 
        # indicates a bug in bzr.  The details of the message may vary
 
59
        # indicates a bug in brz.  The details of the message may vary
55
60
        # depending on whether apport is available or not.  See test_crash for
56
61
        # more.
57
62
        try:
58
 
            raise NotImplementedError, "time travel"
 
63
            raise NotImplementedError("time travel")
59
64
        except NotImplementedError:
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.')
 
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.')
66
70
 
67
71
    def test_format_interrupt_exception(self):
68
72
        try:
69
73
            raise KeyboardInterrupt()
70
74
        except KeyboardInterrupt:
71
75
            # XXX: Some risk that a *real* keyboard interrupt won't be seen
72
 
            pass
73
 
        msg = _format_exception()
74
 
        self.assertTrue(len(msg) > 0)
75
 
        self.assertEqualDiff(msg, 'bzr: interrupted\n')
 
76
            msg = _format_exception()
 
77
        self.assertEqual(msg, 'brz: interrupted\n')
76
78
 
77
79
    def test_format_memory_error(self):
78
80
        try:
79
81
            raise MemoryError()
80
82
        except MemoryError:
81
 
            pass
82
 
        msg = _format_exception()
83
 
        self.assertEquals(msg,
84
 
            "bzr: out of memory\n")
 
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 ")
85
97
 
86
98
    def test_format_os_error(self):
87
99
        try:
88
100
            os.rmdir('nosuchfile22222')
89
 
        except OSError, e:
 
101
        except OSError as e:
90
102
            e_str = str(e)
91
 
        msg = _format_exception()
 
103
            msg = _format_exception()
92
104
        # Linux seems to give "No such file" but Windows gives "The system
93
105
        # cannot find the file specified".
94
 
        self.assertEqual('bzr: ERROR: %s\n' % (e_str,), msg)
 
106
        self.assertEqual('brz: ERROR: %s\n' % (e_str,), msg)
95
107
 
96
108
    def test_format_io_error(self):
97
109
        try:
98
 
            file('nosuchfile22222')
 
110
            open('nosuchfile22222')
99
111
        except IOError:
100
 
            pass
101
 
        msg = _format_exception()
 
112
            msg = _format_exception()
102
113
        # Even though Windows and Linux differ for 'os.rmdir', they both give
103
114
        # 'No such file' for open()
 
115
        # However it now gets translated so we can not test for a specific
 
116
        # message
104
117
        self.assertContainsRe(msg,
105
 
            r'^bzr: ERROR: \[Errno .*\] No such file.*nosuchfile')
 
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\\):")
106
143
 
107
144
    def test_format_unicode_error(self):
108
145
        try:
109
146
            raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
110
147
        except errors.BzrCommandError:
111
 
            pass
112
 
        msg = _format_exception()
 
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)
113
155
 
114
156
    def test_format_exception(self):
115
 
        """Short formatting of bzr exceptions"""
 
157
        """Short formatting of brz exceptions"""
116
158
        try:
117
159
            raise errors.NotBranchError('wibble')
118
160
        except errors.NotBranchError:
119
 
            pass
120
 
        msg = _format_exception()
121
 
        self.assertTrue(len(msg) > 0)
122
 
        self.assertEqualDiff(msg, 'bzr: ERROR: Not a branch: \"wibble\".\n')
 
161
            msg = _format_exception()
 
162
        self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
123
163
 
124
164
    def test_report_external_import_error(self):
125
165
        """Short friendly message for missing system modules."""
126
166
        try:
127
167
            import ImaginaryModule
128
 
        except ImportError, e:
129
 
            pass
 
168
        except ImportError:
 
169
            msg = _format_exception()
130
170
        else:
131
171
            self.fail("somehow succeeded in importing %r" % ImaginaryModule)
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')
 
172
        self.assertContainsRe(
 
173
            msg,
 
174
            "^brz: ERROR: No module named '?ImaginaryModule'?\n"
 
175
            "You may need to install this Python library separately.\n$")
136
176
 
137
177
    def test_report_import_syntax_error(self):
138
178
        try:
139
179
            raise ImportError("syntax error")
140
 
        except ImportError, e:
141
 
            pass
142
 
        msg = _format_exception()
 
180
        except ImportError:
 
181
            msg = _format_exception()
143
182
        self.assertContainsRe(msg,
144
 
            r'Bazaar has encountered an internal error')
 
183
                              'Bazaar has encountered an internal error')
145
184
 
146
185
    def test_trace_unicode(self):
147
186
        """Write Unicode to trace log"""
162
201
        log = self.get_log()
163
202
        self.assertContainsRe(log, 'the unicode character')
164
203
 
 
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
 
165
210
    def test_report_broken_pipe(self):
166
211
        try:
167
212
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
168
 
        except IOError, e:
 
213
        except IOError:
169
214
            msg = _format_exception()
170
 
            self.assertEquals(msg, "bzr: broken pipe\n")
 
215
            self.assertEqual(msg, "brz: broken pipe\n")
171
216
        else:
172
217
            self.fail("expected error not raised")
173
218
 
174
 
    def assertLogStartsWith(self, log, string):
175
 
        """Like assertStartsWith, but skips the log timestamp."""
 
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.
176
222
        self.assertContainsRe(log,
177
 
            '^\\d+\\.\\d+  ' + re.escape(string))
 
223
                              '(?m)^\\d+\\.\\d+  ' + re.escape(string))
178
224
 
179
225
    def test_mutter_callsite_1(self):
180
226
        """mutter_callsite can capture 1 level of stack frame."""
181
227
        mutter_callsite(1, "foo %s", "a string")
182
228
        log = self.get_log()
183
229
        # begin with the message
184
 
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
 
230
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
185
231
        # should show two frame: this frame and the one above
186
 
        self.assertContainsRe(log,
187
 
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
 
232
        self.assertContainsRe(
 
233
            log, 'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
188
234
        # this frame should be the final one
189
235
        self.assertEndsWith(log, ' "a string")\n')
190
236
 
193
239
        mutter_callsite(2, "foo %s", "a string")
194
240
        log = self.get_log()
195
241
        # begin with the message
196
 
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
 
242
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
197
243
        # should show two frame: this frame and the one above
198
 
        self.assertContainsRe(log,
199
 
            'test_trace.py", line \d+, in test_mutter_callsite_2\n')
 
244
        self.assertContainsRe(
 
245
            log, 'test_trace.py", line \\d+, in test_mutter_callsite_2\n')
200
246
        # this frame should be the final one
201
247
        self.assertEndsWith(log, ' "a string")\n')
202
248
 
203
249
    def test_mutter_never_fails(self):
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')
 
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
211
257
        log = self.get_log()
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
 
        
 
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
 
220
266
    def test_show_error(self):
221
267
        show_error('error1')
222
268
        show_error(u'error2 \xb5 blah')
223
269
        show_error('arg: %s', 'blah')
224
 
        show_error('arg2: %(key)s', {'key':'stuff'})
 
270
        show_error('arg2: %(key)s', {'key': 'stuff'})
225
271
        try:
226
272
            raise Exception("oops")
227
 
        except:
 
273
        except BaseException:
228
274
            show_error('kwarg', exc_info=True)
229
275
        log = self.get_log()
230
276
        self.assertContainsRe(log, 'error1')
233
279
        self.assertContainsRe(log, 'arg2: stuff')
234
280
        self.assertContainsRe(log, 'kwarg')
235
281
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
236
 
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
 
282
        self.assertContainsRe(
 
283
            log, 'File ".*test_trace.py", line .*, in test_show_error')
237
284
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
238
285
        self.assertContainsRe(log, 'Exception: oops')
239
286
 
262
309
            # as there's a timestamp at the front.
263
310
            tmp1.seek(0)
264
311
            self.assertContainsRe(tmp1.read(),
265
 
                r"\d+\.\d+  comment to file1\n\d+\.\d+  again to file1\n")
 
312
                                  b"\\d+\\.\\d+  comment to file1\n"
 
313
                                  b"\\d+\\.\\d+  again to file1\n")
266
314
            tmp2.seek(0)
267
315
            self.assertContainsRe(tmp2.read(),
268
 
                r"\d+\.\d+  comment to file2\n")
 
316
                                  b"\\d+\\.\\d+  comment to file2\n")
269
317
        finally:
270
318
            tmp1.close()
271
319
            tmp2.close()
272
320
 
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
 
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
275
323
        # warning to stderr. Since this is normally happening before logging is
276
324
        # set up.
277
325
        self.overrideAttr(sys, 'stderr', StringIO())
278
326
        # Set the log file to something that cannot exist
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')
 
327
        self.overrideEnv('BRZ_LOG', '/no-such-dir/brz.log')
 
328
        self.overrideAttr(trace, '_brz_log_filename')
 
329
        logf = trace._open_brz_log()
 
330
        self.assertIs(None, logf)
 
331
        self.assertContainsRe(
 
332
            sys.stderr.getvalue(),
 
333
            "failed to open trace file: .* '/no-such-dir/brz.log'$")
 
334
 
 
335
    def test__open_brz_log_ignores_cache_dir_error(self):
 
336
        # If the cache directory can not be created and _open_brz_log can thus
 
337
        # not open the file, then we should write the warning to stderr. Since
 
338
        # this is normally happening before logging is set up.
 
339
        self.overrideAttr(sys, 'stderr', StringIO())
 
340
        # Set the cache directory to something that cannot exist
 
341
        self.overrideEnv('BRZ_LOG', None)
 
342
        self.overrideEnv('BRZ_HOME', '/no-such-dir')
 
343
        self.overrideEnv('XDG_CACHE_HOME', '/no-such-dir')
 
344
        self.overrideAttr(trace, '_brz_log_filename')
 
345
        logf = trace._open_brz_log()
 
346
        self.assertIs(None, logf)
 
347
        self.assertContainsRe(
 
348
            sys.stderr.getvalue(),
 
349
            "failed to open trace file: .* '/no-such-dir'$")
287
350
 
288
351
 
289
352
class TestVerbosityLevel(TestCase):
310
373
        self.assertEqual(0, get_verbosity_level())
311
374
 
312
375
 
 
376
class TestLogging(TestCase):
 
377
    """Check logging functionality robustly records information"""
 
378
 
 
379
    def test_note(self):
 
380
        trace.note("Noted")
 
381
        self.assertEqual("    INFO  Noted\n", self.get_log())
 
382
 
 
383
    def test_warning(self):
 
384
        trace.warning("Warned")
 
385
        self.assertEqual(" WARNING  Warned\n", self.get_log())
 
386
 
 
387
    def test_log(self):
 
388
        logging.getLogger("brz").error("Errored")
 
389
        self.assertEqual("   ERROR  Errored\n", self.get_log())
 
390
 
 
391
    def test_log_sub(self):
 
392
        logging.getLogger("brz.test_log_sub").debug("Whispered")
 
393
        self.assertEqual("   DEBUG  Whispered\n", self.get_log())
 
394
 
 
395
    def test_log_unicode_msg(self):
 
396
        logging.getLogger("brz").debug(u"\xa7")
 
397
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
398
 
 
399
    def test_log_unicode_arg(self):
 
400
        logging.getLogger("brz").debug("%s", u"\xa7")
 
401
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
402
 
 
403
    def test_log_utf8_msg(self):
 
404
        logging.getLogger("brz").debug(b"\xc2\xa7")
 
405
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
406
 
 
407
    def test_log_utf8_arg(self):
 
408
        logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
 
409
        if PY3:
 
410
            expected = u"   DEBUG  b'\\xc2\\xa7'\n"
 
411
        else:
 
412
            expected = u"   DEBUG  \xa7\n"
 
413
        self.assertEqual(expected, self.get_log())
 
414
 
 
415
    def test_log_bytes_msg(self):
 
416
        logging.getLogger("brz").debug(b"\xa7")
 
417
        log = self.get_log()
 
418
        self.assertContainsString(log, "UnicodeDecodeError: ")
 
419
        self.assertContainsRe(
 
420
            log, "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
 
421
 
 
422
    def test_log_bytes_arg(self):
 
423
        logging.getLogger("brz").debug(b"%s", b"\xa7")
 
424
        log = self.get_log()
 
425
        if PY3:
 
426
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
427
        else:
 
428
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
429
            self.assertContainsRe(
 
430
                log,
 
431
                "Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
 
432
 
 
433
    def test_log_mixed_strings(self):
 
434
        logging.getLogger("brz").debug(u"%s", b"\xa7")
 
435
        log = self.get_log()
 
436
        if PY3:
 
437
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
438
        else:
 
439
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
440
            self.assertContainsRe(
 
441
                log,
 
442
                "Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
 
443
 
 
444
    def test_log_repr_broken(self):
 
445
        class BadRepr(object):
 
446
            def __repr__(self):
 
447
                raise ValueError("Broken object")
 
448
        logging.getLogger("brz").debug("%s", BadRepr())
 
449
        log = self.get_log()
 
450
        self.assertContainsRe(log, "ValueError: Broken object\n")
 
451
        self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
 
452
 
 
453
 
313
454
class TestBzrLog(TestCaseInTempDir):
314
455
 
315
456
    def test_log_rollover(self):
320
461
        _rollover_trace_maybe(temp_log_name)
321
462
        # should have been rolled over
322
463
        self.assertFalse(os.access(temp_log_name, os.R_OK))
 
464
 
 
465
 
 
466
class TestTraceConfiguration(TestCaseInTempDir):
 
467
 
 
468
    def test_default_config(self):
 
469
        config = trace.DefaultConfig()
 
470
        self.overrideAttr(trace, "_brz_log_filename", None)
 
471
        trace._brz_log_filename = None
 
472
        expected_filename = trace._get_brz_log_filename()
 
473
        self.assertEqual(None, trace._brz_log_filename)
 
474
        config.__enter__()
 
475
        try:
 
476
            # Should have entered and setup a default filename.
 
477
            self.assertEqual(expected_filename, trace._brz_log_filename)
 
478
        finally:
 
479
            config.__exit__(None, None, None)
 
480
            # Should have exited and cleaned up.
 
481
            self.assertEqual(None, trace._brz_log_filename)