Performance when filtering on multiple annotations

Using Django Using the ORM
1

I’m currently sitting in a park with just my phone, so I apologize for not having code to paste in here at the moment. I can follow up later with that tomorrow.

I have a ListView that has a search field that searches all the fields/columns. This particular view has a bunch of count annotations and when there is no search term, those 15 rows load in about a second or 2. But when someone performs a search, the page takes 3 minutes to load.

I had a hunch that this had to do with the lack of the related model paths being provided to prefetch_related, so this morning, I made sure that all the model paths were in prefetch_related, but it still took 3 minutes, and that surprised me.

2 of the perhaps 5 annotations traverse 2 many-related relationships, so it could be as simple as that. I also have a duplicate query happening that I think should be easy to fix.

I figure I can reverse the queries so that it’s not traversing many-related relationships, but I don’t have the infrastructure for that yet, but aside from that and adding an index, I thought I’d see what thoughts anyone might have about improving performance. And I’m wondering why filtering on the count annotations would be 2 orders of magnitude slower.

2

PostgreSQL has to scan the entire table for each Count operation - there is no internal optimization or internal “shortcut” for it. If you’re doing multiple counts of medium-to-large tables, it’s going to take time.

From the docs at PostgreSQL: Documentation: 17: 9.21. Aggregate Functions

Users accustomed to working with other SQL database management systems might be disappointed by the performance of the count aggregate when it is applied to the entire table. A query like:
SELECT count(*) FROM sometable;
will require effort proportional to the size of the table: PostgreSQL will need to scan either the entire table or the entirety of an index that includes all rows in the table.

Also see the reddit article select count from products took 17 seconds for more on this.

IF an approximation would be sufficient, see Count estimate - PostgreSQL wiki

1 Like
3

But why does it take under 2 seconds to do all 5 of those counts for 15 results when there’s no filter but takes 3 minutes when there is a filter. I only have 15 records in the base table in my sandbox. It takes under 2 seconds to count all the relations for all 15 results. When I filter, I get fewer than 15 results back and it takes 3 minutes.

So what you suggest - that it just takes time to perform those counts - would seem to make more sense if it took 3 minutes in both cases (with and without filtering). Why is it so fast when there’s no filter and slow when there is a filter? I don’t get it.

4

Without knowing the actual models, queries, and data involved, there’s no way to tell from here.

Anytime you’re looking to diagnose query-related issues, the first step is always to examine the explains for those queries.

5

OK. I have data to share. I would like some help interpreting it because I’m a little lost. I ran a bunch of cases, but I’m going to share 2: without any filter and with a filter that basically does an OR on all of the fields in the ListView, including the annotations. I also individually tried a single filter on each field individually as a sanity check and each one completed in roughly under 2 seconds.

I generated the effective ORM code that is executed in each case. I’m working with my Study model.

Here is the fast case (no filter). It does all the same counts. It returns all 11 Study records (I’m on a different machine today that doesn’t have as many studies loaded) in roughly 2 seconds:

# ORM query that generates the QuerySet:
Study.objects
.prefetch_related(
    'animals__infusate__tracer_links__tracer__compound',
    'animals__samples__msrun_samples__msrun_sequence',
    'animals__samples__tissue',
    'animals__treatment'
)
.annotate(
    **{
        'name_bstrowsort': Lower(F(name)),
        'total_infusates': Count(F(animals__infusate), distinct=True),
        'animals_infusate_tracer_links_mm_count': Count(F(animals__infusate__tracer_links), distinct=True),
        'animals_mm_count': Count(F(animals), distinct=True),
        'total_tissues': Count(F(animals__samples__tissue), distinct=True),
        'animals_samples_mm_count': Count(F(animals__samples), distinct=True),
        'animals_samples_msrun_samples_mm_count': Count(F(animals__samples__msrun_samples), distinct=True)
    }
)
.order_by(OrderBy(F(name_bstrowsort), descending=False))
.distinct()

