# HG changeset patch # User Gregory Szorc # Date 2016-11-05 03:50:38 # Node ID faf1b8923da222dc172e072c77bba3893f8f7ae8 # Parent 0911191dc4c97cbc8334c8b83782e8134bf621f0 profiling: use vendored statprof and upstream enhancements (BC) Now that the statprof module is vendored and suitable for use, we switch our statprof profiler to use it. This required some minor changes because of drift between the official statprof profiler and the vendored copy. We also incorporate Facebook's improvements from the "statprofext" extension at https://bitbucket.org/facebook/hg-experimental, notably support for different display formats. Because statprof output is different, this is marked as BC. Although most users likely won't notice since most users don't profile. diff --git a/mercurial/help/config.txt b/mercurial/help/config.txt --- a/mercurial/help/config.txt +++ b/mercurial/help/config.txt @@ -1409,9 +1409,9 @@ profiling is done using lsprof. first line of a function. This restriction makes it difficult to identify the expensive parts of a non-trivial function. ``stat`` - Use a third-party statistical profiler, statprof. This profiler - currently runs only on Unix systems, and is most useful for - profiling commands that run for longer than about 0.1 seconds. + Use a statistical profiler, statprof. This profiler is most + most useful for profiling commands that run for longer than + about 0.1 seconds. ``format`` Profiling format. Specific to the ``ls`` instrumenting profiler. @@ -1426,6 +1426,20 @@ profiling is done using lsprof. file, the generated file can directly be loaded into kcachegrind. +``statformat`` + Profiling format for the ``stat`` profiler. + (default: hotpath) + + ``hotpath`` + Show a tree-based display containing the hot path of execution (where + most time was spent). + ``bymethod`` + Show a table of methods ordered by how frequently they are active. + ``byline`` + Show a table of lines in files ordered by how frequently they are active. + ``json`` + Render profiling data as JSON. + ``frequency`` Sampling frequency. Specific to the ``stat`` sampling profiler. (default: 1000) diff --git a/mercurial/profiling.py b/mercurial/profiling.py --- a/mercurial/profiling.py +++ b/mercurial/profiling.py @@ -80,11 +80,7 @@ def flameprofile(ui, fp): @contextlib.contextmanager def statprofile(ui, fp): - try: - import statprof - except ImportError: - raise error.Abort(_( - 'statprof not available - install using "easy_install statprof"')) + from . import statprof freq = ui.configint('profiling', 'freq', default=1000) if freq > 0: @@ -94,12 +90,29 @@ def statprofile(ui, fp): else: ui.warn(_("invalid sampling frequency '%s' - ignoring\n") % freq) - statprof.start() + statprof.start(mechanism='thread') + try: yield finally: - statprof.stop() - statprof.display(fp) + data = statprof.stop() + + profformat = ui.config('profiling', 'statformat', 'hotpath') + + formats = { + 'byline': statprof.DisplayFormats.ByLine, + 'bymethod': statprof.DisplayFormats.ByMethod, + 'hotpath': statprof.DisplayFormats.Hotpath, + 'json': statprof.DisplayFormats.Json, + } + + if profformat in formats: + displayformat = formats[profformat] + else: + ui.warn(_('unknown profiler output format: %s\n') % profformat) + displayformat = statprof.DisplayFormats.Hotpath + + statprof.display(fp, data=data, format=displayformat) @contextlib.contextmanager def profile(ui): diff --git a/tests/test-profile.t b/tests/test-profile.t --- a/tests/test-profile.t +++ b/tests/test-profile.t @@ -47,4 +47,49 @@ A single profile is logged because file #endif +Install an extension that can sleep and guarantee a profiler has time to run + + $ cat >> sleepext.py << EOF + > import time + > from mercurial import cmdutil, commands + > cmdtable = {} + > command = cmdutil.command(cmdtable) + > @command('sleep', [], 'hg sleep') + > def sleep(ui, *args, **kwargs): + > time.sleep(0.1) + > EOF + + $ cat >> $HGRCPATH << EOF + > [extensions] + > sleep = `pwd`/sleepext.py + > EOF + +statistical profiler works + + $ HGPROF=stat hg --profile sleep 2>../out + $ grep Sample ../out + Sample count: \d+ (re) + +Various statprof formatters work + + $ HGPROF=stat hg --profile --config profiling.statformat=byline sleep 2>../out + $ head -n 1 ../out + % cumulative self + $ grep Sample ../out + Sample count: \d+ (re) + + $ HGPROF=stat hg --profile --config profiling.statformat=bymethod sleep 2>../out + $ head -n 1 ../out + % cumulative self + $ grep Sample ../out + Sample count: \d+ (re) + + $ HGPROF=stat hg --profile --config profiling.statformat=hotpath sleep 2>../out + $ grep Sample ../out + Sample count: \d+ (re) + + $ HGPROF=stat hg --profile --config profiling.statformat=json sleep 2>../out + $ cat ../out + \[\[\d+.* (re) + $ cd ..