Python profiler not giving enough information

Question

I am trying to find out why some function is taking a long time to complete.
I am using the profiler like this:

ipdb> import profile
ipdb> profile.runctx('report.generateOutput()', globals(), locals())
         1 function calls in 40.783 CPU seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        0    0.000             0.000          profile:0(profiler)
        1   40.783   40.783   40.783   40.783 profile:0(report.generateOutput())

As you can see, that's not really of much use.
What I need is some detailed information about where all the time is being spent, what am I missing here?

Is `report.generateOutput()` written in C or one *giant* 2k lines of code without any further calls? — , Feb 24 '11 at 17:11
report.generateOutput() is just some 200 lines of Python, using cStringIO — Facundo Casco, Feb 24 '11 at 17:15

score 2 · Answer 1 · answered Feb 24 '11 at 18:23

2

Profile report.generateOutput(), instead of the function call.

To profile an application with a main entry point of foo(), you would add the following to your module:

import cProfile
cProfile.run('foo()')

Maybe the python docs on profiling are helpful.

answered Feb 24 '11 at 18:23

Patrick

999
1
9
21

I was expecting some output like the one in the docs but I can't figure out why I am only getting a single line – Facundo Casco Feb 24 '11 at 18:41
Edit the function you want to profile to include the profiler as described in the docs. Profiling is done line by line, and if your code is only one line, that's all you get. – Patrick Feb 24 '11 at 18:49
Sorry, I may be misssing something. I just don't see any difference between what is in the docs and my code. They call foo() I call report.generateOutput(). Should I be adding something to generateOutput() ? – Facundo Casco Feb 24 '11 at 19:10
Yes. If you want to profile generateOutput(), you should do so, instead of profiling the code that's calling it. Add the necessary lines to the function. – Patrick Feb 24 '11 at 20:22

score 0 · Accepted Answer · edited May 23 '17 at 12:19

0

You say two different things:

"What I need is some detailed information about where all the time is being spent"
"I am trying to find out why some function is taking a long time to complete"

You see, these are not the same thing. I think it is better to ask why than where, because where is actually very fuzzy.

For example, suppose there is a "bottleneck" consisting of a bubble sort of a big array of strings. Where is the time spent? Is it in the inner loop of the bubble sort, or is it in the string compare? Profilers would say the latter, but the reason why it's there, and the actual problem, is higher up the call stack.

Here's an example of how I do it.

edited May 23 '17 at 12:19

Community

1
1

answered Feb 24 '11 at 19:29

Mike Dunlavey

40,059
14
91
135

1

You are right, I want the profiler to tell me where is the time spent so I can figure out why – Facundo Casco Feb 24 '11 at 19:40
@F.C.: Then I recommend a profiler that samples the stack at random times, or do it yourself. It's actually quite easy. The worse the problem is, the quicker you will find it. That link gives an example. – Mike Dunlavey Feb 24 '11 at 20:05

Python profiler not giving enough information

2 Answers2