blackbox.py
240 lines
| 6.7 KiB
| text/x-python
|
PythonLexer
/ hgext / blackbox.py
Bryan O'Sullivan
|
r18676 | # blackbox.py - log repository events to a file for post-mortem debugging | ||
Durham Goode
|
r18669 | # | ||
Bryan O'Sullivan
|
r18676 | # Copyright 2010 Nicolas Dumazet | ||
Durham Goode
|
r18669 | # Copyright 2013 Facebook, Inc. | ||
# | ||||
# This software may be used and distributed according to the terms of the | ||||
# GNU General Public License version 2 or any later version. | ||||
"""log repository events to a blackbox for debugging | ||||
Logs event information to .hg/blackbox.log to help debug and diagnose problems. | ||||
Valentin Gatien-Baron
|
r42834 | The events that get logged can be configured via the blackbox.track and | ||
blackbox.ignore config keys. | ||||
timeless
|
r28246 | |||
Takumi IINO
|
r19162 | Examples:: | ||
Durham Goode
|
r18669 | |||
[blackbox] | ||||
track = * | ||||
Valentin Gatien-Baron
|
r42834 | ignore = pythonhook | ||
timeless
|
r28303 | # dirty is *EXPENSIVE* (slow); | ||
# each log entry indicates `+` if the repository is dirty, like :hg:`id`. | ||||
timeless
|
r28246 | dirty = True | ||
timeless
|
r28305 | # record the source of log messages | ||
logsource = True | ||||
Durham Goode
|
r18669 | |||
[blackbox] | ||||
track = command, commandfinish, commandexception, exthook, pythonhook | ||||
[blackbox] | ||||
track = incoming | ||||
Bryan O'Sullivan
|
r19066 | [blackbox] | ||
# limit the size of a log file | ||||
maxsize = 1.5 MB | ||||
# rotate up to N log files when the current one gets too big | ||||
maxfiles = 3 | ||||
Matt DeVore
|
r40466 | [blackbox] | ||
Valentin Gatien-Baron
|
r49419 | # Include microseconds in log entries with %f (see Python function | ||
Matt DeVore
|
r40466 | # datetime.datetime.strftime) | ||
Simon Sapin
|
r47342 | date-format = %Y-%m-%d @ %H:%M:%S.%f | ||
Matt DeVore
|
r40466 | |||
Durham Goode
|
r18669 | """ | ||
Gregory Szorc
|
r28090 | |||
import re | ||||
Durham Goode
|
r18669 | from mercurial.i18n import _ | ||
timeless
|
r28245 | from mercurial.node import hex | ||
Gregory Szorc
|
r28090 | from mercurial import ( | ||
Gregory Szorc
|
r35685 | encoding, | ||
Yuya Nishihara
|
r40830 | loggingutil, | ||
Yuya Nishihara
|
r32337 | registrar, | ||
Gregory Szorc
|
r28090 | ) | ||
Yuya Nishihara
|
r37138 | from mercurial.utils import ( | ||
dateutil, | ||||
procutil, | ||||
) | ||||
Durham Goode
|
r18669 | |||
Augie Fackler
|
r29841 | # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for | ||
Augie Fackler
|
r25186 | # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should | ||
# be specifying the version(s) of Mercurial they are tested with, or | ||||
# leave the attribute unspecified. | ||||
Augie Fackler
|
r43347 | testedwith = b'ships-with-hg-core' | ||
r33129 | ||||
cmdtable = {} | ||||
command = registrar.command(cmdtable) | ||||
r33130 | configtable = {} | |||
configitem = registrar.configitem(configtable) | ||||
Augie Fackler
|
r43346 | configitem( | ||
Augie Fackler
|
r46554 | b'blackbox', | ||
b'dirty', | ||||
default=False, | ||||
r33186 | ) | |||
Augie Fackler
|
r43346 | configitem( | ||
Augie Fackler
|
r46554 | b'blackbox', | ||
b'maxsize', | ||||
default=b'1 MB', | ||||
Augie Fackler
|
r43346 | ) | ||
configitem( | ||||
Augie Fackler
|
r46554 | b'blackbox', | ||
b'logsource', | ||||
default=False, | ||||
r33130 | ) | |||
Augie Fackler
|
r43346 | configitem( | ||
Augie Fackler
|
r46554 | b'blackbox', | ||
b'maxfiles', | ||||
default=7, | ||||
r33187 | ) | |||
Augie Fackler
|
r43346 | configitem( | ||
Augie Fackler
|
r46554 | b'blackbox', | ||
b'track', | ||||
default=lambda: [b'*'], | ||||
Boris Feld
|
r34746 | ) | ||
Augie Fackler
|
r43346 | configitem( | ||
Augie Fackler
|
r43347 | b'blackbox', | ||
b'ignore', | ||||
default=lambda: [b'chgserver', b'cmdserver', b'extension'], | ||||
Valentin Gatien-Baron
|
r42834 | ) | ||
Valentin Gatien-Baron
|
r49420 | configitem(b'blackbox', b'date-format', default=b'') | ||
r33130 | ||||
Yuya Nishihara
|
r40830 | _lastlogger = loggingutil.proxylogger() | ||
Yuya Nishihara
|
r40795 | |||
Augie Fackler
|
r43346 | |||
Gregory Szorc
|
r49801 | class blackboxlogger: | ||
Yuya Nishihara
|
r40797 | def __init__(self, ui, repo): | ||
self._repo = repo | ||||
Augie Fackler
|
r43347 | self._trackedevents = set(ui.configlist(b'blackbox', b'track')) | ||
self._ignoredevents = set(ui.configlist(b'blackbox', b'ignore')) | ||||
self._maxfiles = ui.configint(b'blackbox', b'maxfiles') | ||||
self._maxsize = ui.configbytes(b'blackbox', b'maxsize') | ||||
Yuya Nishihara
|
r41029 | self._inlog = False | ||
Yuya Nishihara
|
r40680 | |||
Yuya Nishihara
|
r40684 | def tracked(self, event): | ||
Augie Fackler
|
r43346 | return ( | ||
b'*' in self._trackedevents and event not in self._ignoredevents | ||||
) or event in self._trackedevents | ||||
Yuya Nishihara
|
r40684 | |||
Yuya Nishihara
|
r40681 | def log(self, ui, event, msg, opts): | ||
Yuya Nishihara
|
r41029 | # self._log() -> ctx.dirty() may create new subrepo instance, which | ||
# ui is derived from baseui. So the recursion guard in ui.log() | ||||
# doesn't work as it's local to the ui instance. | ||||
if self._inlog: | ||||
return | ||||
self._inlog = True | ||||
try: | ||||
self._log(ui, event, msg, opts) | ||||
finally: | ||||
self._inlog = False | ||||
def _log(self, ui, event, msg, opts): | ||||
Augie Fackler
|
r43347 | default = ui.configdate(b'devel', b'default-date') | ||
Valentin Gatien-Baron
|
r49420 | dateformat = ui.config(b'blackbox', b'date-format') | ||
if dateformat: | ||||
date = dateutil.datestr(default, dateformat) | ||||
else: | ||||
# We want to display milliseconds (more precision seems | ||||
# unnecessary). Since %.3f is not supported, use %f and truncate | ||||
# microseconds. | ||||
Valentin Gatien-Baron
|
r49421 | date = dateutil.datestr(default, b'%Y-%m-%d %H:%M:%S.%f')[:-3] | ||
Yuya Nishihara
|
r40681 | user = procutil.getuser() | ||
Augie Fackler
|
r43347 | pid = b'%d' % procutil.getpid() | ||
changed = b'' | ||||
Yuya Nishihara
|
r40682 | ctx = self._repo[None] | ||
Yuya Nishihara
|
r40681 | parents = ctx.parents() | ||
Augie Fackler
|
r43347 | rev = b'+'.join([hex(p.node()) for p in parents]) | ||
if ui.configbool(b'blackbox', b'dirty') and ctx.dirty( | ||||
Augie Fackler
|
r43346 | missing=True, merge=False, branch=False | ||
): | ||||
Augie Fackler
|
r43347 | changed = b'+' | ||
if ui.configbool(b'blackbox', b'logsource'): | ||||
src = b' [%s]' % event | ||||
Yuya Nishihara
|
r40681 | else: | ||
Augie Fackler
|
r43347 | src = b'' | ||
Yuya Nishihara
|
r40681 | try: | ||
Augie Fackler
|
r43347 | fmt = b'%s %s @%s%s (%s)%s> %s' | ||
Yuya Nishihara
|
r40793 | args = (date, user, rev, changed, pid, src, msg) | ||
Yuya Nishihara
|
r40830 | with loggingutil.openlogfile( | ||
Augie Fackler
|
r43346 | ui, | ||
self._repo.vfs, | ||||
Augie Fackler
|
r43347 | name=b'blackbox.log', | ||
Augie Fackler
|
r43346 | maxfiles=self._maxfiles, | ||
maxsize=self._maxsize, | ||||
) as fp: | ||||
Yuya Nishihara
|
r40681 | fp.write(fmt % args) | ||
except (IOError, OSError) as err: | ||||
Yuya Nishihara
|
r40791 | # deactivate this to avoid failed logging again | ||
Yuya Nishihara
|
r40796 | self._trackedevents.clear() | ||
Augie Fackler
|
r43346 | ui.debug( | ||
Augie Fackler
|
r43347 | b'warning: cannot write to blackbox.log: %s\n' | ||
Augie Fackler
|
r43346 | % encoding.strtolocal(err.strerror) | ||
) | ||||
Yuya Nishihara
|
r40828 | return | ||
_lastlogger.logger = self | ||||
Durham Goode
|
r18669 | |||
Augie Fackler
|
r43346 | |||
Yuya Nishihara
|
r40761 | def uipopulate(ui): | ||
Yuya Nishihara
|
r40795 | ui.setlogger(b'blackbox', _lastlogger) | ||
Yuya Nishihara
|
r40761 | |||
Augie Fackler
|
r43346 | |||
Durham Goode
|
r18669 | def reposetup(ui, repo): | ||
# During 'hg pull' a httppeer repo is created to represent the remote repo. | ||||
# It doesn't have a .hg directory to put a blackbox in, so we don't do | ||||
# the blackbox setup for it. | ||||
if not repo.local(): | ||||
return | ||||
Yuya Nishihara
|
r40761 | # Since blackbox.log is stored in the repo directory, the logger should be | ||
# instantiated per repository. | ||||
Yuya Nishihara
|
r40797 | logger = blackboxlogger(ui, repo) | ||
Yuya Nishihara
|
r40761 | ui.setlogger(b'blackbox', logger) | ||
Jun Wu
|
r34277 | |||
Yuya Nishihara
|
r40795 | # Set _lastlogger even if ui.log is not called. This gives blackbox a | ||
# fallback place to log | ||||
if _lastlogger.logger is None: | ||||
_lastlogger.logger = logger | ||||
Jun Wu
|
r34277 | |||
Augie Fackler
|
r43347 | repo._wlockfreeprefix.add(b'blackbox.log') | ||
Durham Goode
|
r18673 | |||
Augie Fackler
|
r43346 | |||
@command( | ||||
Augie Fackler
|
r43347 | b'blackbox', | ||
Augie Fackler
|
r46554 | [ | ||
(b'l', b'limit', 10, _(b'the number of events to show')), | ||||
], | ||||
Augie Fackler
|
r43347 | _(b'hg blackbox [OPTION]...'), | ||
Rodrigo Damazio
|
r40331 | helpcategory=command.CATEGORY_MAINTENANCE, | ||
Augie Fackler
|
r43346 | helpbasic=True, | ||
) | ||||
Durham Goode
|
r18673 | def blackbox(ui, repo, *revs, **opts): | ||
Augie Fackler
|
r46554 | """view the recent repository events""" | ||
Durham Goode
|
r18673 | |||
Augie Fackler
|
r43347 | if not repo.vfs.exists(b'blackbox.log'): | ||
Durham Goode
|
r18673 | return | ||
Augie Fackler
|
r43906 | limit = opts.get('limit') | ||
Augie Fackler
|
r43347 | fp = repo.vfs(b'blackbox.log', b'r') | ||
lines = fp.read().split(b'\n') | ||||
Durham Goode
|
r18673 | |||
count = 0 | ||||
output = [] | ||||
for line in reversed(lines): | ||||
if count >= limit: | ||||
break | ||||
Valentin Gatien-Baron
|
r49421 | # count the commands by matching lines like: | ||
# 2013/01/23 19:13:36 root> | ||||
# 2013/01/23 19:13:36 root (1234)> | ||||
# 2013/01/23 19:13:36 root @0000000000000000000000000000000000000000 (1234)> | ||||
# 2013-01-23 19:13:36.000 root @0000000000000000000000000000000000000000 (1234)> | ||||
Valentin Gatien-Baron
|
r49420 | if re.match( | ||
Valentin Gatien-Baron
|
r49421 | br'^\d{4}[-/]\d{2}[-/]\d{2} \d{2}:\d{2}:\d{2}(.\d*)? .*> .*', line | ||
Valentin Gatien-Baron
|
r49420 | ): | ||
Durham Goode
|
r18673 | count += 1 | ||
output.append(line) | ||||
Augie Fackler
|
r43347 | ui.status(b'\n'.join(reversed(output))) | ||