Performance issue with self-assign dashboard

[torgeirl]

There seems to be a performance issue with the self-assign dashboard (#1218). According to Google Chrome's performance insights, the HTML has a waiting time of above 5s while the download time is ~zero. This could be related to #1236.

Edit: it might be an issue with how the filter(s) are build, I get terrible preformance for /devilry_examiner/self-assign/<semester-code>/filter/assignedstatus-assigned?cradmin-bgreplaced=true especially.

[espenak]

@torgeirl: As far as I can tell this must be because of the "count" queries that is used to filter by status and to show the counts in the status filters. We CAN change this to use much cheaper exists queries, but then we can not show the counts in the status filter.

It should really not be a problem to handle counts of a few thousand - we normally see this problem when counting millions or at least hundreds of thousands. The problem is usually that postgres has:

• To little disk space (it really likes a lot of disk space to get good IOPS because it caches data is many different ways if it can.
• Too little memory - if the indexes do not fit in memory, things slow down.

[torgeirl]

The problem is usually that postgres has:

• To little disk space (it really likes a lot of disk space to get good IOPS because it caches data is many different ways if it can.
• Too little memory - if the indexes do not fit in memory, things slow down.

@espenak: I'm checking disk and memory status now to rule that out.

[torgeirl]

@espenak: our database server is plentiful on both disk space and memory; in fact, its postgres cache is about the same size of the entire database including indexes.

[torgeirl]

it might be an issue with how the filter(s) are build, I get terrible preformance for /devilry_examiner/self-assign/<semester-code>/filter/assignedstatus-assigned?cradmin-bgreplaced=true especially.

Transactions for /devilry_examiner/self-assign/{roleid}/filter/{filters_string} can be another place to look. Especially two of the 15 DB look-ups invoked by the view render for devilry_examiner_selfassign-self-assign-filter take up to 300-400s each, causing the transaction taking a total of 2s.

[torgeirl]

The JOIN operations from devilry_examiner/self-assign/{roleid}/ transactions have become so expensive that we had to increase the PostgreSQL server's shared_buffers to account for them.

Added to 6.6 milestone, hoping we can make considerable improve for these queries.

[espenak]

@torgeirl this view has very heavy queries, and they are quite optimized (there is always room for a bit more, but they are quite optimized). The problem is that a lot of data has to be joined to make the UI possible and further optimizations will not reduce the amount of joins, but only reduce the query size by a small bit (which may or may not affect the performance by a small margin).

How big did you set shared_buffers? It is not uncommon to have to tune this setting to handle large queries so I do not think that having to change the default value for it has to be seen as a negative.. But there are of course limits to how big it should be.

I think there are only two real options here:

• Completely rethink the view
• Live with this view being resource intensive and continue tuning postgres to get good performance.

Rethinking the view can be "light":

• Remove a lot of the counts and thus providing less info to the users and getting the total queries down by a lot while still keeping the core "heavy" query. This will also lead to a cheaper "subquery" in the main/core query since we do not have to annotate with count, but instead with a cheaper EXISTS subquery. This should make the total overhead of the view a lot lighter. This will change a lot or all of the subqueries and filters here to not COUNT:

  devilry-django/devilry/devilry_examiner/views/selfassign/selfassign.py

  Lines 85 to 157 in 5d54a17

  	def add_filterlist_items(self, filterlist):
  	filterlist.append(devilry_listfilter.assignmentgroup.SearchNotAnonymous())
  	filterlist.append(devilry_listfilter.assignmentgroup.StatusRadioFilter(view=self))
  	filterlist.append(devilry_listfilter.assignmentgroup.AssignmentCheckboxFilter(view=self))
  	filterlist.append(devilry_listfilter.assignmentgroup.AssignedUnassignedRadioFilter(view=self))
  	filterlist.append(devilry_listfilter.assignmentgroup.OrderByDelivery())
  	filterlist.append(devilry_listfilter.assignmentgroup.ExaminerCountFilter())
  	def get_unfiltered_queryset_for_role(self, role):
  	candidatequeryset = (
  	Candidate.objects.select_related("relatedstudent__user")
  	.only(
  	"candidate_id",
  	"assignment_group",
  	"relatedstudent__candidate_id",
  	"relatedstudent__automatic_anonymous_id",
  	"relatedstudent__user__shortname",
  	"relatedstudent__active",
  	"relatedstudent__user__fullname",
  	)
  	.order_by(
  	Lower(
  	Concat(
  	"relatedstudent__user__fullname",
  	"relatedstudent__user__shortname",
  	output_field=models.CharField(),
  	)
  	)
  	)
  	)
  	examinerqueryset = (
  	Examiner.objects.select_related("relatedexaminer__user")
  	.only(
  	"relatedexaminer",
  	"assignmentgroup",
  	"relatedexaminer__automatic_anonymous_id",
  	"relatedexaminer__user__shortname",
  	"relatedexaminer__user__fullname",
  	)
  	.order_by(
  	Lower(
  	Concat(
  	"relatedexaminer__user__fullname",
  	"relatedexaminer__user__shortname",
  	output_field=models.CharField(),
  	)
  	)
  	)
  	)
  	queryset = (
  	assignment_groups_available_for_self_assign(period=role, user=self.request.user)
  	.prefetch_related(models.Prefetch("candidates", queryset=candidatequeryset))
  	.prefetch_related(models.Prefetch("examiners", queryset=examinerqueryset))
  	.annotate(
  	is_examiner=models.Exists(
  	Examiner.objects.filter(
  	relatedexaminer__user=self.request.user, assignmentgroup_id=models.OuterRef("id")
  	)
  	)
  	)
  	.annotate_with_is_waiting_for_feedback_count()
  	.annotate_with_is_waiting_for_deliveries_count()
  	.annotate_with_is_corrected_count()
  	.distinct()
  	.select_related(
  	"cached_data__last_published_feedbackset",
  	"cached_data__last_feedbackset",
  	"cached_data__first_feedbackset",
  	"parentnode",
  	)
  	.order_by("cached_data__last_feedbackset__deadline_datetime")
  	)
  	return queryset

Rethinking can be a completely new workflow:

• Not sure how, but we should be able to figure out something "lighter".

[espenak]

Forgot to mention that I added a django-silk setup for development with a quick markdown guide, and profiled this with django-silk to see the actual SQL queries and query analyzer outputs. The conclusions in the last comment is based on this profiling.