13
14
# You should have received a copy of the GNU General Public License
 
14
15
# 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
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
17
18
# "weren't nothing promised to you.  do i look like i got a promise face?"
 
19
20
"""Tests for trace library"""
 
21
 
from cStringIO import StringIO
 
32
25
from bzrlib.tests import 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,
 
38
 
    _rollover_trace_maybe,
 
43
 
def _format_exception():
 
44
 
    """Format an exception as it would normally be displayed to the user"""
 
46
 
    report_exception(sys.exc_info(), buf)
 
 
26
from bzrlib.trace import format_exception_short, mutter
 
 
27
from bzrlib.errors import NotBranchError, BzrError, BzrNewError
 
50
29
class TestTrace(TestCase):
 
52
30
    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
 
 
31
        """Short formatting of exceptions"""
 
58
33
            raise NotImplementedError, "time travel"
 
59
34
        except NotImplementedError:
 
61
 
        err = _format_exception()
 
62
 
        self.assertEqualDiff(err.splitlines()[0],
 
63
 
                'bzr: ERROR: exceptions.NotImplementedError: time travel')
 
64
 
        self.assertContainsRe(err,
 
65
 
            'Bazaar has encountered an internal error.')
 
67
 
    def test_format_interrupt_exception(self):
 
69
 
            raise KeyboardInterrupt()
 
70
 
        except KeyboardInterrupt:
 
71
 
            # XXX: Some risk that a *real* keyboard interrupt won't be seen
 
73
 
        msg = _format_exception()
 
74
 
        self.assertTrue(len(msg) > 0)
 
75
 
        self.assertEqualDiff(msg, 'bzr: interrupted\n')
 
77
 
    def test_format_memory_error(self):
 
82
 
        msg = _format_exception()
 
83
 
        self.assertEquals(msg,
 
84
 
            "bzr: out of memory\n")
 
86
 
    def test_format_os_error(self):
 
88
 
            os.rmdir('nosuchfile22222')
 
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)
 
96
 
    def test_format_io_error(self):
 
98
 
            file('nosuchfile22222')
 
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')
 
107
 
    def test_format_unicode_error(self):
 
109
 
            raise errors.BzrCommandError(u'argument foo\xb5 does not exist')
 
110
 
        except errors.BzrCommandError:
 
112
 
        msg = _format_exception()
 
 
36
        error_lines = format_exception_short(sys.exc_info()).splitlines()
 
 
37
        self.assertEqualDiff(error_lines[0], 
 
 
38
                'exceptions.NotImplementedError: time travel')
 
 
39
        self.assertContainsRe(error_lines[1], 
 
 
40
                r'^  at .*trace\.py line \d+$')  
 
 
41
        self.assertContainsRe(error_lines[2], 
 
 
42
                r'^  in test_format_sys_exception$')
 
114
44
    def test_format_exception(self):
 
115
 
        """Short formatting of bzr exceptions"""
 
117
 
            raise errors.NotBranchError('wibble')
 
118
 
        except errors.NotBranchError:
 
120
 
        msg = _format_exception()
 
121
 
        self.assertTrue(len(msg) > 0)
 
122
 
        self.assertEqualDiff(msg, 'bzr: ERROR: Not a branch: \"wibble\".\n')
 
124
 
    def test_report_external_import_error(self):
 
125
 
        """Short friendly message for missing system modules."""
 
127
 
            import ImaginaryModule
 
128
 
        except ImportError, e:
 
131
 
            self.fail("somehow succeeded in importing %r" % ImaginaryModule)
 
132
 
        msg = _format_exception()
 
133
 
        self.assertEqual(msg,
 
134
 
            'bzr: ERROR: No module named ImaginaryModule\n'
 
135
 
            'You may need to install this Python library separately.\n')
 
137
 
    def test_report_import_syntax_error(self):
 
139
 
            raise ImportError("syntax error")
 
140
 
        except ImportError, e:
 
142
 
        msg = _format_exception()
 
143
 
        self.assertContainsRe(msg,
 
144
 
            r'Bazaar has encountered an internal error')
 
 
45
        """Short formatting of exceptions"""
 
 
47
            raise NotBranchError, 'wibble'
 
 
48
        except NotBranchError:
 
 
50
        msg = format_exception_short(sys.exc_info())
 
 
51
        self.assertEqualDiff(msg, 'Not a branch: wibble')
 
 
53
    def test_format_old_exception(self):
 
 
