/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: Alexander Belchenko
  • Date: 2008-02-20 10:36:15 UTC
  • mfrom: (3228 +trunk)
  • mto: This revision was merged to the branch mainline in revision 3231.
  • Revision ID: bialix@ukr.net-20080220103615-uxw9jc9m6l63ea27
merge bzr.dev; update patch for 1.3

Show diffs side-by-side

added added

removed removed

Lines of Context:
bzrlib/trace.py
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
 
_start_time = bzrlib._start_time
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
 
    timestamp = '%0.3f  ' % (time.time() - _start_time,)
 
155
    timestamp = '%0.3f  ' % (time.time() - _bzr_log_start_time,)
132
156
    out = timestamp + out + '\n'
133
157
    _trace_file.write(out)
134
 
    # TODO: jam 20051227 Consider flushing the trace file to help debugging
135
 
    #_trace_file.flush()
 
158
    # no need to flush here, the trace file is now linebuffered when it's
 
159
    # opened.
136
160
 
137
161
 
138
162
def mutter_callsite(stacklevel, fmt, *args):
162
186
        return
163
187
 
164
188
 
165
 
def open_tracefile(tracefilename=None):
166
 
    # Messages are always written to here, so that we have some
167
 
    # information if something goes wrong.  In a future version this
168
 
    # file will be removed on successful completion.
169
 
    global _file_handler, _bzr_log_file, _bzr_log_filename
170
 
    import codecs
171
 
 
172
 
    if tracefilename is None:
173
 
        if sys.platform == 'win32':
174
 
            from bzrlib import win32utils
175
 
            home = win32utils.get_home_location()
176
 
        else:
177
 
            home = os.path.expanduser('~')
178
 
        _bzr_log_filename = os.path.join(home, '.bzr.log')
 
189
def _get_bzr_log_filename():
 
190
    # TODO: should this be overridden by $BZR_HOME?
 
191
    if sys.platform == 'win32':
 
192
        from bzrlib import win32utils
 
193
        home = win32utils.get_home_location()
179
194
    else:
180
 
        _bzr_log_filename = tracefilename
181
 
 
182
 
    _bzr_log_filename = os.path.expanduser(_bzr_log_filename)
 
195
        home = os.path.expanduser('~')
 
196
    return os.path.join(home, '.bzr.log')
 
197
 
 
198
 
 
199
def _open_bzr_log():
 
200
    """Open the .bzr.log trace file.  
 
201
 
 
202
    If the log is more than a particular length, the old file is renamed to
 
203
    .bzr.log.old and a new file is started.  Otherwise, we append to the
 
204
    existing file.
 
205
 
 
206
    This sets the global _bzr_log_filename.
 
207
    """
 
208
    global _bzr_log_filename
 
209
    _bzr_log_filename = _get_bzr_log_filename()
183
210
    _rollover_trace_maybe(_bzr_log_filename)
184
211
    try:
185
 
        LINE_BUFFERED = 1
186
 
        #tf = codecs.open(trace_fname, 'at', 'utf8', buffering=LINE_BUFFERED)
187
 
        tf = open(_bzr_log_filename, 'at', LINE_BUFFERED)
188
 
        _bzr_log_file = tf
189
 
        # tf.tell() on windows always return 0 until some writing done
190
 
        tf.write('\n')
191
 
        if tf.tell() <= 2:
192
 
            tf.write("this is a debug log for diagnosing/reporting problems in bzr\n")
193
 
            tf.write("you can delete or truncate this file, or include sections in\n")
194
 
            tf.write("bug reports to https://bugs.launchpad.net/bzr/+filebug\n\n")
195
 
        _file_handler = logging.StreamHandler(tf)
196
 
        fmt = r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s'
197
 
        datefmt = r'%Y-%m-%d %H:%M:%S'
198
 
        _file_handler.setFormatter(logging.Formatter(fmt, datefmt))
199
 
        _file_handler.setLevel(logging.DEBUG)
200
 
        logging.getLogger('').addHandler(_file_handler)
 
212
        bzr_log_file = open(_bzr_log_filename, 'at', 1) # line buffered
 
213
        # bzr_log_file.tell() on windows always return 0 until some writing done
 
214
        bzr_log_file.write('\n')
 
215
        if bzr_log_file.tell() <= 2:
 
216
            bzr_log_file.write("this is a debug log for diagnosing/reporting problems in bzr\n")
 
217
            bzr_log_file.write("you can delete or truncate this file, or include sections in\n")
 
