view hgext/blackbox.py @ 35569:964212780daf

rust: implementation of `hg` This commit provides a mostly-working implementation of the `hg` script in Rust along with scaffolding to support Rust in the repository. If you are familiar with Rust, the contents of the added rust/ directory should be pretty straightforward. We create an "hgcli" package that implements a binary application to run Mercurial. The output of this package is an "hg" binary. Our Rust `hg` (henceforth "rhg") essentially is a port of the existing `hg` Python script. The main difference is the creation of the embedded CPython interpreter is handled by the binary itself instead of relying on the shebang. In that sense, rhg is more similar to the "exe wrapper" we currently use on Windows. However, unlike the exe wrapper, rhg does not call the `hg` Python script. Instead, it uses the CPython APIs to import mercurial modules and call appropriate functions. The amount of code here is surprisingly small. It is my intent to replace the existing C-based exe wrapper with rhg. Preferably in the next Mercurial release. This should be achievable - at least for some Mercurial distributions. The future/timeline for rhg on other platforms is less clear. We already ship a hg.exe on Windows. So if we get the quirks with Rust worked out, shipping a Rust-based hg.exe should hopefully not be too contentious. Now onto the implementation. We're using python27-sys and the cpython crates for talking to the CPython API. We currently don't use too much functionality of the cpython crate and could have probably cut it out. However, it does provide a reasonable abstraction over unsafe {} CPython function calls. While we still have our fair share of those, at least we're not dealing with too much refcounting, error checking, etc. So I think the use of the cpython crate is justified. Plus, there is not-yet-implemented functionality that could benefit from cpython. I see our use of this crate only increasing. The cpython and python27-sys crates are not without their issues. The cpython crate didn't seem to account for the embedding use case in its design. Instead, it seems to assume that you are building a Python extension. It is making some questionable decisions around certain CPython APIs. For example, it insists that PyEval_ThreadsInitialized() is called and that the Python code likely isn't the main thread in the underlying application. It is also missing some functionality that is important for embedded use cases (such as exporting the path to the Python interpreter from its build script). After spending several hours trying to wrangle python27-sys and cpython, I gave up and forked the project on GitHub. Our Cargo.toml tracks this fork. I'm optimistic that the upstream project will accept our contributions and we can eventually unfork. There is a non-trivial amount of code in our custom Cargo build script. Our build.rs (which is called as part of building the hgcli crate): * Validates that the Python interpreter that was detected by the python27-sys crate provides a shared library (we only support shared library linking at this time - although this restriction could be loosened). * Validates that the Python is built with UCS-4 support. This ensures maximum Unicode compatibility. * Exports variables to the crate build allowing the built crate to e.g. find the path to the Python interpreter. The produced rhg should be considered alpha quality. There are several known deficiencies. Many of these are documented with inline TODOs. Probably the biggest limitation of rhg is that it assumes it is running from the ./rust/target/<target> directory of a source distribution. So, rhg is currently not very practical for real-world use. But, if you can `cargo build` it, running the binary *should* yield a working Mercurial CLI. In order to support using rhg with the test harness, we needed to hack up run-tests.py so the path to Mercurial's Python files is set properly. The change is extremely hacky and is only intended to be a stop-gap until the test harness gains first-class support for installing rhg. This will likely occur after we support running rhg outside the source directory. Despite its officially alpha quality, rhg copes extremely well with the test harness (at least on Linux). Using `run-tests.py --with-hg ../rust/target/debug/hg`, I only encounter the following failures: * test-run-tests.t -- Warnings emitted about using an unexpected Mercurial library. This is due to the hacky nature of setting the Python directory when run-tests.py detected rhg. * test-devel-warnings.t -- Expected stack trace missing frame for `hg` (This is expected since we no longer have an `hg` script!) * test-convert.t -- Test running `$PYTHON "$BINDIR"/hg`, which obviously assumes `hg` is a Python script. * test-merge-tools.t -- Same assumption about `hg` being executable with Python. * test-http-bad-server.t -- Seeing exit code 255 instead of 1 around line 358. * test-blackbox.t -- Exit code 255 instead of 1. * test-basic.t -- Exit code 255 instead of 1. It certainly looks like we have a bug around exit code handling. I don't think it is severe enough to hold up review and landing of this initial implementation. Perfect is the enemy of good. Differential Revision: https://phab.mercurial-scm.org/D1581
author Gregory Szorc <gregory.szorc@gmail.com>
date Wed, 10 Jan 2018 08:53:22 -0800
parents 375577785f49
children de598e84c244
line wrap: on
line source

# blackbox.py - log repository events to a file for post-mortem debugging
#
# Copyright 2010 Nicolas Dumazet
# 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.