54
        # format a class that doesn't descend from BzrNewError; 
 
 
55
        # remove this test when everything is unified there
 
 
56
        self.assertFalse(issubclass(BzrError, BzrNewError))
 
 
58
            raise BzrError('some old error')
 
 
61
        msg = format_exception_short(sys.exc_info())
 
 
62
        self.assertEqualDiff(msg, 'some old error')
 
146
64
    def test_trace_unicode(self):
 
147
65
        """Write Unicode to trace log"""
 
148
66
        self.log(u'the unicode character for benzene is \N{BENZENE RING}')
 
150
 
        self.assertContainsRe(log, "the unicode character for benzene is")
 
152
 
    def test_trace_argument_unicode(self):
 
153
 
        """Write a Unicode argument to the trace log"""
 
154
 
        mutter(u'the unicode character for benzene is %s', u'\N{BENZENE RING}')
 
156
 
        self.assertContainsRe(log, 'the unicode character')
 
158
 
    def test_trace_argument_utf8(self):
 
159
 
        """Write a Unicode argument to the trace log"""
 
160
 
        mutter(u'the unicode character for benzene is %s',
 
161
 
               u'\N{BENZENE RING}'.encode('utf-8'))
 
163
 
        self.assertContainsRe(log, 'the unicode character')
 
165
 
    def test_report_broken_pipe(self):
 
167
 
            raise IOError(errno.EPIPE, 'broken pipe foofofo')
 
169
 
            msg = _format_exception()
 
170
 
            self.assertEquals(msg, "bzr: broken pipe\n")
 
172
 
            self.fail("expected error not raised")
 
174
 
    def assertLogStartsWith(self, log, string):
 
175
 
        """Like assertStartsWith, but skips the log timestamp."""
 
176
 
        self.assertContainsRe(log,
 
177
 
            '^\\d+\\.\\d+  ' + re.escape(string))
 
179
 
    def test_mutter_callsite_1(self):
 
180
 
        """mutter_callsite can capture 1 level of stack frame."""
 
181
 
        mutter_callsite(1, "foo %s", "a string")
 
183
 
        # begin with the message
 
184
 
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
 
185
 
        # should show two frame: this frame and the one above
 
186
 
        self.assertContainsRe(log,
 
187
 
            'test_trace\\.py", line \\d+, in test_mutter_callsite_1\n')
 
188
 
        # this frame should be the final one
 
189
 
        self.assertEndsWith(log, ' "a string")\n')
 
191
 
    def test_mutter_callsite_2(self):
 
192
 
        """mutter_callsite can capture 2 levels of stack frame."""
 
193
 
        mutter_callsite(2, "foo %s", "a string")
 
195
 
        # begin with the message
 
196
 
        self.assertLogStartsWith(log, 'foo a string\nCalled from:\n')
 
197
 
        # should show two frame: this frame and the one above
 
198
 
        self.assertContainsRe(log,
 
199
 
            'test_trace.py", line \d+, in test_mutter_callsite_2\n')
 
200
 
        # this frame should be the final one
 
201
 
        self.assertEndsWith(log, ' "a string")\n')
 
203
 
    def test_mutter_never_fails(self):
 
204
 
        # Even if the decode/encode stage fails, mutter should not
 
206
 
        # This test checks that mutter doesn't fail; the current behaviour
 
207
 
        # is that it doesn't fail *and writes non-utf8*.
 
208
 
        mutter(u'Writing a greek mu (\xb5) works in a unicode string')
 
209
 
        mutter('But fails in an ascii string \xb5')
 
210
 
        mutter('and in an ascii argument: %s', '\xb5')
 
212
 
        self.assertContainsRe(log, 'Writing a greek mu')
 
213
 
        self.assertContainsRe(log, "But fails in an ascii string")
 
214
 
        # However, the log content object does unicode replacement on reading
 
215
 
        # to let it get unicode back where good data has been written. So we
 
216
 
        # have to do a replaceent here as well.
 
