/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: Andrew Bennetts
  • Date: 2008-03-27 06:10:18 UTC
  • mfrom: (3309 +trunk)
  • mto: This revision was merged to the branch mainline in revision 3320.
  • Revision ID: andrew.bennetts@canonical.com-20080327061018-dxztpxyv6yoeg3am
Merge from bzr.dev.

Show diffs side-by-side

added added

removed removed

Lines of Context:
1
 
# Copyright (C) 2005, 2006, 2007 Canonical Ltd
 
1
# Copyright (C) 2005, 2006, 2007, 2008 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
49
49
# FIXME: Unfortunately it turns out that python's logging module
50
50
# is quite expensive, even when the message is not printed by any handlers.
51
51
# We should perhaps change back to just simply doing it here.
 
52
#
 
53
# On the other hand, as of 1.2 we generally only call the mutter() statement
 
54
# if (according to debug_flags) we actually intend to write it.  So the
 
55
# increased cost of logging.py is not so bad, and we could standardize on
 
56
# that.
52
57
 
53
58
import codecs
54
59
import logging
73
78
    errors,
74
79
    osutils,
75
80
    plugin,
 
81
    symbol_versioning,
76
82
    )
77
83
""")
78
84
 
79
 
_file_handler = None
80
 
_stderr_handler = None
 
85
 
 
86
# global verbosity for bzrlib; controls the log level for stderr; 0=normal; <0
 
87
# is quiet; >0 is verbose.
81
88
_verbosity_level = 0
 
89
 
 
90
# File-like object where mutter/debug output is currently sent.  Can be
 
91
# changed by _push_log_file etc.  This is directly manipulated by some
 
92
# external code; maybe there should be functions to do that more precisely
 
93
# than push/pop_log_file.
82
94
_trace_file = None
83
 
_trace_depth = 0
84
 
_bzr_log_file = None
 
95
 
 
96
# Absolute path for ~/.bzr.log.  Not changed even if the log/trace output is
 
97
# redirected elsewhere.  Used to show the location in --version.
85
98
_bzr_log_filename = None
86
 
_bzr_log_opened = None
87
 
 
88
 
 
89
 
# configure convenient aliases for output routines
90
 
 
 
99
 
 
100
# The time the first message was written to the trace file, so that we can
 
101
# show relative times since startup.
 
102
_bzr_log_start_time = bzrlib._start_time
 
103
 
 
104
 
 
105
# held in a global for quick reference
91
106
_bzr_logger = logging.getLogger('bzr')
92
107
 
93
108
 
94
109
def note(*args, **kwargs):
95
110
    # FIXME note always emits utf-8, regardless of the terminal encoding
 
111
    #
 
112
    # FIXME: clearing the ui and then going through the abstract logging
 
113
    # framework is whack; we should probably have a logging Handler that
 
114
    # deals with terminal output if needed.
96
115
    import bzrlib.ui
97
116
    bzrlib.ui.ui_factory.clear_term()
98
117
    _bzr_logger.info(*args, **kwargs)
99
118
 
 
119
 
100
120
def warning(*args, **kwargs):
101
121
    import bzrlib.ui
102
122
    bzrlib.ui.ui_factory.clear_term()
103
123
    _bzr_logger.warning(*args, **kwargs)
104
124
 
 
125
 
 
126
# configure convenient aliases for output routines
 
127
#
 
128
# TODO: deprecate them, have one name for each.
105
129
info = note
106
130
log_error = _bzr_logger.error
107
131
error =     _bzr_logger.error
128
152
        out = fmt % tuple(real_args)
129
153
    else:
130
154
        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)
 
155
    timestamp = '%0.3f  ' % (time.time() - _bzr_log_start_time,)
 
156
    out = timestamp + out + '\n'
140
157
    _trace_file.write(out)
141
 
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
142
 
    #_trace_file.flush()
 
158
    # no need to flush here, the trace file is now linebuffered when it's
 
159
    # opened.
143
160
 
144
161
 
145
162
def mutter_callsite(stacklevel, fmt, *args):
169
186
        return
170
187
 
171
188
 
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:
 
189
def _get_bzr_log_filename():
 
190
    bzr_log = os.environ.get('BZR_LOG')
 
191
    if bzr_log:
 
192
        return bzr_log
 
193
    home = os.environ.get('BZR_HOME')
 
194
    if home is None:
180
195
        if sys.platform == 'win32':
181
196
            from bzrlib import win32utils
182
197
            home = win32utils.get_home_location()
183
198
        else:
184
199
            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)
 
200
    return os.path.join(home, '.bzr.log')
 
201
 
 
202
 
 
203
def _open_bzr_log():
 
204
    """Open the .bzr.log trace file.  
 
