I have a new database with only about 225 rows.
I was facing a slow query issue only on the postgres running in production on my Ubuntu server. It was reporting 423.460 ms for the execution time. The postgres on my development Mac wasn’t having the same issue despite similar data and executed in about 1.5ms. So, I took the following steps to try to narrow down the issue.
-
First I checked the version of Postgres. My Mac was running Postgres 15.3 whereas my server wa running 14.8.
-
I also ran
EXPLAIN ANALYZE
on both of them and I found the slow server had a humongous cost and number of rows on the outer mostSort
with sort key:Sort Key: (row_number() OVER (?))
. The same query on my Mac doesn’t have this. TheEXPLAIN ANALYZE
of the Mac instead shows the outer most sort key as:Sort Key: o.row_number
. -
Also, even though my query uses things like
o.kind = 'community'
, on the server, theEXPLAIN ANALYZE
saysp.kind = 'community'
instead. Not sure why it’s usingp
instead ofo
and also not sure if this makes difference? My Mac on the other hand correctly referenceso.kind = 'community'
.
Then, I upgraded my server Postgres to version 15.4 and that magically mostly fixed the issue without me making any changes to the query. The cost and number of rows for the outer most sort is still higher than my Mac. But it’s not as horrible as before. Also note that it’s still reporting the Sort Key: (row_number() OVER (?))
on the outer most sort.
My questions:
- Why is the
Sort Key: (row_number() OVER (?))
on the outer most sort when my query only usesrow_number() over ()
in the second part of myWITH
CTE? - Why the difference in the query between my mac and server even after upgrade?
- Why would a single version upgrade fix this? A sort by
row_number() OVER (?)
seems fairly trivial and I feel like I haven’t yet fixed the root cause of the problem. - How can I reduce the cost and rows to get it similar to my Mac?
I would like to get to the root cause of this problem so it doesn’t come and bite me in the back in future.
EXPLAIN ANALYZE:
explain analyze with
u as (select r.*, case when r.kind = 'user' then 1 else 0 end as extra_sort from records_view r where r.kind != 'action' AND ((r.kind = 'user' AND r.author = ANY('{AUTHOR_NAME}')) OR r.original_signature = ANY('{SOME_SIGNATURE}'))),
o as (select row_number() over (), p.* from (select * from u order by extra_sort DESC ) p),
h as (select o.*, jsonb_strip_nulls(jsonb_build_object('author_handle',ul.handle,'community_handle',cl.handle)) as handles from o left join lookup ul on ul.sig_or_author = o.author left join lookup cl on case when o.kind = 'community' then cl.sig_or_author = o.original_signature else cl.sig_or_author = o.references_original_signature end)
, actioned as (select h.*, case when a.record is not null then jsonb_build_object('signature',a.signature,'record',a.record) else null end as action from h left join records_view a on h.original_signature = a.references_original_signature AND a.author = 'AUTHOR_NAME' AND a.kind = 'action' AND h.kind = ANY('{community,text,user}'))
select record, signature, author, tallies, action, null as original_record, case when handles = '{}'::jsonb then null else handles end as handles from actioned order by row_number;
UBUNTU SERVER BEFORE UPGRADE:
SELECT VERSION();
version
----------------------------------------------------------------------------------------------------------------------------------------
PostgreSQL 14.8 (Ubuntu 14.8-0ubuntu0.22.04.1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 11.3.0-1ubuntu1~22.04.1) 11.3.0, 64-bit
(1 row)
EXPLAIN ANALYZE OUTPUT:
Sort (cost=1380266.29..1382702.79 rows=974600 width=959) (actual time=420.311..420.313 rows=2 loops=1)
Sort Key: (row_number() OVER (?))
Sort Method: quicksort Memory: 29kB
-> Nested Loop Left Join (cost=428.20..54117.14 rows=974600 width=959) (actual time=420.299..420.308 rows=2 loops=1)
Join Filter: CASE WHEN (p.kind = 'community'::text) THEN ((cl.sig_or_author)::text = p.original_signature) ELSE ((cl.sig_or_author)::text = p.references_original_signature) END
Rows Removed by Join Filter: 29
-> Merge Left Join (cost=428.20..493.14 rows=2215 width=1976) (actual time=420.284..420.287 rows=2 loops=1)
Merge Cond: (p.original_signature = r.references_original_signature)
Join Filter: (p.kind = ANY ('{community,text,user}'::text[]))
-> Sort (cost=203.23..204.78 rows=621 width=1293) (actual time=419.832..419.833 rows=2 loops=1)
Sort Key: p.original_signature
Sort Method: quicksort Memory: 28kB
-> Hash Left Join (cost=144.15..174.42 rows=621 width=1293) (actual time=419.826..419.829 rows=2 loops=1)
Hash Cond: (p.author = (ul.sig_or_author)::text)
-> WindowAgg (cost=114.35..129.87 rows=621 width=1428) (actual time=419.812..419.815 rows=2 loops=1)
-> Subquery Scan on p (cost=114.35..122.11 rows=621 width=1253) (actual time=419.809..419.810 rows=2 loops=1)
-> Sort (cost=114.35..115.90 rows=621 width=1420) (actual time=419.807..419.808 rows=2 loops=1)
Sort Key: (CASE WHEN (r_1.kind = 'user'::text) THEN 1 ELSE 0 END) DESC
Sort Method: quicksort Memory: 28kB
-> Nested Loop Left Join (cost=0.00..85.54 rows=621 width=1420) (actual time=419.716..419.803 rows=2 loops=1)
Join Filter: CASE WHEN (r_1.kind = 'user'::text) THEN (r_1.author = t_1.sig_or_author) ELSE (r_1.original_signature = t_1.sig_or_author) END
Rows Removed by Join Filter: 157
-> Seq Scan on records r_1 (cost=0.00..50.95 rows=18 width=1221) (actual time=419.690..419.754 rows=2 loops=1)
Filter: (is_latest AND (kind <> 'action'::text) AND (((kind = 'user'::text) AND (author = ANY ('{AUTHOR_NAME}'::text[]))) OR (original_signature = ANY ('{SOME_SIGNATURE}'::text[]))))
Rows Removed by Filter: 221
-> Materialize (cost=0.00..6.04 rows=69 width=411) (actual time=0.005..0.019 rows=79 loops=2)
-> Seq Scan on tally t_1 (cost=0.00..5.69 rows=69 width=411) (actual time=0.005..0.015 rows=79 loops=1)
-> Hash (cost=18.80..18.80 rows=880 width=64) (actual time=0.008..0.008 rows=15 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 12kB
-> Seq Scan on lookup ul (cost=0.00..18.80 rows=880 width=64) (actual time=0.002..0.003 rows=15 loops=1)
-> Sort (cost=224.97..229.45 rows=1794 width=879) (actual time=0.443..0.444 rows=51 loops=1)
Sort Key: r.references_original_signature
Sort Method: quicksort Memory: 96kB
-> Nested Loop Left Join (cost=0.00..128.01 rows=1794 width=879) (actual time=0.022..0.409 rows=70 loops=1)
Join Filter: CASE WHEN (r.kind = 'user'::text) THEN (r.author = t.sig_or_author) ELSE (r.original_signature = t.sig_or_author) END
Rows Removed by Join Filter: 5530
-> Seq Scan on records r (cost=0.00..50.39 rows=52 width=1221) (actual time=0.002..0.036 rows=70 loops=1)
Filter: (is_latest AND (author = 'AUTHOR_NAME'::text) AND (kind = 'action'::text))
Rows Removed by Filter: 153
-> Materialize (cost=0.00..6.04 rows=69 width=196) (actual time=0.000..0.002 rows=79 loops=70)
-> Seq Scan on tally t (cost=0.00..5.69 rows=69 width=196) (actual time=0.001..0.006 rows=79 loops=1)
-> Materialize (cost=0.00..23.20 rows=880 width=64) (actual time=0.000..0.002 rows=15 loops=2)
-> Seq Scan on lookup cl (cost=0.00..18.80 rows=880 width=64) (actual time=0.001..0.001 rows=15 loops=1)
Planning Time: 1.177 ms
JIT:
Functions: 43
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 3.042 ms, Inlining 9.559 ms, Optimization 266.372 ms, Emission 143.716 ms, Total 422.689 ms
Execution Time: 423.460 ms
(49 rows)
UBUNTU SERVER AFTER UPGRADE:
SELECT VERSION();
version
-----------------------------------------------------------------------------------------------------------------------------------
PostgreSQL 15.4 (Ubuntu 15.4-1.pgdg22.04+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0, 64-bit
(1 row)
EXPLAIN ANALYZE OUTPUT:
Sort (cost=11886.89..11938.75 rows=20745 width=957) (actual time=1.432..1.436 rows=2 loops=1)
Sort Key: (row_number() OVER (?))
Sort Method: quicksort Memory: 27kB
-> Nested Loop Left Join (cost=452.87..1677.43 rows=20745 width=957) (actual time=1.410..1.430 rows=2 loops=1)
Join Filter: CASE WHEN (p.kind = 'community'::text) THEN ((cl.sig_or_author)::text = p.original_signature) ELSE ((cl.sig_or_author)::text = p.references_original_signature) END
Rows Removed by Join Filter: 29
-> Merge Left Join (cost=452.87..535.26 rows=2766 width=1949) (actual time=1.385..1.392 rows=2 loops=1)
Merge Cond: (p.original_signature = r.references_original_signature)
Join Filter: (p.kind = ANY ('{community,text,user}'::text[]))
-> Sort (cost=185.16..186.84 rows=672 width=1268) (actual time=0.279..0.281 rows=2 loops=1)
Sort Key: p.original_signature
Sort Method: quicksort Memory: 27kB
-> Hash Left Join (cost=120.85..153.61 rows=672 width=1268) (actual time=0.270..0.276 rows=2 loops=1)
Hash Cond: (p.author = (ul.sig_or_author)::text)
-> WindowAgg (cost=119.51..136.31 rows=672 width=1426) (actual time=0.246..0.250 rows=2 loops=1)
-> Subquery Scan on p (cost=119.51..127.91 rows=672 width=1251) (actual time=0.241..0.243 rows=2 loops=1)
-> Sort (cost=119.51..121.19 rows=672 width=1418) (actual time=0.240..0.241 rows=2 loops=1)
Sort Key: (CASE WHEN (r_1.kind = 'user'::text) THEN 1 ELSE 0 END) DESC
Sort Method: quicksort Memory: 27kB
-> Nested Loop Left Join (cost=0.00..87.95 rows=672 width=1418) (actual time=0.111..0.234 rows=2 loops=1)
Join Filter: CASE WHEN (r_1.kind = 'user'::text) THEN (r_1.author = t_1.sig_or_author) ELSE (r_1.original_signature = t_1.sig_or_author) END
Rows Removed by Join Filter: 157
-> Seq Scan on records r_1 (cost=0.00..50.90 rows=17 width=1219) (actual time=0.070..0.147 rows=2 loops=1)
Filter: (is_latest AND (kind <> 'action'::text) AND (((kind = 'user'::text) AND (author = ANY ('{AUTHOR_NAME}'::text[]))) OR (original_signature = ANY ('{SOME_SIGNATURE}'::text[]))))
Rows Removed by Filter: 221
-> Materialize (cost=0.00..6.19 rows=79 width=411) (actual time=0.003..0.030 rows=79 loops=2)
-> Seq Scan on tally t_1 (cost=0.00..5.79 rows=79 width=411) (actual time=0.003..0.018 rows=79 loops=1)
-> Hash (cost=1.15..1.15 rows=15 width=190) (actual time=0.012..0.013 rows=15 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 12kB
-> Seq Scan on lookup ul (cost=0.00..1.15 rows=15 width=190) (actual time=0.002..0.003 rows=15 loops=1)
-> Sort (cost=267.70..273.23 rows=2212 width=877) (actual time=1.094..1.097 rows=51 loops=1)
Sort Key: r.references_original_signature
Sort Method: quicksort Memory: 77kB
-> Nested Loop Left Join (cost=0.00..144.81 rows=2212 width=877) (actual time=0.042..1.019 rows=70 loops=1)
Join Filter: CASE WHEN (r.kind = 'user'::text) THEN (r.author = t.sig_or_author) ELSE (r.original_signature = t.sig_or_author) END
Rows Removed by Join Filter: 5530
-> Seq Scan on records r (cost=0.00..50.34 rows=56 width=1219) (actual time=0.003..0.079 rows=70 loops=1)
Filter: (is_latest AND (author = 'AUTHOR_NAME'::text) AND (kind = 'action'::text))
Rows Removed by Filter: 153
-> Materialize (cost=0.00..6.19 rows=79 width=196) (actual time=0.000..0.005 rows=79 loops=70)
-> Seq Scan on tally t (cost=0.00..5.79 rows=79 width=196) (actual time=0.001..0.011 rows=79 loops=1)
-> Materialize (cost=0.00..1.22 rows=15 width=190) (actual time=0.002..0.004 rows=15 loops=2)
-> Seq Scan on lookup cl (cost=0.00..1.15 rows=15 width=190) (actual time=0.001..0.003 rows=15 loops=1)
Planning Time: 1.164 ms
Execution Time: 1.508 ms
(45 rows)
HOME Mac:
SELECT VERSION();
version
--------------------------------------------------------------------------------------------------------------------------------
PostgreSQL 15.3 (Homebrew) on x86_64-apple-darwin22.4.0, compiled by Apple clang version 14.0.3 (clang-1403.0.22.14.1), 64-bit
(1 row)
EXPLAIN ANALYZE OUTPUT:
Sort (cost=25.08..25.10 rows=10 width=1089) (actual time=0.028..0.030 rows=0 loops=1)
Sort Key: o.row_number
Sort Method: quicksort Memory: 25kB
-> Nested Loop Left Join (cost=14.06..24.91 rows=10 width=1089) (actual time=0.023..0.026 rows=0 loops=1)
Join Filter: CASE WHEN (o.kind = 'community'::text) THEN ((cl.sig_or_author)::text = o.original_signature) ELSE ((cl.sig_or_author)::text = o.references_original_signature) END
-> Nested Loop Left Join (cost=14.06..23.30 rows=4 width=2216) (actual time=0.023..0.025 rows=0 loops=1)
Join Filter: ((ul.sig_or_author)::text = o.author)
-> Hash Right Join (cost=14.06..21.93 rows=4 width=2203) (actual time=0.023..0.025 rows=0 loops=1)
Hash Cond: (r.references_original_signature = o.original_signature)
Join Filter: (o.kind = ANY ('{community,text,user}'::text[]))
-> Nested Loop Left Join (cost=0.14..7.99 rows=4 width=1009) (never executed)
Join Filter: CASE WHEN (r.kind = 'user'::text) THEN (r.author = t.sig_or_author) ELSE (r.original_signature = t.sig_or_author) END
-> Index Scan using records_author_idx on records r (cost=0.14..6.77 rows=1 width=1350) (never executed)
Index Cond: (author = 'AUTHOR_NAME'::text)
Filter: (is_latest AND (kind = 'action'::text))
-> Seq Scan on tally t (cost=0.00..1.08 rows=8 width=196) (never executed)
-> Hash (cost=13.87..13.87 rows=4 width=1390) (actual time=0.016..0.017 rows=0 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 8kB
-> Subquery Scan on o (cost=13.73..13.87 rows=4 width=1390) (actual time=0.015..0.016 rows=0 loops=1)
-> WindowAgg (cost=13.73..13.83 rows=4 width=1557) (actual time=0.015..0.016 rows=0 loops=1)
-> Subquery Scan on p (cost=13.73..13.78 rows=4 width=1382) (actual time=0.014..0.015 rows=0 loops=1)
-> Sort (cost=13.73..13.74 rows=4 width=1549) (actual time=0.014..0.015 rows=0 loops=1)
Sort Key: (CASE WHEN (r_1.kind = 'user'::text) THEN 1 ELSE 0 END) DESC
Sort Method: quicksort Memory: 25kB
-> Nested Loop Left Join (cost=8.42..13.69 rows=4 width=1549) (actual time=0.009..0.009 rows=0 loops=1)
Join Filter: CASE WHEN (r_1.kind = 'user'::text) THEN (r_1.author = t_1.sig_or_author) ELSE (r_1.original_signature = t_1.sig_or_author) END
-> Bitmap Heap Scan on records r_1 (cost=8.42..12.44 rows=1 width=1350) (actual time=0.008..0.009 rows=0 loops=1)
Recheck Cond: ((author = ANY ('{AUTHOR_NAME}'::text[])) OR ((original_signature = ANY ('{SOME_SIGNATURE}'::text[])) AND is_latest))
Filter: (is_latest AND (kind <> 'action'::text) AND (((kind = 'user'::text) AND (author = ANY ('{AUTHOR_NAME}'::text[]))) OR (original_signature = ANY ('{SOME_SIGNATURE}'::text[]))))
-> BitmapOr (cost=8.42..8.42 rows=1 width=0) (actual time=0.008..0.008 rows=0 loops=1)
-> Bitmap Index Scan on records_author_idx (cost=0.00..4.15 rows=1 width=0) (actual time=0.004..0.004 rows=0 loops=1)
Index Cond: (author = ANY ('{AUTHOR_NAME}'::text[]))
-> Bitmap Index Scan on records_original_signature_idx (cost=0.00..4.27 rows=1 width=0) (actual time=0.003..0.003 rows=0 loops=1)
Index Cond: (original_signature = ANY ('{SOME_SIGNATURE}'::text[]))
-> Seq Scan on tally t_1 (cost=0.00..1.08 rows=8 width=411) (never executed)
-> Materialize (cost=0.00..1.07 rows=5 width=186) (never executed)
-> Seq Scan on lookup ul (cost=0.00..1.05 rows=5 width=186) (never executed)
-> Materialize (cost=0.00..1.07 rows=5 width=186) (never executed)
-> Seq Scan on lookup cl (cost=0.00..1.05 rows=5 width=186) (never executed)
Planning Time: 1.578 ms
Execution Time: 0.149 ms
(41 rows)
2
Answers
StackOverflow limits my question to 30,000 characters. So, I am adding this detail as asked by @FrankHeikens. Note that this is not the answer, it's an edit to my question:
EDIT: I no longer have access to the old version of postgres on the server. Here's the verbose output of the
explain (analyze, verbose, buffers, settings)
on server:On Home Mac:
Picking one question to answer:
"3. Why would a single version upgrade fix this? A sort by
row_number() OVER (?)
seems fairly trivial … "Because Postgres 15 added a performance optimization for this case exactly. The release notes:
Postgres 16 has another major improvement for
row_number()
. The release notes:Most prominently, this speeds up
row_number()
. It started all here: