/brz/remove-bazaar

To get this branch, use:
bzr branch http://gegoxaren.bato24.eu/bzr/brz/remove-bazaar

« back to all changes in this revision

Viewing changes to bzrlib/trace.py

  • Committer: Canonical.com Patch Queue Manager
  • Date: 2008-01-11 07:06:36 UTC
  • mfrom: (3172.2.1 remote-fetch-formats)
  • Revision ID: pqm@pqm.ubuntu.com-20080111070636-jhozu5eo7wvh1k0o
(andrew) Enable use of smart revision streaming between repos with
        compatible models.

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/trace.py
 
1
# Copyright (C) 2005, 2006, 2007 Canonical Ltd
 
2
#
 
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.
 
7
#
 
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.
 
12
#
 
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., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 
16
 
 
17
"""Messages and logging for bazaar-ng.
 
18
 
 
19
Messages are supplied by callers as a string-formatting template, plus values
 
20
to be inserted into it.  The actual %-formatting is deferred to the log
 
21
library so that it doesn't need to be done for messages that won't be emitted.
 
22
 
 
23
Messages are classified by severity levels: critical, error, warning, info,
 
24
and debug.
 
25
 
 
26
They can be sent to two places: to stderr, and to ~/.bzr.log.  For purposes
 
27
such as running the test suite, they can also be redirected away from both of
 
28
those two places to another location.
 
29
 
 
30
~/.bzr.log gets all messages, and full tracebacks for uncaught exceptions.
 
31
This trace file is always in UTF-8, regardless of the user's default encoding,
 
32
so that we can always rely on writing any message.
 
33
 
 
34
Output to stderr depends on the mode chosen by the user.  By default, messages
 
35
of info and above are sent out, which results in progress messages such as the
 
36
list of files processed by add and commit.  In quiet mode, only warnings and
 
37
above are shown.  In debug mode, stderr gets debug messages too.
 
38
 
 
39
Errors that terminate an operation are generally passed back as exceptions;
 
40
others may be just emitted as messages.
 
41
 
 
42
Exceptions are reported in a brief form to stderr so as not to look scary.
 
43
BzrErrors are required to be able to format themselves into a properly
 
44
explanatory message.  This is not true for builtin exceptions such as
 
45
KeyError, which typically just str to "0".  They're printed in a different
 
46
form.
 
47
"""
 
48
 
 
49
# FIXME: Unfortunately it turns out that python's logging module
 
50
# is quite expensive, even when the message is not printed by any handlers.
 
51
# We should perhaps change back to just simply doing it here.
 
52
 
 
53
import codecs
 
54
import logging
 
55
import os
 
56
import sys
 
57
import re
 
58
import time
 
59
 
 
60
from bzrlib.lazy_import import lazy_import
 
61
lazy_import(globals(), """
 
62
from cStringIO import StringIO
 
63
import errno
 
64
import locale
 
65
import traceback
 
66
""")
 
67
 
 
68
import bzrlib
 
69
 
 
70
lazy_import(globals(), """
 
71
from bzrlib import (
 
72
    debug,
 
73
    errors,
 
74
    osutils,
 
75
    plugin,
 
76
    )
 
77
""")
 
78
 
 
79
_file_handler = None
 
80
_stderr_handler = None
 
81
_verbosity_level = 0
 
82
_trace_file = None
 
83
_trace_depth = 0
 
84
_bzr_log_file = None
 
85
_bzr_log_filename = None
 
86
_bzr_log_opened = None
 
87
 
 
88
 
 
89
# configure convenient aliases for output routines
 
90
 
 
91
_bzr_logger = logging.getLogger('bzr')
 
92
 
 
93
 
 
94
def note(*args, **kwargs):
 
95
    # FIXME note always emits utf-8, regardless of the terminal encoding
 
96
    import bzrlib.ui
 
97
    bzrlib.ui.ui_factory.clear_term()
 
98
    _bzr_logger.info(*args, **kwargs)
 
99
 
 
100
def warning(*args, **kwargs):
 
101
    import bzrlib.ui
 
102
    bzrlib.ui.ui_factory.clear_term()
 
103
    _bzr_logger.warning(*args, **kwargs)
 
104
 
 
105
info = note
 
106
log_error = _bzr_logger.error
 
107
error =     _bzr_logger.error
 
