← Back to branch summary

~bzr-pqm/bzr/bzr.dev

« back to all changes in this revision

Viewing changes to bzrlib/trace.py

Merge bzr.dev and tree-file-ids-as-tuples.

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/trace.py
1
 
# Copyright (C) 2005, 2006 Canonical Ltd
 
1
# Copyright (C) 2005-2011 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
 
"""Messages and logging for bazaar-ng.
 
17
"""Messages and logging.
18
18
 
19
19
Messages are supplied by callers as a string-formatting template, plus values
20
20
to be inserted into it.  The actual %-formatting is deferred to the log
33
33
 
34
34
Output to stderr depends on the mode chosen by the user.  By default, messages
35
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.
 
36
list of files processed by add and commit.  In debug mode, stderr gets debug messages too.
38
37
 
39
38
Errors that terminate an operation are generally passed back as exceptions;
40
39
others may be just emitted as messages.
46
45
form.
47
46
"""
48
47
 
 
48
from __future__ import absolute_import
 
49
 
49
50
# FIXME: Unfortunately it turns out that python's logging module
50
51
# is quite expensive, even when the message is not printed by any handlers.
51
52
# We should perhaps change back to just simply doing it here.
 
53
#
 
54
# On the other hand, as of 1.2 we generally only call the mutter() statement
 
55
# if (according to debug_flags) we actually intend to write it.  So the
 
56
# increased cost of logging.py is not so bad, and we could standardize on
 
57
# that.
52
58
 
 
59
import logging
53
60
import os
54
61
import sys
55
 
import re
 
62
import time
56
63
 
57
64
from bzrlib.lazy_import import lazy_import
58
65
lazy_import(globals(), """
59
66
from cStringIO import StringIO
60
67
import errno
61
 
import logging
 
68
import locale
 
69
import tempfile
62
70
import traceback
63
71
""")
64
72
 
65
73
import bzrlib
66
74
 
67
75
lazy_import(globals(), """
68
 
from bzrlib import debug
 
76
from bzrlib import (
 
77
    debug,
 
78
    errors,
 
79
    osutils,
 
80
    ui,
 
81
    )
69
82
""")
70
83
 
71
 
_file_handler = None
72
 
_stderr_handler = None
73
 
_stderr_quiet = False
 
84
 
 
85
# global verbosity for bzrlib; controls the log level for stderr; 0=normal; <0
 
86
# is quiet; >0 is verbose.
 
87
_verbosity_level = 0
 
88
 
 
89
# File-like object where mutter/debug output is currently sent.  Can be
 
90
# changed by _push_log_file etc.  This is directly manipulated by some
 
91
# external code; maybe there should be functions to do that more precisely
 
92
# than push/pop_log_file.
74
93
_trace_file = None
75
 
_trace_depth = 0
76
 
_bzr_log_file = None
 
94
 
 
95
# Absolute path for ~/.bzr.log.  Not changed even if the log/trace output is
 
96
# redirected elsewhere.  Used to show the location in --version.
77
97
_bzr_log_filename = None
78
98
 
79
 
 
80
 
# configure convenient aliases for output routines
81
 
 
 
99
# The time the first message was written to the trace file, so that we can
 
100
# show relative times since startup.
 
101
_bzr_log_start_time = bzrlib._start_time
 
102
 
 
103
 
 
104
# held in a global for quick reference
82
105
_bzr_logger = logging.getLogger('bzr')
83
106
 
 
107
 
84
108
def note(*args, **kwargs):
85
 
    # FIXME note always emits utf-8, regardless of the terminal encoding
86
 
    import bzrlib.ui
87
 
    bzrlib.ui.ui_factory.clear_term()
 
109
    """Output a note to the user.
 
110
 
 
111
    Takes the same parameters as logging.info.
 
112
 
 
113
    :return: None
 