205
 
 
206
    If the log is more than a particular length, the old file is renamed to
 
207
    .bzr.log.old and a new file is started.  Otherwise, we append to the
 
208
    existing file.
 
209
 
 
210
    This sets the global _bzr_log_filename.
 
211
    """
 
212
    global _bzr_log_filename
 
213
    _bzr_log_filename = _get_bzr_log_filename()
190
214
    _rollover_trace_maybe(_bzr_log_filename)
191
215
    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)
 
216
        bzr_log_file = open(_bzr_log_filename, 'at', 1) # line buffered
 
217
        # bzr_log_file.tell() on windows always return 0 until some writing done
 
218
        bzr_log_file.write('\n')
 
219
        if bzr_log_file.tell() <= 2:
 
220
            bzr_log_file.write("this is a debug log for diagnosing/reporting problems in bzr\n")
 
221
            bzr_log_file.write("you can delete or truncate this file, or include sections in\n")
 
222
            bzr_log_file.write("bug reports to https://bugs.launchpad.net/bzr/+filebug\n\n")
 
223
        return bzr_log_file
208
224
    except IOError, e:
209
225
        warning("failed to open trace file: %s" % (e))
 
226
    # TODO: What should happen if we fail to open the trace file?  Maybe the
 
227
    # objects should be pointed at /dev/null or the equivalent?  Currently
 
228
    # returns None which will cause failures later.
 
229
 
 
230
 
 
231
def enable_default_logging():
 
232
    """Configure default logging: messages to stderr and debug to .bzr.log
 
233
    
 
234
    This should only be called once per process.
 
235
 
 
236
    Non-command-line programs embedding bzrlib do not need to call this.  They
 
237
    can instead either pass a file to _push_log_file, or act directly on
 
238
    logging.getLogger("bzr").
 
239
    
 
240
    Output can be redirected away by calling _push_log_file.
 
241
    """
 
242
    # create encoded wrapper around stderr
 
243
    bzr_log_file = _open_bzr_log()
 
244
    push_log_file(bzr_log_file,
 
245
        r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s',
 
246
        r'%Y-%m-%d %H:%M:%S')
 
247
    # after hooking output into bzr_log, we also need to attach a stderr
 
248
    # handler, writing only at level info and with encoding
 
249
    writer_factory = codecs.getwriter(osutils.get_terminal_encoding())
 
250
    encoded_stderr = writer_factory(sys.stderr, errors='replace')
 
251
    stderr_handler = logging.StreamHandler(encoded_stderr)
 
252
    stderr_handler.setLevel(logging.INFO)
 
253
    logging.getLogger('bzr').addHandler(stderr_handler)
 
254
 
 
255
 
 
256
def push_log_file(to_file, log_format=None, date_format=None):
 
257
    """Intercept log and trace messages and send them to a file.
 
258
 
 
259
    :param to_file: A file-like object to which messages will be sent.
 
260
 
 
261
    :returns: A memento that should be passed to _pop_log_file to restore the 
 
262
    previously active logging.
 
