1
# Copyright (C) 2005, Canonical Ltd
 
 
3
"""Messages and logging for bazaar-ng.
 
 
5
Messages are supplied by callers as a string-formatting template, plus values
 
 
6
to be inserted into it.  The actual %-formatting is deferred to the log
 
 
7
library so that it doesn't need to be done for messages that won't be emitted.
 
 
9
Messages are classified by severity levels: critical, error, warning, info,
 
 
12
They can be sent to two places: to stderr, and to ~/.bzr.log.  For purposes
 
 
13
such as running the test suite, they can also be redirected away from both of
 
 
14
those two places to another location.
 
 
16
~/.bzr.log gets all messages, and full tracebacks for uncaught exceptions.
 
 
17
This trace file is always in UTF-8, regardless of the user's default encoding,
 
 
18
so that we can always rely on writing any message.
 
 
20
Output to stderr depends on the mode chosen by the user.  By default, messages
 
 
21
of info and above are sent out, which results in progress messages such as the
 
 
22
list of files processed by add and commit.  In quiet mode, only warnings and
 
 
23
above are shown.  In debug mode, stderr gets debug messages too.
 
 
25
Errors that terminate an operation are generally passed back as exceptions;
 
 
26
others may be just emitted as messages.
 
 
28
Exceptions are reported in a brief form to stderr so as not to look scary.
 
 
29
BzrErrors are required to be able to format themselves into a properly
 
 
30
explanatory message.  This is not true for builtin excexceptions such as
 
 
31
KeyError, which typically just str to "0".  They're printed in a different
 
 
35
# TODO: in debug mode, stderr should get full tracebacks and also
 
 
36
# debug messages.  (Is this really needed?)
 
 
38
# FIXME: Unfortunately it turns out that python's logging module
 
 
39
# is quite expensive, even when the message is not printed by any handlers.
 
 
40
# We should perhaps change back to just simply doing it here.
 
 
48
from bzrlib.errors import BzrError, BzrNewError
 
 
52
_stderr_handler = None
 
 
58
class QuietFormatter(logging.Formatter):
 
 
59
    """Formatter that supresses the details of errors.
 
 
61
    This is used by default on stderr so as not to scare the user.
 
 
63
    # At first I tried overriding formatException to suppress the
 
 
64
    # exception details, but that has global effect: no loggers
 
 
65
    # can get the exception details is we suppress them here.
 
 
67
    def format(self, record):
 
 
68
        if record.levelno >= logging.WARNING:
 
 
69
            s = 'bzr: ' + record.levelname + ': '
 
 
72
        s += record.getMessage()
 
 
74
            s += '\n' + format_exception_short(record.exc_info)
 
 
77
# configure convenient aliases for output routines
 
 
79
_bzr_logger = logging.getLogger('bzr')
 
 
81
def note(*args, **kwargs):
 
 
83
    bzrlib.ui.ui_factory.clear_term()
 
 
84
    _bzr_logger.info(*args, **kwargs)
 
 
86
def warning(*args, **kwargs):
 
 
88
    bzrlib.ui.ui_factory.clear_term()
 
 
89
    _bzr_logger.warning(*args, **kwargs)
 
 
92
log_error = _bzr_logger.error
 
 
93
error =     _bzr_logger.error
 
 
96
def mutter(fmt, *args):
 
 
97
    if _trace_file is None:
 
 
99
    if hasattr(_trace_file, 'closed') and _trace_file.closed:
 
 
102
        # It seems that if we do ascii % (unicode, ascii) we can
 
 
103
        # get a unicode cannot encode ascii error, so make sure that "fmt"
 
 
104
        # is a unicode string
 
 
105
        out = unicode(fmt) % args
 
 
110
        _trace_file.write(out)
 
 
111
    except UnicodeError, e:
 
 
112
        warning('UnicodeError: %s', e)
 
 
113
        _trace_file.write(repr(out))
 
 
114
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
 
 
119
def _rollover_trace_maybe(trace_fname):
 
 
122
        size = os.stat(trace_fname)[stat.ST_SIZE]
 
 
125
        old_fname = trace_fname + '.old'
 
 
126
        from osutils import rename
 
 
127
        rename(trace_fname, old_fname)
 
 
132
def open_tracefile(tracefilename='~/.bzr.log'):
 
 
133
    # Messages are always written to here, so that we have some
 
 
134
    # information if something goes wrong.  In a future version this
 
 
135
    # file will be removed on successful completion.
 
 
136
    global _file_handler, _bzr_log_file
 
 
139
    trace_fname = os.path.join(os.path.expanduser(tracefilename))
 
 
140
    _rollover_trace_maybe(trace_fname)
 
 
143
        tf = codecs.open(trace_fname, 'at', 'utf8', buffering=LINE_BUFFERED)
 
 
146
            tf.write("\nthis is a debug log for diagnosing/reporting problems in bzr\n")
 
 
147
            tf.write("you can delete or truncate this file, or include sections in\n")
 
 
148
            tf.write("bug reports to bazaar-ng@lists.canonical.com\n\n")
 
 
149
        _file_handler = logging.StreamHandler(tf)
 
 
150
        fmt = r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s'
 
 
151
        datefmt = r'%a %H:%M:%S'
 
 
152
        _file_handler.setFormatter(logging.Formatter(fmt, datefmt))
 
 
153
        _file_handler.setLevel(logging.DEBUG)
 
 
154
        logging.getLogger('').addHandler(_file_handler)
 
 
156
        warning("failed to open trace file: %s" % (e))
 
 
159
def log_startup(argv):
 
 
160
    debug('\n\nbzr %s invoked on python %s (%s)',
 
 
162
          '.'.join(map(str, sys.version_info)),
 
 
164
    debug('  arguments: %r', argv)
 
 
165
    debug('  working dir: %r', os.getcwdu())
 
 
168
def log_exception(msg=None):
 
 
169
    """Log the last exception to stderr and the trace file.
 
 
171
    The exception string representation is used as the error
 
 
172
    summary, unless msg is given.
 
 
177
        exc_str = format_exception_short(sys.exc_info())
 
 
179
    log_exception_quietly()
 
 
182
def log_exception_quietly():
 
 
183
    """Log the last exception to the trace file only.
 
 
185
    Used for exceptions that occur internally and that may be 
 
 
186
    interesting to developers but not to users.  For example, 
 
 
187
    errors loading plugins.
 
 
190
    debug(traceback.format_exc())
 
 
193
def enable_default_logging():
 
 
194
    """Configure default logging to stderr and .bzr.log"""
 
 
195
    # FIXME: if this is run twice, things get confused
 
 
196
    global _stderr_handler, _file_handler, _trace_file, _bzr_log_file
 
 
197
    _stderr_handler = logging.StreamHandler()
 
 
198
    _stderr_handler.setFormatter(QuietFormatter())
 
 
199
    logging.getLogger('').addHandler(_stderr_handler)
 
 
200
    _stderr_handler.setLevel(logging.INFO)
 
 
201
    if not _file_handler:
 
 
203
    _trace_file = _bzr_log_file
 
 
205
        _file_handler.setLevel(logging.DEBUG)
 
 
206
    _bzr_logger.setLevel(logging.DEBUG) 
 
 
210
def be_quiet(quiet=True):
 
 
211
    global _stderr_handler, _stderr_quiet
 
 
213
    _stderr_quiet = quiet
 
 
215
        _stderr_handler.setLevel(logging.WARNING)
 
 
217
        _stderr_handler.setLevel(logging.INFO)
 
 
225
def disable_default_logging():
 
 
226
    """Turn off default log handlers.
 
 
228
    This is intended to be used by the test framework, which doesn't
 
 
229
    want leakage from the code-under-test into the main logs.
 
 
232
    l = logging.getLogger('')
 
 
233
    l.removeHandler(_stderr_handler)
 
 
235
        l.removeHandler(_file_handler)
 
 
239
def enable_test_log(to_file):
 
 
240
    """Redirect logging to a temporary file for a test
 
 
242
    returns an opaque reference that should be passed to disable_test_log
 
 
243
    after the test complete.
 
 
245
    disable_default_logging()
 
 
247
    hdlr = logging.StreamHandler(to_file)
 
 
248
    hdlr.setLevel(logging.DEBUG)
 
 
249
    hdlr.setFormatter(logging.Formatter('%(levelname)8s  %(message)s'))
 
 
250
    _bzr_logger.addHandler(hdlr)
 
 
251
    _bzr_logger.setLevel(logging.DEBUG)
 
 
252
    result = hdlr, _trace_file
 
 
253
    _trace_file = to_file
 
 
257
def disable_test_log((test_log_hdlr, old_trace_file)):
 
 
258
    _bzr_logger.removeHandler(test_log_hdlr)
 
 
259
    test_log_hdlr.close()
 
 
260
    _trace_file = old_trace_file
 
 
261
    enable_default_logging()
 
 
264
def format_exception_short(exc_info):
 
 
265
    """Make a short string form of an exception.
 
 
267
    This is used for display to stderr.  It specially handles exception
 
 
268
    classes without useful string methods.
 
 
270
    The result has no trailing newline.
 
 
272
    exc_info - typically an exception from sys.exc_info()
 
 
274
    exc_type, exc_object, exc_tb = exc_info
 
 
277
            return '(no exception)'
 
 
278
        if isinstance(exc_object, (BzrError, BzrNewError)):
 
 
279
            return str(exc_object)
 
 
282
            tb = traceback.extract_tb(exc_tb)
 
 
283
            msg = '%s: %s' % (exc_type, exc_object)
 
 
287
                msg += '\n  at %s line %d\n  in %s' % (tb[-1][:3])
 
 
289
    except Exception, formatting_exc:
 
 
290
        # XXX: is this really better than just letting it run up?
 
 
291
        return '(error formatting exception of type %s: %s)' \
 
 
292
                % (exc_type, formatting_exc)