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"""
22
from io import StringIO
34
from . import features, TestCaseInTempDir, TestCase, TestSkipped
36
mutter, mutter_callsite, report_exception,
37
set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
40
_rollover_trace_maybe,
45
def _format_exception():
46
"""Format an exception as it would normally be displayed to the user"""
48
report_exception(sys.exc_info(), buf)
52
class TestTrace(TestCase):
54
def test_format_sys_exception(self):
55
# Test handling of an internal/unexpected error that probably
56
# indicates a bug in brz. The details of the message may vary
57
# depending on whether apport is available or not. See test_crash for
60
raise NotImplementedError("time travel")
61
except NotImplementedError:
62
err = _format_exception()
63
self.assertContainsRe(err,
64
'^brz: ERROR: NotImplementedError: time travel')
65
self.assertContainsRe(err,
66
'Bazaar has encountered an internal error.')
68
def test_format_interrupt_exception(self):
70
raise KeyboardInterrupt()
71
except KeyboardInterrupt:
72
# XXX: Some risk that a *real* keyboard interrupt won't be seen
73
msg = _format_exception()
74
self.assertEqual(msg, 'brz: interrupted\n')
76
def test_format_memory_error(self):
80
msg = _format_exception()
83
"brz: out of memory\nUse -Dmem_dump to dump memory to a file.\n")
85
def test_format_mem_dump(self):
86
self.requireFeature(features.meliae)
87
debug.debug_flags.add('mem_dump')
91
msg = _format_exception()
92
self.assertStartsWith(msg,
93
"brz: out of memory\nMemory dumped to ")
95
def test_format_os_error(self):
97
os.rmdir('nosuchfile22222')
100
msg = _format_exception()
101
# Linux seems to give "No such file" but Windows gives "The system
102
# cannot find the file specified".
103
self.assertEqual('brz: ERROR: %s\n' % (e_str,), msg)
105
def test_format_io_error(self):
107
open('nosuchfile22222')
109
msg = _format_exception()
110
# Even though Windows and Linux differ for 'os.rmdir', they both give
111
# 'No such file' for open()
112
# However it now gets translated so we can not test for a specific
114
self.assertContainsRe(msg,
115
'^brz: ERROR: \\[Errno .*\\] .*nosuchfile')
117
def test_format_pywintypes_error(self):
118
self.requireFeature(features.pywintypes)
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(
128
msg, "^brz: ERROR: \\(2, 'RemoveDirectory[AW]?', .*\\)")
130
def test_format_sockets_error(self):
133
sock = socket.socket()
134
sock.send(b"This should fail.")
136
msg = _format_exception()
138
self.assertNotContainsRe(msg,
139
"Traceback \\(most recent call last\\):")
141
def test_format_unicode_error(self):
143
raise errors.CommandError(u'argument foo\xb5 does not exist')
144
except errors.CommandError:
145
msg = _format_exception()
146
expected = 'brz: ERROR: argument foo\xb5 does not exist\n'
147
self.assertEqual(msg, expected)
149
def test_format_exception(self):
150
"""Short formatting of brz exceptions"""
152
raise errors.NotBranchError('wibble')
153
except errors.NotBranchError:
154
msg = _format_exception()
155
self.assertEqual(msg, 'brz: ERROR: Not a branch: \"wibble\".\n')
157
def test_report_external_import_error(self):
158
"""Short friendly message for missing system modules."""
160
import ImaginaryModule
162
msg = _format_exception()
164
self.fail("somehow succeeded in importing %r" % ImaginaryModule)
165
self.assertContainsRe(
167
"^brz: ERROR: No module named '?ImaginaryModule'?\n"
168
"You may need to install this Python library separately.\n$")
170
def test_report_import_syntax_error(self):
172
raise ImportError("syntax error")
174
msg = _format_exception()
175
self.assertContainsRe(msg,
176
'Bazaar has encountered an internal error')
178
def test_trace_unicode(self):
179
"""Write Unicode to trace log"""
180
self.log(u'the unicode character for benzene is \N{BENZENE RING}')
182
self.assertContainsRe(log, "the unicode character for benzene is")
184
def test_trace_argument_unicode(self):
185
"""Write a Unicode argument to the trace log"""
186
mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
188
self.assertContainsRe(log, 'the unicode character')
190
def test_trace_argument_utf8(self):
191
"""Write a Unicode argument to the trace log"""
192
mutter(u'the unicode character for benzene is %s',
193
u'\N{BENZENE RING}'.encode('utf-8'))
195
self.assertContainsRe(log, 'the unicode character')
197
def test_trace_argument_exception(self):
198
err = Exception('an error')
199
mutter(u'can format stringable classes %s', err)
201
self.assertContainsRe(log, 'can format stringable classes an error')
203
def test_report_broken_pipe(self):
205
raise IOError(errno.EPIPE, 'broken pipe foofofo')
207
msg = _format_exception()
208
self.assertEqual(msg, "brz: broken pipe\n")
210
self.fail("expected error not raised")
212
def assertLogContainsLine(self, log, string):
213
"""Assert log contains a line including log timestamp."""
214
# Does not check absolute position in log as there may be kipple.
215
self.assertContainsRe(log,
216
'(?m)^\\d+\\.\\d+ ' + re.escape(string))
218
def test_mutter_callsite_1(self):
219
"""mutter_callsite can capture 1 level of stack frame."""
220
mutter_callsite(1, "foo %s", "a string")
222
# begin with the message
223
self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
224
# should show two frame: this frame and the one above
225
self.assertContainsRe(
226
log, 'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
227
# this frame should be the final one
228
self.assertEndsWith(log, ' "a string")\n')
230
def test_mutter_callsite_2(self):
231
"""mutter_callsite can capture 2 levels of stack frame."""
232
mutter_callsite(2, "foo %s", "a string")
234
# begin with the message
235
self.assertLogContainsLine(log, 'foo a string\nCalled from:\n')
236
# should show two frame: this frame and the one above
237
self.assertContainsRe(
238
log, 'test_trace.py", line \\d+, in test_mutter_callsite_2\n')
239
# this frame should be the final one
240
self.assertEndsWith(log, ' "a string")\n')
242
def test_mutter_never_fails(self):
243
"""Even with unencodable input mutter should not raise errors."""
244
mutter(u'can write unicode \xa7')
245
mutter('can interpolate unicode %s', u'\xa7')
246
mutter(b'can write bytes \xa7')
247
mutter('can repr bytes %r', b'\xa7')
248
mutter('can interpolate bytes %s', b'\xa7')
249
# Log will always be written as utf-8
251
self.assertContainsRe(
253
u'.* +can write unicode \xa7\n'
254
u'.* +can interpolate unicode \xa7\n'
255
u'.* +can write bytes \ufffd\n'
256
u'.* +can repr bytes b\'\\\\xa7\'\n'
257
u'.* +can interpolate bytes (?:\ufffd|b\'\\\\xa7\')\n')
259
def test_show_error(self):
261
show_error(u'error2 \xb5 blah')
262
show_error('arg: %s', 'blah')
263
show_error('arg2: %(key)s', {'key': 'stuff'})
265
raise Exception("oops")
266
except BaseException:
267
show_error('kwarg', exc_info=True)
269
self.assertContainsRe(log, 'error1')
270
self.assertContainsRe(log, u'error2 \xb5 blah')
271
self.assertContainsRe(log, 'arg: blah')
272
self.assertContainsRe(log, 'arg2: stuff')
273
self.assertContainsRe(log, 'kwarg')
274
self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
275
self.assertContainsRe(
276
log, 'File ".*test_trace.py", line .*, in test_show_error')
277
self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
278
self.assertContainsRe(log, 'Exception: oops')
280
def test_push_log_file(self):
281
"""Can push and pop log file, and this catches mutter messages.
283
This is primarily for use in the test framework.
285
tmp1 = tempfile.NamedTemporaryFile()
286
tmp2 = tempfile.NamedTemporaryFile()
288
memento1 = push_log_file(tmp1)
289
mutter("comment to file1")
291
memento2 = push_log_file(tmp2)
293
mutter("comment to file2")
295
pop_log_file(memento2)
296
mutter("again to file1")
298
pop_log_file(memento1)
299
# the files were opened in binary mode, so should have exactly
300
# these bytes. and removing the file as the log target should
301
# have caused them to be flushed out. need to match using regexps
302
# as there's a timestamp at the front.
304
self.assertContainsRe(tmp1.read(),
305
b"\\d+\\.\\d+ comment to file1\n"
306
b"\\d+\\.\\d+ again to file1\n")
308
self.assertContainsRe(tmp2.read(),
309
b"\\d+\\.\\d+ comment to file2\n")
314
def test__open_brz_log_uses_stderr_for_failures(self):
315
# If _open_brz_log cannot open the file, then we should write the
316
# warning to stderr. Since this is normally happening before logging is
318
self.overrideAttr(sys, 'stderr', StringIO())
319
# Set the log file to something that cannot exist
320
self.overrideEnv('BRZ_LOG', '/no-such-dir/brz.log')
321
self.overrideAttr(trace, '_brz_log_filename')
322
logf = trace._open_brz_log()
323
if os.path.isdir('/no-such-dir'):
324
raise TestSkipped('directory creation succeeded')
325
self.assertIs(None, logf)
326
self.assertContainsRe(
327
sys.stderr.getvalue(),
328
"failed to open trace file: .* '/no-such-dir/brz.log'$")
330
def test__open_brz_log_ignores_cache_dir_error(self):
331
# If the cache directory can not be created and _open_brz_log can thus
332
# not open the file, then we should write the warning to stderr. Since
333
# this is normally happening before logging is set up.
334
self.overrideAttr(sys, 'stderr', StringIO())
335
# Set the cache directory to something that cannot exist
336
self.overrideEnv('BRZ_LOG', None)
337
self.overrideEnv('BRZ_HOME', '/no-such-dir')
338
self.overrideEnv('XDG_CACHE_HOME', '/no-such-dir')
339
self.overrideAttr(trace, '_brz_log_filename')
340
logf = trace._open_brz_log()
341
if os.path.isdir('/no-such-dir'):
342
raise TestSkipped('directory creation succeeded')
343
self.assertIs(None, logf)
344
self.assertContainsRe(
345
sys.stderr.getvalue(),
346
"failed to open trace file: .* '/no-such-dir'$")
349
class TestVerbosityLevel(TestCase):
351
def test_verbosity_level(self):
352
set_verbosity_level(1)
353
self.assertEqual(1, get_verbosity_level())
354
self.assertTrue(is_verbose())
355
self.assertFalse(is_quiet())
356
set_verbosity_level(-1)
357
self.assertEqual(-1, get_verbosity_level())
358
self.assertFalse(is_verbose())
359
self.assertTrue(is_quiet())
360
set_verbosity_level(0)
361
self.assertEqual(0, get_verbosity_level())
362
self.assertFalse(is_verbose())
363
self.assertFalse(is_quiet())
365
def test_be_quiet(self):
366
# Confirm the old API still works
368
self.assertEqual(-1, get_verbosity_level())
370
self.assertEqual(0, get_verbosity_level())
373
class TestLogging(TestCase):
374
"""Check logging functionality robustly records information"""
378
self.assertEqual(" INFO Noted\n", self.get_log())
380
def test_warning(self):
381
trace.warning("Warned")
382
self.assertEqual(" WARNING Warned\n", self.get_log())
385
logging.getLogger("brz").error("Errored")
386
self.assertEqual(" ERROR Errored\n", self.get_log())
388
def test_log_sub(self):
389
logging.getLogger("brz.test_log_sub").debug("Whispered")
390
self.assertEqual(" DEBUG Whispered\n", self.get_log())
392
def test_log_unicode_msg(self):
393
logging.getLogger("brz").debug(u"\xa7")
394
self.assertEqual(u" DEBUG \xa7\n", self.get_log())
396
def test_log_unicode_arg(self):
397
logging.getLogger("brz").debug("%s", u"\xa7")
398
self.assertEqual(u" DEBUG \xa7\n", self.get_log())
400
def test_log_utf8_msg(self):
401
logging.getLogger("brz").debug(b"\xc2\xa7")
402
self.assertEqual(u" DEBUG \xa7\n", self.get_log())
404
def test_log_utf8_arg(self):
405
logging.getLogger("brz").debug(b"%s", b"\xc2\xa7")
406
expected = u" DEBUG b'\\xc2\\xa7'\n"
407
self.assertEqual(expected, self.get_log())
409
def test_log_bytes_msg(self):
410
logging.getLogger("brz").debug(b"\xa7")
412
self.assertContainsString(log, "UnicodeDecodeError: ")
413
self.assertContainsRe(
414
log, "Logging record unformattable: b?'\\\\xa7' % \\(\\)\n")
416
def test_log_bytes_arg(self):
417
logging.getLogger("brz").debug(b"%s", b"\xa7")
419
self.assertEqual(u" DEBUG b'\\xa7'\n", self.get_log())
421
def test_log_mixed_strings(self):
422
logging.getLogger("brz").debug(u"%s", b"\xa7")
424
self.assertEqual(u" DEBUG b'\\xa7'\n", self.get_log())
426
def test_log_repr_broken(self):
427
class BadRepr(object):
429
raise ValueError("Broken object")
430
logging.getLogger("brz").debug("%s", BadRepr())
432
self.assertContainsRe(log, "ValueError: Broken object\n")
433
self.assertContainsRe(log, "Logging record unformattable: '%s' % .*\n")
436
class TestBzrLog(TestCaseInTempDir):
438
def test_log_rollover(self):
439
temp_log_name = 'test-log'
440
trace_file = open(temp_log_name, 'at')
441
trace_file.writelines(['test_log_rollover padding\n'] * 200000)
443
_rollover_trace_maybe(temp_log_name)
444
# should have been rolled over
445
self.assertFalse(os.access(temp_log_name, os.R_OK))
448
class TestTraceConfiguration(TestCaseInTempDir):
450
def test_default_config(self):
451
config = trace.DefaultConfig()
452
self.overrideAttr(trace, "_brz_log_filename", None)
453
trace._brz_log_filename = None
454
expected_filename = trace._get_brz_log_filename()
455
self.assertEqual(None, trace._brz_log_filename)
458
# Should have entered and setup a default filename.
459
self.assertEqual(expected_filename, trace._brz_log_filename)
461
config.__exit__(None, None, None)
462
# Should have exited and cleaned up.
463
self.assertEqual(None, trace._brz_log_filename)