Context
I am using Postgres v13 hosted in GCP Cloud SQL. The database partitions most tables by a tenant id.
Structure
The query is more complex than this but I can create a minimal reproducible example from the essence of these three tables:
create table student (
id text not null primary key,
grade_id int not null
);
create table student_snapshot (
student_id text not null,
created_at timestamp not null,
grade_id int not null,
primary key (student_id, created_at)
);
create table test (
id text not null primary key,
student_id text not null,
student_snapshot_date timestamp not null,
foreign key (student_id, student_snapshot_date) references student_snapshot (student_id, created_at)
);
There are students and when they take a test we take a snapshot of the student to understand their demographics at the time the test was taken. There isn't an FK back to student because we want to keep the historic data when the student is deleted. The real example uses partitioned tables but this example uses normal ones for simplicity.
Query
I need to join the 3 tables together in a query like the following:
select t.*, st.grade_id as current_grade_id, snp.grade_id as snapshot_grade_id
from student st
join test t
on t.student_id = st.student_id
join student_snapshot snp
on snp.student_id = t.student_id
and snp.created_at = t.student_snapshot_date
Issue
The query was taking < 1s but can now take upwards of 2hrs after a recent infusion of data into the database (~50% increase). The performance did not degrade linearly as the volume increased. It appears to have changed the normal query plan which now uses a Nested Loop. It appears to be making this choice because it expects the row count to be 2 when it is really closer to 90k. I find it interesting that when I leave off the and snp.created_at = t.student_snapshot_date
condition that the query plan has a reasonable expectation of the number of rows returned and does not choose a Nested Loop.
Here is the query plan for the full query:
QUERY PLAN |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
Nested Loop (cost=2044.29..6432.12 rows=2 width=10) (actual time=65.097..1904659.897 rows=72902 loops=1) |
Output: st.student_id |
Buffers: shared hit=34879380 |
-> Hash Join (cost=2043.88..5769.94 rows=2 width=20) (actual time=41.050..955.542 rows=90631 loops=1) |
Output: t.student_id, snp.student_id |
Hash Cond: ((t.student_id = snp.student_id) AND (t.student_snapshot_date = snp.created_at)) |
Buffers: shared hit=3015 |
-> Seq Scan on public."test" t (cost=0.00..3046.31 rows=90631 width=18) (actual time=0.010..169.664 rows=90631 loops=1) |
Output: t.id, t.student_id, t.student_snapshot_date|
Buffers: shared hit=2140 |
-> Hash (cost=1342.55..1342.55 rows=46755 width=18) (actual time=39.342..39.343 rows=46755 loops=1) |
Output: snp.student_id, snp.created_at |
Buckets: 65536 Batches: 1 Memory Usage: 3069kB |
Buffers: shared hit=875 |
-> Seq Scan on public."student_snapshot" snp (cost=0.00..1342.55 rows=46755 width=18) (actual time=0.018..13.942 rows=46755 loops=1) |
Output: snp.student_id, snp.created_at |
Buffers: shared hit=875 |
-> Index Only Scan using "student_key" on public."student" st (cost=0.41..331.08 rows=1 width=10) (actual time=12.086..21.000 rows=1 loops=90631) |
Output: st.program_id, st.organization_id, st.student_id |
Index Cond: (st.student_id = t.student_id) |
Heap Fetches: 74061 |
Buffers: shared hit=34876365 |
Planning: |
Buffers: shared hit=40 |
Planning Time: 1.063 ms |
Execution Time: 1904722.476 ms |
Note the discrepancy between rows
and actual rows
.
If I remove the date match then I get this:
QUERY PLAN |
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
Hash Join (cost=4254.08..8568.10 rows=92784 width=10) (actual time=114.921..219.856 rows=74332 loops=1) |
Output: st.student_id |
Hash Cond: (t.student_id = st.student_id) |
Buffers: shared hit=3744 |
-> Seq Scan on public."test" t (cost=0.00..3046.31 rows=90631 width=10) (actual time=0.010..12.670 rows=90631 loops=1) |
Output: t.id, t.student_id, t.student_snapshot_date|
Buffers: shared hit=2140 |
-> Hash (cost=3689.98..3689.98 rows=45128 width=20) (actual time=114.737..114.739 rows=36995 loops=1) |
Output: st.student_id, snp.student_id |
Buckets: 65536 Batches: 1 Memory Usage: 2391kB |
Buffers: shared hit=1604 |
-> Hash Join (cost=1720.82..3689.98 rows=45128 width=20) (actual time=33.975..95.906 rows=36995 loops=1) |
Output: st.student_id, snp.student_id |
Hash Cond: (snp.student_id = st.student_id) |
Buffers: shared hit=1604 |
-> Seq Scan on public."student_snapshot" snp (cost=0.00..1342.55 rows=46755 width=10) (actual time=0.030..13.741 rows=46755 loops=1) |
Output: snp.student_id, snp.created_at, snp.program_id, snp.organization_id, snp.first_name, snp.last_name, snp.gender_id, snp.grade_id, snp.date_of_birth, snp.race, snp.academic, snp.zip, snp.state_id |
Buffers: shared hit=875 |
-> Hash (cost=1169.81..1169.81 rows=44081 width=10) (actual time=31.513..31.514 rows=43262 loops=1) |
Output: st.student_id |
Buckets: 65536 Batches: 1 Memory Usage: 2287kB |
Buffers: shared hit=729 |
-> Seq Scan on public."student" st (cost=0.00..1169.81 rows=44081 width=10) (actual time=0.015..10.926 rows=43262 loops=1) |
Output: st.student_id |
Buffers: shared hit=729 |
Planning: |
Buffers: shared hit=40 |
Planning Time: 1.042 ms |
Execution Time: 223.517 ms |
Note the better row estimate and the lack of a Nested Loop.
What I have tried
I tried creating extended statistics to increase the selectibility:
CREATE STATISTICS "test_st_snp_pk" ON student_id, student_snapshot_date FROM "test";
CREATE STATISTICS "st_snp_pk" ON student_id, created_at FROM "student_snapshot";
I tried increasing the stats collection on the relevant columns:
alter table "test" alter student_id set statistics 500;
alter table "test" alter student_snapshot_date set statistics 500;
alter table "student_snapshot" alter student_id set statistics 500;
alter table "student_snapshot" alter created_at set statistics 500;
I tried clustering on a parallel indexes for test
and student_snapshot
to see if it would find more hits if they were sorted the same:
cluster "test" using "test_student_id_student_snapshot_date_idx";
cluster "student_snapshot" using "student_snapshot_pkey";
I ran analyze
after each but had the same plane each time.
The only thing I have done that has worked is to materialize part of the query but that isn't as efficient as it should be. But even that failed when I started adding back in the peripheral tables that were part of the more complex query.
with test_w_snap as materialized (
select t.*, snp.grade_id
from test t
join student_snapshot snp
on snp.student_id = t.student_id
and snp.created_at = t.student_snapshot_date
)
select t.*, st.grade_id as current_grade_id, t.grade_id as snapshot_grade_id
from student st
join test_w_snap t
on t.student_id = st.student_id
I'd much rather find a way to feed the query planner the right statistics to properly estimate and pick the right query plan.
What can I do to get the query planner to have a more accurate estimate?
Update
Though I am still not happy with the row estimates, I found the root issue. The student_snapshot
table used text
for student_id
while the other two used citext
. We recently updated student_snapshot
to also be citext
so that they all matched. I don't understand why it used a better query plan back when they mismatched but in comparing query plans I saw that it was doing snp.student_id = t.student_id::text
. When I altered the query to snp.student_id::text = t.student_id::text
it became fast again. Seems a bit counterintuitive since the conversion should be less efficient, but it led to a much better query plan even though the row estimate was still terribly off. It uses a Parallel Hash Join
instead of a Nested Loop
. Sorry I didn't provide enough context for this earlier.