263
    """
 
264
    global _trace_file
 
265
    # make a new handler
 
266
    new_handler = logging.StreamHandler(to_file)
 
267
    new_handler.setLevel(logging.DEBUG)
 
268
    if log_format is None:
 
269
        log_format = '%(levelname)8s  %(message)s'
 
270
    new_handler.setFormatter(logging.Formatter(log_format, date_format))
 
271
    # save and remove any existing log handlers
 
272
    bzr_logger = logging.getLogger('bzr')
 
273
    old_handlers = bzr_logger.handlers[:]
 
274
    del bzr_logger.handlers[:]
 
275
    # set that as the default logger
 
276
    bzr_logger.addHandler(new_handler)
 
277
    bzr_logger.setLevel(logging.DEBUG)
 
278
    # TODO: check if any changes are needed to the root logger
 
279
    #
 
280
    # TODO: also probably need to save and restore the level on bzr_logger.
 
281
    # but maybe we can avoid setting the logger level altogether, and just set
 
282
    # the level on the handler?
 
283
    #
 
284
    # save the old trace file
 
285
    old_trace_file = _trace_file
 
286
    # send traces to the new one
 
287
    _trace_file = to_file
 
288
    result = new_handler, _trace_file
 
289
    return ('log_memento', old_handlers, new_handler, old_trace_file, to_file)
 
290
 
 
291
 
 
292
def pop_log_file((magic, old_handlers, new_handler, old_trace_file, new_trace_file)):
 
293
    """Undo changes to logging/tracing done by _push_log_file.
 
294
 
 
295
    This flushes, but does not close the trace file.
 
296
    
 
297
    Takes the memento returned from _push_log_file."""
 
298
    assert magic == 'log_memento'
 
299
    global _trace_file
 
300
    _trace_file = old_trace_file
 
301
    bzr_logger = logging.getLogger('bzr')
 
302
    bzr_logger.removeHandler(new_handler)
 
303
    # must be closed, otherwise logging will try to close it atexit, and the
 
304
    # file will likely already be closed underneath.
 
305
    new_handler.close()
 
306
    bzr_logger.handlers = old_handlers
 
307
    new_trace_file.flush()
 
308
 
 
309
 
 
310
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
 
311
def enable_test_log(to_file):
 
312
    """Redirect logging to a temporary file for a test
 
313
    
 
314
    :returns: an opaque reference that should be passed to disable_test_log
 
315
    after the test completes.
 
316
    """
 
317
    return push_log_file(to_file)
 
318
 
 
319
 
 
320
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
 
321
def disable_test_log(memento):
 
322
    return pop_log_file(memento)
210
323
 
211
324
 
212
325
def log_exception_quietly():
216
329
    interesting to developers but not to users.  For example, 
217
330
    errors loading plugins.
218
331
    """
219
 
    import traceback
220
332
    mutter(traceback.format_exc())
221
333
 
222
334
 
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
335
def set_verbosity_level(level):
242
336
    """Set the verbosity level.
243
337
 
267
361
def _update_logging_level(quiet=True):
268
362
    """Hide INFO messages if quiet."""
269
363
    if quiet:
270
 
        _stderr_handler.setLevel(logging.WARNING)
 
364
        _bzr_logger.setLevel(logging.WARNING)
271
365
    else:
272
 
        _stderr_handler.setLevel(logging.INFO)
 
366
        _bzr_logger.setLevel(logging.INFO)
273
367
 
274
368
 
275
369
def is_quiet():
282
376
    return _verbosity_level > 0
283
377
 
284
378
 
 
379
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
285
380
def disable_default_logging():
286
381
    """Turn off default log handlers.
287
382
 
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()
 
383
    Don't call this method, use _push_log_file and _pop_log_file instead.
 
384
    """
 
385
    pass
328
386
 
329
387
 
330
388
def report_exception(exc_info, err_file):
371
429
 
372
430
def report_bug(exc_info, err_file):
373
431
    """Report an exception that probably indicates a bug in bzr"""
374
 
    import traceback
375
432
    exc_type, exc_object, exc_tb = exc_info
376
433
    err_file.write("bzr: ERROR: %s.%s: %s\n" % (
377
434
        exc_type.__module__, exc_type.__name__, exc_object))
380
437
    err_file.write('\n')
381
438
    err_file.write('bzr %s on python %s (%s)\n' % \
382
439
                       (bzrlib.__version__,
383
 
                        '.'.join(map(str, sys.version_info)),
 
440
                        bzrlib._format_version_tuple(sys.version_info),
384
441
                        sys.platform))
385
442
    err_file.write('arguments: %r\n' % sys.argv)
386
443
    err_file.write(