/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 breezy/trace.py

  • Committer: Jelmer Vernooij
  • Date: 2017-07-23 22:06:41 UTC
  • mfrom: (6738 trunk)
  • mto: This revision was merged to the branch mainline in revision 6739.
  • Revision ID: jelmer@jelmer.uk-20170723220641-69eczax9bmv8d6kk
Merge trunk, address review comments.

Show diffs side-by-side

added added

removed removed

Lines of Context:
breezy/trace.py
23
23
Messages are classified by severity levels: critical, error, warning, info,
24
24
and debug.
25
25
 
26
 
They can be sent to two places: stderr, and `$XDG_CACHE_HOME/breezy/brz.log`.
27
 
For purposes such as running the test suite, they can also be redirected away
28
 
from both of those two places to another location.
 
26
They can be sent to two places: to stderr, and to ~/.brz.log.  For purposes
 
27
such as running the test suite, they can also be redirected away from both of
 
28
those two places to another location.
29
29
 
30
 
`brz.log` gets all messages, and full tracebacks for uncaught exceptions.
 
30
~/.brz.log gets all messages, and full tracebacks for uncaught exceptions.
31
31
This trace file is always in UTF-8, regardless of the user's default encoding,
32
32
so that we can always rely on writing any message.
33
33
 
45
45
form.
46
46
"""
47
47
 
 
48
from __future__ import absolute_import
 
49
 
48
50
# FIXME: Unfortunately it turns out that python's logging module
49
51
# is quite expensive, even when the message is not printed by any handlers.
50
52
# We should perhaps change back to just simply doing it here.
55
57
# that.
56
58
 
57
59
import errno
58
 
from io import StringIO
59
60
import logging
60
61
import os
61
62
import sys
63
64
 
64
65
from .lazy_import import lazy_import
65
66
lazy_import(globals(), """
 
67
import locale
66
68
import tempfile
67
69
import traceback
68
70
""")
71
73
 
72
74
lazy_import(globals(), """
73
75
from breezy import (
74
 
    bedding,
75
76
    debug,
 
77
    errors,
76
78
    osutils,
77
79
    ui,
78
80
    )
79
81
""")
80
 
from . import (
81
 
    errors,
 
82
 
 
83
from .sixish import (
 
84
    BytesIO,
 
85
    PY3,
 
86
    StringIO,
 
87
    text_type,
82
88
    )
83
89
 
84
90
 
92
98
# than push/pop_log_file.
93
99
_trace_file = None
94
100
 
95
 
# Absolute path for brz.log.  Not changed even if the log/trace output is
 
101
# Absolute path for ~/.brz.log.  Not changed even if the log/trace output is
96
102
# redirected elsewhere.  Used to show the location in --version.
97
103
_brz_log_filename = None
98
104
 
132
138
    _brz_logger.error(*args, **kwargs)
133
139
 
134
140
 
135
 
class _Bytes(str):
136
 
    """Compat class for displaying bytes on Python 2."""
137
 
 
138
 
    def __repr__(self):
139
 
        return 'b' + str.__repr__(self)
140
 
 
141
 
    def __unicode__(self):
142
 
        return self.decode('ascii', 'replace')
143
 
 
144
 
 
145
141
def mutter(fmt, *args):
146
142
    if _trace_file is None:
147
143
        return
150
146
    if (getattr(_trace_file, 'closed', None) is not None) and _trace_file.closed:
151
147
        return
152
148
 
153
 
    # Let format strings be specified as ascii bytes to help Python 2
154
 
    if isinstance(fmt, bytes):
155
 
        fmt = fmt.decode('ascii', 'replace')
 
149
    if isinstance(fmt, text_type):
 
150
        fmt = fmt.encode('utf8')
156
151
 
157
 
    if args:
158
 
        out = fmt % args
 
152
    if len(args) > 0:
 
153
        # It seems that if we do ascii % (unicode, ascii) we can
 
154
        # get a unicode cannot encode ascii error, so make sure that "fmt"
 
155
        # is a unicode string
 
156
        real_args = []
 
157
        for arg in args:
 
158
            if isinstance(arg, text_type):
 
159
                arg = arg.encode('utf8')
 
160
            real_args.append(arg)
 
161
        out = fmt % tuple(real_args)
159
162
    else:
160
163
        out = fmt
161
164
    now = time.time()
162
 
    out = '%0.3f  %s\n' % (now - _brz_log_start_time, out)
163
 
    _trace_file.write(out.encode('utf-8'))
 
165
    out = b'%0.3f  %s\n' % (now - _brz_log_start_time, out)
 
166
    _trace_file.write(out)
164
167
    # there's no explicit flushing; the file is typically line buffered.
165
168
 
166
169
 
196
199
 
197
200
 
198
201
def _get_brz_log_filename():
199
 
    """Return the brz log filename.
200
 
 
201
 
    :return: A path to the log file
