classification
Title: Add a profile decorator to profile and cProfile
Type: enhancement Stage: patch review
Components: Extension Modules, Library (Lib) Versions: Python 3.7
process
Status: open Resolution:
Dependencies: 8916 Superseder:
Assigned To: Nosy List: arigo, benjamin.peterson, bjorns, debatem1, ezio.melotti, georg.brandl, giampaolo.rodola, louielu, merwok, nbastin, pitrou, rhettinger, tim.peters, tleeuwenburg@gmail.com, ubershmekel
Priority: normal Keywords: needs review, patch

Created on 2010-07-17 14:01 by giampaolo.rodola, last changed 2017-04-23 04:44 by louielu.

Files
File name Uploaded Description Edit
profile.patch giampaolo.rodola, 2010-07-17 14:01
profile.patch giampaolo.rodola, 2013-02-12 15:07 provide new runcall() and runblock() functions review
profile3.patch giampaolo.rodola, 2013-02-25 21:33 review
Pull Requests
URL Status Linked Edit
PR 287 open louielu, 2017-02-25 07:40
PR 1212 open louielu, 2017-04-20 10:22
Messages (13)
msg110555 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2010-07-17 14:01
A patch including tests is in attachment.
Example usage:

>>> from cProfile import profile
>>>
>>> @profile
... def factorial(n):
...     n = abs(int(n))
...     if n < 1: 
...             n = 1
...     x = 1
...     for i in range(1, n+1):
...             x = i * x
...     return x
... 
>>>
>>> factorial(5)
    Thu Jul 15 20:58:21 2010    /tmp/tmpIDejr5

             4 function calls in 0.000 CPU seconds

       Ordered by: internal time, call count

       ncalls  tottime  percall  cumtime  percall filename:lineno(function)
            1    0.000    0.000    0.000    0.000 profiler.py:120(factorial)
            1    0.000    0.000    0.000    0.000 {range}
            1    0.000    0.000    0.000    0.000 {abs}
            1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

120
>>>


Before including doc changes I'd like to hear whether this is actually desirable or not.
msg124464 - (view) Author: Lukas Lueg (ebfe) Date: 2010-12-21 22:08
+1
msg132576 - (view) Author: Tennessee Leeuwenburg (tleeuwenburg@gmail.com) Date: 2011-03-30 09:33
I have been working on a similar idea. I just wanted to raise an issue I ran into which might affect this code also. The decorated function ended up with a different function signature to the original inner function. This can be important sometimes. I had to use the decorator.decorator module to give the outer function the same signature as the inner function.
msg140269 - (view) Author: √Čric Araujo (merwok) * (Python committer) Date: 2011-07-13 15:20
See #8916 for adding standard functionality similar to the decorator module.
msg181917 - (view) Author: Guido van Rossum (gvanrossum) * (Python committer) Date: 2013-02-11 17:54
Brief comments:

- Please don't call it profile -- we already have a module by that name.

- Please make it so that both the decorator and context manager can specify a file where to dump the raw data -- basically it needs to have the same functionality as the functions run()/runctx()/runcall() (the latter TBD, see issue 17130).