114
    """
 
115
    # FIXME: clearing the ui and then going through the abstract logging
 
116
    # framework is whack; we should probably have a logging Handler that
 
117
    # deals with terminal output if needed.
 
118
    ui.ui_factory.clear_term()
88
119
    _bzr_logger.info(*args, **kwargs)
89
120
 
 
121
 
90
122
def warning(*args, **kwargs):
91
 
    import bzrlib.ui
92
 
    bzrlib.ui.ui_factory.clear_term()
 
123
    ui.ui_factory.clear_term()
93
124
    _bzr_logger.warning(*args, **kwargs)
94
125
 
95
 
info = note
96
 
log_error = _bzr_logger.error
97
 
error =     _bzr_logger.error
 
126
 
 
127
def show_error(*args, **kwargs):
 
128
    """Show an error message to the user.
 
129
 
 
130
    Don't use this for exceptions, use report_exception instead.
 
131
    """
 
132
    _bzr_logger.error(*args, **kwargs)
98
133
 
99
134
 
100
135
def mutter(fmt, *args):
101
136
    if _trace_file is None:
102
137
        return
 
138
    # XXX: Don't check this every time; instead anyone who closes the file
 
139
    # ought to deregister it.  We can tolerate None.
103
140
    if (getattr(_trace_file, 'closed', None) is not None) and _trace_file.closed:
104
141
        return
105
142
 
118
155
        out = fmt % tuple(real_args)
119
156
    else:
120
157
        out = fmt
121
 
    out += '\n'
 
158
    now = time.time()
 
159
    timestamp = '%0.3f  ' % (now - _bzr_log_start_time,)
 
160
    out = timestamp + out + '\n'
122
161
    _trace_file.write(out)
123
 
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
124
 
    #_trace_file.flush()
 
162
    # there's no explicit flushing; the file is typically line buffered.
125
163
 
126
164
 
127
165
def mutter_callsite(stacklevel, fmt, *args):
133
171
    :param args: A list of substitution variables.
134
172
    """
135
173
    outf = StringIO()
136
 
    traceback.print_stack(limit=stacklevel + 1, file=outf)
 
174
    if stacklevel is None:
 
175
        limit = None
 
176
    else:
 
177
        limit = stacklevel + 1
 
178
    traceback.print_stack(limit=limit, file=outf)
137
179
    formatted_lines = outf.getvalue().splitlines()
138
180
    formatted_stack = '\n'.join(formatted_lines[:-2])
139
181
    mutter(fmt + "\nCalled from:\n%s", *(args + (formatted_stack,)))
146
188
        if size <= 4 << 20:
147
189
            return
148
190
        old_fname = trace_fname + '.old'
149
 
        from osutils import rename
150
 
        rename(trace_fname, old_fname)
 
191
        osutils.rename(trace_fname, old_fname)
151
192
    except OSError:
152
193
        return
153
194
 
154
195
 
155
 
def open_tracefile(tracefilename=None):
156
 
    # Messages are always written to here, so that we have some
157
 
    # information if something goes wrong.  In a future version this
158
 
    # file will be removed on successful completion.
159
 
    global _file_handler, _bzr_log_file, _bzr_log_filename
160
 
    import codecs
161
 
 
162
 
    if tracefilename is None:
 
196
def _get_bzr_log_filename():
 
197
    bzr_log = os.environ.get('BZR_LOG')
 
198
    if bzr_log:
 
199
        return bzr_log
 
200
    home = os.environ.get('BZR_HOME')
 
201
    if home is None:
163
202
        if sys.platform == 'win32':
164
203
            from bzrlib import win32utils
165
204
            home = win32utils.get_home_location()
166
205
        else:
167
206
            home = os.path.expanduser('~')
168
 
        _bzr_log_filename = os.path.join(home, '.bzr.log')
169
 
    else:
170
 
        _bzr_log_filename = tracefilename
171
 
 
172
 
    _bzr_log_filename = os.path.expanduser(_bzr_log_filename)
 
207
    return os.path.join(home, '.bzr.log')
 
208
 
 
209
 
 
210
def _open_bzr_log():
 
211
    """Open the .bzr.log trace file.
 
212
 
 
213
    If the log is more than a particular length, the old file is renamed to
 
214
    .bzr.log.old and a new file is started.  Otherwise, we append to the
 
215
    existing file.
 
216
 
 
217
    This sets the global _bzr_log_filename.
 
218
    """
 