Examples::

  [blackbox]
  track = *
  # dirty is *EXPENSIVE* (slow);
  # each log entry indicates `+` if the repository is dirty, like :hg:`id`.
  dirty = True
  # record the source of log messages
  logsource = True

  [blackbox]
  track = command, commandfinish, commandexception, exthook, pythonhook

  [blackbox]
  track = incoming

  [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

"""

from __future__ import absolute_import

import errno
import re

from mercurial.i18n import _
from mercurial.node import hex

from mercurial import (
    registrar,
    ui as uimod,
    util,
)

# Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for
# 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.
testedwith = 'ships-with-hg-core'

cmdtable = {}
command = registrar.command(cmdtable)

configtable = {}
configitem = registrar.configitem(configtable)

configitem('blackbox', 'dirty',
    default=False,
)
configitem('blackbox', 'maxsize',
    default='1 MB',
)
configitem('blackbox', 'logsource',
    default=False,
)
configitem('blackbox', 'maxfiles',
    default=7,
)
configitem('blackbox', 'track',
    default=lambda: ['*'],
)

lastui = None

def _openlogfile(ui, vfs):
    def rotate(oldpath, newpath):
        try:
            vfs.unlink(newpath)
        except OSError as err:
            if err.errno != errno.ENOENT:
                ui.debug("warning: cannot remove '%s': %s\n" %
                         (newpath, err.strerror))
        try:
            if newpath:
                vfs.rename(oldpath, newpath)
        except OSError as err:
            if err.errno != errno.ENOENT:
                ui.debug("warning: cannot rename '%s' to '%s': %s\n" %
                         (newpath, oldpath, err.strerror))

    maxsize = ui.configbytes('blackbox', 'maxsize')
    name = 'blackbox.log'
    if maxsize > 0:
        try:
            st = vfs.stat(name)
        except OSError:
            pass
        else:
            if st.st_size >= maxsize:
                path = vfs.join(name)
                maxfiles = ui.configint('blackbox', 'maxfiles')
                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')
    return vfs(name, 'a')

def wrapui(ui):
    class blackboxui(ui.__class__):
        @property
        def _bbvfs(self):
            vfs = None
            repo = getattr(self, '_bbrepo', None)
            if repo:
                vfs = repo.vfs
                if not vfs.isdir('.'):
                    vfs = None
            return vfs

        @util.propertycache
        def track(self):
            return self.configlist('blackbox', 'track')

        def log(self, event, *msg, **opts):
            global lastui
            super(blackboxui, self).log(event, *msg, **opts)

            if not '*' in self.track and not event in self.track:
                return

            if self._bbvfs:
                ui = self
            else:
                # certain ui instances exist outside the context of
                # a repo, so just default to the last blackbox that
                # was seen.
                ui = lastui

            if not ui:
                return
            vfs = ui._bbvfs
            if not vfs:
                return

            repo = getattr(ui, '_bbrepo', None)
            if not lastui or repo:
                lastui = ui
            if getattr(ui, '_bbinlog', False):
                # recursion and failure guard
                return
            ui._bbinlog = True
            default = self.configdate('devel', 'default-date')
            date = util.datestr(default, '%Y/%m/%d %H:%M:%S')
            user = util.getuser()
            pid = '%d' % util.getpid()
            formattedmsg = msg[0] % msg[1:]
            rev = '(unknown)'
            changed = ''
            if repo:
                ctx = repo[None]
                parents = ctx.parents()
                rev = ('+'.join([hex(p.node()) for p in parents]))
                if (ui.configbool('blackbox', 'dirty') and
                    ctx.dirty(missing=True, merge=False, branch=False)):
                    changed = '+'
            if ui.configbool('blackbox', 'logsource'):
                src = ' [%s]' % event
            else:
                src = ''
            try:
                fmt = '%s %s @%s%s (%s)%s> %s'
                args = (date, user, rev, changed, pid, src, formattedmsg)
                with _openlogfile(ui, vfs) as fp:
                    fp.write(fmt % args)
            except (IOError, OSError) as err:
                self.debug('warning: cannot write to blackbox.log: %s\n' %
                           err.strerror)
                # do not restore _bbinlog intentionally to avoid failed
                # logging again
            else:
                ui._bbinlog = False

        def setrepo(self, repo):
            self._bbrepo = repo

    ui.__class__ = blackboxui
    uimod.ui = blackboxui

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

    if util.safehasattr(ui, 'setrepo'):
        ui.setrepo(repo)

        # Set lastui even if ui.log is not called. This gives blackbox a
        # fallback place to log.
        global lastui
        if lastui is None:
            lastui = ui

    repo._wlockfreeprefix.add('blackbox.log')

@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
    '''

    if not repo.vfs.exists('blackbox.log'):
        return

    limit = opts.get(r'limit')
    fp = repo.vfs('blackbox.log', 'r')
    lines = fp.read().split('\n')

    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)))