mercurial/lsprofcalltree.py

stream-clone: avoid opening a revlog in case we do not need it

Opening an revlog has a cost, especially if it is inline as we have to scan the
file and construct an index.

To prevent the associated slowdown, we just do a minimal scan to check that an
inline file is still inline, and simply stream the file without creating a
revlog when we can.

This provides a big boost compared to the previous changeset, even if the full
generation is still penalized by the initial gathering of information.

All benchmarks are run on linux with Python 3.10.7.
# benchmark.name             = hg.exchange.stream.generate
# benchmark.variants.version = v2

### Compared to the previous changesets

We get a large win all across the board!

# mercurial-2018-08-01-zstd-sparse-revlog
before:  0.250694 seconds
after:   0.105986 seconds  (-57.72%)
# pypy-2018-08-01-zstd-sparse-revlog
before:  3.885657 seconds
after:   1.709748 seconds  (-56.00%)
# netbeans-2018-08-01-zstd-sparse-revlog
before: 16.679371 seconds
after:   7.687469 seconds  (-53.91%)
# mozilla-central-2018-08-01-zstd-sparse-revlog
before: 38.575482 seconds
after:  17.520316 seconds  (-54.58%)
# mozilla-try-2019-02-18-zstd-sparse-revlog
before: 81.160994 seconds
after:  37.073753 seconds  (-54.32%)



### Compared to 6.4.3

We are still significantly slower than 6.4.3, the extra time is usually twice
slower than the extra time we observe on the locked section, which is a quite
interesting information.

Except for mercurial-central that is much faster. That discrepancy is not really
explained yet.

# mercurial-2018-08-01-zstd-sparse-revlog
6.4.3:  0.072560 seconds
after:  0.105986 seconds  (+46.07%) (- 0.03 seconds)
# pypy-2018-08-01-zstd-sparse-revlog
6.4.3:  1.211193 seconds
after:  1.709748 seconds  (+41.16%) (-0.45 seconds)
# netbeans-2018-08-01-zstd-sparse-revlog
6.4.3:  4.932843 seconds
after:  7.687469 seconds  (+55.84%) (-2.75 seconds)
# mozilla-central-2018-08-01-zstd-sparse-revlog
6.4.3: 34.012226 seconds
after: 17.520316 seconds  (-48.49%) (-16.49 seconds)
# mozilla-try-2019-02-18-zstd-sparse-revlog
6.4.3: 23.850555 seconds
after: 37.073753 seconds  (+55.44%) (+13.22 seconds)

"""
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 . import pycompat


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


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

    def output(self, out_file):
        self.out_file = out_file
        out_file.write(b'events: Ticks\n')
        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)
        self.out_file.write(b'summary: %d\n' % max_cost)

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

        code = entry.code
        if isinstance(code, str):
            out_file.write(b'fi=~\n')
        else:
            out_file.write(b'fi=%s\n' % pycompat.sysbytes(code.co_filename))

        out_file.write(b'fn=%s\n' % label(code))

        inlinetime = int(entry.inlinetime * 1000)
        if isinstance(code, str):
            out_file.write(b'0 %d\n' % inlinetime)
        else:
            out_file.write(b'%d %d\n' % (code.co_firstlineno, inlinetime))

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

        out_file.write(b'\n')

    def _subentry(self, lineno, subentry):
        out_file = self.out_file
        code = subentry.code
        out_file.write(b'cfn=%s\n' % label(code))
        if isinstance(code, str):
            out_file.write(b'cfi=~\n')
            out_file.write(b'calls=%d 0\n' % subentry.callcount)
        else:
            out_file.write(b'cfi=%s\n' % pycompat.sysbytes(code.co_filename))
            out_file.write(
                b'calls=%d %d\n' % (subentry.callcount, code.co_firstlineno)
            )

        totaltime = int(subentry.totaltime * 1000)
        out_file.write(b'%d %d\n' % (lineno, totaltime))