/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: 2017-07-23 15:59:57 UTC
  • mto: This revision was merged to the branch mainline in revision 6740.
  • Revision ID: jelmer@jelmer.uk-20170723155957-rw4kqurf44fqx4x0
Move AlreadyBuilding/NotBuilding errors.

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_report_broken_pipe(self):
 
201
        try:
 
202
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
 
203
        except IOError as e:
 
204
            msg = _format_exception()
 
205
            self.assertEqual(msg, "brz: broken pipe\n")
 
206
        else:
 
207
            self.fail("expected error not raised")
 
208
 
 
209
    def assertLogContainsLine(self, log, string):
 
210
        """Assert log contains a line including log timestamp."""
 
211
        # Does not check absolute position in log as there may be kipple.
 
212
        self.assertContainsRe(log,
 
213
            '(?m)^\\d+\\.\\d+  ' + re.escape(string))
 
214
 
 
215
    def test_mutter_callsite_1(self):
 
216
        """mutter_callsite can capture 1 level of stack frame."""
 
217
        mutter_callsite(1, "foo %s", "a string")
 
218
        log = self.get_log()
 
219
        # begin with the message
 
220
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
221
        # should show two frame: this frame and the one above
 
222
        self.assertContainsRe(log,
 
223
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
 
224
        # this frame should be the final one
 
225
        self.assertEndsWith(log, ' "a string")\n')
 
226
 
 
227
    def test_mutter_callsite_2(self):
 
228
        """mutter_callsite can capture 2 levels of stack frame."""
 
229
        mutter_callsite(2, "foo %s", "a string")
 
230
        log = self.get_log()
 
231
        # begin with the message
 
232
        self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
 
233
        # should show two frame: this frame and the one above
 
234
        self.assertContainsRe(log,
 
235
            'test_trace.py", line \d+, in test_mutter_callsite_2\n')
 
236
        # this frame should be the final one
 
237
        self.assertEndsWith(log, ' "a string")\n')
 
238
 
 
239
    def test_mutter_never_fails(self):
 
240
        # Even if the decode/encode stage fails, mutter should not
 
241
        # raise an exception
 
242
        # This test checks that mutter doesn't fail; the current behaviour
 
243
        # is that it doesn't fail *and writes non-utf8*.
 
244
        mutter(u'Writing a greek mu (\xb5) works in a unicode string')
 
245
        mutter(b'But fails in an ascii string \xb5')
 
246
        mutter(b'and in an ascii argument: %s', b'\xb5')
 
247
        log = self.get_log()
 
248
        self.assertContainsRe(log, 'Writing a greek mu')
 
249
        self.assertContainsRe(log, "But fails in an ascii string")
 
250
        # However, the log content object does unicode replacement on reading
 
251
        # to let it get unicode back where good data has been written. So we
 
252
        # have to do a replaceent here as well.
 
253
        self.assertContainsRe(log, b"ascii argument: \xb5".decode('utf8',
 
254
            'replace'))
 
255
 
 
256
    def test_show_error(self):
 
257
        show_error('error1')
 
258
        show_error(u'error2 \xb5 blah')
 
259
        show_error('arg: %s', 'blah')
 
260
        show_error('arg2: %(key)s', {'key':'stuff'})
 
261
        try:
 
262
            raise Exception("oops")
 
263
        except:
 
264
            show_error('kwarg', exc_info=True)
 
265
        log = self.get_log()
 
266
        self.assertContainsRe(log, 'error1')
 
267
        self.assertContainsRe(log, u'error2 \xb5 blah')
 
268
        self.assertContainsRe(log, 'arg: blah')
 
269
        self.assertContainsRe(log, 'arg2: stuff')
 
270
        self.assertContainsRe(log, 'kwarg')
 
271
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
 
272
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
 
273
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
 
274
        self.assertContainsRe(log, 'Exception: oops')
 
275
 
 
276
    def test_push_log_file(self):
 
277
        """Can push and pop log file, and this catches mutter messages.
 
278
 
 
279
        This is primarily for use in the test framework.
 
280
        """
 
281
        tmp1 = tempfile.NamedTemporaryFile()
 
282
        tmp2 = tempfile.NamedTemporaryFile()
 
283
        try:
 
284
            memento1 = push_log_file(tmp1)
 
285
            mutter("comment to file1")
 
286
            try:
 
287
                memento2 = push_log_file(tmp2)
 
288
                try:
 
289
                    mutter("comment to file2")
 
290
                finally:
 
291
                    pop_log_file(memento2)
 
292
                mutter("again to file1")
 
293
            finally:
 
294
                pop_log_file(memento1)
 
295
            # the files were opened in binary mode, so should have exactly
 
296
            # these bytes.  and removing the file as the log target should
 
297
            # have caused them to be flushed out.  need to match using regexps
 
298
            # as there's a timestamp at the front.
 
299
            tmp1.seek(0)
 
300
            self.assertContainsRe(tmp1.read(),
 
301
                b"\\d+\\.\\d+  comment to file1\n"
 
302
                b"\\d+\\.\\d+  again to file1\n")
 
303
            tmp2.seek(0)
 
304
            self.assertContainsRe(tmp2.read(),
 
305
                b"\\d+\\.\\d+  comment to file2\n")
 
306
        finally:
 
307
            tmp1.close()
 
308
            tmp2.close()
 
309
 
 
310
    def test__open_brz_log_uses_stderr_for_failures(self):
 
311
        # If _open_brz_log cannot open the file, then we should write the
 
312
        # warning to stderr. Since this is normally happening before logging is
 
313
        # set up.
 
314
        self.overrideAttr(sys, 'stderr', StringIO())
 
315
        # Set the log file to something that cannot exist
 
316
        self.overrideEnv('BRZ_LOG', '/no-such-dir/brz.log')
 
317
        self.overrideAttr(trace, '_brz_log_filename')
 
318
        logf = trace._open_brz_log()
 
319
        self.assertIs(None, logf)
 
320
        self.assertContainsRe(
 
321
            sys.stderr.getvalue(),
 
322
            "failed to open trace file: .* '/no-such-dir/brz.log'$")
 
323
 
 
324
 
 
325
class TestVerbosityLevel(TestCase):
 
326
 
 
327
    def test_verbosity_level(self):
 
328
        set_verbosity_level(1)
 
329
        self.assertEqual(1, get_verbosity_level())
 
330
        self.assertTrue(is_verbose())
 
331
        self.assertFalse(is_quiet())
 
332
        set_verbosity_level(-1)
 
333
        self.assertEqual(-1, get_verbosity_level())
 
334
        self.assertFalse(is_verbose())
 
335
        self.assertTrue(is_quiet())
 
336
        set_verbosity_level(0)
 
337
        self.assertEqual(0, get_verbosity_level())
 
338
        self.assertFalse(is_verbose())
 
339
        self.assertFalse(is_quiet())
 
340
 
 
341
    def test_be_quiet(self):
 
342
        # Confirm the old API still works
 
343
        be_quiet(True)
 
344
        self.assertEqual(-1, get_verbosity_level())
 
345
        be_quiet(False)
 
346
        self.assertEqual(0, get_verbosity_level())
 
347
 
 
348
 
 
349
class TestLogging(TestCase):
 
350
    """Check logging functionality robustly records information"""
 
351
 
 
352
    def test_note(self):
 
353
        trace.note("Noted")
 
354
        self.assertEqual("    INFO  Noted\n", self.get_log())
 
355
 
 
356
    def test_warning(self):
 
357
        trace.warning("Warned")
 
358
        self.assertEqual(" WARNING  Warned\n", self.get_log())
 
359
 
 
360
    def test_log(self):
 
361
        logging.getLogger("brz").error("Errored")
 
362
        self.assertEqual("   ERROR  Errored\n", self.get_log())
 
363
 
 
364
    def test_log_sub(self):
 
365
        logging.getLogger("brz.test_log_sub").debug("Whispered")
 
366
        self.assertEqual("   DEBUG  Whispered\n", self.get_log())
 
367
 
 
368
    def test_log_unicode_msg(self):
 
369
        logging.getLogger("brz").debug(u"\xa7")
 
370
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
371
 
 
372
    def test_log_unicode_arg(self):
 
373
        logging.getLogger("brz").debug("%s", u"\xa7")
 
374
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
375
 
 
376
    def test_log_utf8_msg(self):
 
377
        logging.getLogger("brz").debug(b"\xc2\xa7")
 
378
        self.assertEqual(u"   DEBUG  \xa7\n", self.get_log())
 
379
 
 
380
    def test_log_utf8_arg(self):
 
381
        logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
 
382
        if PY3:
 
383
            expected = u"   DEBUG  b'\\xc2\\xa7'\n"
 
384
        else:
 
385
            expected = u"   DEBUG  \xa7\n"
 
386
        self.assertEqual(expected, self.get_log())
 
387
 
 
388
    def test_log_bytes_msg(self):
 
389
        logging.getLogger("brz").debug(b"\xa7")
 
390
        log = self.get_log()
 
391
        self.assertContainsString(log, "UnicodeDecodeError: ")
 
392
        self.assertContainsRe(log,
 
393
            "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
 
394
 
 
395
    def test_log_bytes_arg(self):
 
396
        logging.getLogger("brz").debug(b"%s", b"\xa7")
 
397
        log = self.get_log()
 
398
        if PY3:
 
399
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
400
        else:
 
401
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
402
            self.assertContainsRe(log,
 
403
                "Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
 
404
 
 
405
    def test_log_mixed_strings(self):
 
406
        logging.getLogger("brz").debug(u"%s", b"\xa7")
 
407
        log = self.get_log()
 
408
        if PY3:
 
409
            self.assertEqual(u"   DEBUG  b'\\xa7'\n", self.get_log())
 
410
        else:
 
411
            self.assertContainsString(log, "UnicodeDecodeError: ")
 
412
            self.assertContainsRe(log,
 
413
                "Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
 
414
 
 
415
    def test_log_repr_broken(self):
 
416
        class BadRepr(object):
 
417
            def __repr__(self):
 
418
                raise ValueError("Broken object")
 
419
        logging.getLogger("brz").debug("%s", BadRepr())
 
420
        log = self.get_log()
 
421
        self.assertContainsRe(log, "ValueError: Broken object\n")
 
422
        self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
 
423
 
 
424
 
 
425
class TestBzrLog(TestCaseInTempDir):
 
426
 
 
427
    def test_log_rollover(self):
 
428
        temp_log_name = 'test-log'
 
429
        trace_file = open(temp_log_name, 'at')
 
430
        trace_file.writelines(['test_log_rollover padding\n'] * 200000)
 
431
        trace_file.close()
 
432
        _rollover_trace_maybe(temp_log_name)
 
433
        # should have been rolled over
 
434
        self.assertFalse(os.access(temp_log_name, os.R_OK))
 
435
 
 
436
 
 
437
class TestTraceConfiguration(TestCaseInTempDir):
 
438
 
 
439
    def test_default_config(self):
 
440
        config = trace.DefaultConfig()
 
441
        self.overrideAttr(trace, "_brz_log_filename", None)
 
442
        trace._brz_log_filename = None
 
443
        expected_filename = trace._get_brz_log_filename()
 
444
        self.assertEqual(None, trace._brz_log_filename)
 
445
        config.__enter__()
 
446
        try:
 
447
            # Should have entered and setup a default filename.
 
448
            self.assertEqual(expected_filename, trace._brz_log_filename)
 
449
        finally:
 
450
            config.__exit__(None, None, None)
 
451
            # Should have exited and cleaned up.
 
452
            self.assertEqual(None, trace._brz_log_filename)