/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: 2018-07-26 19:15:27 UTC
  • mto: This revision was merged to the branch mainline in revision 7055.
  • Revision ID: jelmer@jelmer.uk-20180726191527-wniq205k6tzfo1xx
Install fastimport from git.

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(msg,
 
85
            "brz: out of memory\nUse -Dmem_dump to dump memory to a file.\n")
 
86
 
 
87
    def test_format_mem_dump(self):
 
88
        self.requireFeature(features.meliae)
 
89
        debug.debug_flags.add('mem_dump')
 
90
        try:
 
91
            raise MemoryError()
 
92
        except MemoryError:
 
93
            msg = _format_exception()
 
94
        self.assertStartsWith(msg,
 
95
            "brz: out of memory\nMemory dumped to ")
 
96
 
 
97
    def test_format_os_error(self):
 
98
        try:
 
99
            os.rmdir('nosuchfile22222')
 
100
        except OSError as e:
 
101
            e_str = str(e)
 
102
            msg = _format_exception()
 
103
        # Linux seems to give "No such file" but Windows gives "The system
 
104
        # cannot find the file specified".
 
105
        self.assertEqual('brz: ERROR: %s\n' % (e_str,), msg)
 
106
 
 
107
    def test_format_io_error(self):
 
108
        try:
 
109
            open('nosuchfile22222')
 
110
        except IOError:
 
111
            msg = _format_exception()
 
112
        # Even though Windows and Linux differ for 'os.rmdir', they both give
 
113
        # 'No such file' for open()
 
114
        # However it now gets translated so we can not test for a specific message
 
115
        self.assertContainsRe(msg,
 
116
            '^brz: ERROR: \\[Errno .*\\] .*nosuchfile')
 
117
 
 
118
    def test_format_pywintypes_error(self):
 
119
        self.requireFeature(features.pywintypes)
 
120
        import pywintypes, win32file
 
121
        try:
 
122
            win32file.RemoveDirectory('nosuchfile22222')
 
123
        except pywintypes.error:
 
124
            msg = _format_exception()
 
125
        # GZ 2010-05-03: Formatting for pywintypes.error is basic, a 3-tuple
 
126
        #                with errno, function name, and locale error message
 
127
        self.assertContainsRe(msg,
 
128
            "^brz: ERROR: \\(2, 'RemoveDirectory[AW]?', .*\\)")
 
129
 
 
130
    def test_format_sockets_error(self):
 
131
        try:
 
132
            import socket
 
133
            sock = socket.socket()
 
134
            sock.send(b"This should fail.")
 
135
        except socket.error:
 
136
            msg = _format_exception()
 
137
 
 
138
        self.assertNotContainsRe(msg,
 
139
            "Traceback \\(most recent call last\\):")
 
140
 
 
141
    def test_format_unicode_error(self):
 
142
        try:
 
143
            raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
 
144
        except errors.BzrCommandError:
 
145
            msg = _format_exception()
 
146
        if PY3:
 
147
            expected = 'brz: ERROR: argument foo\xb5 does not exist\n'
 
148
        else:
 
149
            # GZ 2017-06-10: Pretty bogus, should encode per the output stream
 
150
            expected = 'brz: ERROR: argument foo\xc2\xb5 does not exist\n'
 
151
        self.assertEqual(msg, expected)
 
152
 
 
153
    def test_format_exception(self):
 
154
        """Short formatting of brz exceptions"""
 
155
        try:
 
156
            raise errors.NotBranchError('wibble')
 
157
        except errors.NotBranchError:
 
158
            msg = _format_exception()
 
159
        self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
 
160
 
 
161
    def test_report_external_import_error(self):
 
162
        """Short friendly message for missing system modules."""
 
163
        try:
 
164
            import ImaginaryModule
 
165
        except ImportError as e:
 
166
            msg = _format_exception()
 
167
        else:
 
168
            self.fail("somehow succeeded in importing %r" % ImaginaryModule)
 
169
        self.assertContainsRe(msg,
 
170
            "^brz: ERROR: No module named '?ImaginaryModule'?\n"
 
171
            "You may need to install this Python library separately.\n$")
 
172
 
 
173
    def test_report_import_syntax_error(self):
 
174
        try:
 
175
            raise ImportError("syntax error")
 
176
        except ImportError as e:
 
177
            msg = _format_exception()
 
178
        self.assertContainsRe(msg,
 
179
            'Bazaar has encountered an internal error')
 
180
 
 
181
    def test_trace_unicode(self):
 
182
        """Write Unicode to trace log"""
 
183
        self.log(u'the unicode character for benzene is \N{BENZENE RING}')
 
184
        log = self.get_log()
 
185
        self.assertContainsRe(log, "the unicode character for benzene is")
 
186
 
 
187
    def test_trace_argument_unicode(self):
 
188
        """Write a Unicode argument to the trace log"""
 
189
        mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
 
190
        log = self.get_log()
 
191
        self.assertContainsRe(log, 'the unicode character')
 
192
 
 
193
    def test_trace_argument_utf8(self):
 
194
        """Write a Unicode argument to the trace log"""
 
195
        mutter(u'the unicode character for benzene is %s',
 
196
               u'\N{BENZENE RING}'.encode('utf-8'))
 
197
        log = self.get_log()
 
198
        self.assertContainsRe(log, 'the unicode character')
 
199
 
 
200
    def test_trace_argument_exception(self):
 
201
        err = Exception('an error')
 
202
        mutter(u'can format stringable classes %s', err)
 
203
        log = self.get_log()
 
204
        self.assertContainsRe(log, 'can format stringable classes an error')
 
205
 
 
206
    def test_report_broken_pipe(self):
 
207
        try:
 
208
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
 
209
        except IOError as e:
 
210
            msg = _format_exception()
 
211
            self.assertEqual(msg, "brz: broken pipe\n")
 
212
        else:
 
213
            self.fail("expected error not raised")
 
214
 
 
215
    def assertLogContainsLine(self, log, string):
 
216
        """Assert log contains a line including log timestamp."""
 
217
        # Does not check absolute position in log as there may be kipple.
 
218
        self.assertContainsRe(log,
 
219
            '(?m)^\\d+\\.\\d+  ' + re.escape(string))
 
220
 
 
221
    def test_mutter_callsite_1(self):
 
222
        """mutter_callsite can capture 1 level of stack frame."""
 
223
        mutter_callsite(1, "foo %s", "a string")
 
224
        log = self.get_log()
 
225
        # begin with the message
 
226
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
227
        # should show two frame: this frame and the one above
 
