Patchwork [1,of,6] profile: upgrade the "profile" context manager to a full class

login
register
mail settings
Submitter Pierre-Yves David
Date June 9, 2017, 12:32 p.m.
Message ID <a3a4b52464f3dbaf533f.1497011577@nodosa.octopoid.net>
Download mbox | patch
Permalink /patch/21280/
State Accepted
Headers show

Comments

Pierre-Yves David - June 9, 2017, 12:32 p.m.
# HG changeset patch
# User Pierre-Yves David <pierre-yves.david@octobus.net>
# Date 1496882328 -3600
#      Thu Jun 08 01:38:48 2017 +0100
# Node ID a3a4b52464f3dbaf533f62bca7512f42c6a6d449
# Parent  3ef319e9505f376775c91b2ab7d89ac9ac4343e9
# EXP-Topic profile
# Available At https://www.mercurial-scm.org/repo/users/marmoute/mercurial/
#              hg pull https://www.mercurial-scm.org/repo/users/marmoute/mercurial/ -r a3a4b52464f3
profile: upgrade the "profile" context manager to a full class

So far we have been able to use a simple decorator for this. However using the
current context manager makes the scope of the profiling in dispatch
constrainted and the time frame to decide to enable profiling quite limited
(using "maybeprofile")

This is the first step toward the ability to enable the profiling from within
the profiling scope. eg::

  with maybeprofiling(ui) as profiler:
      ...
      bar.foo():
      ...
      if options['profile']:
          profiler.start()
      ...
      fooz()
      ...

My target usecase is adding support for  "--profile" to alias definitions with
effect.  These are to be used with "profiling.output=blackbox" to gather data
about operation that get slow from time to time (eg: pull being minutes instead
of seconds from time to time).

Of course, in such case, the scope of the profiling would be smaller since
profiler would be started after running extensions 'reposetup' (and other
potentially costly logic), but these are not relevant for my target usecase
(multiple second commits, multiple tens of seconds pull).

Currently adding '--profile' to a command through alias requires to re-spin a
Mercurial binary (using "!$HG" in alias), which as a significant performance
impact, especially in context where startup performance is being worked on...

An alternative approach would be to stop using the context manager in dispatch
and move back to a try/finally setup.
Pierre-Yves David - June 9, 2017, 1:07 p.m.
On 06/09/2017 01:32 PM, Pierre-Yves David wrote:
> # HG changeset patch
> # User Pierre-Yves David <pierre-yves.david@octobus.net>
> # Date 1496882328 -3600
> #      Thu Jun 08 01:38:48 2017 +0100
> # Node ID a3a4b52464f3dbaf533f62bca7512f42c6a6d449
> # Parent  3ef319e9505f376775c91b2ab7d89ac9ac4343e9
> # EXP-Topic profile
> # Available At https://www.mercurial-scm.org/repo/users/marmoute/mercurial/
> #              hg pull https://www.mercurial-scm.org/repo/users/marmoute/mercurial/ -r a3a4b52464f3
> profile: upgrade the "profile" context manager to a full class
>
> So far we have been able to use a simple decorator for this. However using the
> current context manager makes the scope of the profiling in dispatch
> constrainted and the time frame to decide to enable profiling quite limited
> (using "maybeprofile")
>
> This is the first step toward the ability to enable the profiling from within
> the profiling scope. eg::
>
>   with maybeprofiling(ui) as profiler:
>       ...
>       bar.foo():
>       ...
>       if options['profile']:
>           profiler.start()
>       ...
>       fooz()
>       ...
>
> My target usecase is adding support for  "--profile" to alias definitions with
> effect.  These are to be used with "profiling.output=blackbox" to gather data
> about operation that get slow from time to time (eg: pull being minutes instead
> of seconds from time to time).

While backporting this series to an older Mercurial, I found out that it 
used to works fine, but got regressed (for good reason) in 4.2. The 
regression comes a changeset that move the profiling boundaries to 
includes the extensions loading time.

   changeset:   30934:6d642ecf1a89
   user:        Bryan O'Sullivan <bryano@fb.com>
   date:        Mon Feb 13 20:47:41 2017 -0800
   summary:     dispatch: start profiling earlier

Cheers,
Yuya Nishihara - June 12, 2017, 1:33 p.m.
On Fri, 09 Jun 2017 13:32:57 +0100, Pierre-Yves David wrote:
> # HG changeset patch
> # User Pierre-Yves David <pierre-yves.david@octobus.net>
> # Date 1496882328 -3600
> #      Thu Jun 08 01:38:48 2017 +0100
> # Node ID a3a4b52464f3dbaf533f62bca7512f42c6a6d449
> # Parent  3ef319e9505f376775c91b2ab7d89ac9ac4343e9
> # EXP-Topic profile
> # Available At https://www.mercurial-scm.org/repo/users/marmoute/mercurial/
> #              hg pull https://www.mercurial-scm.org/repo/users/marmoute/mercurial/ -r a3a4b52464f3
> profile: upgrade the "profile" context manager to a full class

Generally looks good. Queued, thanks.

