/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-08-12 20:24:50 UTC
  • mto: (7290.1.35 work)
  • mto: This revision was merged to the branch mainline in revision 7405.
  • Revision ID: jelmer@jelmer.uk-20190812202450-vdpamxay6sebo93w
Fix path to brz.

Show diffs side-by-side

added added

removed removed

Lines of Context:
breezy/tests/test_trace.py
 
1
# Copyright (C) 2005-2011, 2016 Canonical Ltd
 
2
#
 
3
# This program is free software; you can redistribute it and/or modify
 
4
# it under the terms of the GNU General Public License as published by
 
5
# the Free Software Foundation; either version 2 of the License, or
 
6
# (at your option) any later version.
 
7
#
 
8
# This program is distributed in the hope that it will be useful,
 
9
# but WITHOUT ANY WARRANTY; without even the implied warranty of
 
10
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 
11
# GNU General Public License for more details.
 
12
#
 
13
# You should have received a copy of the GNU General Public License
 
14
# along with this program; if not, write to the Free Software
 
15
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
 
16
 
 
17
# "weren't nothing promised to you.  do i look like i got a promise face?"
 
18
 
 
19
"""Tests for trace library"""
 
20
 
 
21
import errno
 
22
import logging
 
23
import os
 
24
import re
 
25
import sys
 
26
import tempfile
 
27
 
 
28
from .. import (
 
29
    debug,
 
30
    errors,
 
31
    trace,
 
32
    )
 
33
from ..sixish import (
 
34
    PY3,
 
35
    StringIO,
 
36
    )
 
37
from . import features, TestCaseInTempDir, TestCase
 
38
from ..trace import (
 
39
    mutter, mutter_callsite, report_exception,
 
40
    set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
 
41
    pop_log_file,
 
42
    push_log_file,
 
43
    _rollover_trace_maybe,
 
44
    show_error,
 
45
    )
 
46
 
 
47
 
 
48
def _format_exception():
 
49
    """Format an exception as it would normally be displayed to the user"""
 
50
    buf = StringIO()
 
51
    report_exception(sys.exc_info(), buf)
 
52
    return buf.getvalue()
 
53
 
 
54
 
 
55
class TestTrace(TestCase):
 
56
 
 
57
    def test_format_sys_exception(self):
 
58
        # Test handling of an internal/unexpected error that probably
 
59
        # indicates a bug in brz.  The details of the message may vary
 
60
        # depending on whether apport is available or not.  See test_crash for
 
61
        # more.
 
62
        try:
 
63
            raise NotImplementedError("time travel")
 
64
        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.')
 
70
 
 
71
    def test_format_interrupt_exception(self):
 
72
        try:
 
73
            raise KeyboardInterrupt()
 
74
        except KeyboardInterrupt:
 
75
            # XXX: Some risk that a *real* keyboard interrupt won't be seen
 
76
            msg = _format_exception()
 
77
        self.assertEqual(msg, 'brz: interrupted\n')
 
78
 
 
79
    def test_format_memory_error(self):
 
80
        try:
 
81
            raise MemoryError()
 
82
        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 ")
 
97
 
 
98
    def test_format_os_error(self):
 
99
        try:
 
100
            os.rmdir('nosuchfile22222')
 
101
        except OSError as e:
 
102
            e_str = str(e)
 
103
            msg = _format_exception()
 
104
        # Linux seems to give "No such file" but Windows gives "The system
 
105
        # cannot find the file specified".
 
106
        self.assertEqual('brz: ERROR: %s\n' % (e_str,), msg)
 
107
 
 
108
    def test_format_io_error(self):
 
109
        try:
 
110
            open('nosuchfile22222')
 
111
        except IOError:
 
112
            msg = _format_exception()
 
113
        # Even though Windows and Linux differ for 'os.rmdir', they both give
 
114
        # 'No such file' for open()
 
115
        # However it now gets translated so we can not test for a specific
 
116
        # message
 
117
        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\\):")
 
143
 
 
144
    def test_format_unicode_error(self):
 
145
        try:
 
146
            raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
 
147
        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)
 
155
 
 
156
    def test_format_exception(self):
 
157
        """Short formatting of brz exceptions"""
 
158
        try:
 
159
            raise errors.NotBranchError('wibble')
 
160
        except errors.NotBranchError:
 
161
            msg = _format_exception()
 
162
        self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
 
163
 
 
164
    def test_report_external_import_error(self):
 
165
        """Short friendly message for missing system modules."""
 
166
        try:
 
167
            import ImaginaryModule
 
168
        except ImportError:
 
169
            msg = _format_exception()
 
170
        else:
 
171
            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$")
 
176
 
 
177
    def test_report_import_syntax_error(self):
 
178
        try:
 
179
            raise ImportError("syntax error")
 
180
        except ImportError:
 
181
            msg = _format_exception()
 
182
        self.assertContainsRe(msg,
 
183
                              'Bazaar has encountered an internal error')
 
184
 
 
185
    def test_trace_unicode(self):
 
186
        """Write Unicode to trace log"""
 
187
        self.log(u'the unicode character for benzene is \N{BENZENE RING}')
 
188
        log = self.get_log()
 
189
        self.assertContainsRe(log, "the unicode character for benzene is")
 
190
 
 
191
    def test_trace_argument_unicode(self):
 
192
        """Write a Unicode argument to the trace log"""
 
193
        mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
 
194
        log = self.get_log()
 
195
        self.assertContainsRe(log, 'the unicode character')
 
196
 
 
197
    def test_trace_argument_utf8(self):
 
198
        """Write a Unicode argument to the trace log"""
 
199
        mutter(u'the unicode character for benzene is %s',
 
200
               u'\N{BENZENE RING}'.encode('utf-8'))
 
201
        log = self.get_log()
 
202
        self.assertContainsRe(log, 'the unicode character')
 
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
 
 
210
    def test_report_broken_pipe(self):
 
211
        try:
 
212
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
 
213
        except IOError:
 
214
            msg = _format_exception()
 
215
            self.assertEqual(msg, "brz: broken pipe\n")
 
216
        else:
 
217
            self.fail("expected error not raised")
 
218
 
 
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.
 
222
        self.assertContainsRe(log,
 
223
                              '(?m)^\\d+\\.\\d+  ' + re.escape(string))
 
224
 
 
225
    def test_mutter_callsite_1(self):
 
226
        """mutter_callsite can capture 1 level of stack frame."""
 
227
        mutter_callsite(1, "foo %s", "a string")
 
228
        log = self.get_log()
 
229
        # begin with the message
 
230
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
231
        # 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')
 
234
        # this frame should be the final one
 
235
        self.assertEndsWith(log, ' "a string")\n')
 
236
 
 
237
    def test_mutter_callsite_2(self):
 
238
        """mutter_callsite can capture 2 levels of stack frame."""
 
239
        mutter_callsite(2, "foo %s", "a string")
 
240
        log = self.get_log()
 
241
        # begin with the message
 
242
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
243
        # 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')
 
246
        # this frame should be the final one
 
247
        self.assertEndsWith(log, ' "a string")\n')
 
248
 
 
249
    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
 
257
        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
 
 
266
    def test_show_error(self):
 
267
        show_error('error1')
 
268
        show_error(u'error2 \xb5 blah')
 
269
        show_error('arg: %s', 'blah')
 
270
        show_error('arg2: %(key)s', {'key': 'stuff'})
 
271
        try:
 
272
            raise Exception("oops")
 
273
        except BaseException:
 
274
            show_error('kwarg', exc_info=True)
 
275
        log = self.get_log()
 
276
        self.assertContainsRe(log, 'error1')
 
277
        self.assertContainsRe(log, u'error2 \xb5 blah')
 
