~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/trace.py

  • Committer: John Arbash Meinel
  • Date: 2006-04-25 15:05:42 UTC
  • mfrom: (1185.85.85 bzr-encoding)
  • mto: This revision was merged to the branch mainline in revision 1752.
  • Revision ID: john@arbash-meinel.com-20060425150542-c7b518dca9928691
[merge] the old bzr-encoding changes, reparenting them on bzr.dev

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
 
# This program is free software; you can redistribute it and/or modify
2
 
# it under the terms of the GNU General Public License as published by
3
 
# the Free Software Foundation; either version 2 of the License, or
4
 
# (at your option) any later version.
5
 
 
6
 
# This program is distributed in the hope that it will be useful,
7
 
# but WITHOUT ANY WARRANTY; without even the implied warranty of
8
 
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
9
 
# GNU General Public License for more details.
10
 
 
11
 
# You should have received a copy of the GNU General Public License
12
 
# along with this program; if not, write to the Free Software
13
 
# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
14
 
 
15
 
 
16
 
"""Messages and logging for bazaar-ng
17
 
 
18
 
Messages are sent out through the Python logging library.
19
 
 
20
 
They can be sent to two places: to stderr, and to ~/.bzr.log.
21
 
 
22
 
~/.bzr.log gets all messages, and tracebacks of all uncaught
23
 
exceptions.
24
 
 
25
 
Normally stderr only gets messages of level INFO and higher, and gets
26
 
only a summary of exceptions, not the traceback.
 
1
# Copyright (C) 2005, Canonical Ltd
 
2
 
 
3
"""Messages and logging for bazaar-ng.
 
4
 
 
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.
 
8
 
 
9
Messages are classified by severity levels: critical, error, warning, info,
 
10
and debug.
 
11
 
 
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.
 
15
 
 
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.
 
19
 
 
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.
 
24
 
 
25
Errors that terminate an operation are generally passed back as exceptions;
 
26
others may be just emitted as messages.
 
27
 
 
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
 
