Updated On : Aug-10,2022 Time Investment : ~20 mins

line_profiler: Line by Line Profiling of Python Code

> What is Profiling?

Profiling is a process where we analyze 'time' (time complexity) taken by various parts of our code. It let us better understand which parts of our code are slowing down other parts. This can helps us make better decisions to utilize underlying resources efficiently.

Apart from "time", we can also profile 'memory' (space complexity) usage by various parts of our code. This can helps better organize memory and optimize memory usage.

> What are Some Python Libraries to Profile Python Code/Script/Program?

Default Python installation comes with two useful Python libraries "cProfile" and "profile" for profiling Python code. We have already covered a tutorial on cProfile and profile which helps us understand how much time is taken by the various functions of our code.

Apart from these two, there are many other Python libraries that let us profile Python code/script/program.

> When Should you Use "line_profiler" Instead of "cProfile/Profile"?

The cProfile and profile provide profiling results on a function basis but don't give us information on line by line basis of function. The results generated by these libraries have time taken by function calls but no information about time taken by individual lines of each function. Python has a library called line_profiler which can help us better understand the time taken by individual lines of our code.

> What Can You Learn From This Article?

As a part of this tutorial, we have explained how to use Python library "line_profiler" to profile Python code/script/program. We have explained how to profile whole Python script as well as individual functions using "line_profiler". We have also covered how to use "line_profiler" in different contexts like from command line, in Python script, and in Jupyter notebook.

> Ways to Profile Python Code using "line_profiler"

  1. "kernprof" Command Prompt/Shell Command: This command let us profile whole Python script from command line/shell.
  2. "LineProfiler" Object in Python Script: This let us profile individual functions of our code by declaring profiler object in script itself.
  3. "%lprun" Jupyter Notebook Magic Command: This let us profile functions in Jupyter Notebooks using "%lprun" line magic command.

Below, we have listed important sections of tutorial to give an overview of material covered.

Important Sections Of Tutorial

  1. "kernprof": Profile Script from Command Line/Shell
    • 1.1 How to Profile Python Script using "kernprof" Command?
    • 1.2 How to Print Profiling Results to Standard Output?
    • 1.3 How to Check "line_profiler" Version?
    • 1.4 How to Change Time Measurement Unit?
    • 1.5 How to Hide Functions That are not Called?
    • 1.6 How to Write Profiling Results to a File?
  2. How to Profile using "LineProfiler" Object in Code?
    • 2.1 Profile Main Single Function
    • 2.2 Profile Multiple Functions
  3. How to Use "line_profiler" in Jupyter Notebook? ("%lprun")
    • 3.1 Load "line_profiler" as External Module in Notebook
    • 3.2 Profile Single Function
    • 3.3 Profile Multiple Functions

1. "kernprof" Command: Profile Script from Command Line/Shell

Our first example of using line_profiler explains how to use it from a command prompt/shell.

We have designed a simple python script that has one main_func() function which calls 3 other functions. All three other functions generate 100000 random numbers between 1-100 and then take an average of it. We have manually inserted time wait in all functions so that each takes different time to complete even though all perform the same functionality. We need to decorate each function that we want to profile in script with @profile decorator.

random_number_average.py

import time
import random

@profile
def very_slow_random_generator():
    time.sleep(5)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

@profile
def slow_random_generator():
    time.sleep(2)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

@profile
def fast_random_generator():
    time.sleep(1)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

@profile
def main_func():
    result = fast_random_generator()
    print(result)

    result = slow_random_generator()
    print(result)

    result = very_slow_random_generator()
    print(result)

main_func()

1.1 How to Profile Python Script using "kernprof" Command?

The "kernprof" command lets us profile code/script/program using either "cProfile" or "line-by-line profiler". We'll be concentrating line by line profiler. To profiler code using line by line profiler, we need to provide option '-l' or '-line-by-line' else it'll use "cProfile".

The kernprof command will generate a file named script_name.lprof after it has completed profiling. The profiling results are stored in the .lprof file generated in the same directory.

If our script is taking any parameters then we can give them as well after script name (exactly same way as we execute script in command prompt/shell).

IMPORTANT NOTE

Please make a NOTE that our command starts with '!' because we have executed them in Jupyter notebook. If you are executing them in a command prompt or shell then you don't need to include an exclamation mark at the beginning of a command.

!kernprof -l random_number_average.py
50.35903
50.6261
50.5511
Wrote profile results to random_number_average.py.lprof

We can then call the below line to see the output of profiling by executing the below line.

!python -m line_profiler random_number_average.py.lprof
Timer unit: 1e-06 s

Total time: 5.35805 s
File: random_number_average.py
Function: very_slow_random_generator at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           @profile
     5                                           def very_slow_random_generator():
     6         1    5005022.0 5005022.0     93.4      time.sleep(5)
     7         1     352566.0 352566.0      6.6      arr = [random.randint(1,100) for i in range(100000)]
     8         1        466.0    466.0      0.0      return sum(arr) / len(arr)

Total time: 2.35774 s
File: random_number_average.py
Function: slow_random_generator at line 10

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    10                                           @profile
    11                                           def slow_random_generator():
    12         1    2002066.0 2002066.0     84.9      time.sleep(2)
    13         1     355207.0 355207.0     15.1      arr = [random.randint(1,100) for i in range(100000)]
    14         1        466.0    466.0      0.0      return sum(arr) / len(arr)

Total time: 1.35534 s
File: random_number_average.py
Function: fast_random_generator at line 16

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    16                                           @profile
    17                                           def fast_random_generator():
    18         1    1001079.0 1001079.0     73.9      time.sleep(1)
    19         1     353781.0 353781.0     26.1      arr = [random.randint(1,100) for i in range(100000)]
    20         1        478.0    478.0      0.0      return sum(arr) / len(arr)

Total time: 9.07163 s
File: random_number_average.py
Function: main_func at line 22

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    22                                           @profile
    23                                           def main_func():
    24         1    1355500.0 1355500.0     14.9      result = fast_random_generator()
    25         1         46.0     46.0      0.0      print(result)
    26
    27         1    2357866.0 2357866.0     26.0      result = slow_random_generator()
    28         1         52.0     52.0      0.0      print(result)
    29
    30         1    5358152.0 5358152.0     59.1      result = very_slow_random_generator()
    31         1         19.0     19.0      0.0      print(result)

The result generated by line_profiler has one table per function. The table has the same rows as per the number of lines of code in that function.

Explanation of Resulted Table Columns

  1. Hits: The first column represents how many times that line was hit inside that function. In our current example hits has a value of 1 but it can be more than one in case of recurrence.
  2. Time: The second column represents the time taken by that line in total for all hits. This time is as per set unit. The default unit is 1e-6 which will record time in microseconds. To get data in seconds, we'll have to divide it by 1e6. We have later explained how to change this measurement unit.
  3. Per Hit: The third column represents time taken per each call of that line.
  4. % Time: The fourth column represents % of time taken by that line of total function time.
  5. Line Contents: The fifth column represents a line of function.

1.2 How to Print Profiling Results to Standard Output?

If we want to generate output to the shell/command line after the script is profiled using kernprof then we can call it using -v or --view option. This can be useful when profiling results are small else it'll flood output.

  • kernprof -l -v random_number_average.py
  • kernprof -l --view random_number_average.py

1.3 How to Check "line_profiler" Version?

We can check version of "line_profiler" with '-V' or '--version' options.

  • kernprof -V
  • kernprof --version
!kernprof --version
3.5.1

1.4 How to Change Time Measurement Unit?

As we mentioned earlier, the default measurement unit is 1e-6 which measures time in microseconds. We can change it using '-u' or '--unit' options.

  • kernprof -l -u UNIT random_number_average.py
  • kernprof -l --unit UNIT random_number_average.py

Below, we have changed default units from 1e-6 to 1e-3. This will now measure time in milliseconds.

!kernprof -l --view --unit 1e-3 random_number_average.py
50.57105
50.51054
50.43384
Wrote profile results to random_number_average.py.lprof
Timer unit: 0.001 s

Total time: 5.35552 s
File: random_number_average.py
Function: very_slow_random_generator at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           @profile
     5                                           def very_slow_random_generator():
     6         1       5003.3   5003.3     93.4      time.sleep(5)
     7         1        351.6    351.6      6.6      arr = [random.randint(1,100) for i in range(100000)]
     8         1          0.6      0.6      0.0      return sum(arr) / len(arr)

Total time: 2.35322 s
File: random_number_average.py
Function: slow_random_generator at line 10

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    10                                           @profile
    11                                           def slow_random_generator():
    12         1       2000.7   2000.7     85.0      time.sleep(2)
    13         1        352.0    352.0     15.0      arr = [random.randint(1,100) for i in range(100000)]
    14         1          0.5      0.5      0.0      return sum(arr) / len(arr)

Total time: 1.34977 s
File: random_number_average.py
Function: fast_random_generator at line 16

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    16                                           @profile
    17                                           def fast_random_generator():
    18         1       1001.0   1001.0     74.2      time.sleep(1)
    19         1        348.3    348.3     25.8      arr = [random.randint(1,100) for i in range(100000)]
    20         1          0.5      0.5      0.0      return sum(arr) / len(arr)

Total time: 9.059 s
File: random_number_average.py
Function: main_func at line 22

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    22                                           @profile
    23                                           def main_func():
    24         1       1349.9   1349.9     14.9      result = fast_random_generator()
    25         1          0.0      0.0      0.0      print(result)
    26
    27         1       2353.3   2353.3     26.0      result = slow_random_generator()
    28         1          0.0      0.0      0.0      print(result)
    29
    30         1       5355.6   5355.6     59.1      result = very_slow_random_generator()
    31         1          0.0      0.0      0.0      print(result)

1.5 How to Hide Functions That are not Called?

We can inform profiler to remove functions that are not called using '-z' or '--skip-zero' options.

  • kernprof -l -z random_number_average.py
  • kernprof -l --skip-zero random_number_average.py

1.6 How to Write Profiling Results to a File?

We can change the default filename to which "line_profiler" writes profiling results using '-o' or '--outfile' options.

  • kernprof -l -o FILENAME random_number_average.py
  • kernprof -l --outfile FILENAME random_number_average.py
!kernprof -l -o random_generator.dat random_number_average.py
50.38604
50.34009
50.49996
Wrote profile results to random_generator.dat
!python -m line_profiler random_generator.dat
Timer unit: 1e-06 s

Total time: 5.35444 s
File: random_number_average.py
Function: very_slow_random_generator at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           @profile
     5                                           def very_slow_random_generator():
     6         1    5005080.0 5005080.0     93.5      time.sleep(5)
     7         1     348884.0 348884.0      6.5      arr = [random.randint(1,100) for i in range(100000)]
     8         1        475.0    475.0      0.0      return sum(arr) / len(arr)

Total time: 2.34697 s
File: random_number_average.py
Function: slow_random_generator at line 10

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    10                                           @profile
    11                                           def slow_random_generator():
    12         1    2002049.0 2002049.0     85.3      time.sleep(2)
    13         1     344453.0 344453.0     14.7      arr = [random.randint(1,100) for i in range(100000)]
    14         1        465.0    465.0      0.0      return sum(arr) / len(arr)

Total time: 1.36461 s
File: random_number_average.py
Function: fast_random_generator at line 16

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    16                                           @profile
    17                                           def fast_random_generator():
    18         1    1000921.0 1000921.0     73.3      time.sleep(1)
    19         1     363209.0 363209.0     26.6      arr = [random.randint(1,100) for i in range(100000)]
    20         1        485.0    485.0      0.0      return sum(arr) / len(arr)

Total time: 9.06648 s
File: random_number_average.py
Function: main_func at line 22

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    22                                           @profile
    23                                           def main_func():
    24         1    1364767.0 1364767.0     15.1      result = fast_random_generator()
    25         1         29.0     29.0      0.0      print(result)
    26
    27         1    2347066.0 2347066.0     25.9      result = slow_random_generator()
    28         1         27.0     27.0      0.0      print(result)
    29
    30         1    5354556.0 5354556.0     59.1      result = very_slow_random_generator()
    31         1         34.0     34.0      0.0      print(result)

2. How to Profile using "LineProfiler" Object in Code?

As a part of our second example of using line_profiler, we'll explain how we can profile python code by adding few extra lines of code to our script rather than passing it to kernprof from the command line/shell.

Below we have re-written code from our previous example again.

import time
import random

def very_slow_random_generator():
    time.sleep(5)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def slow_random_generator():
    time.sleep(2)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def fast_random_generator():
    time.sleep(1)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def main_func():
    result = fast_random_generator()
    print(result)

    result = slow_random_generator()
    print(result)

    result = very_slow_random_generator()
    print(result)

2.1 Profile Main Single Function

We then need to create an object of LineProfiler class first. We then need to create a wrapper around main_func() by calling the LineProfiler instance passing it main_func. We can then execute that line profiler wrapper which will execute main_func().

from line_profiler import LineProfiler

lprofiler = LineProfiler()

lp_wrapper = lprofiler(main_func)

lp_wrapper()
50.60844
50.66267
50.50243