219
    global _bzr_log_filename
 
220
 
 
221
    def _open_or_create_log_file(filename):
 
222
        """Open existing log file, or create with ownership and permissions
 
223
 
 
224
        It inherits the ownership and permissions (masked by umask) from
 
225
        the containing directory to cope better with being run under sudo
 
226
        with $HOME still set to the user's homedir.
 
227
        """
 
228
        flags = os.O_WRONLY | os.O_APPEND | osutils.O_TEXT
 
229
        while True:
 
230
            try:
 
231
                fd = os.open(filename, flags)
 
232
                break
 
233
            except OSError, e:
 
234
                if e.errno != errno.ENOENT:
 
235
                    raise
 
236
            try:
 
237
                fd = os.open(filename, flags | os.O_CREAT | os.O_EXCL, 0666)
 
238
            except OSError, e:
 
239
                if e.errno != errno.EEXIST:
 
240
                    raise
 
241
            else:
 
242
                osutils.copy_ownership_from_path(filename)
 
243
                break
 
244
        return os.fdopen(fd, 'at', 0) # unbuffered
 
245
 
 
246
 
 
247
    _bzr_log_filename = _get_bzr_log_filename()
173
248
    _rollover_trace_maybe(_bzr_log_filename)
174
249
    try:
175
 
        LINE_BUFFERED = 1
176
 
        #tf = codecs.open(trace_fname, 'at', 'utf8', buffering=LINE_BUFFERED)
177
 
        tf = open(_bzr_log_filename, 'at', LINE_BUFFERED)
178
 
        _bzr_log_file = tf
179
 
        # tf.tell() on windows always return 0 until some writing done
180
 
        tf.write('\n')
181
 
        if tf.tell() <= 2:
182
 
            tf.write("this is a debug log for diagnosing/reporting problems in bzr\n")
183
 
            tf.write("you can delete or truncate this file, or include sections in\n")
184
 
            tf.write("bug reports to bazaar@lists.canonical.com\n\n")
185
 
        _file_handler = logging.StreamHandler(tf)
186
 
        fmt = r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s'
187
 
        datefmt = r'%a %H:%M:%S'
188
 
        _file_handler.setFormatter(logging.Formatter(fmt, datefmt))
189
 
        _file_handler.setLevel(logging.DEBUG)
190
 
        logging.getLogger('').addHandler(_file_handler)
191
 
    except IOError, e:
192
 
        warning("failed to open trace file: %s" % (e))
 
250
        bzr_log_file = _open_or_create_log_file(_bzr_log_filename)
 
251
        bzr_log_file.write('\n')
 
252
        if bzr_log_file.tell() <= 2:
 
253
            bzr_log_file.write("this is a debug log for diagnosing/reporting problems in bzr\n")
 
254
            bzr_log_file.write("you can delete or truncate this file, or include sections in\n")
 
255
            bzr_log_file.write("bug reports to https://bugs.launchpad.net/bzr/+filebug\n\n")
 
256
 
 
257
        return bzr_log_file
 
258
 
 
259
    except EnvironmentError, e:
 
260
        # If we are failing to open the log, then most likely logging has not
 
261
        # been set up yet. So we just write to stderr rather than using
 
262
        # 'warning()'. If we using warning(), users get the unhelpful 'no
 
263
        # handlers registered for "bzr"' when something goes wrong on the
 
264
        # server. (bug #503886)
 
265
        sys.stderr.write("failed to open trace file: %s\n" % (e,))
 
266
    # TODO: What should happen if we fail to open the trace file?  Maybe the
 
267
    # objects should be pointed at /dev/null or the equivalent?  Currently
 
268
    # returns None which will cause failures later.
 
269
    return None
 
270
 
 
271
 
 
272
def enable_default_logging():
 
