Django profiler: My journey to code optimization

For those who have ever written Django code or in fact any code would understand when I say, how tedious it can be to find those bottlenecks and optimize your code.

With me, the similar situation arises during my internship at GreedyGame, when I was assigned a Django project Nucleya, which would serve as GreedyGame’s internal inventory management tool.

I completed the API within a week and a half but it would not comply with our business logic.
Since, Nucleya would be serving as an internal micro-service API to other panels, it’s response time had to be under 10 ms like others.

When I bench-marked my code with ab-Apache bench-marking tool, it gave a response time of about 500 ms, which was much higher than the sweet spot of 10 ms.

Django ORM benchmarking results

So, what to do? How to know what was going wrong?
With trial and error, I managed to get it to 17 ms, but still, the problem was unknown.
Then my CTO, Arink Verma suggested me to use profiling, but then came an another challenge…
I was not able to find any usable and properly documented tool for the same.
Either they were too complicatedly documented, or
They were not in maintenance anymore, or
They required to install and add a hell lot of stuff in my machine and code.

Then finally, I came back to cProfile (ironically, which I skipped before because of its simplicity) and it served the purpose.

My experience from my profiler hunt motivated me to build an easy to use, user-friendly 2 step profiling middleware. Neither too complicate nor any unnecessary installations.

A Trip to my code blocks:

Identification and removal of bottlenecks

For my Search API, I used Django ORM, which gave accurate results, but the response time was above 550 ms.

Initital code (Django-orm)

Profiling results:

Profiling results for Django-orm

There it is!!
Clearly, those insane numbers of database queries were the first problem, taking about 23% of total time. Generally, if your program is making more than 50 db queries it is bound to be slow, and in my case, the number was 851, so that was definitely an issue.

Now, to know what these queries exactly were, I checked out the MySQL log file which gives all the MySQL queries made to the database.

So, Did you get the problem??
What actually happened there was that as Django querysets are lazy, they only fetch information when it is required.
So, in my case it was making repeated trips to the database for all the 286 objects and then for each of that 286 objects, trips to the database to fetch those many to many fields.

I tried using custom serializers, prefetch_related etc., which improved the response time, but did not serve my requirement of 10 ms.

So, I decided to go with the direct approach- raw SQL.

Optimized code (raw SQL)

Here we just bypassed Django and directly written the MySQL query we need to execute.
And it was the time, bench-marking results gave a response time of 8.15 ms.

Raw SQL Benchmarking results

Let’s see what profiling results have to say.

Profiling results for raw SQL

Now that’s something Interesting…
We were making just 2 database queries as compared to 851 earlier and the time was reduced by freaking 98%.

I know there are a lot of Django profiling middlewares out there, but my motivation for this one was to make one of my own and most importantly, one that can be easily used by beginners like me, in which no fancy technical words are used nor any obvious-seeming skips are made.
I have tried to keep it as explanatory as possible, but would really appreciate any changes and contributions to it.

Again you can check out my middleware at django-profile-middleware

I am an undergraduate student pursuing my B tech from Indian Institute of Technology Roorkee. Although, I have a keen interest in Data Sciences, Machine Learning and Entrepreneurship, I love to talk and discuss about any thing under the sun and even above it.
Check out my linkedin profile to know more about me: