blackbox.py
250 lines
| 7.8 KiB
| text/x-python
|
PythonLexer
/ hgext / blackbox.py
|
r18676 | # blackbox.py - log repository events to a file for post-mortem debugging | ||
|
r18669 | # | ||
|
r18676 | # Copyright 2010 Nicolas Dumazet | ||
|
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. | ||||
The events that get logged can be configured via the blackbox.track config key. | ||||
|
r28246 | |||
|
r19162 | Examples:: | ||
|
r18669 | |||
[blackbox] | ||||
track = * | ||||
|
r28303 | # dirty is *EXPENSIVE* (slow); | ||
# each log entry indicates `+` if the repository is dirty, like :hg:`id`. | ||||
|
r28246 | dirty = True | ||
|
r28305 | # record the source of log messages | ||
logsource = True | ||||
|
r18669 | |||
[blackbox] | ||||
track = command, commandfinish, commandexception, exthook, pythonhook | ||||
[blackbox] | ||||
track = incoming | ||||
|
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 | ||||
|
r18669 | """ | ||
|
r28090 | from __future__ import absolute_import | ||
import errno | ||||
import re | ||||
|
r18669 | from mercurial.i18n import _ | ||
|
r28245 | from mercurial.node import hex | ||
|
r28090 | from mercurial import ( | ||
cmdutil, | ||||
|
r28248 | ui as uimod, | ||
|
r28090 | util, | ||
) | ||||
|
r18669 | |||
cmdtable = {} | ||||
command = cmdutil.command(cmdtable) | ||||
|
r29841 | # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for | ||
|
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. | ||||
|
r29841 | testedwith = 'ships-with-hg-core' | ||
|
r28247 | lastui = None | ||
|
r18669 | |||
|
r28243 | filehandles = {} | ||
def _openlog(vfs): | ||||
path = vfs.join('blackbox.log') | ||||
if path in filehandles: | ||||
return filehandles[path] | ||||
filehandles[path] = fp = vfs('blackbox.log', 'a') | ||||
return fp | ||||
def _closelog(vfs): | ||||
path = vfs.join('blackbox.log') | ||||
fp = filehandles[path] | ||||
del filehandles[path] | ||||
fp.close() | ||||
|
r18669 | def wrapui(ui): | ||
class blackboxui(ui.__class__): | ||||
|
r28248 | def __init__(self, src=None): | ||
super(blackboxui, self).__init__(src) | ||||
if src is None: | ||||
self._partialinit() | ||||
else: | ||||
|
r28552 | self._bbfp = getattr(src, '_bbfp', None) | ||
|
r28407 | self._bbinlog = False | ||
|
r28552 | self._bbrepo = getattr(src, '_bbrepo', None) | ||
self._bbvfs = getattr(src, '_bbvfs', None) | ||||
|
r28248 | |||
def _partialinit(self): | ||||
if util.safehasattr(self, '_bbvfs'): | ||||
return | ||||
self._bbfp = None | ||||
|
r28407 | self._bbinlog = False | ||
|
r28248 | self._bbrepo = None | ||
self._bbvfs = None | ||||
def copy(self): | ||||
self._partialinit() | ||||
return self.__class__(self) | ||||
|
r18669 | @util.propertycache | ||
def track(self): | ||||
|
r19052 | return self.configlist('blackbox', 'track', ['*']) | ||
|
r18669 | |||
|
r19066 | def _openlogfile(self): | ||
def rotate(oldpath, newpath): | ||||
try: | ||||
|
r28026 | self._bbvfs.unlink(newpath) | ||
|
r25660 | except OSError as err: | ||
|
r19066 | if err.errno != errno.ENOENT: | ||
self.debug("warning: cannot remove '%s': %s\n" % | ||||
(newpath, err.strerror)) | ||||
try: | ||||
if newpath: | ||||
|
r28026 | self._bbvfs.rename(oldpath, newpath) | ||
|
r25660 | except OSError as err: | ||
|
r19066 | if err.errno != errno.ENOENT: | ||
self.debug("warning: cannot rename '%s' to '%s': %s\n" % | ||||
(newpath, oldpath, err.strerror)) | ||||
|
r28243 | fp = _openlog(self._bbvfs) | ||
|
r19066 | maxsize = self.configbytes('blackbox', 'maxsize', 1048576) | ||
if maxsize > 0: | ||||
|
r28026 | st = self._bbvfs.fstat(fp) | ||
|
r19066 | if st.st_size >= maxsize: | ||
path = fp.name | ||||
|
r28243 | _closelog(self._bbvfs) | ||
|
r19066 | maxfiles = self.configint('blackbox', 'maxfiles', 7) | ||
for i in xrange(maxfiles - 1, 1, -1): | ||||
rotate(oldpath='%s.%d' % (path, i - 1), | ||||
newpath='%s.%d' % (path, i)) | ||||
rotate(oldpath=path, | ||||
newpath=maxfiles > 0 and path + '.1') | ||||
|
r28243 | fp = _openlog(self._bbvfs) | ||
|
r19066 | return fp | ||
|
r28247 | def _bbwrite(self, fmt, *args): | ||
self._bbfp.write(fmt % args) | ||||
self._bbfp.flush() | ||||
|
r18669 | def log(self, event, *msg, **opts): | ||
|
r28247 | global lastui | ||
|
r18669 | super(blackboxui, self).log(event, *msg, **opts) | ||
|
r28248 | self._partialinit() | ||
|
r18669 | |||
if not '*' in self.track and not event in self.track: | ||||
return | ||||
|
r28248 | if self._bbfp: | ||
|
r28247 | ui = self | ||
|
r28248 | elif self._bbvfs: | ||
|
r18831 | try: | ||
|
r28244 | self._bbfp = self._openlogfile() | ||
|
r25660 | except (IOError, OSError) as err: | ||
|
r18831 | self.debug('warning: cannot write to blackbox.log: %s\n' % | ||
err.strerror) | ||||
|
r28026 | del self._bbvfs | ||
|
r28244 | self._bbfp = None | ||
|
r28247 | ui = self | ||
|
r18669 | else: | ||
# certain ui instances exist outside the context of | ||||
# a repo, so just default to the last blackbox that | ||||
# was seen. | ||||
|
r28247 | ui = lastui | ||
|
r18669 | |||
|
r28407 | if not ui or not ui._bbfp: | ||
return | ||||
if not lastui or ui._bbrepo: | ||||
lastui = ui | ||||
if ui._bbinlog: | ||||
# recursion guard | ||||
return | ||||
try: | ||||
ui._bbinlog = True | ||||
|
r18669 | date = util.datestr(None, '%Y/%m/%d %H:%M:%S') | ||
|
r18787 | user = util.getuser() | ||
|
r32155 | pid = '%d' % util.getpid() | ||
|
r18669 | formattedmsg = msg[0] % msg[1:] | ||
|
r28245 | rev = '(unknown)' | ||
|
r28246 | changed = '' | ||
|
r28248 | if ui._bbrepo: | ||
|
r28247 | ctx = ui._bbrepo[None] | ||
|
r28304 | parents = ctx.parents() | ||
rev = ('+'.join([hex(p.node()) for p in parents])) | ||||
if (ui.configbool('blackbox', 'dirty', False) and ( | ||||
any(ui._bbrepo.status()) or | ||||
any(ctx.sub(s).dirty() for s in ctx.substate) | ||||
)): | ||||
changed = '+' | ||||
|
r28305 | if ui.configbool('blackbox', 'logsource', False): | ||
src = ' [%s]' % event | ||||
else: | ||||
src = '' | ||||
|
r18786 | try: | ||
|
r28305 | ui._bbwrite('%s %s @%s%s (%s)%s> %s', | ||
date, user, rev, changed, pid, src, formattedmsg) | ||||
|
r25660 | except IOError as err: | ||
|
r18786 | self.debug('warning: cannot write to blackbox.log: %s\n' % | ||
err.strerror) | ||||
|
r28407 | finally: | ||
ui._bbinlog = False | ||||
|
r18669 | |||
def setrepo(self, repo): | ||||
|
r28248 | self._bbfp = None | ||
|
r28407 | self._bbinlog = False | ||
|
r28248 | self._bbrepo = repo | ||
|
r28026 | self._bbvfs = repo.vfs | ||
|
r18669 | |||
ui.__class__ = blackboxui | ||||
|
r28248 | uimod.ui = blackboxui | ||
|
r18669 | |||
def uisetup(ui): | ||||
wrapui(ui) | ||||
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 | ||||
|
r19230 | if util.safehasattr(ui, 'setrepo'): | ||
ui.setrepo(repo) | ||||
|
r18673 | |||
@command('^blackbox', | ||||
[('l', 'limit', 10, _('the number of events to show')), | ||||
], | ||||
_('hg blackbox [OPTION]...')) | ||||
def blackbox(ui, repo, *revs, **opts): | ||||
'''view the recent repository events | ||||
''' | ||||
|
r28026 | if not repo.vfs.exists('blackbox.log'): | ||
|
r18673 | return | ||
limit = opts.get('limit') | ||||
|
r28244 | fp = repo.vfs('blackbox.log', 'r') | ||
lines = fp.read().split('\n') | ||||
|
r18673 | |||
count = 0 | ||||
output = [] | ||||
for line in reversed(lines): | ||||
if count >= limit: | ||||
break | ||||
# count the commands by matching lines like: 2013/01/23 19:13:36 root> | ||||
if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line): | ||||
count += 1 | ||||
output.append(line) | ||||
ui.status('\n'.join(reversed(output))) | ||||