278
        self.assertContainsRe(log, 'arg: blah')
 
279
        self.assertContainsRe(log, 'arg2: stuff')
 
280
        self.assertContainsRe(log, 'kwarg')
 
281
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
 
282
        self.assertContainsRe(
 
283
            log, 'File ".*test_trace.py", line .*, in test_show_error')
 
284
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
 
285
        self.assertContainsRe(log, 'Exception: oops')
 
286
 
 
287
    def test_push_log_file(self):
 
288
        """Can push and pop log file, and this catches mutter messages.
 
289
 
 
290
        This is primarily for use in the test framework.
 
291
        """
 
292
        tmp1 = tempfile.NamedTemporaryFile()
 
293
        tmp2 = tempfile.NamedTemporaryFile()
 
294
        try:
 
295
            memento1 = push_log_file(tmp1)
 
296
            mutter("comment to file1")
 
297
            try:
 
298
                memento2 = push_log_file(tmp2)
 
299
                try:
 
300
                    mutter("comment to file2")
 
301
                finally:
 
302
                    pop_log_file(memento2)
 
303
                mutter("again to file1")
 
304
            finally:
 
305
                pop_log_file(memento1)
 
306
            # the files were opened in binary mode, so should have exactly
 
307
            # these bytes.  and removing the file as the log target should
 
308
            # have caused them to be flushed out.  need to match using regexps
 
309
            # as there's a timestamp at the front.
 
310
            tmp1.seek(0)
 
311
            self.assertContainsRe(tmp1.read(),
 
312
                                  b"\\d+\\.\\d+  comment to file1\n"
 
313
                                  b"\\d+\\.\\d+  again to file1\n")
 
314
            tmp2.seek(0)
 
315
            self.assertContainsRe(tmp2.read(),
 
316
                                  b"\\d+\\.\\d+  comment to file2\n")
 
317
        finally:
 
318
            tmp1.close()
 
319
            tmp2.close()
 
320
 
 
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
 
323
        # warning to stderr. Since this is normally happening before logging is
 
324
        # set up.
 
325
        self.overrideAttr(sys, 'stderr', StringIO())
 
326
        # 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
        self.assertIs(None, logf)
 
331
        self.assertContainsRe(
 
332
            sys.stderr.getvalue(),
 
333
            "failed to open trace file: .* '/no-such-dir/brz.log'$")
 
334
 
 
335
 
 
336
class TestVerbosityLevel(TestCase):
 
337
 
 
338
    def test_verbosity_level(self):
 
339
        set_verbosity_level(1)
 
340
        self.assertEqual(1, get_verbosity_level())
 
341
        self.assertTrue(is_verbose())
 
342
        self.assertFalse(is_quiet())
 
343
        set_verbosity_level(-1)
 
344
        self.assertEqual(-1, get_verbosity_level())
 
345
        self.assertFalse(is_verbose())
 
346
        self.assertTrue(is_quiet())
 
347
        set_verbosity_level(0)
 
348
        self.assertEqual(0, get_verbosity_level())
 
349
        self.assertFalse(is_verbose())
 
350
        self.assertFalse(is_quiet())
 
351
 
 
352
    def test_be_quiet(self):
 
353
        # Confirm the old API still works
 
354
        be_quiet(True)
 
355
        self.assertEqual(-1, get_verbosity_level())
 
356
        be_quiet(False)
 
357
        self.assertEqual(0, get_verbosity_level())
 
358
 
 
359
 
 
360
class TestLogging(TestCase):
 
361
    """Check logging functionality robustly records information"""
 
362
 
 
363
    def test_note(self):
 
364
        trace.note("Noted")
 
365
        self.assertEqual("    INFO  Noted\n", self.get_log())
 
366
 
 
367
    def test_warning(self):
 
368
        trace.warning("Warned")
 
369
        self.assertEqual(" WARNING  Warned\n", self.get_log())
 
370
 
 
371
    def test_log(self):
 
