[Patches] [ python-Patches-1212837 ] Improved profiler

[SourceForge.net]

Patches item #1212837, was opened at 2005-06-01 16:05
Message generated for change (Comment added) made by arigo
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=305470&aid=1212837&group_id=5470

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: Modules
Group: Python 2.4
Status: Open
Resolution: None
Priority: 5
Submitted By: Brett Rosen (bdrosen)
Assigned to: Nobody/Anonymous (nobody)
Summary: Improved profiler

Initial Comment:
I tried using both hotshot and the old python profiler
and found them both to be inadequate.

The old python profiler seems to give accurate results
for timing, but is slow enough that it adds significant
overhead to what it is measuing (approximately 10 times). 
Furthermore, it has no ability to give detailed stats
about 
children. (how much of the cumulative time was taken up
by each function called by a function)

The hotshot profiler is much faster (profiling) adding
only 30% overhead. However, it is extremely slow to load
the results from the log file. It does not currently
support detailed child stats, although I imagine that
it could be made to do so using the information in the
log file. The biggest problem with it, is that the
time results seem to be highly inaccurate. (doesn't
correspond to actual seconds, although they seem to be 
proportionally wrong)

To address these shortcomings, I wrote a new profiling
module. It adds about the same overhead (30%) as hotshot,
but is much faster in retrieving results. It supports
detailed child stats and gives accurate timing information
in milliseconds. The accompanying .py module could use
additional work though - because of the child stats, I
was not able to reuse the stats module like hotshot does.

I've included a simple test script that runs pystone
for all 3 profilers (and without the profiler) to give
a better idea of the differences. I've also included
a dump of the output of the script running under Windows
XP with python 2.4.1

----------------------------------------------------------------------

>Comment By: Armin Rigo (arigo)
Date: 2005-09-23 07:46

Message:
Logged In: YES 
user_id=4771

I replaced the linked lists with some kind of auto-balacing
trees; the linked lists were creating a huge overhead to
profile large programs.  The reason for not using plain
Python dicts instead is that PyCodeObjects are not very
good at being keys in dicts -- their hash computation takes
ages, and we'd prefer an identity mapping anyway.

The current SVN version is now the first profiler that
works and gives sensible results when profiling the PyPy
translation process.

getstats() is now producing tuples-with-attribute-names
instead of dicts (similar to os.stat()).  This was mostly
motivated by a lack of motivation to introduce error
checking everywhere in the dict-building code, but I think
it's a reasonable change.  There are only a couple of
places left in profile.c still missing checks for error
results or out-of-memory conditions.

The lsprof.py module exposes a simple but minimalistic
interface.  I suggest we keep and document it or a similar
one, but also support -- for compatibility -- the
convoluted interface of the existing profile.py/pstats.py
and/or hotshot, with the option to dump the stats to a file
and reload them.  However I don't think it makes sense to
use exactly the same format as pstats does (as far as I
can guess it doesn't support per-caller information).

----------------------------------------------------------------------

Comment By: Michael Hudson (mwh)
Date: 2005-09-21 18:35

Message:
Logged In: YES 
user_id=6656

Well, you can see what we've done to your baby:

http://codespeak.net/svn/user/arigo/hack/misc/lsprof/profile.c

Mostly it's just C style conformance so far, though we've fixed a couple of 
little bugs too.

----------------------------------------------------------------------

Comment By: Brett Rosen (bdrosen)
Date: 2005-09-21 17:43

Message:
Logged In: YES 
user_id=1289249

I welcome any additional changes (and help making those changes)
that would improve the patch and help get it ready for
inclusion in CPython. 

The main detail that I knew that would need to be addressed
was lspstats.py.  I didn't spend a lot of time working on it
because I generally use a wx TreeListCtrl object to view/sort
the results. What other details need to be addressed?

----------------------------------------------------------------------

Comment By: Armin Rigo (arigo)
Date: 2005-09-21 15:57

Message:
Logged In: YES 
user_id=4771

Thanks for your work.  The two existing profilers are
definitely not satisfactory in my opinion too (I am also
encountering crashes with profile.py).

There are a number of details that should be addressed
before your profiler can be a replacement for the existing
ones, e.g. providing simple entry points and documentations,
and having the C code reviewed.  I am willing to help with
all this.

I hope you won't mind that I have checked your source code
in a public Subversion repository, where I am working a bit
on it together with Michael Hudson.  (Obviously, the goal
is to have the code eventually in the CPython CVS.)

http://codespeak.net/svn/user/arigo/hack/misc/lsprof/

----------------------------------------------------------------------

Comment By: Laura Creighton (lcreighton)
Date: 2005-09-21 15:18

Message:
Logged In: YES 
user_id=376262

We've been using Hotshot at Strakt for a while now.  We
tried your patch and
it worked precisely as advertised.  Thank you for writing it.

Laura Creighton

----------------------------------------------------------------------

Comment By: Brett Rosen (bdrosen)
Date: 2005-09-08 15:25

Message:
Logged In: YES 
user_id=1289249

I've enclosed an updated version of profile.c that fixes
a problem in the original patch

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=305470&aid=1212837&group_id=5470