[Django] #27982: Possible race condition related to queryset union
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
Component: Database | Version: 1.11
layer (models, ORM) |
Severity: Normal | Keywords:
Triage Stage: | Has patch: 0
Unreviewed |
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
-------------------------------------+-------------------------------------
I found a strange bug: the results from a paginator are affected randomly
by setting breakpoints in the IDE.
The bug appears '''only''' when I am using `union` on a queryset.
I am using Django 1.11rc1 with DRF 3.6.2.
The models:
{{{
class BaseNotification(models.Model):
user = models.ForeignKey(settings.AUTH_USER_MODEL,
on_delete=models.CASCADE)
type = models.CharField(max_length=10, choices=TYPES,
default=TYPE_SIMPLE, blank=True)
popup_type = models.CharField(max_length=10, choices=POPUP_TYPES,
default=POPUP_DEFAULT)
title = models.CharField(max_length=200, blank=True)
message = models.TextField()
completed = models.BooleanField(blank=True, default=False)
date_completed = models.DateTimeField(null=True, blank=True,
default=None)
date_created = models.DateTimeField(auto_now_add=True)
class SimpleNotification(BaseNotification):
def save(self, *args, **kwargs):
self.type = self.TYPE_SIMPLE
super().save(*args, **kwargs)
class DecisionNotification(BaseNotification):
... (not relevant)
}}}
The view:
{{{
class NotificationView(ListAPIView):
permission_classes = [IsAuthenticated]
filter_backends = [OrderingFilter]
ordering_fields = ['completed', 'date_created', 'type']
ordering = ['-completed', '-date_created']
serializer_class = NotificationSerializer
def get_queryset(self):
qs1 =
SimpleNotification.objects.filter(user=self.request.user).only(
'type', 'popup_type', 'completed', 'date_created')
qs2 =
DecisionNotification.objects.filter(user=self.request.user).only(
'type', 'popup_type', 'completed', 'date_created')
qs = qs1.union(qs2)
return qs
}}}
The serializer:
{{{
class NotificationSerializer(serializers.ModelSerializer):
title = serializers.CharField(source='the_title')
class Meta:
model = SimpleNotification
fields = ['type', 'popup_type', 'title', 'url', 'completed',
'date_created']
}}}
The problem: I have 5 notifications in DB (3 simple, 2 decision), but it
returns only the first one in normal usage, and sometimes all or sometimes
one when I am using breakpoints.
I've isolated the problem near this line of code:
https://github.com/tomchristie/django-rest-
framework/blob/master/rest_framework/pagination.py#L208. If I put a
breakpoint inside the paginator's init
(https://github.com/django/django/blob/master/django/core/paginator.py#L29)
I get the correct result every time.
http://i.imgur.com/9zoikMQ.png
http://i.imgur.com/bsHgxig.png
I've also attached a video showing the results while using different
breakpoints.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Old description:
New description:
class SimpleNotification(BaseNotification):
http://i.imgur.com/9zoikMQ.png
http://i.imgur.com/bsHgxig.png
--
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:1>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Old description:
> I found a strange bug: the results from a paginator are affected randomly
New description:
class SimpleNotification(BaseNotification):
http://i.imgur.com/9zoikMQ.png
http://i.imgur.com/bsHgxig.png
Here's a short video (1m 35s, 11.6MB)
https://www.dropbox.com/s/72u46vx2n0y9h9y/bug.webm?dl=0
--
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:2>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Tim Graham):
Can you try to simplify the report into a minimal test case that doesn't
involve DRF so we can rule out an issue there and so it's easier to
reproduce the issue?
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:3>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
Yes, it's totally reproducible without DRF.
The view:
{{{
def bug_test(request):
qs1 = SimpleNotification.objects.only(
'type', 'popup_type', 'completed', 'date_created')
qs2 = DecisionNotification.objects.only(
'type', 'popup_type', 'completed', 'date_created')
qs = qs1.union(qs2).order_by('-date_created')
paginator = Paginator(qs, 20)
page = request.GET.get('page')
try:
objects = paginator.page(page)
except (PageNotAnInteger, EmptyPage):
objects = paginator.page(1)
return render(request, 'bug/index.html', {'result': len(objects)})
}}}
Results:
http://i.imgur.com/XzcW5p4.png
http://i.imgur.com/Girk0pO.png
With a breakpoint inside paginator's init I get the correct results,
without it I get only one notification.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:4>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* cc: Florian Apolloner (added)
Comment:
I guess the issue may be that unioning `SimpleNotification` and
`DecisionNotification` won't work well if you have objects pointing to the
same `BaseNotification` since the primary keys will be the same. Perhaps
that case needs to be prohibited?
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:5>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
More info:
`BaseDecision` is abstract.
Running on pg 9.4 with psycopg2 2.7.1
I've added `all=True` to the union and now I get 3 result instead of 1
when it's not working.
http://i.imgur.com/jJ7wBfn.png
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:6>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Tim Graham):
Please check if the same query is running in all cases.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:7>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
Yes, it's the same query.
The version with `all=True`:
{{{
(SELECT "notification_simplenotification"."id",
"notification_simplenotification"."type",
"notification_simplenotification"."popup_type",
"notification_simplenotification"."completed",
"notification_simplenotification"."date_created" FROM
"notification_simplenotification" ORDER BY
"notification_simplenotification"."date_created" DESC) UNION ALL (SELECT
"notification_decisionnotification"."id",
"notification_decisionnotification"."type",
"notification_decisionnotification"."popup_type",
"notification_decisionnotification"."completed",
"notification_decisionnotification"."date_created" FROM
"notification_decisionnotification" ORDER BY
"notification_decisionnotification"."date_created" DESC) ORDER BY (5) DESC
}}}
Without:
{{{
(SELECT "notification_simplenotification"."id",
"notification_simplenotification"."type",
"notification_simplenotification"."popup_type",
"notification_simplenotification"."completed",
"notification_simplenotification"."date_created" FROM
"notification_simplenotification" ORDER BY
"notification_simplenotification"."date_created" DESC) UNION (SELECT
"notification_decisionnotification"."id",
"notification_decisionnotification"."type",
"notification_decisionnotification"."popup_type",
"notification_decisionnotification"."completed",
"notification_decisionnotification"."date_created" FROM
"notification_decisionnotification" ORDER BY
"notification_decisionnotification"."date_created" DESC) ORDER BY (5) DESC
}}}
The original queryset it's OK in paginator, only the count and the results
are not OK: http://i.imgur.com/eFOFqUY.png
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:8>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
Digging deeper, I found something interesting here:
https://github.com/django/django/blob/master/django/core/paginator.py#L69
http://i.imgur.com/W3AwbEQ.png
If I change the `@cached_property` to `@property`, it is called 5 times
and only the first time it shows `[1, 5]`, the other 4 times it shows `[5,
5]`.
Nonetheless, if I remove the breakpoint it returns only one notification.
If I change the order in the list, `[len(self.object_list),
self.object_list.count()]` it shows every time `[5, 5]`.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:9>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
More info on the bug.
When `paginator.count`
(https://github.com/django/django/blob/master/django/core/paginator.py#L69)
is accessed, it calls the queryset's count
(https://github.com/django/django/blob/master/django/db/models/query.py#L339).
At this moment the queryset is not evaluated yet, so it doesn't have a
`_result_cache`, resulting in a call to its own query's `get_count()`
(https://github.com/django/django/blob/master/django/db/models/sql/query.py#L479),
which calls `get_aggregation` where we find at line 466 `result =
compiler.execute_sql(SINGLE)` which always returns only one object from
DB.
Now another interesting part: the result from DB is fetched here:
https://github.com/django/django/blob/master/django/db/models/sql/compiler.py#L885,
and it looks like `<class 'tuple'>: (1, 'simple', 'info', False,
datetime.datetime(2017, 3, 23, 13, 8, 42, 794329))`. From this tuple the
count gets its value, which in reality is the id of the object fetched
from database.
I've added another simple notification to db and I could confirm the bug
by running with `all=True`, which earlier returned `3`, now it returns `4`
(from `<class 'tuple'>: (4, 'simple', 'primary', False,
datetime.datetime(2017, 3, 24, 12, 40, 20, 376582))`).
The query that runs is the same as earlier:
{{{
(SELECT "notification_simplenotification"."id",
"notification_simplenotification"."type",
"notification_simplenotification"."popup_type",
"notification_simplenotification"."completed",
"notification_simplenotification"."date_created" FROM
"notification_simplenotification" ORDER BY
"notification_simplenotification"."date_created" DESC) UNION (SELECT
"notification_decisionnotification"."id",
"notification_decisionnotification"."type",
"notification_decisionnotification"."popup_type",
"notification_decisionnotification"."completed",
"notification_decisionnotification"."date_created" FROM
"notification_decisionnotification" ORDER BY
"notification_decisionnotification"."date_created" DESC)
}}}
It doesn't ask for `count` from what I can see here.
As a quick fix for the Django only version is to evaluate the queryset
before passing it to the paginator.
But this doesn't work with DRF because that querysets gets through
filtering which returns another queryset which again doesn't have the
`_result_cache` populated.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:10>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:11>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Type: Bug | Status: new
(models, ORM) |
Severity: Normal | Resolution:
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Tim Graham):
The documentation says, "In addition, only LIMIT, OFFSET, and ORDER BY
(i.e. slicing and order_by()) are allowed on the resulting QuerySet." The
problem might be that `.count()` isn't supported but doesn't raise an
error message. Florian says, "I don't think we can implement count in a
sensible way without going full sub select."
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:12>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Component: Database layer | Version: 1.11
(models, ORM) |
Keywords: | Triage Stage:
| Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => closed
* resolution: => invalid
Comment:
I opened #27995 to raise a descriptive error on unsupported operations
following `QuerySet.union()`. I think that should solve the issue here?
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:13>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Component: Database layer | Version: 1.11
(models, ORM) |
Severity: Normal | Resolution: invalid
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
Maybe if you catch the exception here
https://github.com/django/django/blob/master/django/core/paginator.py#L73
too so the pagination will continue to work, otherwise it will be pretty
confusing (I want to paginate some queryset and I get a count error).
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:14>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Component: Database layer | Version: 1.11
(models, ORM) |
Severity: Normal | Resolution: invalid
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Florian Apolloner):
@gigelu: Can you check if https://github.com/django/django/pull/8769 fixes
the issue?
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:15>
Django
-------------------------------------+-------------------------------------
Reporter: gigelu | Owner: nobody
Component: Database layer | Version: 1.11
(models, ORM) |
Severity: Normal | Resolution: invalid
Keywords: | Triage Stage:
| Unreviewed
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by gigelu):
Yes, after I've added `or self.combinator` in the if clause, it does a
`SELECT COUNT (*) FROM (... old query ...)`, so the result is good now.
--
Ticket URL: <https://code.djangoproject.com/ticket/27982#comment:16>