Once the line profiler wrapper (main_func) completes, we can call the print_stats() method on the line profiler instance and it'll print the profiling result.

We can see from the below results printed that it only profiled code of main_func. We'll need to make a modification to code a bit if we want to profile other functions as well.

lprofiler.print_stats()
Timer unit: 1e-06 s

Total time: 9.032 s
File: <ipython-input-31-c9c4218f4095>
Function: main_func at line 19

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    19                                           def main_func():
    20         1    1338047.0 1338047.0     14.8      result = fast_random_generator()
    21         1         76.0     76.0      0.0      print(result)
    22
    23         1    2339920.0 2339920.0     25.9      result = slow_random_generator()
    24         1        309.0    309.0      0.0      print(result)
    25
    26         1    5353573.0 5353573.0     59.3      result = very_slow_random_generator()
    27         1         79.0     79.0      0.0      print(result)

2.2 Profile Multiple Functions

Below we are creating the LineProfiler instance again. We are then calling add_function() on it three times passing it the name of three random average generator functions so that it profiles code of them as well. We are then wrapping main_func by calling the line profiler instance. We can then call the line profiler wrapper which will execute main_func() but this time it'll profile code for other three random average generator functions as well along with main_func.

lprofiler = LineProfiler()

lprofiler.add_function(fast_random_generator)
lprofiler.add_function(slow_random_generator)
lprofiler.add_function(very_slow_random_generator)

lp_wrapper = lprofiler(main_func)

lp_wrapper()
50.60993
50.51236
50.64116
lprofiler.print_stats()
Timer unit: 1e-06 s

Total time: 5.35659 s
File: <ipython-input-22-c9c4218f4095>
Function: very_slow_random_generator at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           def very_slow_random_generator():
     5         1    5002484.0 5002484.0     93.4      time.sleep(5)
     6         1     353618.0 353618.0      6.6      arr = [random.randint(1,100) for i in range(100000)]
     7         1        488.0    488.0      0.0      return sum(arr) / len(arr)

Total time: 2.36355 s
File: <ipython-input-22-c9c4218f4095>
Function: slow_random_generator at line 9

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     9                                           def slow_random_generator():
    10         1    2000074.0 2000074.0     84.6      time.sleep(2)
    11         1     363000.0 363000.0     15.4      arr = [random.randint(1,100) for i in range(100000)]
    12         1        481.0    481.0      0.0      return sum(arr) / len(arr)

Total time: 1.36787 s
File: <ipython-input-22-c9c4218f4095>
Function: fast_random_generator at line 14

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    14                                           def fast_random_generator():
    15         1    1001053.0 1001053.0     73.2      time.sleep(1)
    16         1     366340.0 366340.0     26.8      arr = [random.randint(1,100) for i in range(100000)]
    17         1        480.0    480.0      0.0      return sum(arr) / len(arr)

Total time: 9.08865 s
File: <ipython-input-22-c9c4218f4095>
Function: main_func at line 19

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    19                                           def main_func():
    20         1    1367966.0 1367966.0     15.1      result = fast_random_generator()
    21         1         86.0     86.0      0.0      print(result)
    22
    23         1    2363696.0 2363696.0     26.0      result = slow_random_generator()
    24         1        109.0    109.0      0.0      print(result)
    25
    26         1    5356698.0 5356698.0     58.9      result = very_slow_random_generator()
    27         1         91.0     91.0      0.0      print(result)

lprofiler.functions
[<function __main__.fast_random_generator()>,
 <function __main__.slow_random_generator()>,
 <function __main__.very_slow_random_generator()>,
 <function __main__.main_func()>]
lprofiler.timer_unit
1e-06

3. How to Use "line_profiler" in Jupyter Notebook? ("%lprun")

Our third example explains how to use line_profiler in a jupyter notebook.

3.1 Load "line_profiler" as External Module in Notebook

We first need to load line_profiler as an external extension into the jupyter notebook using the %load_ext magic command. This will make the %lprun line magic command available to us which we can use to profile Python code.

If you are someone who is new to magic commands in Notebooks then we would recommend that you check our tutorial on it in your free time. It'll help you better manage notebooks.

%load_ext line_profiler

3.2 Profile Single Function

Below we have created a simple function that generated a numpy array of a random number between 1-100 of size 1000x1000. We are then taking an average of an array and returning average. At the start of the function, we are pausing script for 5 seconds as well.

import time
import numpy as np

def very_slow_random_generator():
    time.sleep(5)
    arr1 = np.random.randint(1,100, size=(1000,1000))
    avg = arr1.mean()
    return avg