273
    """Configure default logging: messages to stderr and debug to .bzr.log
 
274
 
 
275
    This should only be called once per process.
 
276
 
 
277
    Non-command-line programs embedding bzrlib do not need to call this.  They
 
278
    can instead either pass a file to _push_log_file, or act directly on
 
279
    logging.getLogger("bzr").
 
280
 
 
281
    Output can be redirected away by calling _push_log_file.
 
282
 
 
283
    :return: A memento from push_log_file for restoring the log state.
 
284
    """
 
285
    start_time = osutils.format_local_date(_bzr_log_start_time,
 
286
                                           timezone='local')
 
287
    bzr_log_file = _open_bzr_log()
 
288
    if bzr_log_file is not None:
 
289
        bzr_log_file.write(start_time.encode('utf-8') + '\n')
 
290
    memento = push_log_file(bzr_log_file,
 
291
        r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s',
 
292
        r'%Y-%m-%d %H:%M:%S')
 
293
    # after hooking output into bzr_log, we also need to attach a stderr
 
294
    # handler, writing only at level info and with encoding
 
295
    stderr_handler = EncodedStreamHandler(sys.stderr,
 
296
        osutils.get_terminal_encoding(), 'replace', level=logging.INFO)
 
297
    logging.getLogger('bzr').addHandler(stderr_handler)
 
298
    return memento
 
299
 
 
300
 
 
301
def push_log_file(to_file, log_format=None, date_format=None):
 
302
    """Intercept log and trace messages and send them to a file.
 
303
 
 
304
    :param to_file: A file-like object to which messages will be sent.
 
305
 
 
306
    :returns: A memento that should be passed to _pop_log_file to restore the
 
307
        previously active logging.
 
308
    """
 
309
    global _trace_file
 
310
    # make a new handler
 
311
    new_handler = EncodedStreamHandler(to_file, "utf-8", level=logging.DEBUG)
 
312
    if log_format is None:
 
313
        log_format = '%(levelname)8s  %(message)s'
 
314
    new_handler.setFormatter(logging.Formatter(log_format, date_format))
 
315
    # save and remove any existing log handlers
 
316
    bzr_logger = logging.getLogger('bzr')
 
317
    old_handlers = bzr_logger.handlers[:]
 
318
    del bzr_logger.handlers[:]
 
319
    # set that as the default logger
 
320
    bzr_logger.addHandler(new_handler)
 
321
    bzr_logger.setLevel(logging.DEBUG)
 
322
    # TODO: check if any changes are needed to the root logger
 
323
    #
 
324
    # TODO: also probably need to save and restore the level on bzr_logger.
 
325
    # but maybe we can avoid setting the logger level altogether, and just set
 
326
    # the level on the handler?
 
327
    #
 
328
    # save the old trace file
 
329
    old_trace_file = _trace_file
 
330
    # send traces to the new one
 
331
    _trace_file = to_file
 
332
    result = new_handler, _trace_file
 
333
    return ('log_memento', old_handlers, new_handler, old_trace_file, to_file)
 
334
 
 
335
 
 
336
def pop_log_file((magic, old_handlers, new_handler, old_trace_file, new_trace_file)):
 
337
    """Undo changes to logging/tracing done by _push_log_file.
 
338
 
 
339
    This flushes, but does not close the trace file (so that anything that was
 
340
    in it is output.
 
341
 
 
342
    Takes the memento returned from _push_log_file."""
 
343
    global _trace_file
 
344
    _trace_file = old_trace_file
 
345
    bzr_logger = logging.getLogger('bzr')
 
346
    bzr_logger.removeHandler(new_handler)
 
347
    # must be closed, otherwise logging will try to close it at exit, and the
 
348
    # file will likely already be closed underneath.
 
349
    new_handler.close()
 
350
    bzr_logger.handlers = old_handlers
 
351
    if new_trace_file is not None:
 
352
        new_trace_file.flush()
193
353
 
194
354
 
195
355
def log_exception_quietly():
196
356
    """Log the last exception to the trace file only.
197
357
 
198
 
    Used for exceptions that occur internally and that may be 
199
 
    interesting to developers but not to users.  For example, 
 
358
    Used for exceptions that occur internally and that may be
 
359
    interesting to developers but not to users.  For example,
200
360
    errors loading plugins.
201
361
    """