228
        self.assertContainsRe(log,
 
229
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
 
230
        # this frame should be the final one
 
231
        self.assertEndsWith(log, ' "a string")\n')
 
232
 
 
233
    def test_mutter_callsite_2(self):
 
234
        """mutter_callsite can capture 2 levels of stack frame."""
 
235
        mutter_callsite(2, "foo %s", "a string")
 
236
        log = self.get_log()
 
237
        # begin with the message
 
238
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
239
        # should show two frame: this frame and the one above
 
240
        self.assertContainsRe(log,
 
241
            'test_trace.py", line \\d+, in test_mutter_callsite_2\n')
 
242
        # this frame should be the final one
 
243
        self.assertEndsWith(log, ' "a string")\n')
 
244
 
 
245
    def test_mutter_never_fails(self):
 
246
        """Even with unencodable input mutter should not raise errors."""
 
247
        mutter(u'can write unicode \xa7')
 
248
        mutter('can interpolate unicode %s', u'\xa7')
 
249
        mutter(b'can write bytes \xa7')
 
250
        mutter('can repr bytes %r', b'\xa7')
 
251
        mutter('can interpolate bytes %s', b'\xa7')
 
252
        # Log will always be written as utf-8
 
253
        log = self.get_log()
 
254
        self.assertContainsRe(
 
255
            log,
 
256
            u'.* +can write unicode \xa7\n'
 
257
            u'.* +can interpolate unicode \xa7\n'
 
258
            u'.* +can write bytes \ufffd\n'
 
259
            u'.* +can repr bytes b\'\\\\xa7\'\n'
 
260
            u'.* +can interpolate bytes (?:\ufffd|b\'\\\\xa7\')\n')
 
261
 
 
262
    def test_show_error(self):
 
263
        show_error('error1')
 
264
        show_error(u'error2 \xb5 blah')
 
265
        show_error('arg: %s', 'blah')
 
266
        show_error('arg2: %(key)s', {'key':'stuff'})
 
267
        try:
 
268
            raise Exception("oops")
 
269
        except:
 
270
            show_error('kwarg', exc_info=True)
 
271
        log = self.get_log()
 
272
        self.assertContainsRe(log, 'error1')
 
273
        self.assertContainsRe(log, u'error2 \xb5 blah')
 
274
        self.assertContainsRe(log, 'arg: blah')
 
275
        self.assertContainsRe(log, 'arg2: stuff')
 
276
        self.assertContainsRe(log, 'kwarg')
 
277
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
 
278
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
 
279
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
 
280
        self.assertContainsRe(log, 'Exception: oops')
 
281
 
 
282
    def test_push_log_file(self):
 
283
        """Can push and pop log file, and this catches mutter messages.
 
284
 
 
285
        This is primarily for use in the test framework.
 
286
        """
 
287
        tmp1 = tempfile.NamedTemporaryFile()
 
288
        tmp2 = tempfile.NamedTemporaryFile()
 
289
        try:
 
290
            memento1 = push_log_file(tmp1)
 
291
            mutter("comment to file1")
 
292
            try:
 
293
                memento2 = push_log_file(tmp2)
 
294
                try:
 
295
                    mutter("comment to file2")
 
296
                finally:
 
297
                    pop_log_file(memento2)
 
298
                mutter("again to file1")
 
299
            finally:
 
300
                pop_log_file(memento1)
 
301
            # the files were opened in binary mode, so should have exactly
 
302
            # these bytes.  and removing the file as the log target should
 
303
            # have caused them to be flushed out.  need to match using regexps
 
304
            # as there's a timestamp at the front.
 
305
            tmp1.seek(0)
 
306
            self.assertContainsRe(tmp1.read(),
 
307
                b"\\d+\\.\\d+  comment to file1\n"
 
308
                b"\\d+\\.\\d+  again to file1\n")
 
309
            tmp2.seek(0)
 
310
            self.assertContainsRe(tmp2.read(),
 
311
                b"\\d+\\.\\d+  comment to file2\n")
 
312
        finally:
 
313
            tmp1.close()
 
314
            tmp2.close()
 
315
 
 
316
    def test__open_brz_log_uses_stderr_for_failures(self):
 
317
        # If _open_brz_log cannot open the file, then we should write the
 
318
        # warning to stderr. Since this is normally happening before logging is
 
319
        # set up.
 
320
        self.overrideAttr(sys, 'stderr', StringIO())
 
321
        # Set the log file to something that cannot exist
 
322
        self.overrideEnv('BRZ_LOG', '/no-such-dir/brz.log')
 
323
        self.overrideAttr(trace, '_brz_log_filename')
 
324
        logf = trace._open_brz_log()
 
325
        self.assertIs(None, logf)
 
326
        self.assertContainsRe(
 
327
            sys.stderr.getvalue(),
 
328
            "failed to open trace file: .* '/no-such-dir/brz.log'$")
 
329
 
 
330
 
 
331
class TestVerbosityLevel(TestCase):
 
332
 
 
333
    def test_verbosity_level(self):
 
334
        set_verbosity_level(1)
 
335
        self.assertEqual(1, get_verbosity_level())
 
336
        self.assertTrue(is_verbose())
 
337
        self.assertFalse(is_quiet())
 
338
        set_verbosity_level(-1)
 
339
        self.assertEqual(-1, get_verbosity_level())
 
340
        self.assertFalse(is_verbose())
 
341
        self.assertTrue(is_quiet())
 
342
        set_verbosity_level(0)
 
343
        self.assertEqual(0, get_verbosity_level())
 
344
        self.assertFalse(is_verbose())
 
345
        self.assertFalse(is_quiet())
 
346
 
 
347
    def test_be_quiet(self):
 
348
        # Confirm the old API still works
 
349
        be_quiet(True)
 
350
        self.assertEqual(-1, get_verbosity_level())
 
351
        be_quiet(False)
 
352
        self.assertEqual(0, get_verbosity_level())
 
353
 
 
354
 
 
355
class TestLogging(TestCase):
 
356
    """Check logging functionality robustly records information"""
 
357
 
 
358
    def test_note(self):
 
359
        trace.note("Noted")
 
360
        self.assertEqual("    INFO  Noted\n", self.get_log())
 
361
 
 
362
    def test_warning(self):
 
363
        trace.warning("Warned")
 
364
        self.assertEqual(" WARNING  Warned\n", self.get_log())
 
365
 
 
366
    def test_log(self):
 
367
        logging.getLogger("brz").error("Errored")
 
368
        self.assertEqual("   ERROR  Errored\n", self.get_log())
 
369
 
 
370
    def test_log_sub(self):
 
371
        logging.getLogger("brz.test_log_sub").debug("Whispered")
 
372
        self.assertEqual("   DEBUG  Whispered\n", self.get_log())
 
373
 
 
374
    def test_log_unicode_msg(self):
 
375
        logging.getLogger("brz").debug(u"\xa7")
 
376
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
377
 
 
378
    def test_log_unicode_arg(self):
 
379
        logging.getLogger("brz").debug("%s", u"\xa7")
 
380
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
381
 
 
382
    def test_log_utf8_msg(self):
 
383
        logging.getLogger("brz").debug(b"\xc2\xa7")
 
384
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
385
 
 
386
    def test_log_utf8_arg(self):
 
387
        logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
 
388
        if PY3:
 
389
            expected = u"   DEBUG  b'\\xc2\\xa7'\n"
 
390
        else:
 
391
            expected = u"   DEBUG  \xa7\n"
 
392
        self.assertEqual(expected, self.get_log())
 
393
 
 
394
    def test_log_bytes_msg(self):
 
395
        logging.getLogger("brz").debug(b"\xa7")
 
396
        log = self.get_log()
 
397
        self.assertContainsString(log, "UnicodeDecodeError: ")
 
398
        self.assertContainsRe(log,
 
399
            "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
 
400
 
 
401
    def test_log_bytes_arg(self):
 
402
        logging.getLogger("brz").debug(b"%s", b"\xa7")
 
403
        log = self.get_log()
 
404
        if PY3:
 
405
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
406
        else:
 
407
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
408
            self.assertContainsRe(log,
 
409
                "Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
 
410
 
 
411
    def test_log_mixed_strings(self):
 
412
        logging.getLogger("brz").debug(u"%s", b"\xa7")
 
413
        log = self.get_log()
 
414
        if PY3:
 
415
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
416
        else:
 
417
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
418
            self.assertContainsRe(log,
 
419
                "Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
 
420
 
 
421
    def test_log_repr_broken(self):
 
422
        class BadRepr(object):
 
423
            def __repr__(self):
 
424
                raise ValueError("Broken object")
 
425
        logging.getLogger("brz").debug("%s", BadRepr())
 
426
        log = self.get_log()
 
427
        self.assertContainsRe(log, "ValueError: Broken object\n")
 
428
        self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
 
429
 
 
430
 
 
431
class TestBzrLog(TestCaseInTempDir):
 
432
 
 
433
    def test_log_rollover(self):
 
434
        temp_log_name = 'test-log'
 
435
        trace_file = open(temp_log_name, 'at')
 
436
        trace_file.writelines(['test_log_rollover padding\n'] * 200000)
 
437
        trace_file.close()
 
438
        _rollover_trace_maybe(temp_log_name)
 
439
        # should have been rolled over
 
440
        self.assertFalse(os.access(temp_log_name, os.R_OK))
 
441
 
 
442
 
 
443
class TestTraceConfiguration(TestCaseInTempDir):
 
444
 
 
445
    def test_default_config(self):
 
446
        config = trace.DefaultConfig()
 
447
        self.overrideAttr(trace, "_brz_log_filename", None)
 
448
        trace._brz_log_filename = None
 
449
        expected_filename = trace._get_brz_log_filename()
 
450
        self.assertEqual(None, trace._brz_log_filename)
 
451
        config.__enter__()
 
452
        try:
 
453
            # Should have entered and setup a default filename.
 
454
            self.assertEqual(expected_filename, trace._brz_log_filename)
 
455
        finally:
 
456
            config.__exit__(None, None, None)
 
457
            # Should have exited and cleaned up.
 
458
            self.assertEqual(None, trace._brz_log_filename)