The profile module provides APIs for collecting and analyzing statistics about how Python source consumes processor resources.

This output reports in this section have been reformatted to fit on the page. Lines ending with backslash ( \ ) are continued on the next line.

Running the Profiler¶

The most basic starting point in the profile module is run() . It takes a string statement as argument, and creates a report of the time spent executing different lines of code while running the statement.

profile_fibonacci_raw.py ¶ import profile def fib ( n ): # from literateprograms.org # http://bit.ly/hlOQ5m if n == 0 : return 0 elif n == 1 : return 1 else : return fib ( n - 1 ) + fib ( n - 2 ) def fib_seq ( n ): seq = [] if n > 0 : seq . extend ( fib_seq ( n - 1 )) seq . append ( fib ( n )) return seq profile . run ( 'print(fib_seq(20)); print()' )

This recursive version of a Fibonacci sequence calculator is especially useful for demonstrating the profile because the performance can be improved significantly. The standard report format shows a summary and then details for each function executed.

$ python3 profile_fibonacci_raw.py [0, 1, 1, 2, 3, 5, 8, 13, 21, 34, 55, 89, 144, 233, 377, 610, 98\ 7, 1597, 2584, 4181, 6765] 57359 function calls (69 primitive calls) in 0.127 seco\ nds Ordered by: standard name ncalls tottime percall cumtime percall filename:lineno(fu\ nction) 21 0.000 0.000 0.000 0.000 :0(append) 1 0.000 0.000 0.127 0.127 :0(exec) 20 0.000 0.000 0.000 0.000 :0(extend) 2 0.000 0.000 0.000 0.000 :0(print) 1 0.001 0.001 0.001 0.001 :0(setprofile) 1 0.000 0.000 0.127 0.127 <string>:1(<module\ >) 1 0.000 0.000 0.127 0.127 profile:0(print(fi\ b_seq(20)); print()) 0 0.000 0.000 profile:0(profiler\ ) 57291/21 0.126 0.000 0.126 0.006 profile_fibonacci_\ raw.py:11(fib) 21/1 0.000 0.000 0.127 0.127 profile_fibonacci_\ raw.py:22(fib_seq)

The raw version takes 57359 separate function calls and 0.127 seconds to run. The fact that there are only 69 primitive calls says that the vast majority of those 57k calls were recursive. The details about where time was spent are broken out by function in the listing showing the number of calls, total time spent in the function, time per call (tottime/ncalls), cumulative time spent in a function, and the ratio of cumulative time to primitive calls.

Not surprisingly, most of the time here is spent calling fib() repeatedly. Adding a cache decorator reduces the number of recursive calls, and has a big impact on the performance of this function.

profile_fibonacci_memoized.py ¶ import functools import profile @functools . lru_cache ( maxsize = None ) def fib ( n ): # from literateprograms.org # http://bit.ly/hlOQ5m if n == 0 : return 0 elif n == 1 : return 1 else : return fib ( n - 1 ) + fib ( n - 2 ) def fib_seq ( n ): seq = [] if n > 0 : seq . extend ( fib_seq ( n - 1 )) seq . append ( fib ( n )) return seq if __name__ == '__main__' : profile . run ( 'print(fib_seq(20)); print()' )

By remembering the Fibonacci value at each level, most of the recursion is avoided and the run drops down to 89 calls that only take 0.001 seconds. The ncalls count for fib() shows that it never recurses.