202
 
    :raise EnvironmentError: If the cache directory could not be created
203
 
    """
204
 
    brz_log = os.environ.get('BRZ_LOG')
 
202
    brz_log = osutils.path_from_environ('BRZ_LOG')
205
203
    if brz_log:
206
204
        return brz_log
207
 
    return os.path.join(bedding.cache_dir(), 'brz.log')
 
205
    home = osutils.path_from_environ('BRZ_HOME')
 
206
    if home is None:
 
207
        # GZ 2012-02-01: Logging to the home dir is bad, but XDG is unclear
 
208
        #                over what would be better. On windows, bug 240550
 
209
        #                suggests LOCALAPPDATA be used instead.
 
210
        home = osutils._get_home_dir()
 
211
    return os.path.join(home, '.brz.log')
208
212
 
209
213
 
210
214
def _open_brz_log():
211
 
    """Open the brz.log trace file.
 
215
    """Open the .brz.log trace file.
212
216
 
213
217
    If the log is more than a particular length, the old file is renamed to
214
 
    brz.log.old and a new file is started.  Otherwise, we append to the
 
218
    .brz.log.old and a new file is started.  Otherwise, we append to the
215
219
    existing file.
216
220
 
217
221
    This sets the global _brz_log_filename.
241
245
            else:
242
246
                osutils.copy_ownership_from_path(filename)
243
247
                break
244
 
        return os.fdopen(fd, 'ab', 0)  # unbuffered
245
 
 
 
248
        return os.fdopen(fd, 'ab', 0) # unbuffered
 
249
 
 
250
 
 
251
    _brz_log_filename = _get_brz_log_filename()
 
252
    _rollover_trace_maybe(_brz_log_filename)
246
253
    try:
247
 
        _brz_log_filename = _get_brz_log_filename()
248
 
        _rollover_trace_maybe(_brz_log_filename)
249
 
 
250
254
        brz_log_file = _open_or_create_log_file(_brz_log_filename)
251
255
        brz_log_file.write(b'\n')
252
256
        if brz_log_file.tell() <= 2:
253
 
            brz_log_file.write(
254
 
                b"this is a debug log for diagnosing/reporting problems in brz\n")
255
 
            brz_log_file.write(
256
 
                b"you can delete or truncate this file, or include sections in\n")
257
 
            brz_log_file.write(
258
 
                b"bug reports to https://bugs.launchpad.net/brz/+filebug\n\n")
 
257
            brz_log_file.write(b"this is a debug log for diagnosing/reporting problems in brz\n")
 
258
            brz_log_file.write(b"you can delete or truncate this file, or include sections in\n")
 
259
            brz_log_file.write(b"bug reports to https://bugs.launchpad.net/brz/+filebug\n\n")
259
260
 
260
261
        return brz_log_file
261
262
 
273
274
 
274
275
 
275
276
def enable_default_logging():
276
 
    """Configure default logging: messages to stderr and debug to brz.log
 
277
    """Configure default logging: messages to stderr and debug to .brz.log
277
278
 
278
279
    This should only be called once per process.
279
280
 
290
291
    brz_log_file = _open_brz_log()
291
292
    if brz_log_file is not None:
292
293
        brz_log_file.write(start_time.encode('utf-8') + b'\n')
293
 
    memento = push_log_file(
294
 
        brz_log_file,
 
294
    memento = push_log_file(brz_log_file,
295
295
        r'[%(process)5d] %(asctime)s.%(msecs)03d %(levelname)s: %(message)s',
296
296
        r'%Y-%m-%d %H:%M:%S')
297
297
    # after hooking output into brz_log, we also need to attach a stderr
298
298
    # handler, writing only at level info and with encoding
299
 
    stderr_handler = logging.StreamHandler(stream=sys.stderr)
 
299
    stderr_handler = EncodedStreamHandler(sys.stderr,
 
300
        osutils.get_terminal_encoding(), 'replace', level=logging.INFO)
300
301
    logging.getLogger('brz').addHandler(stderr_handler)
301
302
    return memento
302
303
 
332
333
    old_trace_file = _trace_file
333
334
    # send traces to the new one
334
335
    _trace_file = to_file
 
336
    result = new_handler, _trace_file
335
337
    return ('log_memento', old_handlers, new_handler, old_trace_file, to_file)
336
338
 
337
339
 
420
422
 
421
423
_short_fields = ('VmPeak', 'VmSize', 'VmRSS')
422
424
 
423
 
 
424
425
def _debug_memory_proc(message='', short=True):
425
426
    try:
426
 
        status_file = open('/proc/%s/status' % os.getpid(), 'rb')
 
427
        status_file = file('/proc/%s/status' % os.getpid(), 'rb')
427
428
    except IOError:
428
429
        return
429
430
    try:
441
442
                    note(line)
442
443
                    break
443
444
 
444
 
 
445
445
def _dump_memory_usage(err_file):
446
446
    try:
447
447
        try:
453
453
        except ImportError:
454
454
            err_file.write("Dumping memory requires meliae module.\n")
455
455
            log_exception_quietly()
456
 
        except BaseException:
 
456
        except:
457
457
            err_file.write("Exception while dumping memory.\n")
458
458
            log_exception_quietly()
459
459
    finally:
478
478
 
479
479
 
480
480
def report_exception(exc_info, err_file):
481
 
    """Report an exception to err_file (typically stderr) and to brz.log.
 