372
        logging.getLogger("brz").error("Errored")
 
373
        self.assertEqual("   ERROR  Errored\n", self.get_log())
 
374
 
 
375
    def test_log_sub(self):
 
376
        logging.getLogger("brz.test_log_sub").debug("Whispered")
 
377
        self.assertEqual("   DEBUG  Whispered\n", self.get_log())
 
378
 
 
379
    def test_log_unicode_msg(self):
 
380
        logging.getLogger("brz").debug(u"\xa7")
 
381
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
382
 
 
383
    def test_log_unicode_arg(self):
 
384
        logging.getLogger("brz").debug("%s", u"\xa7")
 
385
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
386
 
 
387
    def test_log_utf8_msg(self):
 
388
        logging.getLogger("brz").debug(b"\xc2\xa7")
 
389
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
390
 
 
391
    def test_log_utf8_arg(self):
 
392
        logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
 
393
        if PY3:
 
394
            expected = u"   DEBUG  b'\\xc2\\xa7'\n"
 
395
        else:
 
396
            expected = u"   DEBUG  \xa7\n"
 
397
        self.assertEqual(expected, self.get_log())
 
398
 
 
399
    def test_log_bytes_msg(self):
 
400
        logging.getLogger("brz").debug(b"\xa7")
 
401
        log = self.get_log()
 
402
        self.assertContainsString(log, "UnicodeDecodeError: ")
 
403
        self.assertContainsRe(
 
404
            log, "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
 
405
 
 
406
    def test_log_bytes_arg(self):
 
407
        logging.getLogger("brz").debug(b"%s", b"\xa7")
 
408
        log = self.get_log()
 
409
        if PY3:
 
410
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
411
        else:
 
412
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
413
            self.assertContainsRe(
 
414
                log,
 
415
                "Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
 
416
 
 
417
    def test_log_mixed_strings(self):
 
418
        logging.getLogger("brz").debug(u"%s", b"\xa7")
 
419
        log = self.get_log()
 
420
        if PY3:
 
421
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
422
        else:
 
423
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
424
            self.assertContainsRe(
 
425
                log,
 
426
                "Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
 
427
 
 
428
    def test_log_repr_broken(self):
 
429
        class BadRepr(object):
 
430
            def __repr__(self):
 
431
                raise ValueError("Broken object")
 
432
        logging.getLogger("brz").debug("%s", BadRepr())
 
433
        log = self.get_log()
 
434
        self.assertContainsRe(log, "ValueError: Broken object\n")
 
435
        self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
 
436
 
 
437
 
 
438
class TestBzrLog(TestCaseInTempDir):
 
439
 
 
440
    def test_log_rollover(self):
 
441
        temp_log_name = 'test-log'
 
442
        trace_file = open(temp_log_name, 'at')
 
443
        trace_file.writelines(['test_log_rollover padding\n'] * 200000)
 
444
        trace_file.close()
 
445
        _rollover_trace_maybe(temp_log_name)
 
446
        # should have been rolled over
 
447
        self.assertFalse(os.access(temp_log_name, os.R_OK))
 
448
 
 
449
 
 
450
class TestTraceConfiguration(TestCaseInTempDir):
 
451
 
 
452
    def test_default_config(self):
 
453
        config = trace.DefaultConfig()
 
454
        self.overrideAttr(trace, "_brz_log_filename", None)
 
455
        trace._brz_log_filename = None
 
456
        expected_filename = trace._get_brz_log_filename()
 
457
        self.assertEqual(None, trace._brz_log_filename)
 
458
        config.__enter__()
 
459
        try:
 
460
            # Should have entered and setup a default filename.
 
461
            self.assertEqual(expected_filename, trace._brz_log_filename)
 
462
        finally:
 
463
            config.__exit__(None, None, None)
 
464
            # Should have exited and cleaned up.
 
465
            self.assertEqual(None, trace._brz_log_filename)