annotate mercurial/lsprof.py @ 16719:e7bf09acd410

localrepo: add branchtip() method for faster single-branch lookups

For the PyPy repo with 744 branches and 843 branch heads, this brings
hg log -r default over NFS from:

   CallCount    Recursive    Total(ms)   Inline(ms) module:lineno(function)
        3249            0      1.3222      1.3222   <open>
        3244            0      0.6211      0.6211   <method 'close' of 'file' objects>
        3243            0      0.0800      0.0800   <method 'read' of 'file' objects>
        3241            0      0.0660      0.0660   <method 'seek' of 'file' objects>
        3905            0      0.0476      0.0476   <zlib.decompress>
        3281            0      2.6756      0.0472   mercurial.changelog:182(read)
       +3281            0      2.5256      0.0453   +mercurial.revlog:881(revision)
       +3276            0      0.0389      0.0196   +mercurial.changelog:28(decodeextra)
       +6562            0      0.0123      0.0123   +<method 'split' of 'str' objects>
       +6562            0      0.0408      0.0073   +mercurial.encoding:61(tolocal)
       +3281            0      0.0054      0.0054   +<method 'index' of 'str' objects>
        3241            0      2.2464      0.0456   mercurial.revlog:818(_loadchunk)
       +3241            0      0.6205      0.6205   +<method 'close' of 'file' objects>
       +3241            0      0.0765      0.0765   +<method 'read' of 'file' objects>
       +3241            0      0.0660      0.0660   +<method 'seek' of 'file' objects>
       +3241            0      1.4209      0.0135   +mercurial.store:374(__call__)
       +3241            0      0.0122      0.0107   +mercurial.revlog:810(_addchunk)
        3281            0      2.5256      0.0453   mercurial.revlog:881(revision)
       +3280            0      0.0175      0.0175   +mercurial.revlog:305(rev)
       +3281            0      2.2819      0.0119   +mercurial.revlog:847(_chunkraw)
       +3281            0      0.0603      0.0083   +mercurial.revlog:945(_checkhash)
       +3281            0      0.0051      0.0051   +mercurial.revlog:349(flags)
       +3281            0      0.0040      0.0040   +<mercurial.mpatch.patches>
       13682            0      0.0479      0.0248   <method 'decode' of 'str' objects>
       +7418            0      0.0228      0.0076   +encodings.utf_8:15(decode)
          +1            0      0.0003      0.0000   +encodings:71(search_function)
        3248            0      1.3995      0.0246   mercurial.scmutil:218(__call__)
       +3248            0      1.3222      1.3222   +<open>
       +3248            0      0.0235      0.0184   +os.path:80(split)
       +3248            0      0.0084      0.0068   +mercurial.scmutil:92(__call__)
Time: real 2.750 secs (user 0.680+0.000 sys 0.360+0.000)

down to:

   CallCount    Recursive    Total(ms)   Inline(ms) module:lineno(function)
          55           31      0.0197      0.0163   <__import__>
          +1            0      0.0006      0.0002   +mercurial.context:8(<module>)
          +1            0      0.0042      0.0001   +mercurial.revlog:12(<module>)
          +1            0      0.0002      0.0001   +mercurial.match:8(<module>)
          +1            0      0.0003      0.0001   +mercurial.dirstate:7(<module>)
          +1            0      0.0057      0.0001   +mercurial.changelog:8(<module>)
           1            0      0.0117      0.0032   mercurial.localrepo:525(_readbranchcache)
        +844            0      0.0015      0.0015   +<binascii.unhexlify>
        +845            0      0.0010      0.0010   +<method 'split' of 'str' objects>
        +843            0      0.0045      0.0009   +mercurial.encoding:61(tolocal)
        +843            0      0.0004      0.0004   +<method 'setdefault' of 'dict' objects>
          +1            0      0.0003      0.0003   +<method 'close' of 'file' objects>
           3            0      0.0029      0.0029   <method 'read' of 'file' objects>
           9            0      0.0018      0.0018   <open>
         990            0      0.0017      0.0017   <binascii.unhexlify>
          53            0      0.0016      0.0016   mercurial.demandimport:43(__init__)
         862            0      0.0015      0.0015   <_codecs.utf_8_decode>
         862            0      0.0037      0.0014   <method 'decode' of 'str' objects>
        +862            0      0.0023      0.0008   +encodings.utf_8:15(decode)
         981            0      0.0011      0.0011   <method 'split' of 'str' objects>
         861            0      0.0046      0.0009   mercurial.encoding:61(tolocal)
        +861            0      0.0037      0.0014   +<method 'decode' of 'str' objects>
         862            0      0.0023      0.0008   encodings.utf_8:15(decode)
        +862            0      0.0015      0.0015   +<_codecs.utf_8_decode>
           4            0      0.0008      0.0008   <method 'close' of 'file' objects>
         179          154      0.0202      0.0004   mercurial.demandimport:83(__getattribute__)
         +36           11      0.0199      0.0003   +mercurial.demandimport:55(_load)
         +72            0      0.0001      0.0001   +mercurial.demandimport:83(__getattribute__)
         +36            0      0.0000      0.0000   +<getattr>
           1            0      0.0015      0.0004   mercurial.tags:148(_readtagcache)