108
 
 
109
 
 
110
def mutter(fmt, *args):
 
111
    if _trace_file is None:
 
112
        return
 
113
    if (getattr(_trace_file, 'closed', None) is not None) and _trace_file.closed:
 
114
        return
 
115
 
 
116
    if isinstance(fmt, unicode):
 
117
        fmt = fmt.encode('utf8')
 
118
 
 
119
    if len(args) > 0:
 
120
        # It seems that if we do ascii % (unicode, ascii) we can
 
121
        # get a unicode cannot encode ascii error, so make sure that "fmt"
 
122
        # is a unicode string
 
123
        real_args = []
 
124
        for arg in args:
 
125
            if isinstance(arg, unicode):
 
126
                arg = arg.encode('utf8')
 
127
            real_args.append(arg)
 
128
        out = fmt % tuple(real_args)
 
129
    else:
 
130
        out = fmt
 
131
    out += '\n'
 
132
    if 'times' in debug.debug_flags:
 
133
        global _bzr_log_opened
 
134
        if _bzr_log_opened is None:
 
135
            # This is the first mutter since the process started.  Start the
 
136
            # clock from now.
 
137
            _bzr_log_opened = time.time()
 
138
        timestamp = '%0.3f' % (time.time() - _bzr_log_opened,)
 
139
        out = '%s %s' % (timestamp, out)
 
140
    _trace_file.write(out)
 
141
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
 
142
    #_trace_file.flush()
 
143
 
 
144
 
 
145
def mutter_callsite(stacklevel, fmt, *args):
 
146
    """Perform a mutter of fmt and args, logging the call trace.
 
147
 
 
148
    :param stacklevel: The number of frames to show. None will show all
 
149
        frames.
 
150
    :param fmt: The format string to pass to mutter.
 
151
    :param args: A list of substitution variables.
 
152
    """
 
153
    outf = StringIO()
 
154
    traceback.print_stack(limit=stacklevel + 1, file=outf)
 
155
    formatted_lines = outf.getvalue().splitlines()
 
156
    formatted_stack = '\n'.join(formatted_lines[:-2])
 
157
    mutter(fmt + "\nCalled from:\n%s", *(args + (formatted_stack,)))
 
158
 
 
159
 
 
160
def _rollover_trace_maybe(trace_fname):
 
161
    import stat
 
162
    try:
 
163
        size = os.stat(trace_fname)[stat.ST_SIZE]
 
164
        if size <= 4 << 20:
 
165
            return
 
166
        old_fname = trace_fname + '.old'
 
167
        osutils.rename(trace_fname, old_fname)
 
168
    except OSError:
 
169
        return
 
170
 
 
171
 
 
172
def open_tracefile(tracefilename=None):
 
173
    # Messages are always written to here, so that we have some
 
174
    # information if something goes wrong.  In a future version this
 
175
    # file will be removed on successful completion.
 
176
    global _file_handler, _bzr_log_file, _bzr_log_filename
 
177
    import codecs
 
178
 
 
179
    if tracefilename is None:
 
180
        if sys.platform == 'win32':
 
181
            from bzrlib import win32utils
 
182
            home = win32utils.get_home_location()
 
183
        else:
 
184
            home = os.path.expanduser('~')
 
185
        _bzr_log_filename = os.path.join(home, '.bzr.log')
 
186
    else:
 
187
        _bzr_log_filename = tracefilename
 
188
 
 
189
    _bzr_log_filename = os.path.expanduser(_bzr_log_filename)
 
190
    _rollover_trace_maybe(_bzr_log_filename)
 
191
    try:
 
192
        LINE_BUFFERED = 1
 
193
        #tf = codecs.open(trace_fname, 'at', 'utf8', buffering=LINE_BUFFERED)
 
194
        tf = open(_bzr_log_filename, 'at', LINE_BUFFERED)
 
195
        _bzr_log_file = tf
 
196
        # tf.tell() on windows always return 0 until some writing done
 
197
        tf.write('\n')
 
198
        if tf.tell() <= 2:
 
199
            tf.write("this is a debug log for diagnosing/reporting problems in bzr\n")
 
200
            tf.write("you can delete or truncate this file, or include sections in\n")
 
201
            tf.write("bug reports to https://bugs.launchpad.net/bzr/+filebug\n\n")
 
202
        _file_handler = logging.StreamHandler(tf)
 
