view mercurial/lsprofcalltree.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

"""
lsprofcalltree.py - lsprof output which is readable by kcachegrind

Authors:
    * David Allouche <david <at> allouche.net>
    * Jp Calderone & Itamar Shtull-Trauring
    * Johan Dahlin

This software may be used and distributed according to the terms
of the GNU General Public License, incorporated herein by reference.
"""

from __future__ import absolute_import, print_function

def label(code):
    if isinstance(code, str):
        return '~' + code    # built-in functions ('~' sorts at the end)
    else:
        return '%s %s:%d' % (code.co_name,
                             code.co_filename,
                             code.co_firstlineno)

class KCacheGrind(object):
    def __init__(self, profiler):
        self.data = profiler.getstats()
        self.out_file = None

    def output(self, out_file):
        self.out_file = out_file
        print('events: Ticks', file=out_file)
        self._print_summary()
        for entry in self.data:
            self._entry(entry)

    def _print_summary(self):
        max_cost = 0
        for entry in self.data:
            totaltime = int(entry.totaltime * 1000)
            max_cost = max(max_cost, totaltime)
        print('summary: %d' % max_cost, file=self.out_file)

    def _entry(self, entry):
        out_file = self.out_file

        code = entry.code
        if isinstance(code, str):
            print('fi=~', file=out_file)
        else:
            print('fi=%s' % code.co_filename, file=out_file)
        print('fn=%s' % label(code), file=out_file)

        inlinetime = int(entry.inlinetime * 1000)
        if isinstance(code, str):
            print('0 ', inlinetime, file=out_file)
        else:
            print('%d %d' % (code.co_firstlineno, inlinetime), file=out_file)

        # recursive calls are counted in entry.calls
        if entry.calls:
            calls = entry.calls
        else:
            calls = []

        if isinstance(code, str):
            lineno = 0
        else:
            lineno = code.co_firstlineno

        for subentry in calls:
            self._subentry(lineno, subentry)
        print(file=out_file)

    def _subentry(self, lineno, subentry):
        out_file = self.out_file
        code = subentry.code
        print('cfn=%s' % label(code), file=out_file)
        if isinstance(code, str):
            print('cfi=~', file=out_file)
            print('calls=%d 0' % subentry.callcount, file=out_file)
        else:
            print('cfi=%s' % code.co_filename, file=out_file)
            print('calls=%d %d' % (
                subentry.callcount, code.co_firstlineno), file=out_file)

        totaltime = int(subentry.totaltime * 1000)
        print('%d %d' % (lineno, totaltime), file=out_file)