contrib/hgperf
author Valentin Gatien-Baron <valentin.gatienbaron@gmail.com>
Sun, 13 Sep 2020 22:14:25 -0400
changeset 46889 8759e22f1649
parent 46819 d4ba4d51f85f
permissions -rwxr-xr-x
procutil: avoid using os.fork() to implement runbgcommand We ran into the following deadlock: - some command creates an ssh peer, then raises without explicitly closing the peer (hg id + extension in our case) - dispatch catches the exception, calls ui.log('commandfinish', ..) (the sshpeer is still not closed), which calls logtoprocess, which calls procutil.runbgcommand. - in the child of runbgcommand's fork(), between the fork and the exec, the opening of file descriptors triggers a gc which runs the destructor for sshpeer, which waits on ssh's stderr being closed, which never happens since ssh's stderr is held open by the parent of the fork where said destructor hasn't run Remotefilelog appears to have a hack around this deadlock as well. I don't know if there's more subtlety to it, because even though the problem is determistic, it is very fragile, so I didn't manage to reduce it. I can imagine three ways of tackling this problem: 1. don't run any python between fork and exec in runbgcommand 2. make the finalizer harmless after the fork 3. close the peer without relying on gc behavior This commit goes with 1, as forking without exec'ing is tricky in general in a language with gc finalizers. And maybe it's better in the presence of rust threads. A future commit will try 2 or 3. Performance wise: at low memory usage, it's an improvement. At higher memory usage, it's about 2x faster than before when ensurestart=True, but 2x slower when ensurestart=False. Not sure if that matters. The reason for that last bit is that the subprocess.Popen always waits for the execve to finish, and at high memory usage, execve is slow because it deallocates the large page table. Numbers and script: before after mem=1.0GB, ensurestart=True 52.1ms 26.0ms mem=1.0GB, ensurestart=False 14.7ms 26.0ms mem=0.5GB, ensurestart=True 23.2ms 11.2ms mem=0.5GB, ensurestart=False 6.2ms 11.3ms mem=0.2GB, ensurestart=True 15.7ms 7.4ms mem=0.2GB, ensurestart=False 4.3ms 8.1ms mem=0.0GB, ensurestart=True 2.3ms 0.7ms mem=0.0GB, ensurestart=False 0.8ms 0.8ms import time for memsize in [1_000_000_000, 500_000_000, 250_000_000, 0]: mem = 'a' * memsize for ensurestart in [True, False]: now = time.time() n = 100 for i in range(n): procutil.runbgcommand([b'true'], {}, ensurestart=ensurestart) after = time.time() ms = (after - now) / float(n) * 1000 print(f'mem={memsize / 1e9:.1f}GB, ensurestart={ensurestart} -> {ms:.1f}ms') Differential Revision: https://phab.mercurial-scm.org/D9019

#!/usr/bin/env python3
#
# hgperf - measure performance of Mercurial commands
#
# Copyright 2014 Olivia Mackall <olivia@selenic.com>
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version.

'''measure performance of Mercurial commands

Using ``hgperf`` instead of ``hg`` measures performance of the target
Mercurial command. For example, the execution below measures
performance of :hg:`heads --topo`::

    $ hgperf heads --topo

All command output via ``ui`` is suppressed, and just measurement
result is displayed: see also "perf" extension in "contrib".

Costs of processing before dispatching to the command function like
below are not measured::

    - parsing command line (e.g. option validity check)
    - reading configuration files in

But ``pre-`` and ``post-`` hook invocation for the target command is
measured, even though these are invoked before or after dispatching to
the command function, because these may be required to repeat
execution of the target command correctly.
'''

import os
import sys

libdir = '@LIBDIR@'

if libdir != '@' 'LIBDIR' '@':
    if not os.path.isabs(libdir):
        libdir = os.path.join(
            os.path.dirname(os.path.realpath(__file__)), libdir
        )
        libdir = os.path.abspath(libdir)
    sys.path.insert(0, libdir)

# enable importing on demand to reduce startup time
try:
    from mercurial import demandimport

    demandimport.enable()
except ImportError:
    import sys

    sys.stderr.write(
        "abort: couldn't find mercurial libraries in [%s]\n"
        % ' '.join(sys.path)
    )
    sys.stderr.write("(check your install and PYTHONPATH)\n")
    sys.exit(-1)

from mercurial import (
    dispatch,
    util,
)


def timer(func, title=None):
    results = []
    begin = util.timer()
    count = 0
    while True:
        ostart = os.times()
        cstart = util.timer()
        r = func()
        cstop = util.timer()
        ostop = os.times()
        count += 1
        a, b = ostart, ostop
        results.append((cstop - cstart, b[0] - a[0], b[1] - a[1]))
        if cstop - begin > 3 and count >= 100:
            break
        if cstop - begin > 10 and count >= 3:
            break
    if title:
        sys.stderr.write("! %s\n" % title)
    if r:
        sys.stderr.write("! result: %s\n" % r)
    m = min(results)
    sys.stderr.write(
        "! wall %f comb %f user %f sys %f (best of %d)\n"
        % (m[0], m[1] + m[2], m[1], m[2], count)
    )


orgruncommand = dispatch.runcommand


def runcommand(lui, repo, cmd, fullargs, ui, options, d, cmdpats, cmdoptions):
    ui.pushbuffer()
    lui.pushbuffer()
    timer(
        lambda: orgruncommand(
            lui, repo, cmd, fullargs, ui, options, d, cmdpats, cmdoptions
        )
    )
    ui.popbuffer()
    lui.popbuffer()


dispatch.runcommand = runcommand

dispatch.run()