> +    def __enter__(self):
> +        profiler = encoding.environ.get('HGPROF')
> +        proffn = None
> +        if profiler is None:
> +            profiler = self._ui.config('profiling', 'type', default='stat')
> +        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'
>  
> -    if output == 'blackbox':
> -        fp = util.stringio()
> -    elif output:
> -        path = ui.expandpath(output)
> -        fp = open(path, 'wb')
> -    else:
> -        fp = ui.ferr
> +        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._fp = self._ui.ferr
> +
>          if proffn is not None:
>              pass
>          elif profiler == 'ls':
> @@ -179,18 +185,21 @@ def profile(ui):
>          else:
>              proffn = statprofile
>  
> -        with proffn(ui, fp):
> -            yield
> +        self._profiler = proffn(self._ui, self._fp)
> +        self._profiler.__enter__()

Nit: Perhaps the output file should be closed if the initialization of
self._profiler failed.
Pierre-Yves David - June 12, 2017, 3:06 p.m.
On 06/12/2017 03:33 PM, Yuya Nishihara wrote:
> On Fri, 09 Jun 2017 13:32:57 +0100, Pierre-Yves David wrote:
>> # HG changeset patch
>> # User Pierre-Yves David <pierre-yves.david@octobus.net>
>> # Date 1496882328 -3600
>> #      Thu Jun 08 01:38:48 2017 +0100
>> # Node ID a3a4b52464f3dbaf533f62bca7512f42c6a6d449
>> # Parent  3ef319e9505f376775c91b2ab7d89ac9ac4343e9
>> # EXP-Topic profile
>> # Available At https://www.mercurial-scm.org/repo/users/marmoute/mercurial/
>> #              hg pull https://www.mercurial-scm.org/repo/users/marmoute/mercurial/ -r a3a4b52464f3
>> profile: upgrade the "profile" context manager to a full class
>
> Generally looks good. Queued, thanks.
>
>> +    def __enter__(self):
>> +        profiler = encoding.environ.get('HGPROF')
>> +        proffn = None
>> +        if profiler is None:
>> +            profiler = self._ui.config('profiling', 'type', default='stat')
>> +        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'
>>
>> -    if output == 'blackbox':
>> -        fp = util.stringio()
>> -    elif output:
>> -        path = ui.expandpath(output)
>> -        fp = open(path, 'wb')
>> -    else:
>> -        fp = ui.ferr
>> +        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._fp = self._ui.ferr
>> +
>>          if proffn is not None:
>>              pass
>>          elif profiler == 'ls':
>> @@ -179,18 +185,21 @@ def profile(ui):
>>          else:
>>              proffn = statprofile
>>
>> -        with proffn(ui, fp):
>> -            yield
>> +        self._profiler = proffn(self._ui, self._fp)
>> +        self._profiler.__enter__()
>
> Nit: Perhaps the output file should be closed if the initialization of
> self._profiler failed.

That is not a nit, this is a good semantic catch. I'll follow up with a 
fix. Thanks.

Cheers,

Patch

diff --git a/mercurial/profiling.py b/mercurial/profiling.py
--- a/mercurial/profiling.py
+++ b/mercurial/profiling.py
@@ -141,35 +141,41 @@  def statprofile(ui, fp):
 
         statprof.display(fp, data=data, format=displayformat, **kwargs)
 
-@contextlib.contextmanager
-def profile(ui):
+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.
     """
-    profiler = encoding.environ.get('HGPROF')
-    proffn = None
-    if profiler is None:
-        profiler = ui.config('profiling', 'type', default='stat')
-    if profiler not in ('ls', 'stat', 'flame'):
-        # try load profiler from extension with the same name
-        proffn = _loadprofiler(ui, profiler)
-        if proffn is None:
-            ui.warn(_("unrecognized profiler '%s' - ignored\n") % profiler)
-            profiler = 'stat'
+    def __init__(self, ui):
+        self._ui = ui
+        self._output = None
+        self._fp = None
+        self._profiler = None
 
-    output = ui.config('profiling', 'output')
+    def __enter__(self):
+        profiler = encoding.environ.get('HGPROF')
+        proffn = None
+        if profiler is None:
+            profiler = self._ui.config('profiling', 'type', default='stat')
+        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'
 
-    if output == 'blackbox':
-        fp = util.stringio()
-    elif output:
-        path = ui.expandpath(output)
-        fp = open(path, 'wb')
-    else:
-        fp = ui.ferr
+        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._fp = self._ui.ferr
+
         if proffn is not None:
             pass
         elif profiler == 'ls':
@@ -179,18 +185,21 @@  def profile(ui):
         else:
             proffn = statprofile
 
-        with proffn(ui, fp):
-            yield
+        self._profiler = proffn(self._ui, self._fp)
+        self._profiler.__enter__()
 
-    finally:
-        if output:
-            if output == 'blackbox':
-                val = 'Profile:\n%s' % fp.getvalue()
+    def __exit__(self, exception_type, exception_value, traceback):
+        if self._profiler is None:
+            return
+        self._profiler.__exit__(exception_type, exception_value, traceback)
+        if self._output:
+            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('%', '%%')
-                ui.log('profile', val)
-            fp.close()
+                self._ui.log('profile', val)
+            self._fp.close()
 
 @contextlib.contextmanager
 def maybeprofile(ui):