# EXPLAIN:
Unique  (cost=749.97..753.82 rows=140 width=632)
  ->  Sort  (cost=749.97..750.32 rows=140 width=632)
        Sort Key: "DataRepo_study".name, "DataRepo_study".id, "DataRepo_study".description, (lower(("DataRepo_study".name)::text)), (count(DISTINCT "DataRepo_animal".infusate_id)), (count(DISTINCT "DataRepo_infusatetracer".id)), (count(DISTINCT "DataRepo_animal_studies".animal_id)), (count(DISTINCT "DataRepo_sample".tissue_id)), (count(DISTINCT "DataRepo_sample".id)), (count(DISTINCT "DataRepo_msrunsample".id))
        ->  GroupAggregate  (cost=624.05..744.98 rows=140 width=632)
              Group Key: "DataRepo_study".id, (lower(("DataRepo_study".name)::text))
              ->  Sort  (cost=624.05..637.29 rows=5297 width=608)
                    Sort Key: "DataRepo_study".id, (lower(("DataRepo_study".name)::text))
                    ->  Hash Right Join  (cost=162.75..296.41 rows=5297 width=608)
                          Hash Cond: ("DataRepo_sample".animal_id = "DataRepo_animal".id)
                          ->  Hash Right Join  (cost=106.19..159.32 rows=2861 width=16)
                                Hash Cond: ("DataRepo_msrunsample".sample_id = "DataRepo_sample".id)
                                ->  Seq Scan on "DataRepo_msrunsample"  (cost=0.00..45.61 rows=2861 width=8)
                                ->  Hash  (cost=72.75..72.75 rows=2675 width=12)
                                      ->  Seq Scan on "DataRepo_sample"  (cost=0.00..72.75 rows=2675 width=12)
                          ->  Hash  (cost=49.85..49.85 rows=537 width=568)
                                ->  Hash Left Join  (cost=33.74..49.85 rows=537 width=568)
                                      Hash Cond: ("DataRepo_animal".infusate_id = "DataRepo_infusate".id)
                                      ->  Hash Left Join  (cost=27.68..36.94 rows=408 width=564)
                                            Hash Cond: ("DataRepo_animal_studies".animal_id = "DataRepo_animal".id)
                                            ->  Hash Right Join  (cost=13.15..21.33 rows=408 width=556)
                                                  Hash Cond: ("DataRepo_animal_studies".study_id = "DataRepo_study".id)
                                                  ->  Seq Scan on "DataRepo_animal_studies"  (cost=0.00..7.08 rows=408 width=8)
                                                  ->  Hash  (cost=11.40..11.40 rows=140 width=552)
                                                        ->  Seq Scan on "DataRepo_study"  (cost=0.00..11.40 rows=140 width=552)
                                            ->  Hash  (cost=10.90..10.90 rows=290 width=8)
                                                  ->  Seq Scan on "DataRepo_animal"  (cost=0.00..10.90 rows=290 width=8)
                                      ->  Hash  (cost=4.87..4.87 rows=96 width=8)
                                            ->  Hash Right Join  (cost=2.64..4.87 rows=96 width=8)
                                                  Hash Cond: ("DataRepo_infusatetracer".infusate_id = "DataRepo_infusate".id)
                                                  ->  Seq Scan on "DataRepo_infusatetracer"  (cost=0.00..1.96 rows=96 width=8)
                                                  ->  Hash  (cost=1.73..1.73 rows=73 width=4)
                                                        ->  Seq Scan on "DataRepo_infusate"  (cost=0.00..1.73 rows=73 width=4)

And this is the slow case (filtering for any field that contains “24”). It returns 4 Study records. I didn’t time it on this machine, but it’s definitely very slow. The only difference other than the filter is that one of the annotations not needed for the filter is applies after the filter:

# ORM query that generates the QuerySet:
Study.objects
.prefetch_related(
    'animals__infusate__tracer_links__tracer__compound',
    'animals__samples__msrun_samples__msrun_sequence',
    'animals__samples__tissue',
    'animals__treatment'
)
.annotate(
    **{
        'total_infusates': Count(F(animals__infusate), distinct=True),
        'animals_infusate_tracer_links_mm_count': Count(F(animals__infusate__tracer_links), distinct=True),
        'animals_mm_count': Count(F(animals), distinct=True),
        'total_tissues': Count(F(animals__samples__tissue), distinct=True),
        'animals_samples_mm_count': Count(F(animals__samples), distinct=True),
        'animals_samples_msrun_samples_mm_count': Count(F(animals__samples__msrun_samples), distinct=True)
    }
)
.filter(
    # This is how the Q object prints
    (OR:
        ('name__icontains', '24'),
        ('description__icontains', '24'),
        ('animals__genotype__iexact', '24'),
        ('total_infusates__icontains', '24'),
        ('animals__infusate__name__icontains', '24'),
        ('animals_infusate_tracer_links_mm_count__iexact', '24'),
        ('animals__infusate__tracer_links__tracer__name__icontains', '24'),
        ('animals__infusate__tracer_links__tracer__compound__name__icontains', '24'),
        ('animals__label_combo__iexact', '24'),
        ('animals__treatment__name__icontains', '24'),
        ('animals__samples__researcher__iexact', '24'),
        ('animals__samples__msrun_samples__msrun_sequence__researcher__iexact', '24'),
        ('animals_mm_count__iexact', '24'),
        ('total_tissues__icontains', '24'),
        ('animals_samples_mm_count__iexact', '24'),
        ('animals_samples_msrun_samples_mm_count__iexact', '24'))
.annotate(**{'name_bstrowsort': Lower(F(name))})
.order_by(OrderBy(F(name_bstrowsort), descending=False))
.distinct()

# EXPLAIN:
Unique  (cost=472909.82..477825.97 rows=178769 width=1751)
  ->  Sort  (cost=472909.82..473356.75 rows=178769 width=1751)
        Sort Key: "DataRepo_study".name, "DataRepo_study".id, "DataRepo_study".description, (count(DISTINCT "DataRepo_animal".infusate_id)), (count(DISTINCT "DataRepo_infusatetracer".id)), (count(DISTINCT "DataRepo_animal_studies".animal_id)), (count(DISTINCT "DataRepo_sample".tissue_id)), (count(DISTINCT "DataRepo_sample".id)), (count(DISTINCT "DataRepo_msrunsample".id)), (lower(("DataRepo_study".name)::text))
        ->  GroupAggregate  (cost=1689.45..186015.25 rows=178769 width=1751)
              Group Key: "DataRepo_study".id, (lower(("DataRepo_study".name)::text)), t10.genotype, t11.name, "DataRepo_tracer".name, "DataRepo_compound".name, t10.label_combo, "DataRepo_protocol".name, t16.researcher, "DataRepo_msrunsequence".researcher
              Filter: ((upper(("DataRepo_study".name)::text) ~~ '%24%'::text) OR (upper("DataRepo_study".description) ~~ '%24%'::text) OR (upper((t10.genotype)::text) = '24'::text) OR (upper((count(DISTINCT "DataRepo_animal".infusate_id))::text) ~~ '%24%'::text) OR (upper((t11.name)::text) ~~ '%24%'::text) OR (upper((count(DISTINCT "DataRepo_infusatetracer".id))::text) = '24'::text) OR (upper(("DataRepo_tracer".name)::text) ~~ '%24%'::text) OR (upper(("DataRepo_compound".name)::text) ~~ '%24%'::text) OR (upper((t10.label_combo)::text) = '24'::text) OR (upper(("DataRepo_protocol".name)::text) ~~ '%24%'::text) OR (upper((t16.researcher)::text) = '24'::text) OR (upper(("DataRepo_msrunsequence".researcher)::text) = '24'::text) OR (upper((count(DISTINCT "DataRepo_animal_studies".animal_id))::text) = '24'::text) OR (upper((count(DISTINCT "DataRepo_sample".tissue_id))::text) ~~ '%24%'::text) OR (upper((count(DISTINCT "DataRepo_sample".id))::text) = '24'::text) OR (upper((count(DISTINCT "DataRepo_msrunsample".id))::text) = '24'::text))
              ->  Incremental Sort  (cost=1689.45..150519.33 rows=200280 width=1727)
                    Sort Key: "DataRepo_study".id, (lower(("DataRepo_study".name)::text)), t10.genotype, t11.name, "DataRepo_tracer".name, "DataRepo_compound".name, t10.label_combo, "DataRepo_protocol".name, t16.researcher, "DataRepo_msrunsequence".researcher
                    Presorted Key: "DataRepo_study".id
                    ->  Nested Loop Left Join  (cost=638.56..131138.43 rows=200280 width=1727)
                          Join Filter: (t17.msrun_sequence_id = "DataRepo_msrunsequence".id)
                          ->  Nested Loop Left Join  (cost=638.56..121797.41 rows=200280 width=1183)
                                ->  Nested Loop Left Join  (cost=638.28..56094.88 rows=187259 width=1183)
                                      ->  Nested Loop Left Join  (cost=638.00..29427.06 rows=20301 width=1170)
                                            Join Filter: (t12.tracer_id = "DataRepo_tracer".id)
                                            ->  Nested Loop Left Join  (cost=636.01..16003.67 rows=20301 width=1139)
                                                  ->  Nested Loop Left Join  (cost=635.87..10841.79 rows=15437 width=1139)
                                                        Join Filter: (t10.treatment_id = "DataRepo_protocol".id)
                                                        ->  Nested Loop Left Join  (cost=635.87..8022.13 rows=15437 width=627)
                                                              ->  Nested Loop Left Join  (cost=635.73..4925.35 rows=15437 width=598)
                                                                    ->  Merge Left Join  (cost=635.58..869.17 rows=15437 width=580)
                                                                          Merge Cond: ("DataRepo_study".id = "DataRepo_animal_studies".study_id)
                                                                          ->  Sort  (cost=39.03..40.05 rows=408 width=556)
                                                                                Sort Key: "DataRepo_study".id
                                                                                ->  Hash Right Join  (cost=13.15..21.33 rows=408 width=556)
                                                                                      Hash Cond: (t9.study_id = "DataRepo_study".id)
                                                                                      ->  Seq Scan on "DataRepo_animal_studies" t9  (cost=0.00..7.08 rows=408 width=8)
                                                                                      ->  Hash  (cost=11.40..11.40 rows=140 width=552)
                                                                                            ->  Seq Scan on "DataRepo_study"  (cost=0.00..11.40 rows=140 width=552)
                                                                          ->  Sort  (cost=596.55..609.80 rows=5297 width=28)
                                                                                Sort Key: "DataRepo_animal_studies".study_id
                                                                                ->  Hash Right Join  (cost=148.49..268.91 rows=5297 width=28)
                                                                                      Hash Cond: ("DataRepo_sample".animal_id = "DataRepo_animal".id)
                                                                                      ->  Hash Right Join  (cost=106.19..159.32 rows=2861 width=16)
                                                                                            Hash Cond: ("DataRepo_msrunsample".sample_id = "DataRepo_sample".id)
                                                                                            ->  Seq Scan on "DataRepo_msrunsample"  (cost=0.00..45.61 rows=2861 width=8)
                                                                                            ->  Hash  (cost=72.75..72.75 rows=2675 width=12)
                                                                                                  ->  Seq Scan on "DataRepo_sample"  (cost=0.00..72.75 rows=2675 width=12)
                                                                                      ->  Hash  (cost=35.59..35.59 rows=537 width=20)
                                                                                            ->  Hash Left Join  (cost=20.59..35.59 rows=537 width=20)
                                                                                                  Hash Cond: ("DataRepo_animal".infusate_id = "DataRepo_infusate".id)
                                                                                                  ->  Hash Left Join  (cost=14.53..22.69 rows=408 width=16)
                                                                                                        Hash Cond: ("DataRepo_animal_studies".animal_id = "DataRepo_animal".id)
                                                                                                        ->  Seq Scan on "DataRepo_animal_studies"  (cost=0.00..7.08 rows=408 width=8)
                                                                                                        ->  Hash  (cost=10.90..10.90 rows=290 width=8)
                                                                                                              ->  Seq Scan on "DataRepo_animal"  (cost=0.00..10.90 rows=290 width=8)
                                                                                                  ->  Hash  (cost=4.87..4.87 rows=96 width=8)
                                                                                                        ->  Hash Right Join  (cost=2.64..4.87 rows=96 width=8)
                                                                                                              Hash Cond: ("DataRepo_infusatetracer".infusate_id = "DataRepo_infusate".id)
                                                                                                              ->  Seq Scan on "DataRepo_infusatetracer"  (cost=0.00..1.96 rows=96 width=8)
                                                                                                              ->  Hash  (cost=1.73..1.73 rows=73 width=4)
                                                                                                                    ->  Seq Scan on "DataRepo_infusate"  (cost=0.00..1.73 rows=73 width=4)
                                                                    ->  Index Scan using "DataRepo_animal_pkey" on "DataRepo_animal" t10  (cost=0.15..0.26 rows=1 width=22)
                                                                          Index Cond: (id = t9.animal_id)
                                                              ->  Index Scan using "DataRepo_infusate_pkey" on "DataRepo_infusate" t11  (cost=0.14..0.20 rows=1 width=33)
                                                                    Index Cond: (id = t10.infusate_id)
                                                        ->  Materialize  (cost=0.00..3.19 rows=13 width=520)
                                                              ->  Seq Scan on "DataRepo_protocol"  (cost=0.00..3.13 rows=13 width=520)
                                                  ->  Index Only Scan using unique_infusate_tracer on "DataRepo_infusatetracer" t12  (cost=0.14..0.32 rows=1 width=8)
                                                        Index Cond: (infusate_id = t11.id)
                                            ->  Materialize  (cost=1.99..24.85 rows=44 width=39)
                                                  ->  Hash Right Join  (cost=1.99..24.63 rows=44 width=39)
                                                        Hash Cond: ("DataRepo_compound".id = "DataRepo_tracer".compound_id)
                                                        ->  Seq Scan on "DataRepo_compound"  (cost=0.00..17.89 rows=689 width=21)
                                                        ->  Hash  (cost=1.44..1.44 rows=44 width=26)
                                                              ->  Seq Scan on "DataRepo_tracer"  (cost=0.00..1.44 rows=44 width=26)
                                      ->  Index Scan using "DataRepo_sample_animal_id_d0c92479" on "DataRepo_sample" t16  (cost=0.28..1.21 rows=10 width=21)
                                            Index Cond: (animal_id = t10.id)
                                ->  Index Scan using "DataRepo_msrunsample_sample_id_145999d5" on "DataRepo_msrunsample" t17  (cost=0.28..0.34 rows=1 width=8)
                                      Index Cond: (sample_id = t16.id)
                          ->  Materialize  (cost=0.00..1.04 rows=3 width=520)
                                ->  Seq Scan on "DataRepo_msrunsequence"  (cost=0.00..1.03 rows=3 width=520)

I have a few thoughts about little improvements that could improve performance, though I’m not sure it would account for the dramatic difference. I can fix things like the type conversion that is happening automatically and I could probably exclude some fields from the search based on the search term.

This performance issue only affects the Studies page though. Other views have multiple many-related columns and don’t have this issue with the whole-table search feature (worst case they take 4 seconds). So my guess is that its the number of many-related steps in the path that doesn’t cooperate well with the filtering… The Study:Animal step (Many:Many) really increases the number of records involved and while the other views contain multiple many-related steps, they don’t have that big step from Study to Animal. I might disable the search on just the fields that start with animals__samples__msrun_samples and see if that affects performance.

6

OK. I did some trial and error and I determined that including these 2 fields in the whole-table search account for the vast majority of the time. If I disable search on both of them, the page loads in a few seconds (on par with the performance without any filtering):

  • animals__samples__msrun_samples__msrun_sequence__researcher
  • animals__samples__researcher

I wonder if indexes for these could solve the speed issue.

7

The foreign keys will create indexes by default, there’s no need to add indexes for them. Indexing the individual fields isn’t going to help with these conditionals either.

A search using icontains is another predicate that will result in a full table scan - adding an index is not going to help with that. Also, doing the case insensitive search adds to the problem because of the function call needing to be performed on every row during the search process.

The timings are expanding quickly by the nested sequential scans being performed. There’s a combinatorial effect coming in to play here. You can see by looking at the cost estimates and processed row counts just how much work is being done for these filters.

If I had to optimize this, I’d be looking at rearchitecting some of the data structures to facilitate these searches. In general this would likely involve changing some field definitions and possibly additing additional columns or tables with pre-transformed data. Getting rid of the ‘like’ and case-insensitive searches would do a lot to help here.

8

For those researcher fields in particular that cause so much slowness, I have another option. I’m using Bootstrap Table’s search interface and I generate dropdowns for filtering those column using a method called get_researchers() that gets the entire unique set of researchers in the DB. This particular search feature however comes from the whole-table search field. I could search the entire drop-down list in python and if there are matches, I could do entire case sensitive matches, for example:

my_python_matches = [n for n in get_researchers() if search_term.lower() in n.lower()]
...
.filter(animals__samples__researcher__in=my_python_matches)

All of the search functionality thus far though is entirely implemented in DB queries and javascript (when not in server-side mode). I’ll have to think through how I want to incorporate a python component…

9

Most likely this is due to the field you’re filtering on not being in an index that’s useful for that particular query, so a full table scan is required. A simple count on every row has been optimised every which way, but make it read other fields and look for matches and you’re going to slow it down.

We have similar issues for large tables - not least in admin which does counts by default. What Ive done in a couple of cases is implement an approximate count (which gets the count from postgres table stats and does sort of rely on vacuum having been run recently), and also a max count cutoff in some cases where we don’t really care about having to page to the final screen of many millions of rows.

1 Like