Mercurial > hg
view mercurial/profiling.py @ 35793:4fb2bb61597c
bundle2: increase payload part chunk size to 32kb
Bundle2 payload parts are framed chunks. Esentially, we obtain
data in equal size chunks of size `preferedchunksize` and emit those
to a generator. That generator is fed into a compressor (which can
be the no-op compressor, which just re-emits the generator). And
the output from the compressor likely goes to a file descriptor
or socket.
What this means is that small chunk sizes create more Python objects
and Python function calls than larger chunk sizes. And as we know,
Python object and function call overhead in performance sensitive
code matters (at least with CPython).
This commit increases the bundle2 part payload chunk size from 4k
to 32k. Practically speaking, this means that the chunks we feed
into a compressor (implemented in C code) or feed directly into a
file handle or socket write() are larger. It's possible the chunks
might be larger than what the receiver can handle in one logical
operation. But at that point, we're in C code, which is much more
efficient at dealing with splitting up the chunk and making multiple
function calls than Python is.
A downside to larger chunks is that the receiver has to wait for that
much data to arrive (either raw or from a decompressor) before it
can process the chunk. But 32kb still feels like a small buffer to
have to wait for. And in many cases, the client will convert from
8 read(4096) to 1 read(32768). That's happening in Python land. So
we cut down on the number of Python objects and function calls,
making the client faster as well. I don't think there are any
significant concerns to increasing the payload chunk size to 32kb.
The impact of this change on performance significant. Using `curl`
to obtain a stream clone bundle2 payload from a server on localhost
serving the mozilla-unified repository:
before: 20.78 user; 7.71 system; 80.5 MB/s
after: 13.90 user; 3.51 system; 132 MB/s
legacy: 9.72 user; 8.16 system; 132 MB/s
bundle2 stream clone generation is still more resource intensive than
legacy stream clone (that's likely because of the use of a
util.chunkbuffer). But the throughput is the same. We might
be in territory we're this is effectively a benchmark of the
networking stack or Python's syscall throughput.
From the client perspective, `hg clone -U --stream`:
before: 33.50 user; 7.95 system; 53.3 MB/s
after: 22.82 user; 7.33 system; 72.7 MB/s
legacy: 29.96 user; 7.94 system; 58.0 MB/s
And for `hg clone --stream` with a working directory update of
~230k files:
after: 119.55 user; 26.47 system; 0:57.08 wall
legacy: 126.98 user; 26.94 system; 1:05.56 wall
So, it appears that bundle2's stream clone is now definitively faster
than legacy stream clone!
Differential Revision: https://phab.mercurial-scm.org/D1932
author | Gregory Szorc <gregory.szorc@gmail.com> |
---|---|
date | Sat, 20 Jan 2018 22:55:42 -0800 |
parents | 83dfbda40e67 |
children | 7b86aa31b004 |
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 from .i18n import _ from . import ( encoding, error, extensions, util, ) def _loadprofiler(ui, profiler): """load profiler extension. return profile method, or None on failure""" extname = profiler extensions.loadall(ui, whitelist=[extname]) try: mod = extensions.find(extname) except KeyError: return None else: return getattr(mod, 'profile', None) @contextlib.contextmanager def lsprofile(ui, fp): format = ui.config('profiling', 'format') field = ui.config('profiling', 'sort') limit = ui.configint('profiling', 'limit') climit = ui.configint('profiling', 'nested') 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') filter_ = None collapse_recursion = True thread = flamegraph.ProfileThread(fp, 1.0 / freq, filter_, collapse_recursion) start_time = util.timer() try: thread.start() yield finally: thread.stop() thread.join() print('Collected %d stack frames (%d unique) in %2.2f seconds.' % ( util.timer() - start_time, thread.num_frames(), thread.num_frames(unique=True))) @contextlib.contextmanager def statprofile(ui, fp): from . import statprof freq = ui.configint('profiling', 'freq') 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(mechanism='thread') try: yield finally: data = statprof.stop() profformat = ui.config('profiling', 'statformat') formats = { 'byline': statprof.DisplayFormats.ByLine, 'bymethod': statprof.DisplayFormats.ByMethod, 'hotpath': statprof.DisplayFormats.Hotpath, 'json': statprof.DisplayFormats.Json, 'chrome': statprof.DisplayFormats.Chrome, } if profformat in formats: displayformat = formats[profformat] else: ui.warn(_('unknown profiler output format: %s\n') % profformat) displayformat = statprof.DisplayFormats.Hotpath kwargs = {} def fraction(s): if isinstance(s, (float, int)): return float(s) if s.endswith('%'): v = float(s[:-1]) / 100 else: v = float(s) if 0 <= v <= 1: return v raise ValueError(s) if profformat == 'chrome': showmin = ui.configwith(fraction, 'profiling', 'showmin', 0.005) showmax = ui.configwith(fraction, 'profiling', 'showmax') kwargs.update(minthreshold=showmin, maxthreshold=showmax) elif profformat == 'hotpath': # inconsistent config: profiling.showmin limit = ui.configwith(fraction, 'profiling', 'showmin', 0.05) kwargs['limit'] = limit statprof.display(fp, data=data, format=displayformat, **kwargs) class profile(object): """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. """ def __init__(self, ui, enabled=True): self._ui = ui self._output = None self._fp = None self._fpdoclose = True self._profiler = None self._enabled = enabled self._entered = False self._started = False def __enter__(self): self._entered = True if self._enabled: self.start() return self def start(self): """Start profiling. The profiling will stop at the context exit. If the profiler was already started, this has no effect.""" if not self._entered: raise error.ProgrammingError() if self._started: return self._started = True profiler = encoding.environ.get('HGPROF') proffn = None if profiler is None: profiler = self._ui.config('profiling', 'type') if profiler not in ('ls', 'stat', 'flame'): # try load profiler from extension with the same name proffn = _loadprofiler(self._ui, profiler) if proffn is None: self._ui.warn(_("unrecognized profiler '%s' - ignored\n") % profiler) profiler = 'stat' self._output = self._ui.config('profiling', 'output') try: if self._output == 'blackbox': self._fp = util.stringio() elif self._output: path = self._ui.expandpath(self._output) self._fp = open(path, 'wb') else: self._fpdoclose = False self._fp = self._ui.ferr if proffn is not None: pass elif profiler == 'ls': proffn = lsprofile elif profiler == 'flame': proffn = flameprofile else: proffn = statprofile self._profiler = proffn(self._ui, self._fp) self._profiler.__enter__() except: # re-raises self._closefp() raise def __exit__(self, exception_type, exception_value, traceback): propagate = None if self._profiler is not None: propagate = self._profiler.__exit__(exception_type, exception_value, traceback) if self._output == 'blackbox': val = 'Profile:\n%s' % self._fp.getvalue() # ui.log treats the input as a format string, # so we need to escape any % signs. val = val.replace('%', '%%') self._ui.log('profile', val) self._closefp() return propagate def _closefp(self): if self._fpdoclose and self._fp is not None: self._fp.close()