cProfile Examples in Python

Goal

This post aims to introduce how to use cProfile to measure the running time for each statement and find the bottleneck of your program.

Libraries

In [1]:
import cProfile

Define your function

define your sub functions

In [37]:
def linear_func(n):
    for i in range(n):
        pass
    return

def quad_func(n):
    for i in range(n):
        for i in range(n):
            pass

    return

def exp_func(n):
    if n <= 1:
        return n
    return exp_func(n-1) + exp_func(n-2)
In [38]:
def main_func(n):
    linear_func(n)
    quad_func(n)
    exp_func(n)

Profile the main function

In [40]:
cProfile.run('main_func(n=20)')
         21897 function calls (7 primitive calls) in 0.006 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.000    0.000 <ipython-input-37-393400eb079b>:1(linear_func)
  21891/1    0.006    0.000    0.006    0.006 <ipython-input-37-393400eb079b>:13(exp_func)
        1    0.000    0.000    0.000    0.000 <ipython-input-37-393400eb079b>:6(quad_func)
        1    0.000    0.000    0.006    0.006 <ipython-input-38-1333493d3326>:1(main_func)
        1    0.000    0.000    0.006    0.006 <string>:1(<module>)
        1    0.000    0.000    0.006    0.006 {built-in method builtins.exec}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


How to read the result

  • ncalls is the number of calls.
  • tottime is a total of the time spent.
  • percall is the average time for each call, i.e., tottime divided by ncalls
  • cumtime is the cumulative time spent.
  • (2nd) percall is the quotient of cumtime divided by primitive calls
  • filename:lineno(function) indicates the information about the function with the format "{file name}:{line number}{function name}"

Comments

Comments powered by Disqus