view hgdemandimport/tracing.py @ 39627:ee7ee0c516ca

narrow: intersect provided matcher with narrowmatcher in `hg diff` This provides significant speedups when running diff, and no change in behavior that I'm aware of (or that the tests found). I tested with a repo that I started using narrow in after it was created and attempted to run `hg diff -c .` and similar commands in it on a commit that had files not in the narrowspec. Timing numbers below, using a similar setup as my previous commits. before=9db85644, m-u is mozilla-unified at eb39298e432d (flatmanifest) and 0553b7f29eaf (treemanifest). l-d-r is a repo simulating a situation I've encountered where there's one directory with 30k+ subdirectories. N means narrow, T means treemanifest. The narrowspec is pretty small when in use, and importantly the narrowspec is applied *after* doing the initial checkout (without narrowing), so all of these files exist in the filesystem, which is not normally the case if someone has been using narrow for the entire life of the clone. Anything less than a 5% difference in performance is most likely noise. diff --git: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 1.292 s +- 0.009 s | 1.295 s +- 0.010 s | 100.2% m-u | | x | 1.296 s +- 0.042 s | 1.299 s +- 0.026 s | 100.2% m-u | x | | 1.292 s +- 0.010 s | 1.297 s +- 0.021 s | 100.4% m-u | x | x | 84.2 ms +- 1.2 ms | 83.6 ms +- 0.2 ms | 99.3% l-d-r | | | 188.7 ms +- 2.7 ms | 188.8 ms +- 2.0 ms | 100.1% l-d-r | | x | 189.9 ms +- 1.5 ms | 189.4 ms +- 1.2 ms | 99.7% l-d-r | x | | 97.1 ms +- 1.0 ms | 87.1 ms +- 1.0 ms | 89.7% <-- l-d-r | x | x | 96.9 ms +- 0.8 ms | 87.2 ms +- 0.7 ms | 90.0% <-- diff -c . --git: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 231.6 ms +- 3.1 ms | 228.9 ms +- 1.6 ms | 98.8% m-u | | x | 150.5 ms +- 1.7 ms | 150.7 ms +- 1.4 ms | 100.1% m-u | x | | 233.7 ms +- 2.4 ms | 232.2 ms +- 1.9 ms | 99.4% m-u | x | x | 126.1 ms +- 1.2 ms | 126.8 ms +- 1.2 ms | 100.6% l-d-r | | | 82.1 ms +- 2.0 ms | 81.8 ms +- 1.4 ms | 99.6% l-d-r | | x | 3.732 s +- 0.020 s | 3.746 s +- 0.027 s | 100.4% l-d-r | x | | 83.1 ms +- 0.8 ms | 107.6 ms +- 2.4 ms | 129.5% <-- l-d-r | x | x | 758.2 ms +- 38.8 ms | 188.5 ms +- 1.8 ms | 24.9% <-- rebase -r . --keep -d .^^: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 5.532 s +- 0.087 s | 5.496 s +- 0.016 s | 99.3% m-u | | x | 5.554 s +- 0.061 s | 5.532 s +- 0.013 s | 99.6% m-u | x | | 5.602 s +- 0.134 s | 5.508 s +- 0.035 s | 98.3% m-u | x | x | 582.2 ms +- 15.2 ms | 572.9 ms +- 12.0 ms | 98.4% l-d-r | | | 629.5 ms +- 12.3 ms | 622.5 ms +- 7.3 ms | 98.9% l-d-r | | x | 6.173 s +- 0.062 s | 6.185 s +- 0.076 s | 100.2% l-d-r | x | | 274.5 ms +- 10.0 ms | 272.1 ms +- 6.2 ms | 99.1% l-d-r | x | x | 4.835 s +- 0.056 s | 4.826 s +- 0.034 s | 99.8% status --change . --copies: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 214.4 ms +- 1.4 ms | 212.2 ms +- 1.7 ms | 99.0% m-u | | x | 130.9 ms +- 1.2 ms | 131.7 ms +- 1.1 ms | 100.6% m-u | x | | 215.0 ms +- 2.1 ms | 214.9 ms +- 2.7 ms | 100.0% m-u | x | x | 109.5 ms +- 2.3 ms | 107.8 ms +- 0.9 ms | 98.4% l-d-r | | | 79.6 ms +- 0.9 ms | 79.8 ms +- 1.6 ms | 100.3% l-d-r | | x | 3.799 s +- 0.037 s | 3.928 s +- 0.021 s | 103.4% <--? l-d-r | x | | 82.7 ms +- 0.7 ms | 83.2 ms +- 1.0 ms | 100.6% l-d-r | x | x | 746.8 ms +- 6.1 ms | 739.0 ms +- 4.2 ms | 99.0% status --copies: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 1.884 s +- 0.012 s | 1.885 s +- 0.013 s | 100.1% m-u | | x | 1.897 s +- 0.027 s | 1.909 s +- 0.077 s | 100.6% m-u | x | | 1.886 s +- 0.021 s | 1.891 s +- 0.030 s | 100.3% m-u | x | x | 92.0 ms +- 0.7 ms | 92.4 ms +- 0.4 ms | 100.4% l-d-r | | | 570.3 ms +- 18.7 ms | 552.2 ms +- 4.5 ms | 96.8% l-d-r | | x | 568.9 ms +- 16.1 ms | 567.2 ms +- 11.9 ms | 99.7% l-d-r | x | | 171.1 ms +- 2.5 ms | 170.4 ms +- 1.2 ms | 99.6% l-d-r | x | x | 171.6 ms +- 3.4 ms | 171.5 ms +- 1.7 ms | 99.9% update $rev^; ~/src/hg/hg{hg}/hg update $rev: repo | N | T | before (mean +- stdev) | after (mean +- stdev) | % of before ------+---+---+------------------------+-----------------------+------------ m-u | | | 3.107 s +- 0.017 s | 3.116 s +- 0.012 s | 100.3% m-u | | x | 2.943 s +- 0.010 s | 2.945 s +- 0.019 s | 100.1% m-u | x | | 3.116 s +- 0.033 s | 3.118 s +- 0.027 s | 100.1% m-u | x | x | 318.5 ms +- 2.7 ms | 320.8 ms +- 4.8 ms | 100.7% l-d-r | | | 428.9 ms +- 4.4 ms | 429.5 ms +- 4.0 ms | 100.1% l-d-r | | x | 9.593 s +- 0.081 s | 9.869 s +- 0.043 s | 102.9% l-d-r | x | | 253.2 ms +- 3.6 ms | 254.0 ms +- 2.8 ms | 100.3% l-d-r | x | x | 1.613 s +- 0.009 s | 1.630 s +- 0.017 s | 101.1% Differential Revision: https://phab.mercurial-scm.org/D4587
author spectral <spectral@google.com>
date Thu, 13 Sep 2018 22:48:27 -0700
parents 452790284a15
children d0b8a3cfd732
line wrap: on
line source

# Support code for event tracing in Mercurial. Lives in demandimport
# so it can also be used in demandimport.
#
# Copyright 2018 Google LLC.
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version.
from __future__ import absolute_import

import contextlib
import os

_pipe = None
_checked = False

@contextlib.contextmanager
def log(whencefmt, *whenceargs):
    global _pipe, _session, _checked
    if _pipe is None:
        if _checked:
            yield
            return
        _checked = True
        if 'HGCATAPULTSERVERPIPE' not in os.environ:
            yield
            return
        _pipe = open(os.environ['HGCATAPULTSERVERPIPE'], 'w', 1)
        _session = os.environ.get('HGCATAPULTSESSION', 'none')
    whence = whencefmt % whenceargs
    try:
        # Both writes to the pipe are wrapped in try/except to ignore
        # errors, as we can see mysterious errors in here if the pager
        # is active. Presumably other conditions could trigger
        # problems too.
        try:
            _pipe.write('START %s %s\n' % (_session, whence))
        except IOError:
            pass
        yield
    finally:
        try:
            _pipe.write('END %s %s\n' % (_session, whence))
        except IOError:
            pass