We can then call the very_slow_random_generator() function by first registering it with the %lprun line magic command and then calling it so that code inside it will be profiled line by line.

NOTE

Please make a NOTE that we have to register all functions that we need to profile using '-f' option.

%lprun -f very_slow_random_generator very_slow_random_generator()
49.998236
Timer unit: 1e-06 s

Total time: 5.01748 s
File: <ipython-input-13-8e4f20603e75>
Function: very_slow_random_generator at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     5                                           def very_slow_random_generator():
     6         1    5005205.0 5005205.0     99.8      time.sleep(5)
     7         1      10931.0  10931.0      0.2      arr1 = np.random.randint(1,100, size=(1000,1000))
     8         1       1344.0   1344.0      0.0      avg = arr1.mean()
     9         1          1.0      1.0      0.0      return avg

3.3 Profile Multiple Functions

Below we have re-written code from the previous example. We'll try to profile all functions in the below code by using the %lprun line magic command.

import time
import random

def very_slow_random_generator():
    time.sleep(5)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def slow_random_generator():
    time.sleep(2)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def fast_random_generator():
    time.sleep(1)
    arr = [random.randint(1,100) for i in range(100000)]
    return sum(arr) / len(arr)

def main_func():
    result = fast_random_generator()
    print(result)

    result = slow_random_generator()
    print(result)

    result = very_slow_random_generator()
    print(result)

Below we have explained how we can profile all functions using the %lprun line magic command. We first need to register all functions with %lprun with -f option and then calling main_func(). This way it'll profile code of all functions.

%lprun -f main_func -f fast_random_generator -f slow_random_generator -f very_slow_random_generator main_func()
50.5898
50.31312
50.35173
Timer unit: 1e-06 s

Total time: 5.37966 s
File: <ipython-input-38-c9c4218f4095>
Function: very_slow_random_generator at line 4

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     4                                           def very_slow_random_generator():
     5         1    5005309.0 5005309.0     93.0      time.sleep(5)
     6         1     373891.0 373891.0      7.0      arr = [random.randint(1,100) for i in range(100000)]
     7         1        457.0    457.0      0.0      return sum(arr) / len(arr)

Total time: 2.33906 s
File: <ipython-input-38-c9c4218f4095>
Function: slow_random_generator at line 9

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     9                                           def slow_random_generator():
    10         1    2002214.0 2002214.0     85.6      time.sleep(2)
    11         1     336388.0 336388.0     14.4      arr = [random.randint(1,100) for i in range(100000)]
    12         1        454.0    454.0      0.0      return sum(arr) / len(arr)

Total time: 1.35545 s
File: <ipython-input-38-c9c4218f4095>
Function: fast_random_generator at line 14

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    14                                           def fast_random_generator():
    15         1    1001058.0 1001058.0     73.9      time.sleep(1)
    16         1     353907.0 353907.0     26.1      arr = [random.randint(1,100) for i in range(100000)]
    17         1        482.0    482.0      0.0      return sum(arr) / len(arr)

Total time: 9.07528 s
File: <ipython-input-38-c9c4218f4095>
Function: main_func at line 19

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    19                                           def main_func():
    20         1    1355544.0 1355544.0     14.9      result = fast_random_generator()
    21         1        118.0    118.0      0.0      print(result)
    22
    23         1    2339153.0 2339153.0     25.8      result = slow_random_generator()
    24         1        351.0    351.0      0.0      print(result)
    25
    26         1    5379754.0 5379754.0     59.3      result = very_slow_random_generator()
    27         1        362.0    362.0      0.0      print(result)
Sunny Solanki  Sunny Solanki

Share Views Stuck Somewhere? Need Help with Coding? Have Doubts About the Topic/Code?

When going through coding examples, it's quite common to have doubts and errors.

If you have doubts about some code examples or are stuck somewhere when trying our code, send us an email at coderzcolumn07@gmail.com. We'll help you or point you in the direction where you can find a solution to your problem.

You can even send us a mail if you are trying something new and need guidance regarding coding. We'll try to respond as soon as possible.

Share Views Want to Share Your Views? Have Any Suggestions?

If you want to

  • provide some suggestions on topic
  • share your views
  • include some details in tutorial
  • suggest some new topics on which we should create tutorials/blogs
Please feel free to contact us at coderzcolumn07@gmail.com. We appreciate and value your feedbacks. You can also support us with a small contribution by clicking DONATE.