Mercurial > hg
view mercurial/profiling.py @ 29830:92ac2baaea86
revlog: use an LRU cache for delta chain bases
Profiling using statprof revealed a hotspot during changegroup
application calculating delta chain bases on generaldelta repos.
Essentially, revlog._addrevision() was performing a lot of redundant
work tracing the delta chain as part of determining when the chain
distance was acceptable. This was most pronounced when adding
revisions to manifests, which can have delta chains thousands of
revisions long.
There was a delta chain base cache on revlogs before, but it only
captured a single revision. This was acceptable before generaldelta,
when _addrevision would build deltas from the previous revision and
thus we'd pretty much guarantee a cache hit when resolving the delta
chain base on a subsequent _addrevision call. However, it isn't
suitable for generaldelta because parent revisions aren't necessarily
the last processed revision.
This patch converts the delta chain base cache to an LRU dict cache.
The cache can hold multiple entries, so generaldelta repos have a
higher chance of getting a cache hit.
The impact of this change when processing changegroup additions is
significant. On a generaldelta conversion of the "mozilla-unified"
repo (which contains heads of the main Firefox repositories in
chronological order - this means there are lots of transitions between
heads in revlog order), this change has the following impact when
performing an `hg unbundle` of an uncompressed bundle of the repo:
before: 5:42 CPU time
after: 4:34 CPU time
Most of this time is saved when applying the changelog and manifest
revlogs:
before: 2:30 CPU time
after: 1:17 CPU time
That nearly a 50% reduction in CPU time applying changesets and
manifests!
Applying a gzipped bundle of the same repo (effectively simulating a
`hg clone` over HTTP) showed a similar speedup:
before: 5:53 CPU time
after: 4:46 CPU time
Wall time improvements were basically the same as CPU time.
I didn't measure explicitly, but it feels like most of the time
is saved when processing manifests. This makes sense, as large
manifests tend to have very long delta chains and thus benefit the
most from this cache.
So, this change effectively makes changegroup application (which is
used by `hg unbundle`, `hg clone`, `hg pull`, `hg unshelve`, and
various other commands) significantly faster when delta chains are
long (which can happen on repos with large numbers of files and thus
large manifests).
In theory, this change can result in more memory utilization. However,
we're caching a dict of ints. At most we have 200 ints + Python object
overhead per revlog. And, the cache is really only populated when
performing read-heavy operations, such as adding changegroups or
scanning an individual revlog. For memory bloat to be an issue, we'd
need to scan/read several revisions from several revlogs all while
having active references to several revlogs. I don't think there are
many operations that do this, so I don't think memory bloat from the
cache will be an issue.
author | Gregory Szorc <gregory.szorc@gmail.com> |
---|---|
date | Mon, 22 Aug 2016 21:48:50 -0700 |
parents | 88d3c1ab03a7 |
children | faf1b8923da2 |
line wrap: on
line source
# profiling.py - profiling functions # # Copyright 2016 Gregory Szorc <gregory.szorc@gmail.com> # # This software may be used and distributed according to the terms of the # GNU General Public License version 2 or any later version. from __future__ import absolute_import, print_function import contextlib import os import sys import time from .i18n import _ from . import ( error, util, ) @contextlib.contextmanager def lsprofile(ui, fp): format = ui.config('profiling', 'format', default='text') field = ui.config('profiling', 'sort', default='inlinetime') limit = ui.configint('profiling', 'limit', default=30) climit = ui.configint('profiling', 'nested', default=0) if format not in ['text', 'kcachegrind']: ui.warn(_("unrecognized profiling format '%s'" " - Ignored\n") % format) format = 'text' try: from . import lsprof except ImportError: raise error.Abort(_( 'lsprof not available - install from ' 'http://codespeak.net/svn/user/arigo/hack/misc/lsprof/')) p = lsprof.Profiler() p.enable(subcalls=True) try: yield finally: p.disable() if format == 'kcachegrind': from . import lsprofcalltree calltree = lsprofcalltree.KCacheGrind(p) calltree.output(fp) else: # format == 'text' stats = lsprof.Stats(p.getstats()) stats.sort(field) stats.pprint(limit=limit, file=fp, climit=climit) @contextlib.contextmanager def flameprofile(ui, fp): try: from flamegraph import flamegraph except ImportError: raise error.Abort(_( 'flamegraph not available - install from ' 'https://github.com/evanhempel/python-flamegraph')) # developer config: profiling.freq freq = ui.configint('profiling', 'freq', default=1000) filter_ = None collapse_recursion = True thread = flamegraph.ProfileThread(fp, 1.0 / freq, filter_, collapse_recursion) start_time = time.clock() try: thread.start() yield finally: thread.stop() thread.join() print('Collected %d stack frames (%d unique) in %2.2f seconds.' % ( time.clock() - start_time, thread.num_frames(), thread.num_frames(unique=True))) @contextlib.contextmanager def statprofile(ui, fp): try: import statprof except ImportError: raise error.Abort(_( 'statprof not available - install using "easy_install statprof"')) freq = ui.configint('profiling', 'freq', default=1000) if freq > 0: # Cannot reset when profiler is already active. So silently no-op. if statprof.state.profile_level == 0: statprof.reset(freq) else: ui.warn(_("invalid sampling frequency '%s' - ignoring\n") % freq) statprof.start() try: yield finally: statprof.stop() statprof.display(fp) @contextlib.contextmanager def profile(ui): """Start profiling. Profiling is active when the context manager is active. When the context manager exits, profiling results will be written to the configured output. """ profiler = os.getenv('HGPROF') if profiler is None: profiler = ui.config('profiling', 'type', default='ls') if profiler not in ('ls', 'stat', 'flame'): ui.warn(_("unrecognized profiler '%s' - ignored\n") % profiler) profiler = 'ls' output = ui.config('profiling', 'output') if output == 'blackbox': fp = util.stringio() elif output: path = ui.expandpath(output) fp = open(path, 'wb') else: fp = sys.stderr try: if profiler == 'ls': proffn = lsprofile elif profiler == 'flame': proffn = flameprofile else: proffn = statprofile with proffn(ui, fp): yield finally: if output: if output == 'blackbox': val = 'Profile:\n%s' % fp.getvalue() # ui.log treats the input as a format string, # so we need to escape any % signs. val = val.replace('%', '%%') ui.log('profile', val) fp.close() @contextlib.contextmanager def maybeprofile(ui): """Profile if enabled, else do nothing. This context manager can be used to optionally profile if profiling is enabled. Otherwise, it does nothing. The purpose of this context manager is to make calling code simpler: just use a single code path for calling into code you may want to profile and this function determines whether to start profiling. """ if ui.configbool('profiling', 'enabled'): with profile(ui): yield else: yield