202
 
    import traceback
203
362
    mutter(traceback.format_exc())
204
363
 
205
364
 
206
 
def enable_default_logging():
207
 
    """Configure default logging to stderr and .bzr.log"""
208
 
    # FIXME: if this is run twice, things get confused
209
 
    global _stderr_handler, _file_handler, _trace_file, _bzr_log_file
210
 
    _stderr_handler = logging.StreamHandler()
211
 
    logging.getLogger('').addHandler(_stderr_handler)
212
 
    _stderr_handler.setLevel(logging.INFO)
213
 
    if not _file_handler:
214
 
        open_tracefile()
215
 
    _trace_file = _bzr_log_file
216
 
    if _file_handler:
217
 
        _file_handler.setLevel(logging.DEBUG)
218
 
    _bzr_logger.setLevel(logging.DEBUG)
 
365
def set_verbosity_level(level):
 
366
    """Set the verbosity level.
 
367
 
 
368
    :param level: -ve for quiet, 0 for normal, +ve for verbose
 
369
    """
 
370
    global _verbosity_level
 
371
    _verbosity_level = level
 
372
    _update_logging_level(level < 0)
 
373
    ui.ui_factory.be_quiet(level < 0)
 
374
 
 
375
 
 
376
def get_verbosity_level():
 
377
    """Get the verbosity level.
 
378
 
 
379
    See set_verbosity_level() for values.
 
380
    """
 
381
    return _verbosity_level
219
382
 
220
383
 
221
384
def be_quiet(quiet=True):
222
 
    global _stderr_handler, _stderr_quiet
223
 
    
224
 
    _stderr_quiet = quiet
225
 
    if quiet:
226
 
        _stderr_handler.setLevel(logging.WARNING)
227
 
    else:
228
 
        _stderr_handler.setLevel(logging.INFO)
 
385
    if quiet:
 
386
        set_verbosity_level(-1)
 
387
    else:
 
388
        set_verbosity_level(0)
 
389
 
 
390
 
 
391
def _update_logging_level(quiet=True):
 
392
    """Hide INFO messages if quiet."""
 
393
    if quiet:
 
394
        _bzr_logger.setLevel(logging.WARNING)
 
395
    else:
 
396
        _bzr_logger.setLevel(logging.INFO)
229
397
 
230
398
 
231
399
def is_quiet():
232
 
    global _stderr_quiet
233
 
    return _stderr_quiet
234
 
 
235
 
 
236
 
def disable_default_logging():
237
 
    """Turn off default log handlers.
238
 
 
239
 
    This is intended to be used by the test framework, which doesn't
240
 
    want leakage from the code-under-test into the main logs.
241
 
    """
242
 
 
243
 
    l = logging.getLogger('')
244
 
    l.removeHandler(_stderr_handler)
245
 
    if _file_handler:
246
 
        l.removeHandler(_file_handler)
247
 
    _trace_file = None
248
 
 
249
 
 
250
 
def enable_test_log(to_file):
251
 
    """Redirect logging to a temporary file for a test
252
 
    
253
 
    returns an opaque reference that should be passed to disable_test_log
254
 
    after the test completes.
255
 
    """
256
 
    disable_default_logging()
257
 
    global _trace_file
258
 
    global _trace_depth
259
 
    hdlr = logging.StreamHandler(to_file)
260
 
    hdlr.setLevel(logging.DEBUG)
261
 
    hdlr.setFormatter(logging.Formatter('%(levelname)8s  %(message)s'))
262
 
    _bzr_logger.addHandler(hdlr)
263
 
    _bzr_logger.setLevel(logging.DEBUG)
264
 
    result = hdlr, _trace_file, _trace_depth
265
 
    _trace_file = to_file
266
 
    _trace_depth += 1
267
 
    return result
268
 
 
269
 
 
270
 
def disable_test_log((test_log_hdlr, old_trace_file, old_trace_depth)):
271
 
    _bzr_logger.removeHandler(test_log_hdlr)
272
 
    test_log_hdlr.close()
273
 
    global _trace_file