203
        fmt = r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s'
 
204
        datefmt = r'%Y-%m-%d %H:%M:%S'
 
205
        _file_handler.setFormatter(logging.Formatter(fmt, datefmt))
 
206
        _file_handler.setLevel(logging.DEBUG)
 
207
        logging.getLogger('').addHandler(_file_handler)
 
208
    except IOError, e:
 
209
        warning("failed to open trace file: %s" % (e))
 
210
 
 
211
 
 
212
def log_exception_quietly():
 
213
    """Log the last exception to the trace file only.
 
214
 
 
215
    Used for exceptions that occur internally and that may be 
 
216
    interesting to developers but not to users.  For example, 
 
217
    errors loading plugins.
 
218
    """
 
219
    import traceback
 
220
    mutter(traceback.format_exc())
 
221
 
 
222
 
 
223
def enable_default_logging():
 
224
    """Configure default logging to stderr and .bzr.log"""
 
225
    # FIXME: if this is run twice, things get confused
 
226
    global _stderr_handler, _file_handler, _trace_file, _bzr_log_file
 
227
    # create encoded wrapper around stderr
 
228
    stderr = codecs.getwriter(osutils.get_terminal_encoding())(sys.stderr,
 
229
        errors='replace')
 
230
    _stderr_handler = logging.StreamHandler(stderr)
 
231
    logging.getLogger('').addHandler(_stderr_handler)
 
232
    _stderr_handler.setLevel(logging.INFO)
 
233
    if not _file_handler:
 
234
        open_tracefile()
 
235
    _trace_file = _bzr_log_file
 
236
    if _file_handler:
 
237
        _file_handler.setLevel(logging.DEBUG)
 
238
    _bzr_logger.setLevel(logging.DEBUG)
 
239
 
 
240
 
 
241
def set_verbosity_level(level):
 
242
    """Set the verbosity level.
 
243
 
 
244
    :param level: -ve for quiet, 0 for normal, +ve for verbose
 
245
    """
 
246
    global _verbosity_level
 
247
    _verbosity_level = level
 
248
    _update_logging_level(level < 0)
 
249
 
 
250
 
 
251
def get_verbosity_level():
 
252
    """Get the verbosity level.
 
253
 
 
254
    See set_verbosity_level() for values.
 
255
    """
 
256
    return _verbosity_level
 
257
 
 
258
 
 
259
def be_quiet(quiet=True):
 
260
    # Perhaps this could be deprecated now ...
 
261
    if quiet:
 
262
        set_verbosity_level(-1)
 
263
    else:
 
264
        set_verbosity_level(0)
 
265
 
 
266
 
 
267
def _update_logging_level(quiet=True):
 
268
    """Hide INFO messages if quiet."""
 
269
    if quiet:
 
270
        _stderr_handler.setLevel(logging.WARNING)
 
271
    else:
 
272
        _stderr_handler.setLevel(logging.INFO)
 
273
 
 
274
 
 
275
def is_quiet():
 
276
    """Is the verbosity level negative?"""
 
277
    return _verbosity_level < 0
 
278
 
 
279
 
 
280
def is_verbose():
 
281
    """Is the verbosity level positive?"""
 
282
    return _verbosity_level > 0
 
283
 
 
284
 
 
285
def disable_default_logging():
 
286
    """Turn off default log handlers.
 
287
 
 
288
    This is intended to be used by the test framework, which doesn't
 
289
    want leakage from the code-under-test into the main logs.
 
290
    """
 
291
 
 
292
    l = logging.getLogger('')
 
293
    l.removeHandler(_stderr_handler)
 
294
    if _file_handler:
 
295
        l.removeHandler(_file_handler)
 
296
    _trace_file = None
 
297
 
 
298
 
 
299
def enable_test_log(to_file):
 
300
    """Redirect logging to a temporary file for a test
 
301
    
 
302
    returns an opaque reference that should be passed to disable_test_log
 
303
    after the test completes.
 
304
    """
 
305
    disable_default_logging()
 
306
    global _trace_file
 
307
    global _trace_depth
 
308
    hdlr = logging.StreamHandler(to_file)
 
309
    hdlr.setLevel(logging.DEBUG)
 
310
    hdlr.setFormatter(logging.Formatter('%(levelname)8s  %(message)s'))
 
311
    _bzr_logger.addHandler(hdlr)
 
