Django Query extremely slow

Question

I have a problem with a Django application. Queries on the model Scope are extremely slow and after some debugging I still have no clue where the problem lies.

When I query the db like scope = Scope.objects.get(pk='Esoterik I') it takes 5 to 10 seconds. The database has less than 10 entries and an index on the primary key, so it is way too slow. When executing the an equivalent query on the db like SELECT * FROM scope WHERE title='Esoterik I'; everything is ok and it takes only about 50ms.

The same problem happens if I query a set of results like scope_list = Scope.objects.filter(members=some_user) and then call print(scope_list) or iterate over the list elements. The query itself only takes a few ms but the print or iterating of the elements takes again like 5 to 10 seconds but the set has only two entries.

Database Backend is Postgresql. The same problem occurs on the local development server and apache.

Here the code of the model:

class Scope(models.Model):
    title = models.CharField(primary_key=True, max_length=30)

    ## the semester the scope is linked with
    assoc_semester  =   models.ForeignKey(Semester, null=True) 

    ## the grade of the scope. can be Null if the scope is not a class
    assoc_grade     =   models.ForeignKey(Grade, null=True)

    ## the timetable of the scope. can be null if the scope is not direct associated with a class
    assoc_timetable =   models.ForeignKey(Timetable, null=True)

    ## the associated subject of the scope
    assoc_subject   =   models.ForeignKey(Subject)

    ## the calendar of the scope
    assoc_calendar  =   models.ForeignKey(Calendar)

    ## the usergroup of the scope
    assoc_usergroup =   models.ForeignKey(Group)

    members = models.ManyToManyField(User)

    unread_count = None

update

Here is the output of the python profiler. It seems that query.py was getting called 1.6 million times - a little too much.

Answer 1

You should try and first isolate the problem. Run manage.py shell and run the following:

scope = Scope.objects.get(pk='Esoterik I')
print scope

Now django queries are not executed until they very much have to. That is to say, if you're experiencing slowness after the first line, the problem is somewhere in the creation of the query which would suggest problems with the object manager. The next step would be to try and execute raw SQL through django, and make sure the problem is really with the manager and not a bug in django in general.

If you're experiencing slowness with the second line, the problem is eitherwith the actual execution of the query, or with the display\printing of the data. You can force-execute the query without printing it (check the documentation) to find out which one it is.

That's as far as I understand but I think the best way to solve this is to break the process down to different parts and finding out which part is the one causing the slowness

Answer 2

For being sure about the database execution time, it is better to test queries generated by Django since Django-generated queries may not be a simple SELECT * from blah blah

To see the Django generated query:

_somedata = Scope.objects.filter(pk='Esoterik I') # you must use filter in here
print somedata.query.__format__('')

This will display you the complete query generated by Django. Then copy it and open a Postgresql console and use Postgresql analyze tools:

EXPLAIN ANALYZE <your django query here>;

like:

EXPLAIN ANALYZE SELECT * FROMsomeapp_scope WHERE id = 'Esoterik I';

EXPLAIN will show average execution data while ANAYLZE will also show you some extra data about execution time of that analyze.

You can also see if any index is used by postgresql during query execution in those analyze results.