~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/tests/test_trace.py

  • Committer: Martin Pool
  • Date: 2010-06-02 05:03:31 UTC
  • mto: This revision was merged to the branch mainline in revision 5279.
  • Revision ID: mbp@canonical.com-20100602050331-n2p1qt8hfsahspnv
Correct more sloppy use of the term 'Linux'

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
 
# Copyright (C) 2005, 2006 Canonical Ltd
 
1
# Copyright (C) 2005-2010 Canonical Ltd
2
2
#
3
3
# This program is free software; you can redistribute it and/or modify
4
4
# it under the terms of the GNU General Public License as published by
12
12
#
13
13
# You should have received a copy of the GNU General Public License
14
14
# along with this program; if not, write to the Free Software
15
 
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
15
# Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
16
16
 
17
17
# "weren't nothing promised to you.  do i look like i got a promise face?"
18
18
 
21
21
from cStringIO import StringIO
22
22
import errno
23
23
import os
 
24
import re
24
25
import sys
 
26
import tempfile
25
27
 
26
28
from bzrlib import (
27
29
    errors,
28
 
    )
29
 
from bzrlib.tests import TestCaseInTempDir, TestCase
30
 
from bzrlib.trace import mutter, mutter_callsite, report_exception
 
30
    trace,
 
31
    )
 
32
from bzrlib.tests import features, TestCaseInTempDir, TestCase
 
33
from bzrlib.trace import (
 
34
    mutter, mutter_callsite, report_exception,
 
35
    set_verbosity_level, get_verbosity_level, is_quiet, is_verbose, be_quiet,
 
36
    pop_log_file,
 
37
    push_log_file,
 
38
    _rollover_trace_maybe,
 
39
    show_error,
 
40
    )
31
41
 
32
42
 
33
43
def _format_exception():
40
50
class TestTrace(TestCase):
41
51
 
42
52
    def test_format_sys_exception(self):
 
53
        # Test handling of an internal/unexpected error that probably
 
54
        # indicates a bug in bzr.  The details of the message may vary
 
55
        # depending on whether apport is available or not.  See test_crash for
 
56
        # more.
43
57
        try:
44
58
            raise NotImplementedError, "time travel"
45
59
        except NotImplementedError:
48
62
        self.assertEqualDiff(err.splitlines()[0],
49
63
                'bzr: ERROR: exceptions.NotImplementedError: time travel')
50
64
        self.assertContainsRe(err,
51
 
                r'File.*test_trace.py')
 
65
            'Bazaar has encountered an internal error.')
52
66
 
53
67
    def test_format_interrupt_exception(self):
54
68
        try:
60
74
        self.assertTrue(len(msg) > 0)
61
75
        self.assertEqualDiff(msg, 'bzr: interrupted\n')
62
76
 
 
77
    def test_format_memory_error(self):
 
78
        try:
 
79
            raise MemoryError()
 
80
        except MemoryError:
 
81
            pass
 
82
        msg = _format_exception()
 
83
        self.assertEquals(msg,
 
84
            "bzr: out of memory\n")
 
85
 
63
86
    def test_format_os_error(self):
64
87
        try:
 
88
            os.rmdir('nosuchfile22222')
 
89
        except OSError, e:
 
90
            e_str = str(e)
 
91
        msg = _format_exception()
 
92
        # Linux seems to give "No such file" but Windows gives "The system
 
93
        # cannot find the file specified".
 
94
        self.assertEqual('bzr: ERROR: %s\n' % (e_str,), msg)
 
95
 
 
96
    def test_format_io_error(self):
 
97
        try:
65
98
            file('nosuchfile22222')
66
 
        except (OSError, IOError):
67
 
            pass
68
 
        msg = _format_exception()
69
 
        self.assertContainsRe(msg, r'^bzr: ERROR: \[Errno .*\] No such file.*nosuchfile')
 
99
        except IOError:
 
100
            pass
 
101
        msg = _format_exception()
 
102
        # Even though Windows and Linux differ for 'os.rmdir', they both give
 
103
        # 'No such file' for open()
 
104
        self.assertContainsRe(msg,
 
105
            r'^bzr: ERROR: \[Errno .*\] No such file.*nosuchfile')
 
106
 
 
107
    def test_format_pywintypes_error(self):
 
108
        self.requireFeature(features.pywintypes)
 
109
        import pywintypes, win32file
 
110
        try:
 
111
            win32file.RemoveDirectory('nosuchfile22222')
 
112
        except pywintypes.error:
 
113
            pass
 
114
        msg = _format_exception()
 
115
        # GZ 2010-05-03: Formatting for pywintypes.error is basic, a 3-tuple
 
116
        #                with errno, function name, and locale error message
 
117
        self.assertContainsRe(msg,
 
118
            r"^bzr: ERROR: \(2, 'RemoveDirectory[AW]?', .*\)")
70
119
 
71
120
    def test_format_unicode_error(self):
72
121
        try:
85
134
        self.assertTrue(len(msg) > 0)
