Possible bug related to queryset union

[gigelu]

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

Here's a short video (1m 35s, 11.6MB) ​https://www.dropbox.com/s/72u46vx2n0y9h9y/bug.webm?dl=0

[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?

[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.

[Tim Graham]

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?

[gigelu]

More info:
BaseNotification 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 results instead of 1 when it's not working.
​http://i.imgur.com/jJ7wBfn.png

[Tim Graham]

Please check if the same query is running in all cases.

[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

[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].

[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.

[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."

[Tim Graham]

I opened #27995 to raise a descriptive error on unsupported operations following QuerySet.union(). I think that should solve the issue here?

[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).

[Florian Apolloner]

@gigelu: Can you check if ​https://github.com/django/django/pull/8769 fixes the issue?

[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.