Python line_profiler code example

Question

I am trying to figure out how I can run Python's line_profiler to get the line by line execution times in the format given in the answer to this question.

I installed the module and am calling its LineProfiler object as below but the output I get is just a single time and not a line by line summary.

Any ideas? Furthermore, how can I get the time for the numbers = [random.randint(1,100) for i in range(1000)] line that is outside any function?

from line_profiler import LineProfiler
import random

def do_stuff(numbers):

    s = sum(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

numbers = [random.randint(1,100) for i in range(1000)]
profile = LineProfiler(do_stuff(numbers))
profile.print_stats()
[] Timer unit: 3.20721e-07 s

Solution 1

The line_profiler test cases (found on GitHub) have an example of how to generate profile data from within a Python script. You have to wrap the function that you want to profile and then call the wrapper passing any desired function arguments.

from line_profiler import LineProfiler
import random

def do_stuff(numbers):
    s = sum(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

numbers = [random.randint(1,100) for i in range(1000)]
lp = LineProfiler()
lp_wrapper = lp(do_stuff)
lp_wrapper(numbers)
lp.print_stats()

Output:

Timer unit: 1e-06 s

Total time: 0.000649 s
File: <ipython-input-2-2e060b054fea>
Function: do_stuff at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           def do_stuff(numbers):
     5         1           10     10.0      1.5      s = sum(numbers)
     6         1          186    186.0     28.7      l = [numbers[i]/43 for i in range(len(numbers))]
     7         1          453    453.0     69.8      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

Adding Additional Functions to Profile

Also, you can add additional functions to be profiled as well. For example, if you had a second called function and you only wrap the calling function, you'll only see the profile results from the calling function.

from line_profiler import LineProfiler
import random

def do_other_stuff(numbers):
    s = sum(numbers)

def do_stuff(numbers):
    do_other_stuff(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

numbers = [random.randint(1,100) for i in range(1000)]
lp = LineProfiler()
lp_wrapper = lp(do_stuff)
lp_wrapper(numbers)
lp.print_stats()

The above would only produce the following profile output for the calling function:

Timer unit: 1e-06 s

Total time: 0.000773 s
File: <ipython-input-3-ec0394d0a501>
Function: do_stuff at line 7

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     7                                           def do_stuff(numbers):
     8         1           11     11.0      1.4      do_other_stuff(numbers)
     9         1          236    236.0     30.5      l = [numbers[i]/43 for i in range(len(numbers))]
    10         1          526    526.0     68.0      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

In this case, you can add the additional called function to profile like this:

from line_profiler import LineProfiler
import random

def do_other_stuff(numbers):
    s = sum(numbers)

def do_stuff(numbers):
    do_other_stuff(numbers)
    l = [numbers[i]/43 for i in range(len(numbers))]
    m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

numbers = [random.randint(1,100) for i in range(1000)]
lp = LineProfiler()
lp.add_function(do_other_stuff)   # add additional function to profile
lp_wrapper = lp(do_stuff)
lp_wrapper(numbers)
lp.print_stats()

Output:

Timer unit: 1e-06 s

Total time: 9e-06 s
File: <ipython-input-4-dae73707787c>
Function: do_other_stuff at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           def do_other_stuff(numbers):
     5         1            9      9.0    100.0      s = sum(numbers)

Total time: 0.000694 s
File: <ipython-input-4-dae73707787c>
Function: do_stuff at line 7

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     7                                           def do_stuff(numbers):
     8         1           12     12.0      1.7      do_other_stuff(numbers)
     9         1          208    208.0     30.0      l = [numbers[i]/43 for i in range(len(numbers))]
    10         1          474    474.0     68.3      m = ['hello'+str(numbers[i]) for i in range(len(numbers))]

NOTE: Adding functions to profile in this way does not require changes to the profiled code (i.e., no need to add @profile decorators).

Solution 2

As described in the documentation:

in your script, you can decorate any function you want to profile with @profile

You want to decorate your do_stuff function with @profile and then run

kernprof -v -l script_to_profile.py

to get the annotated output printed to your terminal. The profile will also be written to script_to_profile.py.lprof and you can re-create the output later with

python -m line_profiler script_to_profile.py.lprof

Comments

[Jeremy Kahan]

I think now kernprof -v -l script_to_profile.py not kernprof.py -v -l script_to_profile.py

[kynan]

Thanks, updated. Seems there is now kernprof as console script.