481
    """Report an exception to err_file (typically stderr) and to .brz.log.
482
482
 
483
483
    This will show either a full traceback or a short message as appropriate.
484
484
 
485
485
    :return: The appropriate exit code for this error.
486
486
    """
487
 
    # Log the full traceback to brz.log
 
487
    # Log the full traceback to ~/.brz.log
488
488
    log_exception_quietly()
489
489
    if 'error' in debug.debug_flags:
490
490
        print_exception(exc_info, err_file)
501
501
            err_file.write("Use -Dmem_dump to dump memory to a file.\n")
502
502
        return errors.EXIT_ERROR
503
503
    elif isinstance(exc_object, ImportError) \
504
 
            and str(exc_object).startswith("No module named "):
505
 
        report_user_error(
506
 
            exc_info, err_file,
 
504
        and str(exc_object).startswith("No module named "):
 
505
        report_user_error(exc_info, err_file,
507
506
            'You may need to install this Python library separately.')
508
507
        return errors.EXIT_ERROR
509
508
    elif not getattr(exc_object, 'internal_error', True):
510
509
        report_user_error(exc_info, err_file)
511
510
        return errors.EXIT_ERROR
512
 
    elif isinstance(exc_object, EnvironmentError):
 
511
    elif osutils.is_environment_error(exc_object):
513
512
        if getattr(exc_object, 'errno', None) == errno.EPIPE:
514
513
            err_file.write("brz: broken pipe\n")
515
514
            return errors.EXIT_ERROR
540
539
    :param advice: Extra advice to the user to be printed following the
541
540
        exception.
542
541
    """
543
 
    err_file.write(("brz: ERROR: %s\n" % (str(exc_info[1]),)))
 
542
    err_file.write("brz: ERROR: %s\n" % (exc_info[1],))
544
543
    if advice:
545
 
        err_file.write(("%s\n" % advice))
 
544
        err_file.write("%s\n" % advice)
546
545
 
547
546
 
548
547
def report_bug(exc_info, err_file):
556
555
    try:
557
556
        sys.stdout.flush()
558
557
        sys.stderr.flush()
559
 
    except ValueError:
 
558
    except ValueError as e:
560
559
        # On Windows, I get ValueError calling stdout.flush() on a closed
561
560
        # handle
562
561
        pass
600
599
 
601
600
    def emit(self, record):
602
601
        try:
603
 
            if not isinstance(record.msg, str):
 
602
            if not isinstance(record.msg, text_type):
604
603
                msg = record.msg.decode("utf-8")
605
 
                record.msg = msg
 
604
                if PY3:
 
605
                    record.msg = msg
606
606
            line = self.format(record)
607
 
            if not isinstance(line, str):
 
607
            if not isinstance(line, text_type):
608
608
                line = line.decode("utf-8")
609
609
            self.stream.write(line.encode(self.encoding, self.errors) + b"\n")
610
610
        except Exception:
612
612
            # Try saving the details that would have been logged in some form
613
613
            msg = args = "<Unformattable>"
614
614
            try:
615
 
                msg = repr(record.msg)
616
 
                args = repr(record.args)
 
615
                msg = repr(record.msg).encode("ascii", "backslashescape")
 
616
                args = repr(record.args).encode("ascii", "backslashescape")
617
617
            except Exception:
618
618
                pass
619
619
            # Using mutter() bypasses the logging module and writes directly
630
630
    """
631
631
 
632
632
    def __enter__(self):
633
 
        return self  # This is bound to the 'as' clause in a with statement.
 
633
        return self # This is bound to the 'as' clause in a with statement.
634
634
 
635
635
    def __exit__(self, exc_type, exc_val, exc_tb):
636
 
        return False  # propogate exceptions.
 
636
        return False # propogate exceptions.
637
637
 
638
638
 
639
639
class DefaultConfig(Config):
645
645
    def __enter__(self):
646
646
        self._original_filename = _brz_log_filename
647
647
        self._original_state = enable_default_logging()
648
 
        return self  # This is bound to the 'as' clause in a with statement.
 
648
        return self # This is bound to the 'as' clause in a with statement.
649
649
 
650
650
    def __exit__(self, exc_type, exc_val, exc_tb):
651
651
        pop_log_file(self._original_state)
652
652
        global _brz_log_filename
653
653
        _brz_log_filename = self._original_filename
654
 
        return False  # propogate exceptions.
 
654
        return False # propogate exceptions.