How to profile a method with arguments in a loop?

Question

I have a class Foo and it implements a method compute. I would like to see how long compute takes and where it spends most of its time when executing. To resolve the first problem, I used timeit.default_timer in a loop and averaged:

import numpy as np
from timeit import default_timer as Timer

foo = Foo()
n = int(10e8)
times = np.empty(n)

for i in range(n):
    start = Timer()
    foo.compute(i)
    times[i] = Timer() - start

print(np.sum(times) / times.size)

This tells me what the average execution time of each compute call was, easy enough; except its slower than I thought.

Now I would like to break down the execution profile of compute, but the followingn doesn't seem to do the trick:

import cProfile

for i in range(n):
    cProfile.run(foo.compute(i))

I didn't think it would work anyhow, but the docs seem to suggest I would have to put this loop in a method and then profile that loop? So I tried that but it doesn't show whats going on inside compute which is what I desire. How can this be accomplished?

Answer 1

Instead of using run(), you can use runctx(), which provides arguments to supply globals and locals dictionaries.

cProfile.runctx("foo.compute(n)", {"n": n, "foo": Foo()}, {})

To aggregate the results from multiple profile runs, see How to calculate the average result of several cProfile results?.

Answer 2

To use cProfile, you need to pass the function as a string argument or "command". So, simply modifying your original code should work:

for i in range(n):
    cProfile.run("foo.compute(i)")

However, in your case, it seems like you want to profile the execution of a "real world" case and see where you have bottlenecks that you can optimize. Profiling the function is not the same as benchmarking it. The Python documentation on profilers also states:

Note The profiler modules are designed to provide an execution profile for a given program, not for benchmarking purposes (for that, there is timeit for reasonably accurate results).

When benchmarking, you want to execute the command many times in a loop, in order to get the average execution time +- standard deviation, which should be representative of what happens in reality and allows you to compare different solutions. However, profiling breaks down a single run of the command. This should be enough to identify which specific components of the method take more time than others (vs. how long they actually take), and this order of magnitude shouldn't really change between runs (although the specific time it takes might fluctuate).

If you do actually want to calculate statistics on the average run, you could generate the stats over many runs and then extract the data to manipulate it further:

pr = cProfile.Profile()
pr.enable()
 
for i in range(n):
    foo.compute(i)

pr.disable()
pr.create_stats()
stats = pr.stats

(pr.stats is a dictionary that gets formatted into the print statement you see when you profile)