32
form.
27
33
"""
28
34
 
29
 
 
30
35
# TODO: in debug mode, stderr should get full tracebacks and also
31
36
# debug messages.  (Is this really needed?)
32
37
 
33
 
# TODO: When running the test suites, we should add an additional
34
 
# logger that sends messages into the test log file.
 
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.
35
41
 
36
42
 
37
43
import sys
38
44
import os
39
45
import logging
40
 
import traceback
 
46
 
 
47
import bzrlib
 
48
from bzrlib.errors import BzrError, BzrNewError
41
49
 
42
50
 
43
51
_file_handler = None
44
52
_stderr_handler = None
 
53
_stderr_quiet = False
 
54
_trace_file = None
 
55
_bzr_log_file = None
45
56
 
46
57
 
47
58
class QuietFormatter(logging.Formatter):
54
65
    # can get the exception details is we suppress them here.
55
66
 
56
67
    def format(self, record):
57
 
        s = 'bzr: '
58
68
        if record.levelno >= logging.WARNING:
59
 
            s += record.levelname + ': '
60
 
            
61
 
        s += record.getMessage() 
62
 
            
 
69
            s = 'bzr: ' + record.levelname + ': '
 
70
        else:
 
71
            s = ''
 
72
        s += record.getMessage()
63
73
        if record.exc_info:
64
 
            # give just a summary of the exception, not the whole thing
65
 
            exinfo = traceback.extract_tb(record.exc_info[2])
66
 
            # the format of this string matches one of the REs
67
 
            s += '\n'
68
 
            s += ('  at %s line %d, in %s()\n' % exinfo[-1][:3])
69
 
            s += '  see ~/.bzr.log for debug information'
70
 
 
 
74
            s += '\n' + format_exception_short(record.exc_info)
71
75
        return s
72
76
        
73
 
 
74
 
 
75
 
 
76
 
################
77
77
# configure convenient aliases for output routines
78
78
 
79
79
_bzr_logger = logging.getLogger('bzr')
80
 
_bzr_logger.setLevel(logging.DEBUG) 
81
 
 
82
 
info = note = _bzr_logger.info
83
 
warning =   _bzr_logger.warning
 
80
 
 
81
def note(*args, **kwargs):
 
82
    import bzrlib.ui
 
83
    bzrlib.ui.ui_factory.clear_term()
 
84
    _bzr_logger.info(*args, **kwargs)
 
85
 
 
86
def warning(*args, **kwargs):
 
87
    import bzrlib.ui
 
88
    bzrlib.ui.ui_factory.clear_term()
 
89
    _bzr_logger.warning(*args, **kwargs)
 
90
 
 
91
info = note
84
92
log_error = _bzr_logger.error
85
93
error =     _bzr_logger.error
86
 
mutter =    _bzr_logger.debug
87
 
debug =     _bzr_logger.debug
88
 
 
89
 
 
90
 
 
91
 
 
92
 
# we do the rollover using this code, rather than the default from python
93
 
# logging, because we only want to rollover at program startup, not on each
94
 
# message.  maybe that's not a good enough reason.
 
94
 
 
95
 
 
96
def mutter(fmt, *args):
 
97
    if _trace_file is None:
 
98
        return
 
99
    if hasattr(_trace_file, 'closed') and _trace_file.closed:
 
100
        return
 
101
    if len(args) > 0:
 
102
        out = fmt % args
 
103
    else:
 
104
        out = fmt
 
105
    out += '\n'
 
106
    try:
 
107
        _trace_file.write(out)
 
108
    except UnicodeError, e:
 
109
        warning('UnicodeError: %s', e)
 
110
        _trace_file.write(repr(out))
 
111
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
 
112
    #_trace_file.flush()
 
113
debug = mutter
 
114
 
95
115
 
96
116
def _rollover_trace_maybe(trace_fname):
97
117
    import stat
100
120
        if size <= 4 << 20:
101
121
            return
102
122
        old_fname = trace_fname + '.old'
103
 
 
104
 
        try:
105
 
            # must remove before rename on windows
106
 
            os.remove(old_fname)
107
 
        except OSError:
108
 
            pass
109
 
 
110
 
        try:
111
 
            # might fail if in use on windows
112
 
            os.rename(trace_fname, old_fname)
113
 
        except OSError:
114
 
            pass
 
123
        from osutils import rename
 
124
        rename(trace_fname, old_fname)
115
125
    except OSError:
116
126
        return
117
127
 
118
128
 
119
 
 
120
129
def open_tracefile(tracefilename='~/.bzr.log'):
121
130
    # Messages are always written to here, so that we have some
122
131
    # information if something goes wrong.  In a future version this
123
132
    # file will be removed on successful completion.
124
 
    global _file_handler
 
133
    global _file_handler, _bzr_log_file
125
134
    import stat, codecs
126
135
 
127
136
    trace_fname = os.path.join(os.path.expanduser(tracefilename))
128
137
    _rollover_trace_maybe(trace_fname)
129
 
 
130
 
    # buffering=1 means line buffered
131
138
    try:
132
 
        tf = codecs.open(trace_fname, 'at', 'utf8', buffering=1)
133
 
 
134
 
        if os.fstat(tf.fileno())[stat.ST_SIZE] == 0:
 
139
        LINE_BUFFERED = 1
 
140
        tf = codecs.open(trace_fname, 'at', 'utf8', buffering=LINE_BUFFERED)
 
141
        _bzr_log_file = tf
 
142
        if tf.tell() == 0:
135
143
            tf.write("\nthis is a debug log for diagnosing/reporting problems in bzr\n")
136
144
            tf.write("you can delete or truncate this file, or include sections in\n")
137
145
            tf.write("bug reports to bazaar-ng@lists.canonical.com\n\n")
138
 
        
139
146
        _file_handler = logging.StreamHandler(tf)
140
147
        fmt = r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s'
141
148
        datefmt = r'%a %H:%M:%S'
142
149
        _file_handler.setFormatter(logging.Formatter(fmt, datefmt))
143
150
        _file_handler.setLevel(logging.DEBUG)
144
151
        logging.getLogger('').addHandler(_file_handler)
145
 
 
146
152
    except IOError, e:
147
153
        warning("failed to open trace file: %s" % (e))
148
154
 
149
155
 
150
156
def log_startup(argv):
151
 
    import bzrlib
152
 
 
153
 
    debug('bzr %s invoked on python %s (%s)',
 
157
    debug('\n\nbzr %s invoked on python %s (%s)',
154
158
          bzrlib.__version__,
155
159
          '.'.join(map(str, sys.version_info)),
156
160
          sys.platform)
157
 
 
158
161
    debug('  arguments: %r', argv)
159
 
    debug('  working dir: %s', os.getcwdu())
 
162
    debug('  working dir: %r', os.getcwdu())
160
163
 
161
164
 
162
165
def log_exception(msg=None):
163
 
    """Log the last exception into the trace file.
 
166
    """Log the last exception to stderr and the trace file.
164
167
 
165
168
    The exception string representation is used as the error
166
169
    summary, unless msg is given.
167
170
    """
168
 
    if msg == None:
169
 
        ei = sys.exc_info()
170
 
        msg = str(ei[1])
171
 
 
172
 
    if msg and (msg[-1] == '\n'):
173
 
        msg = msg[:-1]
174
 
        
175
 
    _bzr_logger.exception(msg)
176
 
 
 
171
    if msg:
 
172
        error(msg)
 
173
    else:
 
174
        exc_str = format_exception_short(sys.exc_info())
 
175
        error(exc_str)
 
