perf: clear vfs audit_cache before each run When generating a stream clone, we spend a large amount of time auditing path. Before this changes, the first run was warming the vfs cache for the other runs, leading to a large runtime difference and a "faulty" reported timing for the operation. We now clear this important cache between run to get a more realistic timing. Below are some example of median time change when clearing these cases. The maximum time for a run did not changed significantly. ### data-env-vars.name = mozilla-central-2018-08-01-zstd-sparse-revlog # benchmark.name = hg.perf.exchange.stream.generate # bin-env-vars.hg.flavor = default # bin-env-vars.hg.py-re2-module = default # benchmark.variants.version = latest no-clearing: 17.289905 cache-clearing: 21.587965 (+24.86%, +4.30) ## data-env-vars.name = mozilla-central-2024-03-22-zstd-sparse-revlog no-clearing: 32.670748 cache-clearing: 40.467095 (+23.86%, +7.80) ## data-env-vars.name = mozilla-try-2019-02-18-zstd-sparse-revlog no-clearing: 37.838858 cache-clearing: 46.072749 (+21.76%, +8.23) ## data-env-vars.name = mozilla-unified-2024-03-22-zstd-sparse-revlog no-clearing: 32.969395 cache-clearing: 39.646209 (+20.25%, +6.68) In addition, this significantly reduce the timing difference between the performance command, from the perf extensions and a `real `hg bundle` call producing a stream bundle. Some significant differences remain especially on the "mozilla-try" repositories, but they are now smaller. Note that some of that difference will actually not be attributable to the stream generation (like maybe phases or branch map computation). Below are some benchmarks done on a currently draft changeset fixing some unrelated slowness in `hg bundle` (34a78972af409d1ff37c29e60f6ca811ad1a457d) ### data-env-vars.name = mozilla-central-2018-08-01-zstd-sparse-revlog # bin-env-vars.hg.flavor = default # bin-env-vars.hg.py-re2-module = default hg.perf.exchange.stream.generate: 21.587965 hg.command.bundle: 24.301799 (+12.57%, +2.71) ## data-env-vars.name = mozilla-central-2024-03-22-zstd-sparse-revlog hg.perf.exchange.stream.generate: 40.467095 hg.command.bundle: 44.831317 (+10.78%, +4.36) ## data-env-vars.name = mozilla-unified-2024-03-22-zstd-sparse-revlog hg.perf.exchange.stream.generate: 39.646209 hg.command.bundle: 45.395258 (+14.50%, +5.75) ## data-env-vars.name = mozilla-try-2019-02-18-zstd-sparse-revlog hg.perf.exchange.stream.generate: 46.072749 hg.command.bundle: 55.882608 (+21.29%, +9.81) ## data-env-vars.name = mozilla-try-2023-03-22-zlib-general-delta hg.perf.exchange.stream.generate: 334.716708 hg.command.bundle: 377.856767 (+12.89%, +43.14) ## data-env-vars.name = mozilla-try-2023-03-22-zstd-sparse-revlog hg.perf.exchange.stream.generate: 302.972301 hg.command.bundle: 326.098755 (+7.63%, +23.13)

#!/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()