86
135
        self.assertEqualDiff(msg, 'bzr: ERROR: Not a branch: \"wibble\".\n')
87
136
 
 
137
    def test_report_external_import_error(self):
 
138
        """Short friendly message for missing system modules."""
 
139
        try:
 
140
            import ImaginaryModule
 
141
        except ImportError, e:
 
142
            pass
 
143
        else:
 
144
            self.fail("somehow succeeded in importing %r" % ImaginaryModule)
 
145
        msg = _format_exception()
 
146
        self.assertEqual(msg,
 
147
            'bzr: ERROR: No module named ImaginaryModule\n'
 
148
            'You may need to install this Python library separately.\n')
 
149
 
 
150
    def test_report_import_syntax_error(self):
 
151
        try:
 
152
            raise ImportError("syntax error")
 
153
        except ImportError, e:
 
154
            pass
 
155
        msg = _format_exception()
 
156
        self.assertContainsRe(msg,
 
157
            r'Bazaar has encountered an internal error')
 
158
 
88
159
    def test_trace_unicode(self):
89
160
        """Write Unicode to trace log"""
90
161
        self.log(u'the unicode character for benzene is \N{BENZENE RING}')
91
 
        self.assertContainsRe(self._get_log(keep_log_file=True),
92
 
                              "the unicode character for benzene is")
93
 
    
 
162
        log = self.get_log()
 
163
        self.assertContainsRe(log, "the unicode character for benzene is")
 
164
 
94
165
    def test_trace_argument_unicode(self):
95
166
        """Write a Unicode argument to the trace log"""
96
167
        mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
97
 
        self.assertContainsRe(self._get_log(keep_log_file=True),
98
 
                              'the unicode character')
 
168
        log = self.get_log()
 
169
        self.assertContainsRe(log, 'the unicode character')
99
170
 
100
171
    def test_trace_argument_utf8(self):
101
172
        """Write a Unicode argument to the trace log"""
102
173
        mutter(u'the unicode character for benzene is %s',
103
174
               u'\N{BENZENE RING}'.encode('utf-8'))
104
 
        self.assertContainsRe(self._get_log(keep_log_file=True),
105
 
                              'the unicode character')
 
175
        log = self.get_log()
 
176
        self.assertContainsRe(log, 'the unicode character')
106
177
 
107
178
    def test_report_broken_pipe(self):
108
179
        try:
113
184
        else:
114
185
            self.fail("expected error not raised")
115
186
 
 
187
    def assertLogStartsWith(self, log, string):
 
188
        """Like assertStartsWith, but skips the log timestamp."""
 
189
        self.assertContainsRe(log,
 
190
            '^\\d+\\.\\d+  ' + re.escape(string))
 
191
 
116
192
    def test_mutter_callsite_1(self):
117
193
        """mutter_callsite can capture 1 level of stack frame."""
118
194
        mutter_callsite(1, "foo %s", "a string")
119
 
        log = self._get_log(keep_log_file=True)
 
195
        log = self.get_log()
120
196
        # begin with the message
121
 
        self.assertStartsWith(log, 'foo a string\nCalled from:\n')
 
197
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
122
198
        # should show two frame: this frame and the one above
123
199
        self.assertContainsRe(log,
124
 
            'test_trace\.py", line \d+, in test_mutter_callsite_1\n')
 
200
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
125
201
        # this frame should be the final one
126
202
        self.assertEndsWith(log, ' "a string")\n')
127
203
 
128
204
    def test_mutter_callsite_2(self):
129
205
        """mutter_callsite can capture 2 levels of stack frame."""
130
206
        mutter_callsite(2, "foo %s", "a string")
131
 
        log = self._get_log(keep_log_file=True)
 
207
        log = self.get_log()
132
208
        # begin with the message
133
 
        self.assertStartsWith(log, 'foo a string\nCalled from:\n')
 
209
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
134
210
        # should show two frame: this frame and the one above
135
211
        self.assertContainsRe(log,
136
212
            'test_trace.py", line \d+, in test_mutter_callsite_2\n')
140
216
    def test_mutter_never_fails(self):
141
217
        # Even if the decode/encode stage fails, mutter should not
142
218
        # raise an exception
 
219
        # This test checks that mutter doesn't fail; the current behaviour
 
220
        # is that it doesn't fail *and writes non-utf8*.
143
221
        mutter(u'Writing a greek mu (\xb5) works in a unicode string')
144
222
        mutter('But fails in an ascii string \xb5')
145
223
        mutter('and in an ascii argument: %s', '\xb5')
146
 
        log = self._get_log(keep_log_file=True)
 
224
        log = self.get_log()
147
225
        self.assertContainsRe(log, 'Writing a greek mu')
148
226
        self.assertContainsRe(log, "But fails in an ascii string")
149
 
        self.assertContainsRe(log, u"ascii argument: \xb5")
150
 
 
 
227
        # However, the log content object does unicode replacement on reading
 
228
        # to let it get unicode back where good data has been written. So we
 
229
        # have to do a replaceent here as well.
 
