Mercurial > hg
view mercurial/lsprof.py @ 20182:04036798ebed
branches: avoid unnecessary changectx.branch() calls
This requires reading from the changelog, which can be costly over NFS.
Note that this does not totally remove reading from the changelog; we
still do that when calling changectx.closesbranch(). That call will be
removed in a later patch.
Running hg branches on the PyPy repo (with 996) over a busy NFS server,
before this change:
$ time hg --profile branches > /dev/null
CallCount Recursive Total(s) Inline(s) module:lineno(function)
2042 0 2.2827 2.2827 <open>
2036 0 0.9840 0.9840 <method 'close' of 'file' objects>
2036 0 0.0464 0.0464 <method 'read' of 'file' objects>
5233 0 0.1985 0.0453 mercurial.repoview:161(changelog)
10462 0 0.0791 0.0314 mercurial.changelog:133(tip)
5233 0 0.0388 0.0176 mercurial.localrepo:26(__get__)
10462 0 0.0250 0.0126 <len>
5233 0 0.0059 0.0039 mercurial.repoview:112(filterrevs)
10462 0 0.0029 0.0029 <hash>
2034 0 0.0444 0.0444 <method 'seek' of 'file' objects>
5340 0 0.0390 0.0390 mercurial.revlog:296(rev)
2582 0 0.0371 0.0371 <zlib.decompress>
3155 0 0.1963 0.0366 mercurial.context:202(__init__)
3155 0 0.1238 0.0306 mercurial.repoview:161(changelog)
3155 0 0.0261 0.0080 mercurial.changelog:183(rev)
9465 0 0.0061 0.0061 <isinstance>
1096 0 0.0023 0.0023 <binascii.unhexlify>
4251 0 0.0014 0.0014 <len>
2059 0 3.7341 0.0332 mercurial.changelog:270(read)
2059 0 3.6304 0.0307 mercurial.revlog:907(revision)
2057 0 0.0262 0.0137 mercurial.changelog:28(decodeextra)
4118 0 0.0094 0.0094 <method 'split' of 'str' objects>
4118 0 0.0270 0.0048 mercurial.encoding:61(tolocal)
2059 0 0.0040 0.0040 <method 'index' of 'str' objects>
10462 0 0.0791 0.0314 mercurial.changelog:133(tip)
10462 0 0.0289 0.0207 mercurial.changelog:190(node)
10462 0 0.0188 0.0091 <len>
52433 20932 0.0478 0.0310 <len>
20932 0 0.0221 0.0168 mercurial.revlog:262(__len__)
2059 0 3.6304 0.0307 mercurial.revlog:907(revision)
real 0m4.361s
user 0m0.986s
sys 0m0.237s
After this change:
$ time hg --profile branches > /dev/null
CallCount Recursive Total(s) Inline(s) module:lineno(function)
1069 0 1.1098 1.1098 <open>
1063 0 0.4865 0.4865 <method 'close' of 'file' objects>
4122 0 0.1811 0.0404 mercurial.repoview:161(changelog)
8240 0 0.0712 0.0272 mercurial.changelog:133(tip)
4122 0 0.0378 0.0177 mercurial.localrepo:26(__get__)
8240 0 0.0221 0.0115 <len>
4122 0 0.0057 0.0033 mercurial.repoview:112(filterrevs)
8240 0 0.0025 0.0025 <hash>
3029 0 0.1979 0.0371 mercurial.context:202(__init__)
3029 0 0.1278 0.0310 mercurial.repoview:161(changelog)
3029 0 0.0230 0.0081 mercurial.changelog:183(rev)
9087 0 0.0061 0.0061 <isinstance>
1096 0 0.0026 0.0026 <binascii.unhexlify>
4125 0 0.0014 0.0014 <len>
4229 0 0.0337 0.0337 mercurial.revlog:296(rev)
1061 0 0.0296 0.0296 <method 'seek' of 'file' objects>
1063 0 0.0292 0.0292 <method 'read' of 'file' objects>
8240 0 0.0712 0.0272 mercurial.changelog:133(tip)
8240 0 0.0271 0.0196 mercurial.changelog:190(node)
8240 0 0.0169 0.0083 <len>
40476 16488 0.0422 0.0271 <len>
16488 0 0.0193 0.0152 mercurial.revlog:262(__len__)
1342 0 0.0241 0.0241 <zlib.decompress>
9445 0 0.0336 0.0224 mercurial.changelog:190(node)
9445 0 0.0112 0.0112 mercurial.revlog:317(node)
1074 0 1.9102 0.0224 mercurial.changelog:270(read)
1074 0 1.8397 0.0202 mercurial.revlog:907(revision)
1073 0 0.0187 0.0099 mercurial.changelog:28(decodeextra)
2148 0 0.0061 0.0061 <method 'split' of 'str' objects>
2148 0 0.0184 0.0034 mercurial.encoding:61(tolocal)
real 0m2.402s
user 0m0.735s
sys 0m0.177s
author | Brodie Rao <brodie@sf.io> |
---|---|
date | Fri, 15 Nov 2013 23:18:08 -0500 |
parents | a40d608e2a7b |
children | 9c75daf89450 |
line wrap: on
line source
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(s)", "Inline(s)", "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 % (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()