Execution time of lines within a function

[monkeyboy]

Hello,

I have a function that hotshot says is very slow. I can get the
aggregate execution time, but is there a way to get the execution time
of each line so I can find the bottleneck?

Thank you

 

[Neil Cerutti]

I have a function that hotshot says is very slow. I can get the
aggregate execution time, but is there a way to get the
execution time of each line so I can find the bottleneck?

Try 'print_callees' on the stats object for your bottleneck. That
may help.

 

[monkeyboy]

Thanks Neil,

I looked at that, but maybe I don't understand the output. I was hoping
to see the cummulative time for the function and then the time
associated with each statement (line) within the function.

In the hotshot output below, I can see the function being called 100
times, which is correct, but the rest seems at too low a level for me
to understand which statements are causing the slow execution.

Any suggestions?

hw6r3.py:276(main) hw6r3.py:73(findw)(100) 26700.865
hw6r3.py:126(findphi)(100)
6153.585
hw6r3.py:173(findu)(100) 1823.852
hw6r3.py:197(findv)(100) 2392.977
numeric.py:31(zeros_like)(3)
0.072
numeric.py:286(array_str)(1)
0.677
rpc.py:545(__getattr__)(13)
0.197
rpc.py:589(__call__)(12) 51.334
rpc.py:319(putmessage) <string>:1(fileno)(12) 0.039
rpc.py:149(debug)(12) 0.126
rpc.py:236(asyncreturn) rpc.py:149(debug)(24) 0.126
rpc.py:242(decoderesponse)(12)
0.015
rpc.py:277(getresponse)(12)
48.166


Regards,

Frank

 

[Neil Cerutti]

Thanks Neil,

I looked at that, but maybe I don't understand the output. I
was hoping to see the cummulative time for the function and
then the time associated with each statement (line) within the
function.

Any suggestions?

I don't think the Python Profiler goes down to that level. The
next step might be to analyze the function yourself and try to
understand why it is so slow. Post the code here and let the
readers pick it apart.

In the hotshot output below, I can see the function being
called 100 times, which is correct, but the rest seems at too
low a level for me to understand which statements are causing
the slow execution.


hw6r3.py:276(main) hw6r3.py:73(findw)(100) 26700.865

Is this the print_callees output?

 

[monkeyboy]

The output was from print_callees(). It appears as though print_stats()
and print_callees() return the same data, just in a different
orangization. There is supposed to be a "lineevents=1" option in
hotshot.Profile, for line timings, but it doesn't seem to work in
Python 2.4.

Thanks for your help

 

[Paul McGuire]

Hello,

I have a function that hotshot says is very slow. I can get the
aggregate execution time, but is there a way to get the execution time
of each line so I can find the bottleneck?

Thank you

The PythonDecoratorLibrary page on the Python wiki has a link to a @profile
decorator, that I have used to profile the contents of targeted functions
(only just now, I don't seem to be able to get to the wiki to get the exact
link).

-- Paul

 

[Ed Leafe]

The PythonDecoratorLibrary page on the Python wiki has a link to a
@profile
decorator, that I have used to profile the contents of targeted
functions
(only just now, I don't seem to be able to get to the wiki to get
the exact
link).

http://mg.pov.lt/blog/profilehooks-1.0.html

Note that the license has been changed from GPL to MIT, making it
distributable with non-GPL projects.

-- Ed Leafe
-- http://leafe.com
-- http://dabodev.com