176
    log_exception_quietly()
 
177
 
 
178
 
 
179
def log_exception_quietly():
 
180
    """Log the last exception to the trace file only.
 
181
 
 
182
    Used for exceptions that occur internally and that may be 
 
183
    interesting to developers but not to users.  For example, 
 
184
    errors loading plugins.
 
185
    """
 
186
    import traceback
 
187
    debug(traceback.format_exc())
177
188
 
178
189
 
179
190
def enable_default_logging():
180
191
    """Configure default logging to stderr and .bzr.log"""
181
 
    global _stderr_handler, _file_handler
182
 
 
 
192
    # FIXME: if this is run twice, things get confused
 
193
    global _stderr_handler, _file_handler, _trace_file, _bzr_log_file
183
194
    _stderr_handler = logging.StreamHandler()
184
195
    _stderr_handler.setFormatter(QuietFormatter())
185
 
 
 
196
    logging.getLogger('').addHandler(_stderr_handler)
 
197
    _stderr_handler.setLevel(logging.INFO)
186
198
    if not _file_handler:
187
199
        open_tracefile()
188
 
 
189
 
    if os.environ.get('BZR_DEBUG'):
190
 
        level = logging.DEBUG
 
200
    _trace_file = _bzr_log_file
 
201
    if _file_handler:
 
202
        _file_handler.setLevel(logging.DEBUG)
 
203
    _bzr_logger.setLevel(logging.DEBUG) 
 
204
 
 
205
 
 
206
 
 
207
def be_quiet(quiet=True):
 
208
    global _stderr_handler, _stderr_quiet
 
209
    
 
210
    _stderr_quiet = quiet
 
211
    if quiet:
 
212
        _stderr_handler.setLevel(logging.WARNING)
191
213
    else:
192
 
        level = logging.INFO
193
 
 
194
 
    _stderr_handler.setLevel(logging.INFO)
195
 
    _file_handler.setLevel(level)
196
 
 
197
 
    logging.getLogger('').addHandler(_stderr_handler)
198
 
 
 
214
        _stderr_handler.setLevel(logging.INFO)
 
215
 
 
216
 
 
217
def is_quiet():
 
218
    global _stderr_quiet
 
219
    return _stderr_quiet
199
220
 
200
221
 
201
222
def disable_default_logging():
209
230
    l.removeHandler(_stderr_handler)
210
231
    if _file_handler:
211
232
        l.removeHandler(_file_handler)
 
233
    _trace_file = None
 
234
 
 
235
 
 
236
def enable_test_log(to_file):
 
237
    """Redirect logging to a temporary file for a test
 
238
    
 
239
    returns an opaque reference that should be passed to disable_test_log
 
240
    after the test complete.
 
241
    """
 
242
    disable_default_logging()
 
243
    global _trace_file
 
244
    hdlr = logging.StreamHandler(to_file)
 
245
    hdlr.setLevel(logging.DEBUG)
 
246
    hdlr.setFormatter(logging.Formatter('%(levelname)8s  %(message)s'))
 
247
    _bzr_logger.addHandler(hdlr)
 
248
    _bzr_logger.setLevel(logging.DEBUG)
 
249
    result = hdlr, _trace_file
 
250
    _trace_file = to_file
 
251
    return result
 
252
 
 
253
 
 
254
def disable_test_log((test_log_hdlr, old_trace_file)):
 
255
    _bzr_logger.removeHandler(test_log_hdlr)
 
256
    test_log_hdlr.close()
 
257
    _trace_file = old_trace_file
 
258
    enable_default_logging()
 
259
 
 
260
 
 
261
def format_exception_short(exc_info):
 
262
    """Make a short string form of an exception.
 
263
 
 
264
    This is used for display to stderr.  It specially handles exception
 
265
    classes without useful string methods.
 
266
 
 
267
    The result has no trailing newline.
 
268
 
 
269
    exc_info - typically an exception from sys.exc_info()
 
270
    """
 
271
    exc_type, exc_object, exc_tb = exc_info
 
272
    try:
 
273
        if exc_type is None:
 
274
            return '(no exception)'
 
275
        if isinstance(exc_object, (BzrError, BzrNewError)):
 
276
            return str(exc_object)
 
277
        else:
 
278
            import traceback
 
279
            tb = traceback.extract_tb(exc_tb)
 
280
            msg = '%s: %s' % (exc_type, exc_object)
 
281
            if msg[-1] == '\n':
 
282
                msg = msg[:-1]
 
283
            if tb:
 
284
                msg += '\n  at %s line %d\n  in %s' % (tb[-1][:3])
 
285
            return msg
 
286
    except Exception, formatting_exc:
 
287
        # XXX: is this really better than just letting it run up?
 
288
        return '(error formatting exception of type %s: %s)' \
 
289
                % (exc_type, formatting_exc)