Kernprof comes with the line_profiler tool, by default, and allows us to easily get started using the line_profiler tool. With line_profiler, we need to explicitly state the functions that we need to profile within our codebase. This is typically done using the @profile decorator.

For the purpose of this example, let's create a very simple program that features two functions, a slow function and a fast function. We somewhat suspect that slowFunction() might be the one that is causing our program to be inefficient, and due to its colossal size, we are unable to wrap every line of it with a time calculation.

If we wanted a line-by-line analysis of exactly how long everything takes, then we can add the @profile decorator in order to see what has gone wrong, as follows:

import random
import time

@profile
def slowFunction():
  time.sleep(random.randint(1,5))
  print("Slow Function Executed")

def fastFunction():
  print("Fast Function Executed")

def main():
  slowFunction()
  fastFunction()

if __name__ == '__main__':
  main()

In order to run our tool, we first have to call the kernprof tool in order to generate an .lprof file. It's this file that we've just generated that we'll be passing into our line_profiler tool in order to see the exact output.

$ python3.6 -m kernprof -l profileTest.py
Slow Function Executed
Fast Function Executed
Wrote profile results to profileTest.py.lprof

$ python3.6 -m line_profiler profileTest.py.lprof
Timer unit: 1e-06 s

Total time: 3.00152 s
File: profileTest.py
Function: slowFunction at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    4                                           @profile
    5                                           def slowFunction():
    6         1      3001412 3001412.0    100.0    time.sleep(random.randint(1,5))
    7         1          106    106.0      0.0    print("Slow Function Executed")

As you can see, we first run our kernprof, which runs through our program, and successfully generates our profileTest.py.lprof file. We then pass this file into our line_profiler tool, and it outputs a table that features the line numbers of the code we've executed, the number of times that line was hit, and the time per hit.

As you can see, line 6 was deemed to have taken up 100.0 percent of the time rounded up. It took just slightly over 3 seconds, and has crippled the execution time of our program. Armed with this knowledge, we can try to refactor our app to possibly remove this unnecessary line, and greatly improve the speed at which our program executes.