[Django] #33973: Performance regression when moving from 3.1 to 3.2
Django
-------------------------------------+-------------------------------------
Reporter: Marc | Owner: nobody
Parizeau |
Type: | Status: new
Uncategorized |
Component: | Version: 3.2
Uncategorized | Keywords: performance
Severity: Normal | regression
Triage Stage: | Has patch: 0
Unreviewed |
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
-------------------------------------+-------------------------------------
I am seing a sharp increase in execution time for some of my queries when
moving from Django 3.1 to 3.2. And the performance hit appears to be the
same for Django 4.
My backend is Postgres 14.2.
My Django project has forums for different types of content. The forum app
consists essentially of 5 tables:
1. a `Post` table that contains forum posts (essentially a text field);
2. a `Thread` table where rows point to a specific content and post;
3. a `FollowUp` table where rows point to a specific thread and post;
4. a `ThreadEntry` table where rows point to a thread, a user, and the
last seen thread post for this user;
5. a `FollowUpEntry` table where rows point to a followup, a user, and the
last seen followup post for this user.
Here is an example query that executes 2 times slower on 3.2 than on 3.1:
{{{
Content.objects.all().annotate(
has_unread_posts=Greatest(
# a content is unread if at least one condition is true
Exists(
# a thread has never been read (has no user entry)
Thread.objects.filter(
content=OuterRef('pk'),
).exclude(threadentry__user=user)
),
Exists(
# a thread entry is not up-to-date
ThreadEntry.objects.filter(
thread__content=OuterRef('pk'),
user=user,
).exclude(post=F('thread__post'))
),
Exists(
# a followup has never been read
FollowUp.objects.filter(
thread__content=OuterRef('pk')
).exclude(followupentry__user=user)
),
Exists(
# a followup entry is not up-to-date
FollowUpEntry.objects.filter(
followup__thread__content=OuterRef('pk'),
user=user,
).exclude(post=F('followup__post'))
),
)
).filter(
has_unread_posts=True,
).order_by(
'course__uid',
'-version__start',
).select_related(
'course',
'version',
)
}}}
`Course` and `Version` are other tables related to `Content`.
I want to know with this query, for each content, whether or not there is
something new in the corresponding forum for a given user. There is
something new if any one of the following condition is true:
1. there exists a thread for which the user has no thread entry (an entry
is added when the thread is first read by the user);
2. there exists a user thread entry for which the last read post is not up
to date with the current thread post (the thread owner has modified the
post since);
3. there exists a followup for which the user has no followup entry (an
entry is added when the followup is first read by the user);
4. there exists a user followup entry for which the last read post is not
up to date with the followup post (the followup owner has modified the
post since).
On my machine, just by changing the Django version using pip, and nothing
else, this query takes about 1 second of execution on Django 3.1.14, and a
little more than 2 seconds on Django 3.2.15, so about a 2x increase. Here
are the current table sizes for my forum app:
- `Thread`: ~30K
- `FollowUp`: ~46K
- `ThreadEntry`: ~1.3M
- `FollowUpEntry`: ~4.5M
- `Post`: ~103K
And there is 33 `Content` rows.
Am I the only one observing such performance regressions with Django 3.2?
On other more complex queries that contain nested subqueries, I have seen
up to **30x** execution time increases.
Did something major happen in SQL generation from 3.1 to 3.2?
Am I doing something wrong? How can this happen?
Any help on understanding what is going on with Django 3.2 would be much
appreciated.
Best regards,
--
Ticket URL: <https://code.djangoproject.com/ticket/33973>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
-------------------------------------+-------------------------------------
Type: Uncategorized | Status: new
Component: Uncategorized | Version: 3.2
Severity: Normal | Resolution:
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Marc Parizeau):
After more digging, it appears that the two worst culprits in my query are
the 1st and 3rd `Exists`. The 1st is about 10x slower on 3.2.15 than on
3.1.14. The 3rd is about 6x slower on 3.2.15 than on 3.1.14. The execution
times for the 2nd and 4th `Exists` are about the same for 3.2 and 3.1.
If I use only the 1st `Exists` in my query, by commenting out the 3
others, and by adding a False for the `Greatest` requirement of min 2
args, I obtain de following explanations (I also removed the `order_by`
and `select_related` clauses to simplify the query as much as possible):
On Django 3.1.14:
{{{
time 0.03233041700000072
Sort (cost=25581.33..25581.33 rows=1 width=1207)
Sort Key: content_course.uid, content_version.start DESC
-> Nested Loop Left Join (cost=0.14..25581.32 rows=1 width=1207)
Join Filter: (content_content.version_id = content_version.id)
-> Nested Loop Left Join (cost=0.14..13437.94 rows=1 width=1202)
Join Filter: (content_content.course_id = content_course.id)
-> Nested Loop (cost=0.14..13436.58 rows=1 width=1124)
-> Seq Scan on content_teacher (cost=0.00..7.65
rows=1 width=8)
Filter: (user_id = 59)
-> Index Scan using content_semester_pkey on
content_content (cost=0.14..12150.00 rows=1 width=1124)
Index Cond: (id = content_teacher.content_id)
Filter: ((id <> 58) AND GREATEST((hashed SubPlan
8), false))
SubPlan 8
-> Seq Scan on forum_thread v0_1
(cost=12114.13..13913.92 rows=14672 width=8)
Filter: (NOT (hashed SubPlan 7))
SubPlan 7
-> Bitmap Heap Scan on
forum_threadentry u1_1 (cost=75.76..12097.65 rows=6592 width=8)
Recheck Cond: (user_id = 59)
Filter: (thread_id IS NOT NULL)
-> Bitmap Index Scan on
forum_threadentry_user_id_585e5649 (cost=0.00..74.11 rows=6625 width=0)
Index Cond: (user_id = 59)
-> Seq Scan on content_course (cost=0.00..1.16 rows=16
width=86)
-> Seq Scan on content_version (cost=0.00..1.24 rows=24
width=12)
SubPlan 2
-> Bitmap Heap Scan on forum_thread v0
(cost=12139.37..13583.67 rows=587 width=0)
Recheck Cond: (content_id = content_content.id)
Filter: (NOT (hashed SubPlan 1))
-> Bitmap Index Scan on
forum_question_semester_id_e4f29334 (cost=0.00..25.09 rows=1174 width=0)
Index Cond: (content_id = content_content.id)
SubPlan 1
-> Bitmap Heap Scan on forum_threadentry u1
(cost=75.76..12097.65 rows=6592 width=8)
Recheck Cond: (user_id = 59)
Filter: (thread_id IS NOT NULL)
-> Bitmap Index Scan on
forum_threadentry_user_id_585e5649 (cost=0.00..74.11 rows=6625 width=0)
Index Cond: (user_id = 59)
}}}
On Django 3.2.15:
{{{
time 0.30839854199999195
Sort (cost=62.30..62.31 rows=1 width=1207)
Sort Key: content_course.uid, content_version.start DESC
-> Nested Loop Left Join (cost=0.41..62.29 rows=1 width=1207)
-> Nested Loop Left Join (cost=0.28..40.58 rows=1 width=1202)
-> Nested Loop (cost=0.14..39.68 rows=1 width=1124)
-> Seq Scan on content_teacher (cost=0.00..7.65
rows=1 width=8)
Filter: (user_id = 59)
-> Index Scan using content_semester_pkey on
content_content (cost=0.14..28.99 rows=1 width=1124)
Index Cond: (id = content_teacher.content_id)
Filter: ((id <> 58) AND GREATEST((SubPlan 3),
false))
SubPlan 3
-> Nested Loop Anti Join
(cost=0.43..18547.19 rows=909 width=0)
-> Seq Scan on forum_thread v0_1
(cost=0.00..1799.79 rows=1174 width=8)
Filter: (content_id =
content_content.id)
-> Index Only Scan using
forum_threadentry_thread_id_user_id_cd21c4a5_uniq on forum_threadentry
u1_1 (cost=0.43..55.66 rows=33 width=8)
Index Cond: ((thread_id = v0_1.id)
AND (user_id = 59))
-> Index Scan using content_course_pkey on content_course
(cost=0.14..0.82 rows=1 width=86)
Index Cond: (id = content_content.course_id)
-> Index Scan using content_version_pkey on content_version
(cost=0.14..0.82 rows=1 width=12)
Index Cond: (id = content_content.version_id)
SubPlan 1
-> Nested Loop Anti Join (cost=0.43..18547.19 rows=909
width=0)
-> Seq Scan on forum_thread v0 (cost=0.00..1799.79
rows=1174 width=8)
Filter: (content_id = content_content.id)
-> Index Only Scan using
forum_threadentry_thread_id_user_id_cd21c4a5_uniq on forum_threadentry u1
(cost=0.43..55.66 rows=33 width=8)
Index Cond: ((thread_id = v0.id) AND (user_id = 59))
}}}
So it appears that the strategies of the two Django versions are indeed
not the same. And it also appears that the regression stems from the
implementation of `exclude(threadentry__user=user)` clause.
Hope this info can help a gourou isolate the problem source (SQL is out of
my league).
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:1>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: new
Component: Uncategorized | Version: 3.2
Severity: Normal | Resolution:
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Marc Parizeau):
So the exact Django query that lead to the above results is:
{{{
Content.objects.filter(
teacher__user=user,
).exclude(
pk=content.pk,
).annotate(
unread=Greatest(
Exists(
# a thread has no user entry (0.03; 0.30)
Thread.objects.filter(
content=OuterRef('pk'),
).exclude(threadentry__user=user)
),
)
).filter(
unread=True,
)
}}}
Which produces the following SQL.
**On Django 3.1.14**:
{{{
SELECT "content_content"."id", "content_content"."created",
"content_content"."description", "content_content"."disabled",
"content_content"."modified", "content_content"."objectives",
"content_content"."published", "content_content"."title",
"content_content"."course_id", "content_content"."version_id",
"content_content"."exercise_weight", "content_content"."midterm_weight",
"content_content"."final_weight", "content_content"."project_weight",
"content_content"."forum_weight", "content_content"."welcome_video",
"content_content"."navigate_video", "content_content"."forum_video",
"content_content"."lambda_fct_id", "content_content"."dl_key_version",
"content_content"."dl_key_token", "content_content"."exam_key_token",
"content_content"."lectures_url", GREATEST(EXISTS(SELECT V0."id",
V0."created", V0."disabled", V0."modified", V0."title", V0."content_id",
V0."owner_id", V0."post_id", V0."tag", V0."start", V0."uid",
V0."question", V0."important", V0."resolved", V0."authorized", V0."votes",
V0."mptt_id", V0."linked_content_type_id", V0."linked_content_id" FROM
"forum_thread" V0 WHERE (V0."content_id" = "content_content"."id" AND NOT
(V0."id" IN (SELECT U1."thread_id" FROM "forum_threadentry" U1 WHERE
(U1."user_id" = 59 AND U1."thread_id" IS NOT NULL))))), False) AS "unread"
FROM "content_content" INNER JOIN "content_teacher" ON
("content_content"."id" = "content_teacher"."content_id") LEFT OUTER JOIN
"content_course" ON ("content_content"."course_id" =
"content_course"."id") LEFT OUTER JOIN "content_version" ON
("content_content"."version_id" = "content_version"."id") WHERE
("content_teacher"."user_id" = 59 AND NOT ("content_content"."id" = 58)
AND GREATEST(EXISTS(SELECT V0."id", V0."created", V0."disabled",
V0."modified", V0."title", V0."content_id", V0."owner_id", V0."post_id",
V0."tag", V0."start", V0."uid", V0."question", V0."important",
V0."resolved", V0."authorized", V0."votes", V0."mptt_id",
V0."linked_content_type_id", V0."linked_content_id" FROM "forum_thread" V0
WHERE (V0."content_id" = "content_content"."id" AND NOT (V0."id" IN
(SELECT U1."thread_id" FROM "forum_threadentry" U1 WHERE (U1."user_id" =
59 AND U1."thread_id" IS NOT NULL))))), False)) ORDER BY
"content_course"."uid" ASC, "content_version"."start" DESC
}}}
**On Django 3.2.15**:
{{{
SELECT "content_content"."id", "content_content"."created",
"content_content"."description", "content_content"."disabled",
"content_content"."modified", "content_content"."objectives",
"content_content"."published", "content_content"."title",
"content_content"."course_id", "content_content"."version_id",
"content_content"."exercise_weight", "content_content"."midterm_weight",
"content_content"."final_weight", "content_content"."project_weight",
"content_content"."forum_weight", "content_content"."welcome_video",
"content_content"."navigate_video", "content_content"."forum_video",
"content_content"."lambda_fct_id", "content_content"."dl_key_version",
"content_content"."dl_key_token", "content_content"."exam_key_token",
"content_content"."lectures_url", GREATEST(EXISTS(SELECT (1) AS "a" FROM
"forum_thread" V0 WHERE (V0."content_id" = "content_content"."id" AND NOT
(EXISTS(SELECT (1) AS "a" FROM "forum_threadentry" U1 WHERE (U1."user_id"
= 59 AND U1."thread_id" = V0."id") LIMIT 1))) LIMIT 1), False) AS "unread"
FROM "content_content" INNER JOIN "content_teacher" ON
("content_content"."id" = "content_teacher"."content_id") LEFT OUTER JOIN
"content_course" ON ("content_content"."course_id" =
"content_course"."id") LEFT OUTER JOIN "content_version" ON
("content_content"."version_id" = "content_version"."id") WHERE
("content_teacher"."user_id" = 59 AND NOT ("content_content"."id" = 58)
AND GREATEST(EXISTS(SELECT (1) AS "a" FROM "forum_thread" V0 WHERE
(V0."content_id" = "content_content"."id" AND NOT (EXISTS(SELECT (1) AS
"a" FROM "forum_threadentry" U1 WHERE (U1."user_id" = 59 AND
U1."thread_id" = V0."id") LIMIT 1))) LIMIT 1), False)) ORDER BY
"content_course"."uid" ASC, "content_version"."start" DESC
}}}
Again, hope this helps!
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:2>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: new
Component: Uncategorized | Version: 3.2
Severity: Normal | Resolution:
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Mariusz Felisiak):
> Did something major happen in SQL generation from 3.1 to 3.2?
Each version of Django includes many bugfixes and new ORM features that
affect the generated SQL.
Can you reproduce the same regression on Django 4.1 and the current `main`
branch? Can you
[https://docs.djangoproject.com/en/stable/internals/contributing/triaging-
tickets/#bisecting-a-regression bisect a regression]?
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:3>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: new
Component: Uncategorized | Version: 3.2
Severity: Normal | Resolution:
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Marc Parizeau):
Here is the "explanation" for Django 4.0.7:
{{{
time 0.3011052919999955
And the corresponding SQL:
{{{
SELECT "content_content"."id", "content_content"."created",
"content_content"."description", "content_content"."disabled",
"content_content"."modified", "content_content"."objectives",
"content_content"."published", "content_content"."title",
"content_content"."course_id", "content_content"."version_id",
"content_content"."exercise_weight", "content_content"."midterm_weight",
"content_content"."final_weight", "content_content"."project_weight",
"content_content"."forum_weight", "content_content"."welcome_video",
"content_content"."navigate_video", "content_content"."forum_video",
"content_content"."lambda_fct_id", "content_content"."dl_key_version",
"content_content"."dl_key_token", "content_content"."exam_key_token",
"content_content"."lectures_url", GREATEST(EXISTS(SELECT (1) AS "a" FROM
"forum_thread" V0 WHERE (V0."content_id" = ("content_content"."id") AND
NOT (EXISTS(SELECT (1) AS "a" FROM "forum_threadentry" U1 WHERE
(U1."user_id" = 59 AND U1."thread_id" = (V0."id")) LIMIT 1))) LIMIT 1),
False) AS "unread" FROM "content_content" INNER JOIN "content_teacher" ON
("content_content"."id" = "content_teacher"."content_id") LEFT OUTER JOIN
"content_course" ON ("content_content"."course_id" =
"content_course"."id") LEFT OUTER JOIN "content_version" ON
("content_content"."version_id" = "content_version"."id") WHERE
("content_teacher"."user_id" = 59 AND NOT ("content_content"."id" = 58)
AND GREATEST(EXISTS(SELECT (1) AS "a" FROM "forum_thread" V0 WHERE
(V0."content_id" = ("content_content"."id") AND NOT (EXISTS(SELECT (1) AS
"a" FROM "forum_threadentry" U1 WHERE (U1."user_id" = 59 AND
U1."thread_id" = (V0."id")) LIMIT 1))) LIMIT 1), False)) ORDER BY
"content_course"."uid" ASC, "content_version"."start" DESC
}}}
As for Django 4.1, I can't do it right now, because I am getting
`Expression contains mixed types: IntegerField, SmallIntegerField` errors
which I haven't been able to remove so far.
But my issues definitely started with Django 3.2, not with Django 4 which
seems to behave similarly for my specific query.
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:4>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Component: Database layer | Version: 3.2
(models, ORM) |
Severity: Normal | Resolution: needsinfo
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* cc: Simon Charette (added)
* resolution: => needsinfo
* status: new => closed
* component: Uncategorized => Database layer (models, ORM)
Comment:
Using `EXISTS` to exclude multi-valued relationship was introduced in
8593e162c9cb63a6c0b06daf045bc1c21eb4d7c1. However this should be is easier
to optimize for query planers, it's not clear to me why you're facing a
performance regression. Perhaps the query plan should be regenerated or
this is an issue in PostgreSQL 14.2. I don't think there is anything that
we could improve in Django.
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:5>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: closed
Component: Database layer | Version: 3.2
(models, ORM) |
Severity: Normal | Resolution: needsinfo
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Marc Parizeau):
Replying to [comment:5 Mariusz Felisiak]:
> Using `EXISTS` to exclude multi-valued relationship was introduced in
8593e162c9cb63a6c0b06daf045bc1c21eb4d7c1. However this should be is easier
to optimize for query planers, it's not clear to me why you're facing a
performance regression. Perhaps the query plan should be regenerated or
this is an issue in PostgreSQL 14.2. I don't think there is anything that
we could improve in Django.
Not sure I understand what you are saying. You are saying that the
regression I am observing is definitely not caused by the Django generated
SQL? That the issue must stem from the query planers of postgres? Are you
sure about that?
Any suggestion on what I should do moving forward? What postgres version
do you suggest I use to get the proper query planers for Django 3.2/4?
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:6>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: closed
Component: Database layer | Version: 3.2
(models, ORM) |
Severity: Normal | Resolution: needsinfo
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Simon Charette):
Bonjour Marc,
There are some sources listed on the
[https://github.com/django/django/pull/13606 PR] that introduced these
changes that documents the performance benefits of using `EXISTS` over
`IN` and the case where `IN` will be faster which I believe is what you're
experiencing here.
Given there are performance benefits in most cases and `IN` is only faster
[https://www.percona.com/blog/2020/04/16/sql-optimizations-in-postgresql-
in-vs-exists-vs-any-all-vs-join/ when the subquery returns a small number
of rows] as a hashmap can be created I believe we should keep the change
around.
The good news is that you can restore the previous behaviour by being more
explicit in your usage of `exclude` by using an explicit `IN` lookup
instead.
{{{#!python
user_thread_entries = ThreadEntry.objects.filter(user=user,
thread__isnull=False).values("thread")
Content.objects.annotate(
unread=Exists(
Thread.objects.filter(
content=OuterRef('pk'),
).exclude(pk__in=user_thread_entries)
)
).filter(
unread=True,
)
}}}
Keep in mind though that, as pointed out in the article, this query will
only be faster for users with a relatively small number of thread entries
as Postgres will turn the set of rows into a hashmap which is means that
this query will become more expensive as the number of threads user
creates increase.
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:7>
Django
-------------------------------------+-------------------------------------
Reporter: Marc Parizeau | Owner: nobody
Type: Uncategorized | Status: closed
Component: Database layer | Version: 3.2
(models, ORM) |
Severity: Normal | Resolution: needsinfo
Keywords: performance | Triage Stage:
regression | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Marc Parizeau):
Replying to [comment:7 Simon Charette]:
Thanks for the suggestion. I've tried it and it does not seem to reduce
the execution time for my test case that has about 26K threads for it's
user. So, the limitation that you mention probably applies. I am still
trying to understand what might be going on (my mastery of SQL is somewhat
limited), and why Django 3.1 was doing better than 3.2 for my specific
query. Anyway, for the time being, I've decided to move on to other
problems, since this one is mostly severe for myself, and not for my
regular users who have access to only a subset of the available contents.
I worry, however, that the problem will only grow as more content is
added...
I've also tried indexing, but so far to no improvement.
If I eventually find a solution, I will report it here.
Thanks for your help!
--
Ticket URL: <https://code.djangoproject.com/ticket/33973#comment:8>