changeset 30316:faf1b8923da2

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.

--- a/mercurial/help/config.txt	Thu Oct 20 23:16:32 2016 +0900
+++ b/mercurial/help/config.txt	Fri Nov 04 20:50:38 2016 -0700
@@ -1409,9 +1409,9 @@
       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 @@
       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)

--- a/mercurial/profiling.py	Thu Oct 20 23:16:32 2016 +0900
+++ b/mercurial/profiling.py	Fri Nov 04 20:50:38 2016 -0700
@@ -80,11 +80,7 @@
 
 @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 @@
     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):

--- a/tests/test-profile.t	Thu Oct 20 23:16:32 2016 +0900
+++ b/tests/test-profile.t	Fri Nov 04 20:50:38 2016 -0700
@@ -47,4 +47,49 @@
 
 #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 ..