274
 
    global _trace_depth
275
 
    _trace_file = old_trace_file
276
 
    _trace_depth = old_trace_depth
277
 
    if not _trace_depth:
278
 
        enable_default_logging()
 
400
    """Is the verbosity level negative?"""
 
401
    return _verbosity_level < 0
 
402
 
 
403
 
 
404
def is_verbose():
 
405
    """Is the verbosity level positive?"""
 
406
    return _verbosity_level > 0
 
407
 
 
408
 
 
409
def debug_memory(message='', short=True):
 
410
    """Write out a memory dump."""
 
411
    if sys.platform == 'win32':
 
412
        from bzrlib import win32utils
 
413
        win32utils.debug_memory_win32api(message=message, short=short)
 
414
    else:
 
415
        _debug_memory_proc(message=message, short=short)
 
416
 
 
417
 
 
418
_short_fields = ('VmPeak', 'VmSize', 'VmRSS')
 
419
 
 
420
def _debug_memory_proc(message='', short=True):
 
421
    try:
 
422
        status_file = file('/proc/%s/status' % os.getpid(), 'rb')
 
423
    except IOError:
 
424
        return
 
425
    try:
 
426
        status = status_file.read()
 
427
    finally:
 
428
        status_file.close()
 
429
    if message:
 
430
        note(message)
 
431
    for line in status.splitlines():
 
432
        if not short:
 
433
            note(line)
 
434
        else:
 
435
            for field in _short_fields:
 
436
                if line.startswith(field):
 
437
                    note(line)
 
438
                    break
 
439
 
 
440
def _dump_memory_usage(err_file):
 
441
    try:
 
442
        try:
 
443
            fd, name = tempfile.mkstemp(prefix="bzr_memdump", suffix=".json")
 
444
            dump_file = os.fdopen(fd, 'w')
 
445
            from meliae import scanner
 
446
            scanner.dump_gc_objects(dump_file)
 
447
            err_file.write("Memory dumped to %s\n" % name)
 
448
        except ImportError:
 
449
            err_file.write("Dumping memory requires meliae module.\n")
 
450
            log_exception_quietly()
 
451
        except:
 
452
            err_file.write("Exception while dumping memory.\n")
 
453
            log_exception_quietly()
 
454
    finally:
 
455
        if dump_file is not None:
 
456
            dump_file.close()
 
457
        elif fd is not None:
 
458
            os.close(fd)
 
459
 
 
460
 
 
461
def _qualified_exception_name(eclass, unqualified_bzrlib_errors=False):
 
462
    """Give name of error class including module for non-builtin exceptions
 
463
 
 
464
    If `unqualified_bzrlib_errors` is True, errors specific to bzrlib will
 
465
    also omit the module prefix.
 
466
    """
 
467
    class_name = eclass.__name__
 
468
    module_name = eclass.__module__
 
469
    if module_name in ("exceptions", "__main__") or (
 
470
            unqualified_bzrlib_errors and module_name == "bzrlib.errors"):
 
471
        return class_name
 
472
    return "%s.%s" % (module_name, class_name)
279
473
 
280
474
 
281
475
def report_exception(exc_info, err_file):
282
 
    exc_type, exc_object, exc_tb = exc_info
 
476
    """Report an exception to err_file (typically stderr) and to .bzr.log.
 
477
 
 
478
    This will show either a full traceback or a short message as appropriate.
 
479
 
 
480
    :return: The appropriate exit code for this error.
 
481
    """
283
482
    # Log the full traceback to ~/.bzr.log
284
483
    log_exception_quietly()
285
 
    if (isinstance(exc_object, IOError)
286
 
        and getattr(exc_object, 'errno', None) == errno.EPIPE):
287
 
        print >>err_file, "bzr: broken pipe"
288
 
    elif isinstance(exc_object, KeyboardInterrupt):
289
 
        print >>err_file, "bzr: interrupted"
 
484
    if 'error' in debug.debug_flags:
 
485
        print_exception(exc_info, err_file)
 
486
        return errors.EXIT_ERROR
 