- Please also make Profile object itself the context manager -- all you have to do is add __enter__() and __exit__() that call enable() and disable().  (But this doesn't completely replace the global function, which has more functionality -- it prints the profile or dumps the data).
msg181918 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2013-02-11 17:55
Ok, will look into this soon.
msg181962 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2013-02-12 15:07
A preliminary patch for cProfile.py is in attachment. Will make changes to profile.py later.
msg182986 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2013-02-25 21:33
Ok, here's an updated patch modeled after:
http://hg.python.org/cpython/rev/422169310b7c

It works fine with cProfile.py but not with profile.py where I get this exception when I try to use the context manager (tests can be run in order to reproduce it):

  File "/home/giampaolo/svn/python/3.4-profile/Lib/profile.py", line 339, in trace_dispatch_return
    assert frame is self.cur[-2].f_back, ("Bad return", self.cur[-3])
AssertionError: ('Bad return', ('profile', 0, ''))

I have no clue what this error means.
I wasn't able to add a context manager for profile.Profile for the same reason.
Any clue?
msg288522 - (view) Author: Louie Lu (louielu) * Date: 2017-02-24 12:34
Ping. Is there any reason why this patch doesn't accept?
msg288530 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2017-02-24 18:43
The original patch is basically blocked by the cryptic assertion error reported above. It's not clear what it means or how to work around it.
msg288546 - (view) Author: Louie Lu (louielu) * Date: 2017-02-25 07:35
giampaolo: it seems that contextmanager will somehow make a bad return in  `trace_dispatch_return`:

$ ./python tests.py
# logging.fatal('%r %r' % (frame.f_code.co_name, self.cur[-3]))
CRITICAL:root:'runblock' '' ('profile', 0, '')
CRITICAL:root:'__enter__' '' ('profile', 0, '')
Traceback (most recent call last):
  File "tests.py", line 18, in <module>
    with p.runblock():
  File "/home/grd/Python/cpython/Lib/contextlib.py", line 82, in __enter__
    return next(self.gen)
  File "/home/grd/Python/cpython/Lib/profile.py", line 256, in trace_dispatch_i
    if self.dispatch[event](self, frame, t):
  File "/home/grd/Python/cpython/Lib/profile.py", line 346, in trace_dispatch_return
    raise AssertionError("Bad return", self.cur[-3])
AssertionError: ('Bad return', ('profile', 0, ''))

I make a workaround in GitHub PR, that skip the assert when self.cur[-3] is ('profile', 0, ''), and this work fine with your test cases.

p.s. I'm not very sure about the assertion of bad return, maybe this workaround may cause some side affact I didn't notice.
msg292148 - (view) Author: Giampaolo Rodola' (giampaolo.rodola) * (Python committer) Date: 2017-04-23 04:11
Original patch still applies. Not sure if we should continue with that one or with your new PR. The original assertion error is still there. I CCed Tim Peters as it appears he's the one who originally added it in 2001 - maybe he has some clue.
msg292150 - (view) Author: Louie Lu (louielu) * Date: 2017-04-23 04:44
Giampaolo, the assertion is still worked good, and no need to remove them. The assertion is to prevent dispatch return too more, to return upper then when the profiler was created.

The problem why profile __enter__ can't work, is because it misses the simulate_call between __enter__ and upper frame.

The original scenes:

pr = profile.Profile()  # It will call simulate_call at the end of init
sys.setprofile(pr.dispatcher)
# profile
sys.setprofile(None)

The break scenes:

def profile_helper(pr):
    sys.setprofile(pr.dispatcher)
    # Function will return None, dead here

pr = profile.Profile()  # Create simulate_call
# We go into profile_helper, but didn't simulate a call!! (didn't setprofile yet)
profile_helper(pr)      
sys.setprofile(None)

The #30113 issue fix this:

def profile_helper(pr):
    pr._adjust_frame()  # call simuate_call here
    sys.setprofile(pr.dispatcher)

pr = profile.Profile()  # Create simulate_call
profile_helper(pr)      
sys.setprofile(None)

Creating this simuate_call, then profiler can go back to the upper frame without error.
History
Date User Action Args
2017-04-23 04:44:07louielusetmessages: + msg292150
2017-04-23 04:11:53giampaolo.rodolasetmessages: + msg292148
versions: + Python 3.7, - Python 3.4
2017-04-20 10:22:07louielusetpull_requests: + pull_request1335
2017-02-25 10:54:15fdrakesetnosy: - fdrake
2017-02-25 07:40:19louielusetpull_requests: + pull_request257
2017-02-25 07:35:22louielusetmessages: + msg288546
2017-02-24 18:43:42giampaolo.rodolasetmessages: + msg288530
2017-02-24 18:41:08gvanrossumsetnosy: - gvanrossum
2017-02-24 12:34:03louielusetnosy: + louielu
messages: + msg288522
2013-03-14 13:20:09giampaolo.rodolasetnosy: + tim.peters, fdrake, rhettinger, nbastin, benjamin.peterson
2013-02-25 21:33:51ebfesetnosy: - ebfe
2013-02-25 21:33:18giampaolo.rodolasetfiles: + profile3.patch
nosy: + arigo
messages: + msg182986

2013-02-25 15:59:34merwoksetversions: + Python 3.4, - Python 3.3
2013-02-25 15:59:30merwoksetnosy: + bjorns
2013-02-25 15:59:18merwoklinkissue17130 superseder
2013-02-12 15:07:18giampaolo.rodolasetfiles: + profile.patch

messages: + msg181962
2013-02-12 12:47:33giampaolo.rodolasetnosy: + georg.brandl
2013-02-11 17:55:25giampaolo.rodolasetmessages: + msg181918
2013-02-11 17:54:11gvanrossumsetnosy: + gvanrossum
messages: + msg181917
2012-01-25 09:45:03ubershmekelsetnosy: + ubershmekel
2011-07-13 15:57:25collinwintersetnosy: - collinwinter
2011-07-13 15:26:50ezio.melottisetnosy: + ezio.melotti
2011-07-13 15:20:28merwoksettitle: A decorator for cProfile and profile modules -> Add a profile decorator to profile and cProfile
nosy: + merwok

messages: + msg140269

dependencies: + Move PEP 362 (function signature objects) into inspect
components: + Extension Modules, - Benchmarks
2011-03-30 09:33:06tleeuwenburg@gmail.comsetnosy: + tleeuwenburg@gmail.com
messages: + msg132576
2010-12-21 22:08:38ebfesetnosy: + ebfe
messages: + msg124464
2010-12-14 19:05:55r.david.murraysetassignee: collinwinter ->
stage: patch review
type: enhancement
versions: + Python 3.3, - Python 3.2
2010-07-18 01:12:40debatem1setnosy: + debatem1
2010-07-17 14:01:10giampaolo.rodolacreate