[Tutor] profiling python code

[Kent Johnson]

On Thu, Jan 22, 2009 at 4:18 AM, Norman Khine <norman at khine.net> wrote:
> Hello,
>
> I have this output when running the profile on one of my modules:
>

It's a bit easier to intepret with the headers:
ncalls  tottime  percall  cumtime  percall filename:lineno(function)

> 9815/9644    0.009    0.000    0.009    0.000 {len}
>        6    0.000    0.000    0.000    0.000 {locals}
>        5    0.000    0.000    0.001    0.000 {map}
>        1    0.000    0.000    0.000    0.000 {math.exp}
>        3    0.000    0.000    0.000    0.000 {math.log}
>        1    0.000    0.000    0.000    0.000 {math.sqrt}
>       97    0.000    0.000    0.000    0.000 {max}
>        9    0.001    0.000    0.001    0.000 {method '__reduce_ex__' of
> 'object' objects}
>     7539    0.009    0.000    0.009    0.000 {method 'append' of 'list'
> objects}
>
>
> The
> 9815/9644    0.009    0.000    0.009    0.000 {len}
>
> line does it mean that the module is making 9815 requests to the len
> function?

Yes.

> Also the line
>
> 7539    0.009    0.000    0.009    0.000 {method 'append' of 'list' objects}
>
> it looks high!?!

That depends on what the code is doing.

> How should I interpret this?

That your code is spending most of its time in len() and
list.append(). The cumtime column is the most useful for figuring out
where the time goes. If ncalls is higher than expected then it might
be worth figuring out why.

Is this an exercise to understand the profiler or real code you are
trying to speed up? Showing the code might help.

Kent