487
    exc_type, exc_object, exc_tb = exc_info
 
488
    if isinstance(exc_object, KeyboardInterrupt):
 
489
        err_file.write("bzr: interrupted\n")
 
490
        return errors.EXIT_ERROR
 
491
    elif isinstance(exc_object, MemoryError):
 
492
        err_file.write("bzr: out of memory\n")
 
493
        if 'mem_dump' in debug.debug_flags:
 
494
            _dump_memory_usage(err_file)
 
495
        else:
 
496
            err_file.write("Use -Dmem_dump to dump memory to a file.\n")
 
497
        return errors.EXIT_ERROR
 
498
    elif isinstance(exc_object, ImportError) \
 
499
        and str(exc_object).startswith("No module named "):
 
500
        report_user_error(exc_info, err_file,
 
501
            'You may need to install this Python library separately.')
 
502
        return errors.EXIT_ERROR
290
503
    elif not getattr(exc_object, 'internal_error', True):
291
504
        report_user_error(exc_info, err_file)
292
 
    elif isinstance(exc_object, (OSError, IOError)):
 
505
        return errors.EXIT_ERROR
 
506
    elif osutils.is_environment_error(exc_object):
 
507
        if getattr(exc_object, 'errno', None) == errno.EPIPE:
 
508
            err_file.write("bzr: broken pipe\n")
 
509
            return errors.EXIT_ERROR
293
510
        # Might be nice to catch all of these and show them as something more
294
511
        # specific, but there are too many cases at the moment.
295
512
        report_user_error(exc_info, err_file)
 
513
        return errors.EXIT_ERROR
296
514
    else:
297
515
        report_bug(exc_info, err_file)
 
516
        return errors.EXIT_INTERNAL_ERROR
 
517
 
 
518
 
 
519
def print_exception(exc_info, err_file):
 
520
    exc_type, exc_object, exc_tb = exc_info
 
521
    err_file.write("bzr: ERROR: %s.%s: %s\n" % (
 
522
        exc_type.__module__, exc_type.__name__, exc_object))
 
523
    err_file.write('\n')
 
524
    traceback.print_exception(exc_type, exc_object, exc_tb, file=err_file)
298
525
 
299
526
 
300
527
# TODO: Should these be specially encoding the output?
301
 
def report_user_error(exc_info, err_file):
 
528
def report_user_error(exc_info, err_file, advice=None):
302
529
    """Report to err_file an error that's not an internal error.
303
530
 
304
531
    These don't get a traceback unless -Derror was given.
 
532
 
 
533
    :param exc_info: 3-tuple from sys.exc_info()
 
534
    :param advice: Extra advice to the user to be printed following the
 
535
        exception.
305
536
    """
306
 
    if 'error' in debug.debug_flags:
307
 
        report_bug(exc_info, err_file)
308
 
        return
309
 
    print >>err_file, "bzr: ERROR:", str(exc_info[1])
 
537
    err_file.write("bzr: ERROR: %s\n" % (exc_info[1],))
 
538
    if advice:
 
539
        err_file.write("%s\n" % (advice,))
310
540
 
311
541
 
312
542
def report_bug(exc_info, err_file):
313
543
    """Report an exception that probably indicates a bug in bzr"""
314
 
    import traceback
315
 
    exc_type, exc_object, exc_tb = exc_info
316
 
    print >>err_file, "bzr: ERROR: %s.%s: %s" % (
317
 
        exc_type.__module__, exc_type.__name__, exc_object)
318
 
    print >>err_file
319
 
    traceback.print_exception(exc_type, exc_object, exc_tb, file=err_file)
320
 
    print >>err_file
321
 
    print >>err_file, 'bzr %s on python %s (%s)' % \
322
 
                       (bzrlib.__version__,
323
 
                        '.'.join(map(str, sys.version_info)),
324
 
                        sys.platform)
325
 
    print >>err_file, 'arguments: %r' % sys.argv
326
 
    print >>err_file
327
 
    print >>err_file, "** please send this report to bazaar@lists.ubuntu.com"
 
544
    from bzrlib.crash import report_bug
 
