1
# Copyright (C) 2005-2011 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"""
21
from cStringIO import StringIO
33
from bzrlib.tests import features, TestCaseInTempDir, TestCase
34
from bzrlib.trace import (
35
mutter, mutter_callsite, report_exception,
36
set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
39
_rollover_trace_maybe,
44
def _format_exception():
45
"""Format an exception as it would normally be displayed to the user"""
47
report_exception(sys.exc_info(), buf)
51
class TestTrace(TestCase):
53
def test_format_sys_exception(self):
54
# Test handling of an internal/unexpected error that probably
55
# indicates a bug in bzr. The details of the message may vary
56
# depending on whether apport is available or not. See test_crash for
59
raise NotImplementedError, "time travel"
60
except NotImplementedError:
62
err = _format_exception()
63
self.assertEqualDiff(err.splitlines()[0],
64
'bzr: ERROR: exceptions.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
74
msg = _format_exception()
75
self.assertTrue(len(msg) > 0)
76
self.assertEqualDiff(msg, 'bzr: interrupted\n')
78
def test_format_memory_error(self):
83
msg = _format_exception()
84
self.assertEquals(msg,
85
"bzr: out of memory\nUse -Dmem_dump to dump memory to a file.\n")
87
def test_format_mem_dump(self):
88
self.requireFeature(features.meliae)
89
debug.debug_flags.add('mem_dump')
94
msg = _format_exception()
95
self.assertStartsWith(msg,
96
"bzr: 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('bzr: ERROR: %s\n' % (e_str,), msg)
108
def test_format_io_error(self):
110
file('nosuchfile22222')
113
msg = _format_exception()
114
# Even though Windows and Linux differ for 'os.rmdir', they both give
115
# 'No such file' for open()
116
# However it now gets translated so we can not test for a specific message
117
self.assertContainsRe(msg,
118
r'^bzr: ERROR: \[Errno .*\] .*nosuchfile')
120
def test_format_pywintypes_error(self):
121
self.requireFeature(features.pywintypes)
122
import pywintypes, win32file
124
win32file.RemoveDirectory('nosuchfile22222')
125
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(msg,
131
r"^bzr: ERROR: \(2, 'RemoveDirectory[AW]?', .*\)")
133
def test_format_sockets_error(self):
136
sock = socket.socket()
137
sock.send("This should fail.")
140
msg = _format_exception()
142
self.assertNotContainsRe(msg,
143
r"Traceback (most recent call last):")
145
def test_format_unicode_error(self):
147
raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
148
except errors.BzrCommandError:
150
msg = _format_exception()
152
def test_format_exception(self):
153
"""Short formatting of bzr exceptions"""
155
raise errors.NotBranchError('wibble')
156
except errors.NotBranchError:
158
msg = _format_exception()
159
self.assertTrue(len(msg) > 0)
160
self.assertEqualDiff(msg, 'bzr: ERROR: Not a branch: \"wibble\".\n')
162
def test_report_external_import_error(self):
163
"""Short friendly message for missing system modules."""
165
import ImaginaryModule
166
except ImportError, e:
169
self.fail("somehow succeeded in importing %r" % ImaginaryModule)
170
msg = _format_exception()
171
self.assertEqual(msg,
172
'bzr: ERROR: No module named ImaginaryModule\n'
173
'You may need to install this Python library separately.\n')
175
def test_report_import_syntax_error(self):
177
raise ImportError("syntax error")
178
except ImportError, e:
180
msg = _format_exception()
181
self.assertContainsRe(msg,
182
r'Bazaar has encountered an internal error')
184
def test_trace_unicode(self):
185
"""Write Unicode to trace log"""
186
self.log(u'the unicode character for benzene is \N{BENZENE RING}')
188
self.assertContainsRe(log, "the unicode character for benzene is")
190
def test_trace_argument_unicode(self):
191
"""Write a Unicode argument to the trace log"""
192
mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
194
self.assertContainsRe(log, 'the unicode character')
196
def test_trace_argument_utf8(self):
197
"""Write a Unicode argument to the trace log"""
198
mutter(u'the unicode character for benzene is %s',
199
u'\N{BENZENE RING}'.encode('utf-8'))
201
self.assertContainsRe(log, 'the unicode character')
203
def test_report_broken_pipe(self):
205
raise IOError(errno.EPIPE, 'broken pipe foofofo')
207
msg = _format_exception()
208
self.assertEquals(msg, "bzr: broken pipe\n")
210
self.fail("expected error not raised")
212
def assertLogStartsWith(self, log, string):
213
"""Like assertStartsWith, but skips the log timestamp."""
214
self.assertContainsRe(log,
215
'^\\d+\\.\\d+ ' + re.escape(string))
217
def test_mutter_callsite_1(self):
218
"""mutter_callsite can capture 1 level of stack frame."""
219
mutter_callsite(1, "foo %s", "a string")
221
# begin with the message
222
self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
223
# should show two frame: this frame and the one above
224
self.assertContainsRe(log,
225
'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
226
# this frame should be the final one
227
self.assertEndsWith(log, ' "a string")\n')
229
def test_mutter_callsite_2(self):
230
"""mutter_callsite can capture 2 levels of stack frame."""
231
mutter_callsite(2, "foo %s", "a string")
233
# begin with the message
234
self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
235
# should show two frame: this frame and the one above
236
self.assertContainsRe(log,
237
'test_trace.py", line \d+, in test_mutter_callsite_2\n')
238
# this frame should be the final one
239
self.assertEndsWith(log, ' "a string")\n')
241
def test_mutter_never_fails(self):
242
# Even if the decode/encode stage fails, mutter should not
244
# This test checks that mutter doesn't fail; the current behaviour
245
# is that it doesn't fail *and writes non-utf8*.
246
mutter(u'Writing a greek mu (\xb5) works in a unicode string')
247
mutter('But fails in an ascii string \xb5')
248
mutter('and in an ascii argument: %s', '\xb5')
250
self.assertContainsRe(log, 'Writing a greek mu')
251
self.assertContainsRe(log, "But fails in an ascii string")
252
# However, the log content object does unicode replacement on reading
253
# to let it get unicode back where good data has been written. So we
254
# have to do a replaceent here as well.
255
self.assertContainsRe(log, "ascii argument: \xb5".decode('utf8',
258
def test_show_error(self):
260
show_error(u'error2 \xb5 blah')
261
show_error('arg: %s', 'blah')
262
show_error('arg2: %(key)s', {'key':'stuff'})
264
raise Exception("oops")
266
show_error('kwarg', exc_info=True)
268
self.assertContainsRe(log, 'error1')
269
self.assertContainsRe(log, u'error2 \xb5 blah')
270
self.assertContainsRe(log, 'arg: blah')
271
self.assertContainsRe(log, 'arg2: stuff')
272
self.assertContainsRe(log, 'kwarg')
273
self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
274
self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
275
self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
276
self.assertContainsRe(log, 'Exception: oops')
278
def test_push_log_file(self):
279
"""Can push and pop log file, and this catches mutter messages.
281
This is primarily for use in the test framework.
283
tmp1 = tempfile.NamedTemporaryFile()
284
tmp2 = tempfile.NamedTemporaryFile()
286
memento1 = push_log_file(tmp1)
287
mutter("comment to file1")
289
memento2 = push_log_file(tmp2)
291
mutter("comment to file2")
293
pop_log_file(memento2)
294
mutter("again to file1")
296
pop_log_file(memento1)
297
# the files were opened in binary mode, so should have exactly
298
# these bytes. and removing the file as the log target should
299
# have caused them to be flushed out. need to match using regexps
300
# as there's a timestamp at the front.
302
self.assertContainsRe(tmp1.read(),
303
r"\d+\.\d+ comment to file1\n\d+\.\d+ again to file1\n")
305
self.assertContainsRe(tmp2.read(),
306
r"\d+\.\d+ comment to file2\n")
311
def test__open_bzr_log_uses_stderr_for_failures(self):
312
# If _open_bzr_log cannot open the file, then we should write the
313
# warning to stderr. Since this is normally happening before logging is
315
self.overrideAttr(sys, 'stderr', StringIO())
316
# Set the log file to something that cannot exist
317
self.overrideEnv('BZR_LOG', os.getcwd() + '/no-dir/bzr.log')
318
self.overrideAttr(trace, '_bzr_log_filename')
319
logf = trace._open_bzr_log()
320
self.assertIs(None, logf)
321
self.assertContainsRe(sys.stderr.getvalue(),
322
'failed to open trace file: .*/no-dir/bzr.log')
325
class TestVerbosityLevel(TestCase):
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())
341
def test_be_quiet(self):
342
# Confirm the old API still works
344
self.assertEqual(-1, get_verbosity_level())
346
self.assertEqual(0, get_verbosity_level())
349
class TestBzrLog(TestCaseInTempDir):
351
def test_log_rollover(self):
352
temp_log_name = 'test-log'
353
trace_file = open(temp_log_name, 'at')
354
trace_file.writelines(['test_log_rollover padding\n'] * 200000)
356
_rollover_trace_maybe(temp_log_name)
357
# should have been rolled over
358
self.assertFalse(os.access(temp_log_name, os.R_OK))
361
class TestTraceConfiguration(TestCaseInTempDir):
363
def test_default_config(self):
364
config = trace.DefaultConfig()
365
self.overrideAttr(trace, "_bzr_log_filename", None)
366
trace._bzr_log_filename = None
367
expected_filename = trace._get_bzr_log_filename()
368
self.assertEqual(None, trace._bzr_log_filename)
371
# Should have entered and setup a default filename.
372
self.assertEqual(expected_filename, trace._bzr_log_filename)
374
config.__exit__(None, None, None)
375
# Should have exited and cleaned up.
376
self.assertEqual(None, trace._bzr_log_filename)