1
# Copyright (C) 2005-2011, 2016 Canonical Ltd
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.
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.
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
17
# "weren't nothing promised to you. do i look like i got a promise face?"
19
"""Tests for trace library"""
33
from ..sixish import (
37
from . import features, TestCaseInTempDir, TestCase, TestSkipped
39
mutter, mutter_callsite, report_exception,
40
set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
43
_rollover_trace_maybe,
48
def _format_exception():
49
"""Format an exception as it would normally be displayed to the user"""
51
report_exception(sys.exc_info(), buf)
55
class TestTrace(TestCase):
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
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.')
71
def test_format_interrupt_exception(self):
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')
79
def test_format_memory_error(self):
83
msg = _format_exception()
86
"brz: out of memory\nUse -Dmem_dump to dump memory to a file.\n")
88
def test_format_mem_dump(self):
89
self.requireFeature(features.meliae)
90
debug.debug_flags.add('mem_dump')
94
msg = _format_exception()
95
self.assertStartsWith(msg,
96
"brz: out of memory\nMemory dumped to ")
98
def test_format_os_error(self):
100
os.rmdir('nosuchfile22222')
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)
108
def test_format_io_error(self):
110
open('nosuchfile22222')
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
117
self.assertContainsRe(msg,
118
'^brz: ERROR: \\[Errno .*\\] .*nosuchfile')
120
def test_format_pywintypes_error(self):
121
self.requireFeature(features.pywintypes)
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]?', .*\\)")
133
def test_format_sockets_error(self):
136
sock = socket.socket()
137
sock.send(b"This should fail.")
139
msg = _format_exception()
141
self.assertNotContainsRe(msg,
142
"Traceback \\(most recent call last\\):")
144
def test_format_unicode_error(self):
146
raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
147
except errors.BzrCommandError:
148
msg = _format_exception()
150
expected = 'brz: ERROR: argument foo\xb5 does not exist\n'
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)
156
def test_format_exception(self):
157
"""Short formatting of brz exceptions"""
159
raise errors.NotBranchError('wibble')
160
except errors.NotBranchError:
161
msg = _format_exception()
162
self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
164
def test_report_external_import_error(self):
165
"""Short friendly message for missing system modules."""
167
import ImaginaryModule
169
msg = _format_exception()
171
self.fail("somehow succeeded in importing %r" % ImaginaryModule)
172
self.assertContainsRe(
174
"^brz: ERROR: No module named '?ImaginaryModule'?\n"
175
"You may need to install this Python library separately.\n$")
177
def test_report_import_syntax_error(self):
179
raise ImportError("syntax error")
181
msg = _format_exception()
182
self.assertContainsRe(msg,
183
'Bazaar has encountered an internal error')
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}')
189
self.assertContainsRe(log, "the unicode character for benzene is")
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}')
195
self.assertContainsRe(log, 'the unicode character')
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'))
202
self.assertContainsRe(log, 'the unicode character')
204
def test_trace_argument_exception(self):
205
err = Exception('an error')
206
mutter(u'can format stringable classes %s', err)
208
self.assertContainsRe(log, 'can format stringable classes an error')
210
def test_report_broken_pipe(self):
212
raise IOError(errno.EPIPE, 'broken pipe foofofo')
214
msg = _format_exception()
215
self.assertEqual(msg, "brz: broken pipe\n")
217
self.fail("expected error not raised")
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))
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")
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')
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")
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')
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
258
self.assertContainsRe(
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')
266
def test_show_error(self):
268
show_error(u'error2 \xb5 blah')
269
show_error('arg: %s', 'blah')
270
show_error('arg2: %(key)s', {'key': 'stuff'})
272
raise Exception("oops")
273
except BaseException:
274
show_error('kwarg', exc_info=True)
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')
287
def test_push_log_file(self):
288
"""Can push and pop log file, and this catches mutter messages.
290
This is primarily for use in the test framework.
292
tmp1 = tempfile.NamedTemporaryFile()
293
tmp2 = tempfile.NamedTemporaryFile()
295
memento1 = push_log_file(tmp1)
296
mutter("comment to file1")
298
memento2 = push_log_file(tmp2)
300
mutter("comment to file2")
302
pop_log_file(memento2)
303
mutter("again to file1")
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.
311
self.assertContainsRe(tmp1.read(),
312
b"\\d+\\.\\d+ comment to file1\n"
313
b"\\d+\\.\\d+ again to file1\n")
315
self.assertContainsRe(tmp2.read(),
316
b"\\d+\\.\\d+ comment to file2\n")
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
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
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'$")
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'$")
356
class TestVerbosityLevel(TestCase):
358
def test_verbosity_level(self):
359
set_verbosity_level(1)
360
self.assertEqual(1, get_verbosity_level())
361
self.assertTrue(is_verbose())
362
self.assertFalse(is_quiet())
363
set_verbosity_level(-1)
364
self.assertEqual(-1, get_verbosity_level())
365
self.assertFalse(is_verbose())
366
self.assertTrue(is_quiet())
367
set_verbosity_level(0)
368
self.assertEqual(0, get_verbosity_level())
369
self.assertFalse(is_verbose())
370
self.assertFalse(is_quiet())
372
def test_be_quiet(self):
373
# Confirm the old API still works
375
self.assertEqual(-1, get_verbosity_level())
377
self.assertEqual(0, get_verbosity_level())
380
class TestLogging(TestCase):
381
"""Check logging functionality robustly records information"""
385
self.assertEqual(" INFO Noted\n", self.get_log())
387
def test_warning(self):
388
trace.warning("Warned")
389
self.assertEqual(" WARNING Warned\n", self.get_log())
392
logging.getLogger("brz").error("Errored")
393
self.assertEqual(" ERROR Errored\n", self.get_log())
395
def test_log_sub(self):
396
logging.getLogger("brz.test_log_sub").debug("Whispered")
397
self.assertEqual(" DEBUG Whispered\n", self.get_log())
399
def test_log_unicode_msg(self):
400
logging.getLogger("brz").debug(u"\xa7")
401
self.assertEqual(u" DEBUG \xa7\n", self.get_log())
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())
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())
411
def test_log_utf8_arg(self):
412
logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
414
expected = u" DEBUG b'\\xc2\\xa7'\n"
416
expected = u" DEBUG \xa7\n"
417
self.assertEqual(expected, self.get_log())
419
def test_log_bytes_msg(self):
420
logging.getLogger("brz").debug(b"\xa7")
422
self.assertContainsString(log, "UnicodeDecodeError: ")
423
self.assertContainsRe(
424
log, "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
426
def test_log_bytes_arg(self):
427
logging.getLogger("brz").debug(b"%s", b"\xa7")
430
self.assertEqual(u" DEBUG b'\\xa7'\n", self.get_log())
432
self.assertContainsString(log, "UnicodeDecodeError: ")
433
self.assertContainsRe(
435
"Logging record unformattable: ?'%s' % \\(b?'\\\\xa7',\\)\n")
437
def test_log_mixed_strings(self):
438
logging.getLogger("brz").debug(u"%s", b"\xa7")
441
self.assertEqual(u" DEBUG b'\\xa7'\n", self.get_log())
443
self.assertContainsString(log, "UnicodeDecodeError: ")
444
self.assertContainsRe(
446
"Logging record unformattable: u'%s' % \\('\\\\xa7',\\)\n")
448
def test_log_repr_broken(self):
449
class BadRepr(object):
451
raise ValueError("Broken object")
452
logging.getLogger("brz").debug("%s", BadRepr())
454
self.assertContainsRe(log, "ValueError: Broken object\n")
455
self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
458
class TestBzrLog(TestCaseInTempDir):
460
def test_log_rollover(self):
461
temp_log_name = 'test-log'
462
trace_file = open(temp_log_name, 'at')
463
trace_file.writelines(['test_log_rollover padding\n'] * 200000)
465
_rollover_trace_maybe(temp_log_name)
466
# should have been rolled over
467
self.assertFalse(os.access(temp_log_name, os.R_OK))
470
class TestTraceConfiguration(TestCaseInTempDir):
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)
480
# Should have entered and setup a default filename.
481
self.assertEqual(expected_filename, trace._brz_log_filename)
483
config.__exit__(None, None, None)
484
# Should have exited and cleaned up.
485
self.assertEqual(None, trace._brz_log_filename)
added
removed
breezy/tests/test_trace.py
