Profiling Django applications – part2

2012-08-13 django

Profiling using CProfile.

Sometimes it is advantageous to look at what your application is doing before it goes in to production. Using tools like iPDB and PDB we can step through code, particularly in the view that you are working on, but it doesn’t tell the full picture of what is going on up-until that view is called, or after the HTTPResponse is starting to be returned.

It is easy to start profiling django runserver using CProfile:

 python -m CProfile manage.py runserver --noreload > profileout 

Here what we are doing is starting up manage.py runserver wrapped in the profiler – CProfile. We start runserver with –noreload so that it doesn’t fork the filesystem watching process that probably doesn’t need to be profiled, and then we push the results of CProfile out to a file called “profileout”.

This will give us output like this:

So what we can see here is a list of calls, files and the time it takes to complete and how often they are called.

This is some interesting information, and there are actually plenty of resources to look into this. In a later part of the serious we will further into these results.

But I prefer that we actually look into where we spend the most time and so I often take the results of CProfile and create a graph of it.

 python -m CProfile -o output.pstats manage.py runserver --noreload 

This time we are running whilst outputing to output.pstats, a file that we can then feed into various utilities such as gprof2dot. This requires the dot library for generating graphs (installed on my OSX system using homebrew). Gprof2dot is available from http://code.google.com/p/jrfonseca/wiki/Gprof2Dot – simply download and install it. It requires graphviz.

 python gprof2dot.y -f pstats output.pstats | dot -Tpng -o output.png 

This will then create a png graph of where the most time is spent as a program is called.