218
            bzr_log_file.write("bug reports to https://bugs.launchpad.net/bzr/+filebug\n\n")
 
219
        return bzr_log_file
201
220
    except IOError, e:
202
221
        warning("failed to open trace file: %s" % (e))
 
222
    # TODO: What should happen if we fail to open the trace file?  Maybe the
 
223
    # objects should be pointed at /dev/null or the equivalent?  Currently
 
224
    # returns None which will cause failures later.
 
225
 
 
226
 
 
227
def enable_default_logging():
 
228
    """Configure default logging: messages to stderr and debug to .bzr.log
 
229
    
 
230
    This should only be called once per process.
 
231
 
 
232
    Non-command-line programs embedding bzrlib do not need to call this.  They
 
233
    can instead either pass a file to _push_log_file, or act directly on
 
234
    logging.getLogger("bzr").
 
235
    
 
236
    Output can be redirected away by calling _push_log_file.
 
237
    """
 
238
    # create encoded wrapper around stderr
 
239
    bzr_log_file = _open_bzr_log()
 
240
    push_log_file(bzr_log_file,
 
241
        r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s',
 
242
        r'%Y-%m-%d %H:%M:%S')
 
243
    # after hooking output into bzr_log, we also need to attach a stderr
 
244
    # handler, writing only at level info and with encoding
 
245
    writer_factory = codecs.getwriter(osutils.get_terminal_encoding())
 
246
    encoded_stderr = writer_factory(sys.stderr, errors='replace')
 
247
    stderr_handler = logging.StreamHandler(encoded_stderr)
 
248
    stderr_handler.setLevel(logging.INFO)
 
249
    logging.getLogger('bzr').addHandler(stderr_handler)
 
250
 
 
251
 
 
252
def push_log_file(to_file, log_format=None, date_format=None):
 
253
    """Intercept log and trace messages and send them to a file.
 
254
 
 
255
    :param to_file: A file-like object to which messages will be sent.
 
256
 
 
257
    :returns: A memento that should be passed to _pop_log_file to restore the 
 
258
    previously active logging.
 
259
    """
 
260
    global _trace_file
 
261
    # make a new handler
 
262
    new_handler = logging.StreamHandler(to_file)
 
263
    new_handler.setLevel(logging.DEBUG)
 
264
    if log_format is None:
 
265
        log_format = '%(levelname)8s  %(message)s'
 
266
    new_handler.setFormatter(logging.Formatter(log_format, date_format))
 
267
    # save and remove any existing log handlers
 
268
    bzr_logger = logging.getLogger('bzr')
 
269
    old_handlers = bzr_logger.handlers[:]
 
270
    del bzr_logger.handlers[:]
 
271
    # set that as the default logger
 
272
    bzr_logger.addHandler(new_handler)
 
273
    bzr_logger.setLevel(logging.DEBUG)
 
274
    # TODO: check if any changes are needed to the root logger
 
275
    #
 
276
    # TODO: also probably need to save and restore the level on bzr_logger.
 
277
    # but maybe we can avoid setting the logger level altogether, and just set
 
278
    # the level on the handler?
 
279
    #
 
280
    # save the old trace file
 
281
    old_trace_file = _trace_file
 
282
    # send traces to the new one
 
283
    _trace_file = to_file
 
284
    result = new_handler, _trace_file
 
285
    return ('log_memento', old_handlers, new_handler, old_trace_file, to_file)
 
286
 
 
287
 
 
288
def pop_log_file((magic, old_handlers, new_handler, old_trace_file, new_trace_file)):
 
289
    """Undo changes to logging/tracing done by _push_log_file.
 
290
 
 
291
    This flushes, but does not close the trace file.
 
292
    
 
293
    Takes the memento returned from _push_log_file."""
 
294
    assert magic == 'log_memento'
 
295
    global _trace_file
 
296
    _trace_file = old_trace_file
 
297
    bzr_logger = logging.getLogger('bzr')
 
298
    bzr_logger.removeHandler(new_handler)
 
299
    # must be closed, otherwise logging will try to close it atexit, and the
 
300
    # file will likely already be closed underneath.
 
301
    new_handler.close()
 
302
    bzr_logger.handlers = old_handlers
 
303
    new_trace_file.flush()
 
304
 
 
305
 
 
306
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
 
307
def enable_test_log(to_file):
 
308
    """Redirect logging to a temporary file for a test
 
309
    
 
310
    :returns: an opaque reference that should be passed to disable_test_log
 
311
    after the test completes.
 
312
    """
 
