[Python-ideas] Allow Profile() to be used as a context manager

[Robert Kern]

On 1/25/12 8:19 AM, Yuval Greenfield wrote:
> On Wed, Jan 25, 2012 at 8:36 AM, David Townshend
> <aquavitae69 at gmail.com
> <mailto:aquavitae69 at gmail.com>> wrote:
>
>     [...]
>     Any major objections to this?
>
>
>
>   At first this sounded like a good idea but 2 things pop to mind:
>
>  1. How does one get the pstat profiling output from the context manager? Will
>     printing out the results be the only option?
>  2. Usually when I profile I don't want to touch the code at all so eventually
>     if I'll use this context manager it'll be more akin to
>
>
>      with profile.Profiler():
>          main()
>
> Which isn't much of a win over
>
>      profile.run('main()')
>
>
> Now if you're talking about a reentrant profiler, that's interesting:
>
>      profiler = profile.Profiler()
>
>      while is_working:
>          with profiler:
>              do_hard_task()
>      do_a_hard_but_i_dont_care_now_task()
>
>      with profiler:
>          do_a_diff_hard_task()
>
>
> and then I can call whatever method is there to get the pstat. If this is the
> vision then it sounds awesome.

<shameless-advertisement>

You may want to take a look at my kernprof script mentioned elsewhere in the thread:

   http://packages.python.org/line_profiler/
   http://pypi.python.org/pypi/line_profiler/

Besides adding the context manager to Profile, it is a generic "runner" script 
that will run your script under the profiler and dump the results to a file. In 
the normal use case of profiling the entire script, you don't have to modify 
your code at all:

   [line_profiler]$ kernprof.py -v pystone.py
   Pystone(1.1) time for 50000 passes = 0.918603
   This machine benchmarks at 54430.5 pystones/second
   Wrote profile results to pystone.py.prof
            1100070 function calls in 0.929 seconds

      Ordered by: standard name

      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
           1    0.000    0.000    0.929    0.929 <string>:1(<module>)
       50000    0.140    0.000    0.322    0.000 pystone.py:137(Proc1)
       50000    0.029    0.000    0.029    0.000 pystone.py:153(Proc2)
       50000    0.036    0.000    0.048    0.000 pystone.py:164(Proc3)
       50000    0.015    0.000    0.015    0.000 pystone.py:174(Proc4)
       50000    0.013    0.000    0.013    0.000 pystone.py:181(Proc5)
       50000    0.033    0.000    0.043    0.000 pystone.py:188(Proc6)
      150000    0.034    0.000    0.034    0.000 pystone.py:207(Proc7)
       50000    0.100    0.000    0.126    0.000 pystone.py:212(Proc8)
      150000    0.035    0.000    0.035    0.000 pystone.py:225(Func1)
   ...

But if you do want to use the context manager or the decorator, then there is a 
flag to the script that injects the Profile instance into the builtins. Then you 
can use "@profile" or "with profile:" to only enable the profiler at certain 
points (and multiple points as in your use case above). These are the only 
modifications you need to make. The stats dumping is handled by kernprof.

   [line_profiler]$ grin -A10 '@profile' pystone.py
   pystone.py:
     164 : @profile
     165 + def Proc3(PtrParOut):
     166 +     global IntGlob
     167 +
     168 +     if PtrGlb is not None:
     169 +         PtrParOut = PtrGlb.PtrComp
     170 +     else:
     171 +         IntGlob = 100
     172 +     PtrGlb.IntComp = Proc7(10, IntGlob)
     173 +     return PtrParOut
     174 +
     182 : @profile
     183 + def Proc5():
     184 +     global Char1Glob
     185 +     global BoolGlob
     186 +
     187 +     Char1Glob = 'A'
     188 +     BoolGlob = FALSE
     189 +
     190 + def Proc6(EnumParIn):
     191 +     EnumParOut = EnumParIn
     192 +     if not Func3(EnumParIn):

   [line_profiler]$ kernprof.py -v --builtin pystone.py
   Pystone(1.1) time for 50000 passes = 1.08921
   This machine benchmarks at 45904.8 pystones/second
   Wrote profile results to pystone.py.prof
            350000 function calls in 0.192 seconds

      Ordered by: standard name

      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      100000    0.116    0.000    0.123    0.000 kernprof.py:73(disable_by_count)
       50000    0.042    0.000    0.055    0.000 pystone.py:164(Proc3)
       50000    0.013    0.000    0.013    0.000 pystone.py:182(Proc5)
       50000    0.013    0.000    0.013    0.000 pystone.py:209(Proc7)
      100000    0.007    0.000    0.007    0.000 {method 'disable' of 
'_lsprof.Profiler' objects}

</shameless-advertisement>

-- 
Robert Kern

"I have come to believe that the whole world is an enigma, a harmless enigma
  that is made terrible by our own mad attempt to interpret it as though it had
  an underlying truth."
   -- Umberto Eco