230
        self.assertContainsRe(log, "ascii argument: \xb5".decode('utf8',
 
231
            'replace'))
 
232
        
 
233
    def test_show_error(self):
 
234
        show_error('error1')
 
235
        show_error(u'error2 \xb5 blah')
 
236
        show_error('arg: %s', 'blah')
 
237
        show_error('arg2: %(key)s', {'key':'stuff'})
 
238
        try:
 
239
            raise Exception("oops")
 
240
        except:
 
241
            show_error('kwarg', exc_info=True)
 
242
        log = self.get_log()
 
243
        self.assertContainsRe(log, 'error1')
 
244
        self.assertContainsRe(log, u'error2 \xb5 blah')
 
245
        self.assertContainsRe(log, 'arg: blah')
 
246
        self.assertContainsRe(log, 'arg2: stuff')
 
247
        self.assertContainsRe(log, 'kwarg')
 
248
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
 
249
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
 
250
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
 
251
        self.assertContainsRe(log, 'Exception: oops')
 
252
 
 
253
    def test_push_log_file(self):
 
254
        """Can push and pop log file, and this catches mutter messages.
 
255
 
 
256
        This is primarily for use in the test framework.
 
257
        """
 
258
        tmp1 = tempfile.NamedTemporaryFile()
 
259
        tmp2 = tempfile.NamedTemporaryFile()
 
260
        try:
 
261
            memento1 = push_log_file(tmp1)
 
262
            mutter("comment to file1")
 
263
            try:
 
264
                memento2 = push_log_file(tmp2)
 
265
                try:
 
266
                    mutter("comment to file2")
 
267
                finally:
 
268
                    pop_log_file(memento2)
 
269
                mutter("again to file1")
 
270
            finally:
 
271
                pop_log_file(memento1)
 
272
            # the files were opened in binary mode, so should have exactly
 
273
            # these bytes.  and removing the file as the log target should
 
274
            # have caused them to be flushed out.  need to match using regexps
 
275
            # as there's a timestamp at the front.
 
276
            tmp1.seek(0)
 
277
            self.assertContainsRe(tmp1.read(),
 
278
                r"\d+\.\d+  comment to file1\n\d+\.\d+  again to file1\n")
 
279
            tmp2.seek(0)
 
280
            self.assertContainsRe(tmp2.read(),
 
281
                r"\d+\.\d+  comment to file2\n")
 
282
        finally:
 
283
            tmp1.close()
 
284
            tmp2.close()
 
285
 
 
286
    def test__open_bzr_log_uses_stderr_for_failures(self):
 
287
        # If _open_bzr_log cannot open the file, then we should write the
 
288
        # warning to stderr. Since this is normally happening before logging is
 
289
        # set up.
 
290
        self.overrideAttr(sys, 'stderr', StringIO())
 
291
        # Set the log file to something that cannot exist
 
292
        # FIXME: A bit dangerous: we are not in an isolated dir here -- vilajam
 
293
        # 20100125
 
294
        os.environ['BZR_LOG'] = os.getcwd() + '/no-dir/bzr.log'
 
295
        self.overrideAttr(trace, '_bzr_log_filename')
 
296
        logf = trace._open_bzr_log()
 
297
        self.assertIs(None, logf)
 
298
        self.assertContainsRe(sys.stderr.getvalue(),
 
299
                              'failed to open trace file: .*/no-dir/bzr.log')
 
300
 
 
301
 
 
302
class TestVerbosityLevel(TestCase):
 
303
 
 
304
    def test_verbosity_level(self):
 
305
        set_verbosity_level(1)
 
306
        self.assertEqual(1, get_verbosity_level())
 
307
        self.assertTrue(is_verbose())
 
308
        self.assertFalse(is_quiet())
 
309
        set_verbosity_level(-1)
 
310
        self.assertEqual(-1, get_verbosity_level())
 
311
        self.assertFalse(is_verbose())
 
312
        self.assertTrue(is_quiet())
 
313
        set_verbosity_level(0)
 
314
        self.assertEqual(0, get_verbosity_level())
 
315
        self.assertFalse(is_verbose())
 
316
        self.assertFalse(is_quiet())
 
317
 
 
318
    def test_be_quiet(self):
 
319
        # Confirm the old API still works
 
320
        be_quiet(True)
 
321
        self.assertEqual(-1, get_verbosity_level())
 
322
        be_quiet(False)
 
323
        self.assertEqual(0, get_verbosity_level())
 
324
 
 
325
 
 
326
class TestBzrLog(TestCaseInTempDir):
 
327
 
 
328
    def test_log_rollover(self):
 
329
        temp_log_name = 'test-log'
 
330
        trace_file = open(temp_log_name, 'at')
 
331
        trace_file.writelines(['test_log_rollover padding\n'] * 200000)
 
332
        trace_file.close()
 
333
        _rollover_trace_maybe(temp_log_name)
 
334
        # should have been rolled over
 
335
        self.assertFalse(os.access(temp_log_name, os.R_OK))