217
 
        self.assertContainsRe(log, "ascii argument: \xb5".decode('utf8',
 
220
 
    def test_show_error(self):
 
222
 
        show_error(u'error2 \xb5 blah')
 
223
 
        show_error('arg: %s', 'blah')
 
224
 
        show_error('arg2: %(key)s', {'key':'stuff'})
 
226
 
            raise Exception("oops")
 
228
 
            show_error('kwarg', exc_info=True)
 
230
 
        self.assertContainsRe(log, 'error1')
 
231
 
        self.assertContainsRe(log, u'error2 \xb5 blah')
 
232
 
        self.assertContainsRe(log, 'arg: blah')
 
233
 
        self.assertContainsRe(log, 'arg2: stuff')
 
234
 
        self.assertContainsRe(log, 'kwarg')
 
235
 
        self.assertContainsRe(log, 'Traceback \\(most recent call last\\):')
 
236
 
        self.assertContainsRe(log, 'File ".*test_trace.py", line .*, in test_show_error')
 
237
 
        self.assertContainsRe(log, 'raise Exception\\("oops"\\)')
 
238
 
        self.assertContainsRe(log, 'Exception: oops')
 
240
 
    def test_push_log_file(self):
 
241
 
        """Can push and pop log file, and this catches mutter messages.
 
243
 
        This is primarily for use in the test framework.
 
245
 
        tmp1 = tempfile.NamedTemporaryFile()
 
246
 
        tmp2 = tempfile.NamedTemporaryFile()
 
248
 
            memento1 = push_log_file(tmp1)
 
249
 
            mutter("comment to file1")
 
251
 
                memento2 = push_log_file(tmp2)
 
253
 
                    mutter("comment to file2")
 
255
 
                    pop_log_file(memento2)
 
256
 
                mutter("again to file1")
 
258
 
                pop_log_file(memento1)
 
259
 
            # the files were opened in binary mode, so should have exactly
 
260
 
            # these bytes.  and removing the file as the log target should
 
261
 
            # have caused them to be flushed out.  need to match using regexps
 
262
 
            # as there's a timestamp at the front.
 
264
 
            self.assertContainsRe(tmp1.read(),
 
265
 
                r"\d+\.\d+  comment to file1\n\d+\.\d+  again to file1\n")
 
267
 
            self.assertContainsRe(tmp2.read(),
 
268
 
                r"\d+\.\d+  comment to file2\n")
 
273
 
    def test__open_bzr_log_uses_stderr_for_failures(self):
 
274
 
        # If _open_bzr_log cannot open the file, then we should write the
 
275
 
        # warning to stderr. Since this is normally happening before logging is
 
277
 
        self.overrideAttr(sys, 'stderr', StringIO())
 
278
 
        # Set the log file to something that cannot exist
 
279
 
        # FIXME: A bit dangerous: we are not in an isolated dir here -- vilajam
 
281
 
        os.environ['BZR_LOG'] = os.getcwd() + '/no-dir/bzr.log'
 
282
 
        self.overrideAttr(trace, '_bzr_log_filename')
 
283
 
        logf = trace._open_bzr_log()
 
284
 
        self.assertIs(None, logf)
 
285
 
        self.assertContainsRe(sys.stderr.getvalue(),
 
286
 
                              'failed to open trace file: .*/no-dir/bzr.log')
 
289
 
class TestVerbosityLevel(TestCase):
 
291
 
    def test_verbosity_level(self):
 
292
 
        set_verbosity_level(1)
 
293
 
        self.assertEqual(1, get_verbosity_level())
 
294
 
        self.assertTrue(is_verbose())
 
295
 
        self.assertFalse(is_quiet())
 
296
 
        set_verbosity_level(-1)
 
297
 
        self.assertEqual(-1, get_verbosity_level())
 
298
 
        self.assertFalse(is_verbose())
 
299
 
        self.assertTrue(is_quiet())
 
300
 
        set_verbosity_level(0)
 
301
 
        self.assertEqual(0, get_verbosity_level())
 
302
 
        self.assertFalse(is_verbose())
 
303
 
        self.assertFalse(is_quiet())
 
305
 
    def test_be_quiet(self):
 
306
 
        # Confirm the old API still works
 
308
 
        self.assertEqual(-1, get_verbosity_level())
 
310
 
        self.assertEqual(0, get_verbosity_level())
 
313
 
class TestBzrLog(TestCaseInTempDir):
 
315
 
    def test_log_rollover(self):
 
316
 
        temp_log_name = 'test-log'
 
317
 
        trace_file = open(temp_log_name, 'at')
 
318
 
        trace_file.writelines(['test_log_rollover padding\n'] * 200000)
 
320
 
        _rollover_trace_maybe(temp_log_name)
 
321
 
        # should have been rolled over
 
322
 
        self.assertFalse(os.access(temp_log_name, os.R_OK))
 
 
67
        self.assertContainsRe('the unicode character',