Python profiling

There are many reasons to profile your code: You are simply baffled as to why your code is running slow, you want to learn more on the internals of the language you are programming in, you don’t want to optimise in the dark, well the list goes on and on.

Yet having written software for years, it’s a technique which isn’t much used in the world of data engineering/ big data. One of the reasons is definitely the cheap memory prices. Why would you slave for an hour reviewing your code and only gain 2 seconds if you could just add a couple gigabytes of RAM with a few mouse clicks (long live cloud right) ?

Then again, it’s just good practice to know where your code is spending most of its time so just have a look on what you can improve.

So let’s have a look and see how we can get started with profiling python code.

Demo functions

So get your python shell / IDE ready and let’s code 2 functions in a file called example_functions.py:

def increase_by_1_loop(dummy_list):
    secondlist=[]
    for i in range(0,len(dummy_list)):
        secondlist.append(dummy_list[i]+1)

    return secondlist
def increase_by_1_list_comp(dummy_list):
    return [x+1 for x in dummy_list]

The goal in each case is the same. For a given list, which contains integers, add 1 to each value.

We all know that the second function is more optimal then the first one but the goal here is to show how it works with the cProfile function.

Using the cProfile function

So now we will create a list containing integers and call each function, passing the list along.

First import the cProfile function.

import cProfile

This is a standard library in python so no need to install anything.

Next let’s create a dummy list with some values , then call the cProfiler for each of the functions we have written.

dummy_list=list(range(0,10000))

cProfile.run('increase_by_1_loop(dummy_list)', filename='first_iteration.cprof' )
cProfile.run('increase_by_1_list_comp(dummy_list)', filename='second_iteration.cprof' )

As you can see, it is easy to pass arguments to the functions within cProfile.

Run the code and you will now get 2 output files, containing the breakdown of your program.

Visualise the output

Installing prerequisites

Before we can go to the visualisation part we will first have to install some additional packages. To visualise I am going to use pyprof2calltree. Since the tool uses kcachegrind, we’ll do this installation first.

For those on mac os run the following command:

brew install qcachegrind --with-graphviz

For any other OS I suggest you google a bit, there are lots of scripts out there who can make your life a bit easier.

Next we need to install pyprof2calltree, which is a python package, so let’s use pip3:

pip3 install pyprof2calltree

Visualise the code

So everything is in place, time to view our code breakdown.

Run the following command from your terminal ( if you are using a virtualenv don’t forget to activate it and use the one where you installed pyprof2calltree)

pyprof2calltree -k -i /pythonprofiling/profiler/first_iteration.cprof

Total overview of the code including graph

The output gives us an insight on the time the programming has been running and where most time has spent. In our example we can see that most of the time was spend in the function increase_by_1_loop. Furthermore we saw that the append function was called 10000 times and that it takes a total of 4.8 millions nanoseconds to call the function. In the break down you could go even further and have a look at how long a single append takes, but I guess you get the picture.

Specific view (upper right pane) on total time execution per call

So basically our program isn’t that efficient. So let’s check the second function.

From the generic view we see a lot less calls being made and since we use list comprehension, there is less complexity inside the function.

General breakdown of the comprehension list

If we have a look at the detailed view we see that the function call, increase_by_1_list_comp, only takes 744000 nanoseconds to complete, so we are about 6 times more efficient then in the previous version.

Detailed info on how long a single function call takes

Final words

While it is true that many developers are short on time when having to deliver a product, it’s not a bad thing to look at the basics. As an alternative you could generate these graphs as part of a code review. Once you have written your program it takes only a small amount of time to adapt the code and have a profiler in place.

If you want to view the entire codebase you can find it on my github page.