[PATCH] perf: get the timer function through
Augie Fackler
raf at durin42.com
Tue Nov 4 07:20:27 CST 2014
On Tue, Nov 04, 2014 at 01:08:45PM +0000, Pierre-Yves David wrote:
> # HG changeset patch
> # User Pierre-Yves David <pierre-yves.david at fb.com>
> # Date 1415097606 0
> # Tue Nov 04 10:40:06 2014 +0000
> # Node ID cec5c3a6139b79da12956a612df4f793c521408f
> # Parent 30e0dcd7c5ffd99fb9c2474e9d73ca01a7d292fa
> perf: get the timer function through
This summary line confuses me. Would "perf: use a formatter for
output" be better?
>
> We want to use a `formatter` object in the perf extensions. This will allow the
> use of formatted output like json. To avoid adding logic to create a formatter
> and passe it around to the timer function to every function, we add a function
> in charge of returning a `timer` function as simple as before but embedding an
> appropriate formatter.
+1
>
> This new `gettimer` function also return the formatter as it needs to be
> explicitly closed at the end of the command.
>
> example output:
>
>
> $ hg --config ui.formatjson=True perfvolatilesets visible obsolete
> [
> {
> "comb": 0.02,
> "count": 126,
> "sys": 0.0,
> "title": "obsolete",
> "user": 0.02,
> "wall": 0.0199398994446
> },
> {
> "comb": 0.02,
> "count": 117,
> "sys": 0.0,
> "title": "visible",
> "user": 0.02,
> "wall": 0.0250301361084
> }
> ]
>
> diff --git a/contrib/perf.py b/contrib/perf.py
> --- a/contrib/perf.py
> +++ b/contrib/perf.py
> @@ -2,15 +2,32 @@
> '''helper extension to measure performance'''
>
> from mercurial import cmdutil, scmutil, util, commands, obsolete
> from mercurial import repoview, branchmap, merge, copies
> import time, os, sys
> +import functools
>
> cmdtable = {}
> command = cmdutil.command(cmdtable)
>
> -def timer(func, title=None):
> +def gettimer(ui, opts=None):
>
Bonus points if you can come up with a better name than gettimer,
since it also gets a formatter.
> + """return a timer function and formatter: (timer, formatter)
> +
> + This functions exist to gather the creation of formatter in a single
> + place instead of duplicating it in all performance command.
> +
> + (the formatter creation code is not yet here)
But I see a ui.formatter() below? Am I missing something?
> """
> + if opts is None:
> + opts = {}
> + # redirect all to stderr
> + ui = ui.copy()
> + ui.fout = ui.ferr
> + # get a formatter
> + fm = ui.formatter('perf', opts)
> + return functools.partial(_timer, fm), fm
> +
> +def _timer(fm, func, title=None):
> results = []
> begin = time.time()
> count = 0
> while True:
> ostart = os.times()
> @@ -23,52 +40,68 @@ def timer(func, title=None):
> results.append((cstop - cstart, b[0] - a[0], b[1]-a[1]))
> if cstop - begin > 3 and count >= 100:
> break
> if cstop - begin > 10 and count >= 3:
> break
> +
> + fm.startitem()
> +
> if title:
> - sys.stderr.write("! %s\n" % title)
> + fm.write('title', '! %s\n', title)
> if r:
> - sys.stderr.write("! result: %s\n" % r)
> + fm.write('result', '! result: %s\n', r)
> m = min(results)
> - sys.stderr.write("! wall %f comb %f user %f sys %f (best of %d)\n"
> - % (m[0], m[1] + m[2], m[1], m[2], count))
> + fm.plain('!')
> + fm.write('wall', ' wall %f', m[0])
> + fm.write('comb', ' comb %f', m[1] + m[2])
> + fm.write('user', ' user %f', m[1])
> + fm.write('sys', ' sys %f', m[2])
> + fm.write('count', ' (best of %d)', count)
> + fm.plain('\n')
>
> @command('perfwalk')
> def perfwalk(ui, repo, *pats):
> + timer, fm = gettimer(ui)
> try:
> m = scmutil.match(repo[None], pats, {})
> timer(lambda: len(list(repo.dirstate.walk(m, [], True, False))))
> except Exception:
> try:
> m = scmutil.match(repo[None], pats, {})
> timer(lambda: len([b for a, b, c in repo.dirstate.statwalk([], m)]))
> except Exception:
> timer(lambda: len(list(cmdutil.walk(repo, pats, {}))))
> + fm.end()
>
> @command('perfannotate')
> def perfannotate(ui, repo, f):
> + timer, fm = gettimer(ui)
> fc = repo['.'][f]
> timer(lambda: len(fc.annotate(True)))
> + fm.end()
>
> @command('perfstatus',
> [('u', 'unknown', False,
> 'ask status to look for unknown files')])
> def perfstatus(ui, repo, **opts):
> #m = match.always(repo.root, repo.getcwd())
> #timer(lambda: sum(map(len, repo.dirstate.status(m, [], False, False,
> # False))))
> + timer, fm = gettimer(ui)
> timer(lambda: sum(map(len, repo.status(**opts))))
> + fm.end()
>
> @command('perfaddremove')
> def perfaddremove(ui, repo):
> + timer, fm = gettimer(ui)
> try:
> oldquiet = repo.ui.quiet
> repo.ui.quiet = True
> timer(lambda: scmutil.addremove(repo, dry_run=True))
> finally:
> repo.ui.quiet = oldquiet
> + fm.end()
>
> def clearcaches(cl):
> # behave somewhat consistently across internal API changes
> if util.safehasattr(cl, 'clearcaches'):
> cl.clearcaches()
> @@ -77,92 +110,111 @@ def clearcaches(cl):
> cl._nodecache = {nullid: nullrev}
> cl._nodepos = None
>
> @command('perfheads')
> def perfheads(ui, repo):
> + timer, fm = gettimer(ui)
> cl = repo.changelog
> def d():
> len(cl.headrevs())
> clearcaches(cl)
> timer(d)
> + fm.end()
>
> @command('perftags')
> def perftags(ui, repo):
> import mercurial.changelog
> import mercurial.manifest
> + timer, fm = gettimer(ui)
> def t():
> repo.changelog = mercurial.changelog.changelog(repo.sopener)
> repo.manifest = mercurial.manifest.manifest(repo.sopener)
> repo._tags = None
> return len(repo.tags())
> timer(t)
> + fm.end()
>
> @command('perfancestors')
> def perfancestors(ui, repo):
> + timer, fm = gettimer(ui)
> heads = repo.changelog.headrevs()
> def d():
> for a in repo.changelog.ancestors(heads):
> pass
> timer(d)
> + fm.end()
>
> @command('perfancestorset')
> def perfancestorset(ui, repo, revset):
> + timer, fm = gettimer(ui)
> revs = repo.revs(revset)
> heads = repo.changelog.headrevs()
> def d():
> s = repo.changelog.ancestors(heads)
> for rev in revs:
> rev in s
> timer(d)
> + fm.end()
>
> @command('perfdirs')
> def perfdirs(ui, repo):
> + timer, fm = gettimer(ui)
> dirstate = repo.dirstate
> 'a' in dirstate
> def d():
> dirstate.dirs()
> del dirstate._dirs
> timer(d)
> + fm.end()
>
> @command('perfdirstate')
> def perfdirstate(ui, repo):
> + timer, fm = gettimer(ui)
> "a" in repo.dirstate
> def d():
> repo.dirstate.invalidate()
> "a" in repo.dirstate
> timer(d)
> + fm.end()
>
> @command('perfdirstatedirs')
> def perfdirstatedirs(ui, repo):
> + timer, fm = gettimer(ui)
> "a" in repo.dirstate
> def d():
> "a" in repo.dirstate._dirs
> del repo.dirstate._dirs
> timer(d)
> + fm.end()
>
> @command('perfdirstatefoldmap')
> def perffoldmap(ui, repo):
> + timer, fm = gettimer(ui)
> dirstate = repo.dirstate
> 'a' in dirstate
> def d():
> dirstate._foldmap.get('a')
> del dirstate._foldmap
> del dirstate._dirs
> timer(d)
> + fm.end()
>
> @command('perfdirstatewrite')
> def perfdirstatewrite(ui, repo):
> + timer, fm = gettimer(ui)
> ds = repo.dirstate
> "a" in ds
> def d():
> ds._dirty = True
> ds.write()
> timer(d)
> + fm.end()
>
> @command('perfmergecalculate',
> [('r', 'rev', '.', 'rev to merge against')])
> def perfmergecalculate(ui, repo, rev):
> + timer, fm = gettimer(ui)
> wctx = repo[None]
> rctx = scmutil.revsingle(repo, rev, rev)
> ancestor = wctx.ancestor(rctx)
> # we don't want working dir files to be stat'd in the benchmark, so prime
> # that cache
> @@ -171,142 +223,176 @@ def perfmergecalculate(ui, repo, rev):
> # acceptremote is True because we don't want prompts in the middle of
> # our benchmark
> merge.calculateupdates(repo, wctx, rctx, ancestor, False, False, False,
> acceptremote=True)
> timer(d)
> + fm.end()
>
> @command('perfpathcopies', [], "REV REV")
> def perfpathcopies(ui, repo, rev1, rev2):
> + timer, fm = gettimer(ui)
> ctx1 = scmutil.revsingle(repo, rev1, rev1)
> ctx2 = scmutil.revsingle(repo, rev2, rev2)
> def d():
> copies.pathcopies(ctx1, ctx2)
> timer(d)
> + fm.end()
>
> @command('perfmanifest', [], 'REV')
> def perfmanifest(ui, repo, rev):
> + timer, fm = gettimer(ui)
> ctx = scmutil.revsingle(repo, rev, rev)
> t = ctx.manifestnode()
> def d():
> repo.manifest._mancache.clear()
> repo.manifest._cache = None
> repo.manifest.read(t)
> timer(d)
> + fm.end()
>
> @command('perfchangeset')
> def perfchangeset(ui, repo, rev):
> + timer, fm = gettimer(ui)
> n = repo[rev].node()
> def d():
> repo.changelog.read(n)
> #repo.changelog._cache = None
> timer(d)
> + fm.end()
>
> @command('perfindex')
> def perfindex(ui, repo):
> import mercurial.revlog
> + timer, fm = gettimer(ui)
> mercurial.revlog._prereadsize = 2**24 # disable lazy parser in old hg
> n = repo["tip"].node()
> def d():
> cl = mercurial.revlog.revlog(repo.sopener, "00changelog.i")
> cl.rev(n)
> timer(d)
> + fm.end()
>
> @command('perfstartup')
> def perfstartup(ui, repo):
> + timer, fm = gettimer(ui)
> cmd = sys.argv[0]
> def d():
> os.system("HGRCPATH= %s version -q > /dev/null" % cmd)
> timer(d)
> + fm.end()
>
> @command('perfparents')
> def perfparents(ui, repo):
> + timer, fm = gettimer(ui)
> nl = [repo.changelog.node(i) for i in xrange(1000)]
> def d():
> for n in nl:
> repo.changelog.parents(n)
> timer(d)
> + fm.end()
>
> @command('perflookup')
> def perflookup(ui, repo, rev):
> + timer, fm = gettimer(ui)
> timer(lambda: len(repo.lookup(rev)))
> + fm.end()
>
> @command('perfrevrange')
> def perfrevrange(ui, repo, *specs):
> + timer, fm = gettimer(ui)
> revrange = scmutil.revrange
> timer(lambda: len(revrange(repo, specs)))
> + fm.end()
>
> @command('perfnodelookup')
> def perfnodelookup(ui, repo, rev):
> + timer, fm = gettimer(ui)
> import mercurial.revlog
> mercurial.revlog._prereadsize = 2**24 # disable lazy parser in old hg
> n = repo[rev].node()
> cl = mercurial.revlog.revlog(repo.sopener, "00changelog.i")
> def d():
> cl.rev(n)
> clearcaches(cl)
> timer(d)
> + fm.end()
>
> @command('perflog',
> [('', 'rename', False, 'ask log to follow renames')])
> def perflog(ui, repo, **opts):
> + timer, fm = gettimer(ui)
> ui.pushbuffer()
> timer(lambda: commands.log(ui, repo, rev=[], date='', user='',
> copies=opts.get('rename')))
> ui.popbuffer()
> + fm.end()
>
> @command('perfmoonwalk')
> def perfmoonwalk(ui, repo):
> """benchmark walking the changelog backwards
>
> This also loads the changelog data for each revision in the changelog.
> """
> + timer, fm = gettimer(ui)
> def moonwalk():
> for i in xrange(len(repo), -1, -1):
> ctx = repo[i]
> ctx.branch() # read changelog data (in addition to the index)
> timer(moonwalk)
> + fm.end()
>
> @command('perftemplating')
> def perftemplating(ui, repo):
> + timer, fm = gettimer(ui)
> ui.pushbuffer()
> timer(lambda: commands.log(ui, repo, rev=[], date='', user='',
> template='{date|shortdate} [{rev}:{node|short}]'
> ' {author|person}: {desc|firstline}\n'))
> ui.popbuffer()
> + fm.end()
>
> @command('perfcca')
> def perfcca(ui, repo):
> + timer, fm = gettimer(ui)
> timer(lambda: scmutil.casecollisionauditor(ui, False, repo.dirstate))
> + fm.end()
>
> @command('perffncacheload')
> def perffncacheload(ui, repo):
> + timer, fm = gettimer(ui)
> s = repo.store
> def d():
> s.fncache._load()
> timer(d)
> + fm.end()
>
> @command('perffncachewrite')
> def perffncachewrite(ui, repo):
> + timer, fm = gettimer(ui)
> s = repo.store
> s.fncache._load()
> def d():
> s.fncache._dirty = True
> s.fncache.write()
> timer(d)
> + fm.end()
>
> @command('perffncacheencode')
> def perffncacheencode(ui, repo):
> + timer, fm = gettimer(ui)
> s = repo.store
> s.fncache._load()
> def d():
> for p in s.fncache.entries:
> s.encode(p)
> timer(d)
> + fm.end()
>
> @command('perfdiffwd')
> def perfdiffwd(ui, repo):
> """Profile diff of working directory changes"""
> + timer, fm = gettimer(ui)
> options = {
> 'w': 'ignore_all_space',
> 'b': 'ignore_space_change',
> 'B': 'ignore_blank_lines',
> }
> @@ -317,44 +403,50 @@ def perfdiffwd(ui, repo):
> ui.pushbuffer()
> commands.diff(ui, repo, **opts)
> ui.popbuffer()
> title = 'diffopts: %s' % (diffopt and ('-' + diffopt) or 'none')
> timer(d, title)
> + fm.end()
>
> @command('perfrevlog',
> [('d', 'dist', 100, 'distance between the revisions')],
> "[INDEXFILE]")
> def perfrevlog(ui, repo, file_, **opts):
> + timer, fm = gettimer(ui)
> from mercurial import revlog
> dist = opts['dist']
> def d():
> r = revlog.revlog(lambda fn: open(fn, 'rb'), file_)
> for x in xrange(0, len(r), dist):
> r.revision(r.node(x))
>
> timer(d)
> + fm.end()
>
> @command('perfrevset',
> [('C', 'clear', False, 'clear volatile cache between each call.')],
> "REVSET")
> def perfrevset(ui, repo, expr, clear=False):
> """benchmark the execution time of a revset
>
> Use the --clean option if need to evaluate the impact of build volatile
> revisions set cache on the revset execution. Volatile cache hold filtered
> and obsolete related cache."""
> + timer, fm = gettimer(ui)
> def d():
> if clear:
> repo.invalidatevolatilesets()
> for r in repo.revs(expr): pass
> timer(d)
> + fm.end()
>
> @command('perfvolatilesets')
> def perfvolatilesets(ui, repo, *names):
> """benchmark the computation of various volatile set
>
> Volatile set computes element related to filtering and obsolescence."""
> + timer, fm = gettimer(ui)
> repo = repo.unfiltered()
>
> def getobs(name):
> def d():
> repo.invalidatevolatilesets()
> @@ -378,20 +470,22 @@ def perfvolatilesets(ui, repo, *names):
> if names:
> allfilter = [n for n in allfilter if n in names]
>
> for name in allfilter:
> timer(getfiltered(name), title=name)
> + fm.end()
>
> @command('perfbranchmap',
> [('f', 'full', False,
> 'Includes build time of subset'),
> ])
> def perfbranchmap(ui, repo, full=False):
> """benchmark the update of a branchmap
>
> This benchmarks the full repo.branchmap() call with read and write disabled
> """
> + timer, fm = gettimer(ui)
> def getbranchmap(filtername):
> """generate a benchmark function for the filtername"""
> if filtername is None:
> view = repo
> else:
> @@ -430,5 +524,6 @@ def perfbranchmap(ui, repo, full=False):
> for name in allfilters:
> timer(getbranchmap(name), title=str(name))
> finally:
> branchmap.read = oldread
> branchmap.branchcache.write = oldwrite
> + fm.end()
> _______________________________________________
> Mercurial-devel mailing list
> Mercurial-devel at selenic.com
> http://selenic.com/mailman/listinfo/mercurial-devel
More information about the Mercurial-devel
mailing list