Profiling in Django
Profile your Django apps with ease.
This article is written as a part of Individual Review competency for Software Projects course 2020 at Faculty of Computer Science, University of Indonesia.
As developers, we strive to bring feature requirements to life. We utilized every tool at our disposal to fulfill them. The product is validated, the features are accepted. Great.
But sometimes, the unintended happens: our application perform poorly, the request-response cycles takes too long, and other performance issues arise. This leads us to a question: how to easily spot which code that bring impacts to the performance?
This article will discuss briefly about profiling and give examples of profiling tools to profile a Django application.
Taken from Wikipedia, profiling is a form of dynamic program analysis that measures, for example, the space or time complexity of a program, the usage of particular instructions, or the frequency and duration of function calls.
Profiling can be achieved either by instrumenting either the program source code or using a tool called profiler. This article will limit the discussion to the latter. The aforementioned metrics are related to the performance of our application. Knowing which aspect our application performed poorly is advantageous as to knowing which “hot spot” that can be optimized.
Django Profiling Tools
Many Python profiling tools exist, but this article will limit only to the most used tools:
django-silk . The two tools mainly profile in regards to function calls and execution time.
Profiling Django with cProfile
cProfile is a built-in profiler tool provided by Python. Alongside
profile , it provides deterministic profiling of Python programs.
cProfile is recommended for most users as it brings more reasonable overhead than
profile . Thus,
cProfile is more suitable for profiling long-running programs.
The official documentation provides a manual for profiling simple Python application and detailed reference on its module. To incorporate
cProfile to Django views, we can write our own middleware that captures the profiling on every request sent to our Django views. But thankfully, there exists a simpler solution: django-cprofile-middleware. It is a simple profiling middleware created by a Github user omarish. With a simple installation to our Django application, we can profile any Django view with it.
To install this middleware with
pip, just run
pip install django-cprofile-middleware
django_cprofile_middleware.middleware.ProfilerMiddleware to the end of
MIDDLEWARE in the settings file (usually
It should look like this:
MIDDLEWARE = [
Or, if you are using Django version lower than 1.10, add the middleware to the of
The profiler will only be available when the setting
DEBUG is set to
True . It also requires us to be logged-in as an authenticated user which
is_staff option is set to
True . To disable this requirement, we can add an additional setting as follows:
DJANGO_CPROFILE_MIDDLEWARE_REQUIRE_STAFF = False .
Now we are going to profile an endpoint with the code snippet below as its corresponding view class.
Basically, the view will look up a user object from the database by username and email from the given
The view can be accessed from
To profile this view with the installed middleware, we can just append
prof parameter to the end of the URL, i.e.
Here is the result from the profiler, displayed in HTML output:
There is a lot going on in the output. Let’s take a look at what every line represents…
- The first line indicates that 1850 function calls were monitored. Out of 1850 calls, 1811 were primitive, which means that they were not induced via recursions.
- The second line:
Ordered by: internal time, tells us that the output was sorted by the
Now onto the columns…
ncalls: total number of calls to the given function at the corresponding row. You may noticed that there are two numbers displayed (for example
245/242). This data means that the respective function recursed (performed recursion), where the second value,
242is the number of primitive calls and the first value,
245is the total number of calls.
tottime: the total time spent in the given function at the corresponding row (excluding call time to sub-functions).
percall(the first one): the quotient of
cumtime: the cumulative time spent in the given function including its subfunctions.
percall(the second one): the quotient of
cumtimedivided by primitive calls.
filename:lineno(function_name): the respective function.
We can also tell the middleware how many results to be displayed by adding query parameter
count with zero or positive integer value. For example:
This has the default value of 100.
Are we stuck with this form of display? Of course not, we can visualize the profile result further with Python profiler visualizing library, such as
SnakeViz . We will choose
SnakeViz for this demonstration.
pip , run
pip install SnakeViz .
Before visualizing the profile result, we need to download it by adding query parameter
download . For example:
Save the output file to any directory. By default the file will be named
Open the command line to where the
view.prof is located, then run
snakeviz view.prof . The library will open a web server on port
8080 and automatically open a web page containing the visualization.
The visualized data is very interactive. We can inspect a single function call to see its profile information, such as call stack, file name, line number (where the function resides), and the file directory in which the file resides in our working directory. In addition, we received the previous profile data with sorting and searching features.
We can also tweak the
SnakeViz ‘s settings such as display style, function call depth, and cutoff, as shown in the figure above.
With this tool, we can interactively pinpoint which line of code that brings performance impact to our view. Once pinpointed, we can take appropriate action such as optimizing the code.
Profiling Django with django-silk
cProfile has done us good in pinpointing which line of code that brought performance impact to our view. But the profile result could not show which database query that brings performance hit. This is needed especially when our application is centered around database (SQL) queries.
django-silk comes in.
django-silk is developed and maintained by the good folks at Jazzband. The library, called Silk, has the ability to display database queries information to its user interface (UI). That’s what makes this tool is much more powerful and more suitable for Django application. In fact, Silk can also be combined with
cProfile , giving us a complete profiling tool.
Silk can be installed via
pip via this command:
pip install django-silk
Then, we need to add the followings in
MIDDLEWARE = [
]INSTALLED_APPS = [
To enable access to the UI, we need to add the following to
urlpatterns += [path("silk/", include("silk.urls", namespace="silk"))]
Make sure to run
python manage.py migrate and
python manage.py collectstatic before using Silk.
Now, Silk will automatically intercept requests we make to our views and the UI can be accessed from the path
We will use the same URL from the
cProfile section for this demonstration:
After making some requests to the view, the results will be displayed in the Silk UI.
We can see from the above figure that every requests were intercepted. Silk gives us the timestamp of the request (in UTC), the HTTP method and response code, the URL accessed, the total time spent overall, the total time on making database queries, and how many queries were made.
We can inspect a profile result to see the details, as shown in the figure below.
Each detail contains the information on query parameters (if any), request headers, response headers and raw response body (not shown above).
Note: Because Silk intercepts and stores all HTTP requests into the database in plain text (to Silk’s own database tables), including sensitive ones, it is imperative that we should only use Silk in development or testing environment as to not bring the Silk database into production environment.
Remember that Silk has the ability to show the database queries? We can see them by going into the “SQL” section.
We can see all the queries including involved tables, number of SQL joins, and execution time in miliseconds. Clicking one of the query will result in another SQL detail page.
We can see the raw SQL query alongside the Python stacktrace that leads up to the said query. By having this information, we can learn what goes on behind the scene as we make Django ORM (Object Relational Mapping) calls from the Python level inside the view. We can decide whether our ORM queries were efficient or not and we can take appropriate actions.
Profiling is an important activity in software engineering. It enables us to inspect our application so we can decide whether we should do optimization or not. Having a good profiling tool is also important; we can rely on them on finding “hot spot” in our application.
This wraps up the article. If you have any suggestions, don’t hesitate to comment :)
Thanks for reading!
The Python Profilers - Python 3.8.2 documentation
Source code: Lib/profile.py and Lib/pstats.py and provide deterministic profiling of Python programs. A profile is a…
This is a simple profiling middleware for Django applications. I wrote it because I got tired of printing "start"…