312
    _bzr_logger.setLevel(logging.DEBUG)
 
313
    result = hdlr, _trace_file, _trace_depth
 
314
    _trace_file = to_file
 
315
    _trace_depth += 1
 
316
    return result
 
317
 
 
318
 
 
319
def disable_test_log((test_log_hdlr, old_trace_file, old_trace_depth)):
 
320
    _bzr_logger.removeHandler(test_log_hdlr)
 
321
    test_log_hdlr.close()
 
322
    global _trace_file
 
323
    global _trace_depth
 
324
    _trace_file = old_trace_file
 
325
    _trace_depth = old_trace_depth
 
326
    if not _trace_depth:
 
327
        enable_default_logging()
 
328
 
 
329
 
 
330
def report_exception(exc_info, err_file):
 
331
    """Report an exception to err_file (typically stderr) and to .bzr.log.
 
332
 
 
333
    This will show either a full traceback or a short message as appropriate.
 
334
 
 
335
    :return: The appropriate exit code for this error.
 
336
    """
 
337
    exc_type, exc_object, exc_tb = exc_info
 
338
    # Log the full traceback to ~/.bzr.log
 
339
    log_exception_quietly()
 
340
    if (isinstance(exc_object, IOError)
 
341
        and getattr(exc_object, 'errno', None) == errno.EPIPE):
 
342
        err_file.write("bzr: broken pipe\n")
 
343
        return errors.EXIT_ERROR
 
344
    elif isinstance(exc_object, KeyboardInterrupt):
 
345
        err_file.write("bzr: interrupted\n")
 
346
        return errors.EXIT_ERROR
 
347
    elif not getattr(exc_object, 'internal_error', True):
 
348
        report_user_error(exc_info, err_file)
 
349
        return errors.EXIT_ERROR
 
350
    elif isinstance(exc_object, (OSError, IOError)):
 
351
        # Might be nice to catch all of these and show them as something more
 
352
        # specific, but there are too many cases at the moment.
 
353
        report_user_error(exc_info, err_file)
 
354
        return errors.EXIT_ERROR
 
355
    else:
 
356
        report_bug(exc_info, err_file)
 
357
        return errors.EXIT_INTERNAL_ERROR
 
358
 
 
359
 
 
360
# TODO: Should these be specially encoding the output?
 
361
def report_user_error(exc_info, err_file):
 
362
    """Report to err_file an error that's not an internal error.
 
363
 
 
364
    These don't get a traceback unless -Derror was given.
 
365
    """
 
366
    if 'error' in debug.debug_flags:
 
367
        report_bug(exc_info, err_file)
 
368
        return
 
369
    err_file.write("bzr: ERROR: %s\n" % (exc_info[1],))
 
370
 
 
371
 
 
372
def report_bug(exc_info, err_file):
 
373
    """Report an exception that probably indicates a bug in bzr"""
 
374
    import traceback
 
375
    exc_type, exc_object, exc_tb = exc_info
 
376
    err_file.write("bzr: ERROR: %s.%s: %s\n" % (
 
377
        exc_type.__module__, exc_type.__name__, exc_object))
 
378
    err_file.write('\n')
 
379
    traceback.print_exception(exc_type, exc_object, exc_tb, file=err_file)
 
380
    err_file.write('\n')
 
381
    err_file.write('bzr %s on python %s (%s)\n' % \
 
382
                       (bzrlib.__version__,
 
383
                        '.'.join(map(str, sys.version_info)),
 
384
                        sys.platform))
 
385
    err_file.write('arguments: %r\n' % sys.argv)
 
386
    err_file.write(
 
387
        'encoding: %r, fsenc: %r, lang: %r\n' % (
 
388
            osutils.get_user_encoding(), sys.getfilesystemencoding(),
 
389
            os.environ.get('LANG')))
 
390
    err_file.write("plugins:\n")
 
391
    for name, a_plugin in sorted(plugin.plugins().items()):
 
392
        err_file.write("  %-20s %s [%s]\n" %
 
393
            (name, a_plugin.path(), a_plugin.__version__))
 
394
    err_file.write(
 
395
"""\
 
396
*** Bazaar has encountered an internal error.
 
397
    Please report a bug at https://bugs.launchpad.net/bzr/+filebug
 
398
    including this traceback, and a description of what you
 
399
    were doing when the error occurred.
 
400
""")