313
    return push_log_file(to_file)
 
314
 
 
315
 
 
316
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
 
317
def disable_test_log(memento):
 
318
    return pop_log_file(memento)
203
319
 
204
320
 
205
321
def log_exception_quietly():
209
325
    interesting to developers but not to users.  For example, 
210
326
    errors loading plugins.
211
327
    """
212
 
    import traceback
213
328
    mutter(traceback.format_exc())
214
329
 
215
330
 
216
 
def enable_default_logging():
217
 
    """Configure default logging to stderr and .bzr.log"""
218
 
    # FIXME: if this is run twice, things get confused
219
 
    global _stderr_handler, _file_handler, _trace_file, _bzr_log_file
220
 
    # create encoded wrapper around stderr
221
 
    stderr = codecs.getwriter(osutils.get_terminal_encoding())(sys.stderr,
222
 
        errors='replace')
223
 
    _stderr_handler = logging.StreamHandler(stderr)
224
 
    logging.getLogger('').addHandler(_stderr_handler)
225
 
    _stderr_handler.setLevel(logging.INFO)
226
 
    if not _file_handler:
227
 
        open_tracefile()
228
 
    _trace_file = _bzr_log_file
229
 
    if _file_handler:
230
 
        _file_handler.setLevel(logging.DEBUG)
231
 
    _bzr_logger.setLevel(logging.DEBUG)
232
 
 
233
 
 
234
331
def set_verbosity_level(level):
235
332
    """Set the verbosity level.
236
333
 
260
357
def _update_logging_level(quiet=True):
261
358
    """Hide INFO messages if quiet."""
262
359
    if quiet:
263
 
        _stderr_handler.setLevel(logging.WARNING)
 
360
        _bzr_logger.setLevel(logging.WARNING)
264
361
    else:
265
 
        _stderr_handler.setLevel(logging.INFO)
 
362
        _bzr_logger.setLevel(logging.INFO)
266
363
 
267
364
 
268
365
def is_quiet():
275
372
    return _verbosity_level > 0
276
373
 
277
374
 
 
375
@symbol_versioning.deprecated_function(symbol_versioning.one_two)
278
376
def disable_default_logging():
279
377
    """Turn off default log handlers.
280
378
 
281
 
    This is intended to be used by the test framework, which doesn't
282
 
    want leakage from the code-under-test into the main logs.
283
 
    """
284
 
 
285
 
    l = logging.getLogger('')
286
 
    l.removeHandler(_stderr_handler)
287
 
    if _file_handler:
288
 
        l.removeHandler(_file_handler)
289
 
    _trace_file = None
290
 
 
291
 
 
292
 
def enable_test_log(to_file):
293
 
    """Redirect logging to a temporary file for a test
294
 
    
295
 
    returns an opaque reference that should be passed to disable_test_log
296
 
    after the test completes.
297
 
    """
298
 
    disable_default_logging()
299
 
    global _trace_file
300
 
    global _trace_depth
301
 
    hdlr = logging.StreamHandler(to_file)
302
 
    hdlr.setLevel(logging.DEBUG)
303
 
    hdlr.setFormatter(logging.Formatter('%(levelname)8s  %(message)s'))
304
 
    _bzr_logger.addHandler(hdlr)
305
 
    _bzr_logger.setLevel(logging.DEBUG)
306
 
    result = hdlr, _trace_file, _trace_depth
307
 
    _trace_file = to_file
308
 
    _trace_depth += 1
309
 
    return result
310
 
 
311
 
 
312
 
def disable_test_log((test_log_hdlr, old_trace_file, old_trace_depth)):
313
 
    _bzr_logger.removeHandler(test_log_hdlr)
314
 
    test_log_hdlr.close()
315
 
    global _trace_file
316
 
    global _trace_depth
317
 
    _trace_file = old_trace_file
318
 
    _trace_depth = old_trace_depth
319
 
    if not _trace_depth:
320
 
        enable_default_logging()
 
379
    Don't call this method, use _push_log_file and _pop_log_file instead.
 
380
    """
 
381
    pass
321
382
 
322
383
 
323
384
def report_exception(exc_info, err_file):
364
425
 
365
426
def report_bug(exc_info, err_file):
366
427
    """Report an exception that probably indicates a bug in bzr"""
367
 
    import traceback
368
428
    exc_type, exc_object, exc_tb = exc_info
369
429
    err_file.write("bzr: ERROR: %s.%s: %s\n" % (
370
430
        exc_type.__module__, exc_type.__name__, exc_object))