Time: real 0.060 secs (user 0.030+0.000 sys 0.010+0.000)

import sys
from _lsprof import Profiler, profiler_entry

__all__ = ['profile', 'Stats']

def profile(f, *args, **kwds):
    """XXX docstring"""
    p = Profiler()
    p.enable(subcalls=True, builtins=True)
    try:
        f(*args, **kwds)
    finally:
        p.disable()
    return Stats(p.getstats())


class Stats(object):
    """XXX docstring"""

    def __init__(self, data):
        self.data = data

    def sort(self, crit="inlinetime"):
        """XXX docstring"""
        if crit not in profiler_entry.__dict__:
            raise ValueError("Can't sort by %s" % crit)
        self.data.sort(key=lambda x: getattr(x, crit), reverse=True)
        for e in self.data:
            if e.calls:
                e.calls.sort(key=lambda x: getattr(x, crit), reverse=True)

    def pprint(self, top=None, file=None, limit=None, climit=None):
        """XXX docstring"""
        if file is None:
            file = sys.stdout
        d = self.data
        if top is not None:
            d = d[:top]
        cols = "% 12s %12s %11.4f %11.4f   %s\n"
        hcols = "% 12s %12s %12s %12s %s\n"
        file.write(hcols % ("CallCount", "Recursive", "Total(ms)",
                            "Inline(ms)", "module:lineno(function)"))
        count = 0
        for e in d:
            file.write(cols % (e.callcount, e.reccallcount, e.totaltime,
                               e.inlinetime, label(e.code)))
            count += 1
            if limit is not None and count == limit:
                return
            ccount = 0
            if climit and e.calls:
                for se in e.calls:
                    file.write(cols % ("+%s" % se.callcount, se.reccallcount,
                                       se.totaltime, se.inlinetime,
                                       "+%s" % label(se.code)))
                    count += 1
                    ccount += 1
                    if limit is not None and count == limit:
                        return
                    if climit is not None and ccount == climit:
                        break

    def freeze(self):
        """Replace all references to code objects with string
        descriptions; this makes it possible to pickle the instance."""

        # this code is probably rather ickier than it needs to be!
        for i in range(len(self.data)):
            e = self.data[i]
            if not isinstance(e.code, str):
                self.data[i] = type(e)((label(e.code),) + e[1:])
            if e.calls:
                for j in range(len(e.calls)):
                    se = e.calls[j]
                    if not isinstance(se.code, str):
                        e.calls[j] = type(se)((label(se.code),) + se[1:])

_fn2mod = {}

def label(code):
    if isinstance(code, str):
        return code
    try:
        mname = _fn2mod[code.co_filename]
    except KeyError:
        for k, v in list(sys.modules.iteritems()):
            if v is None:
                continue
            if not isinstance(getattr(v, '__file__', None), str):
                continue
            if v.__file__.startswith(code.co_filename):
                mname = _fn2mod[code.co_filename] = k
                break
        else:
            mname = _fn2mod[code.co_filename] = '<%s>' % code.co_filename

    return '%s:%d(%s)' % (mname, code.co_firstlineno, code.co_name)


if __name__ == '__main__':
    import os
    sys.argv = sys.argv[1:]
    if not sys.argv:
        print >> sys.stderr, "usage: lsprof.py <script> <arguments...>"
        sys.exit(2)
    sys.path.insert(0, os.path.abspath(os.path.dirname(sys.argv[0])))
    stats = profile(execfile, sys.argv[0], globals(), locals())
    stats.sort()
    stats.pprint()