545
    report_bug(exc_info, err_file)
 
546
 
 
547
 
 
548
def _flush_stdout_stderr():
 
549
    # called from the bzrlib library finalizer returned by bzrlib.initialize()
 
550
    try:
 
551
        sys.stdout.flush()
 
552
        sys.stderr.flush()
 
553
    except ValueError, e:
 
554
        # On Windows, I get ValueError calling stdout.flush() on a closed
 
555
        # handle
 
556
        pass
 
557
    except IOError, e:
 
558
        import errno
 
559
        if e.errno in [errno.EINVAL, errno.EPIPE]:
 
560
            pass
 
561
        else:
 
562
            raise
 
563
 
 
564
 
 
565
def _flush_trace():
 
566
    # called from the bzrlib library finalizer returned by bzrlib.initialize()
 
567
    global _trace_file
 
568
    if _trace_file:
 
569
        _trace_file.flush()
 
570
 
 
571
 
 
572
class EncodedStreamHandler(logging.Handler):
 
573
    """Robustly write logging events to a stream using the specified encoding
 
574
 
 
575
    Messages are expected to be formatted to unicode, but UTF-8 byte strings
 
576
    are also accepted. An error during formatting or a str message in another
 
577
    encoding will be quitely noted as an error in the Bazaar log file.
 
578
 
 
579
    The stream is not closed so sys.stdout or sys.stderr may be passed.
 
580
    """
 
581
 
 
582
    def __init__(self, stream, encoding=None, errors='strict', level=0):
 
583
        logging.Handler.__init__(self, level)
 
584
        self.stream = stream
 
585
        if encoding is None:
 
586
            encoding = getattr(stream, "encoding", "ascii")
 
587
        self.encoding = encoding
 
588
        self.errors = errors
 
589
 
 
590
    def flush(self):
 
591
        flush = getattr(self.stream, "flush", None)
 
592
        if flush is not None:
 
593
            flush()
 
594
 
 
595
    def emit(self, record):
 
596
        try:
 
597
            line = self.format(record)
 
598
            if not isinstance(line, unicode):
 
599
                line = line.decode("utf-8")
 
600
            self.stream.write(line.encode(self.encoding, self.errors) + "\n")
 
601
        except Exception:
 
602
            log_exception_quietly()
 
603
            # Try saving the details that would have been logged in some form
 
604
            msg = args = "<Unformattable>"
 
605
            try:
 
606
                msg = repr(record.msg).encode("ascii")
 
607
                args = repr(record.args).encode("ascii")
 
608
            except Exception:
 
609
                pass
 
610
            # Using mutter() bypasses the logging module and writes directly
 
611
            # to the file so there's no danger of getting into a loop here.
 
612
            mutter("Logging record unformattable: %s %% %s", msg, args)
 
613
 
 
614
 
 
615
class Config(object):
 
616
    """Configuration of message tracing in bzrlib.
 
617
 
 
618
    This implements the context manager protocol and should manage any global
 
619
    variables still used. The default config used is DefaultConfig, but
 
620
    embedded uses of bzrlib may wish to use a custom manager.
 
621
    """
 
622
 
 
623
    def __enter__(self):
 
624
        return self # This is bound to the 'as' clause in a with statement.
 
625
 
 
626
    def __exit__(self, exc_type, exc_val, exc_tb):
 
627
        return False # propogate exceptions.
 
628
 
 
629
 
 
630
class DefaultConfig(Config):
 
631
    """A default configuration for tracing of messages in bzrlib.
 
632
 
 
633
    This implements the context manager protocol.
 
634
    """
 
635
 
 
636
    def __enter__(self):
 
637
        self._original_filename = _bzr_log_filename
 
638
        self._original_state = enable_default_logging()
 
639
        return self # This is bound to the 'as' clause in a with statement.
 
640
 
 
641
    def __exit__(self, exc_type, exc_val, exc_tb):
 
642
        pop_log_file(self._original_state)
 
643
        global _bzr_log_filename
 
644
        _bzr_log_filename = self._original_filename
 
645
        return False # propogate exceptions.