Re: [Tutor] Profiling in Python

[Magnus Lycka]

> I'm just wondering what is "profiling" and how do you do it in Python.  Any help is welcome.  Thanks in advance.

Profiling is the process of determining how much
time is spent in different parts of your program
while it's running.

It is a very important part improving runtime
performance and understanding of the code.

It's very difficult to know where the bottlenecks
in code occur, and if 80% of the runtime is spent
in one particular routine, it's not possible to
improve performance more than 25% however much you
improve the rest of the program. You must improve
*this* routine (or call it less often).

Besides seeing the time spent in different parts of
the code, seeing how many times various routines are
called might be an important eye opener for the
programmer. It will often make you understand that
you aren't doing things the right way, or that the
usage pattern is different than you thought.

An example (not very meaningful) session could look
like this:

>>> import profile
>>> import calendar
>>> profile.run("calendar.calendar(2004)")
         149 function calls in 0.358 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.012    0.012 <string>:1(?)
       12    0.001    0.000    0.001    0.000 calendar.py:105(monthcalendar)
       62    0.002    0.000    0.002    0.000 calendar.py:124(week)
        1    0.000    0.000    0.002    0.002 calendar.py:135(weekheader)
       27    0.000    0.000    0.000    0.000 calendar.py:169(format3cstring)
        1    0.002    0.002    0.012    0.012 calendar.py:178(calendar)
       12    0.004    0.000    0.004    0.000 calendar.py:34(__getitem__)
        7    0.002    0.000    0.002    0.000 calendar.py:47(__getitem__)
        1    0.000    0.000    0.000    0.000 calendar.py:80(isleap)
       12    0.000    0.000    0.000    0.000 calendar.py:91(weekday)
       12    0.000    0.000    0.000    0.000 calendar.py:96(monthrange)
        1    0.347    0.347    0.358    0.358 profile:0(calendar.calendar(2004))
        0    0.000             0.000          profile:0(profiler)


For more info look here:
http://www.python.org/doc/current/lib/profile-instant.html

There are actually two profilers now. The old one (profile)
is written in Python. The new one (hotshot) is written in
C, and it's (as one might expect) much faster, i.e. it doesn't
slow down program execution nearly as much. On the other hand
it collects much more data, so the analysis takes longer. (At
least reading in the profiling data. In the typical case, you
would not analyze righth away like above, but rather store the
measurement results in a file, and analyze that after the
program run. I sometimes set a command line switch in python
programs, and ask users to start the program in profiling
mode and do whatever they feel is too slow if they have
complained about performance. Then I ask them to send me the
generated profiling file, and I can analyze why their runs
go slowly. I often lack enough data to run into trouble, or
I might not use the program in exactly the same way, which
might give me a very different execution time.)

For an example of using hotshot, see
http://www.python.org/doc/current/lib/hotshot-example.html

-- 
Magnus Lycka, Thinkware AB
Alvans vag 99, SE-907 50 UMEA, SWEDEN
phone: int+46 70 582 80 65, fax: int+46 70 612 80 65
http://www.thinkware.se/  mailto:magnus at thinkware.se