EralpB
Reputation: 1742
Adding ORDER BY to SQL query explodes runtime
My query execution time explodes when I add an ORDER BY, I can't seem to get the reasoning behind it. I feel it should be simple to order on an indexed field.
So two queries look like this:
This one takes 30-50 seconds:
EXPLAIN (ANALYZE, COSTS, VERBOSE, BUFFERS, FORMAT JSON)
SELECT * FROM "content_entry"
INNER JOIN "marketplace_review" ON ("content_entry"."id" = "marketplace_review"."entry_ptr_id")
INNER JOIN "marketplace_product" ON ("marketplace_review"."product_id" = "marketplace_product"."id")
WHERE ("content_entry"."type" = 3 AND "marketplace_product"."brand_id" = 750)
ORDER BY "content_entry"."timestamp" DESC
LIMIT 3
This one takes less than one second
EXPLAIN (ANALYZE, COSTS, VERBOSE, BUFFERS, FORMAT JSON)
SELECT * FROM "content_entry"
INNER JOIN "marketplace_review" ON ("content_entry"."id" = "marketplace_review"."entry_ptr_id")
INNER JOIN "marketplace_product" ON ("marketplace_review"."product_id" = "marketplace_product"."id")
WHERE ("content_entry"."type" = 3 AND "marketplace_product"."brand_id" = 750)
LIMIT 3
The output of the one with order by:
[
{
"Plan": {
"Node Type": "Limit",
"Parallel Aware": false,
"Startup Cost": 1.43,
"Total Cost": 98242.01,
"Plan Rows": 3,
"Plan Width": 385,
"Actual Startup Time": 2668.251,
"Actual Total Time": 45068.099,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 60929421,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Nested Loop",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Join Type": "Inner",
"Startup Cost": 1.43,
"Total Cost": 29046467.49,
"Plan Rows": 887,
"Plan Width": 385,
"Actual Startup Time": 2668.250,
"Actual Total Time": 45068.095,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 60929421,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Nested Loop",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Join Type": "Inner",
"Startup Cost": 1.00,
"Total Cost": 18561128.82,
"Plan Rows": 17657640,
"Plan Width": 389,
"Actual Startup Time": 0.036,
"Actual Total Time": 23010.813,
"Actual Rows": 5636983,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 29168382,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Index Scan",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Scan Direction": "Backward",
"Index Name": "content_entry_d7e6d55b",
"Relation Name": "content_entry",
"Schema": "public",
"Alias": "content_entry",
"Startup Cost": 0.56,
"Total Cost": 5903549.69,
"Plan Rows": 24176239,
"Plan Width": 385,
"Actual Startup Time": 0.031,
"Actual Total Time": 5038.896,
"Actual Rows": 5636983,
"Actual Loops": 1,
"Output": [""],
"Filter": "(content_entry.type = 3)",
"Rows Removed by Filter": 1872638,
"Shared Hit Blocks": 6559529,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
},
{
"Node Type": "Index Scan",
"Parent Relationship": "Inner",
"Parallel Aware": false,
"Scan Direction": "Forward",
"Index Name": "marketplace_review_pkey",
"Relation Name": "marketplace_review",
"Schema": "public",
"Alias": "marketplace_review",
"Startup Cost": 0.44,
"Total Cost": 0.51,
"Plan Rows": 1,
"Plan Width": 8,
"Actual Startup Time": 0.002,
"Actual Total Time": 0.002,
"Actual Rows": 1,
"Actual Loops": 5636983,
"Output": [""],
"Index Cond": "(marketplace_review.entry_ptr_id = content_entry.id)",
"Rows Removed by Index Recheck": 0,
"Shared Hit Blocks": 22608853,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
}
]
},
{
"Node Type": "Index Scan",
"Parent Relationship": "Inner",
"Parallel Aware": false,
"Scan Direction": "Forward",
"Index Name": "marketplace_product_pkey",
"Relation Name": "marketplace_product",
"Schema": "public",
"Alias": "marketplace_product",
"Startup Cost": 0.43,
"Total Cost": 0.58,
"Plan Rows": 1,
"Plan Width": 4,
"Actual Startup Time": 0.003,
"Actual Total Time": 0.003,
"Actual Rows": 0,
"Actual Loops": 5636983,
"Output": ["marketplace_product.id"],
"Index Cond": "(marketplace_product.id = marketplace_review.product_id)",
"Rows Removed by Index Recheck": 0,
"Filter": "(marketplace_product.brand_id = 750)",
"Rows Removed by Filter": 1,
"Shared Hit Blocks": 31761039,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
}
]
}
]
},
"Planning Time": 1.493,
"Triggers": [
],
"Execution Time": 45068.146
}
]
And output of the one without order by:
[
{
"Plan": {
"Node Type": "Limit",
"Parallel Aware": false,
"Startup Cost": 24.64,
"Total Cost": 1780.29,
"Plan Rows": 3,
"Plan Width": 1412,
"Actual Startup Time": 0.039,
"Actual Total Time": 0.060,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 25,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Nested Loop",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Join Type": "Inner",
"Startup Cost": 24.64,
"Total Cost": 527304.93,
"Plan Rows": 901,
"Plan Width": 1412,
"Actual Startup Time": 0.038,
"Actual Total Time": 0.059,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 25,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Nested Loop",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Join Type": "Inner",
"Startup Cost": 24.08,
"Total Cost": 526285.64,
"Plan Rows": 1249,
"Plan Width": 1027,
"Actual Startup Time": 0.028,
"Actual Total Time": 0.033,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Shared Hit Blocks": 10,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Index Scan",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Scan Direction": "Forward",
"Index Name": "marketplace_product_521b20f5",
"Relation Name": "marketplace_product",
"Schema": "public",
"Alias": "marketplace_product",
"Startup Cost": 0.43,
"Total Cost": 761.18,
"Plan Rows": 189,
"Plan Width": 986,
"Actual Startup Time": 0.010,
"Actual Total Time": 0.010,
"Actual Rows": 1,
"Actual Loops": 1,
"Output": [""],
"Index Cond": "(marketplace_product.brand_id = 750)",
"Rows Removed by Index Recheck": 0,
"Shared Hit Blocks": 4,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
},
{
"Node Type": "Bitmap Heap Scan",
"Parent Relationship": "Inner",
"Parallel Aware": false,
"Relation Name": "marketplace_review",
"Schema": "public",
"Alias": "marketplace_review",
"Startup Cost": 23.65,
"Total Cost": 2771.16,
"Plan Rows": 939,
"Plan Width": 41,
"Actual Startup Time": 0.013,
"Actual Total Time": 0.017,
"Actual Rows": 3,
"Actual Loops": 1,
"Output": [""],
"Recheck Cond": "(marketplace_review.product_id = marketplace_product.id)",
"Rows Removed by Index Recheck": 0,
"Exact Heap Blocks": 3,
"Lossy Heap Blocks": 0,
"Shared Hit Blocks": 6,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Plans": [
{
"Node Type": "Bitmap Index Scan",
"Parent Relationship": "Outer",
"Parallel Aware": false,
"Index Name": "marketplace_review_product_id_4e8c6bab491b1730_idx",
"Startup Cost": 0.00,
"Total Cost": 23.42,
"Plan Rows": 939,
"Plan Width": 0,
"Actual Startup Time": 0.009,
"Actual Total Time": 0.009,
"Actual Rows": 13,
"Actual Loops": 1,
"Index Cond": "(marketplace_review.product_id = marketplace_product.id)",
"Shared Hit Blocks": 3,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
}
]
}
]
},
{
"Node Type": "Index Scan",
"Parent Relationship": "Inner",
"Parallel Aware": false,
"Scan Direction": "Forward",
"Index Name": "content_entry_pkey",
"Relation Name": "content_entry",
"Schema": "public",
"Alias": "content_entry",
"Startup Cost": 0.56,
"Total Cost": 0.81,
"Plan Rows": 1,
"Plan Width": 385,
"Actual Startup Time": 0.006,
"Actual Total Time": 0.006,
"Actual Rows": 1,
"Actual Loops": 3,
"Output": [""],
"Index Cond": "(content_entry.id = marketplace_review.entry_ptr_id)",
"Rows Removed by Index Recheck": 0,
"Filter": "(content_entry.type = 3)",
"Rows Removed by Filter": 0,
"Shared Hit Blocks": 15,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
}
]
}
]
},
"Planning Time": 0.771,
"Triggers": [
],
"Execution Time": 0.182
}
]
Just ordering without joins is again under 1 second, which is normal because ordered field is indexed, so I don't get why joins corrupt the ordering that much.
Upvotes: 1
Views: 216
Answers (1)
Erwin Brandstetter
Reputation: 656804
Your query with reduced noise:
SELECT *
FROM content_entry ce
JOIN marketplace_review mr ON mr.entry_ptr_id = ce.id
JOIN marketplace_product mp ON mp.id = mr.product_id
WHERE ce.type = 3
AND mp.brand_id = 750
ORDER BY ce.timestamp DESC -- adding this makes it slow
LIMIT 3
A query with LIMIT 3 and no ORDER BY is free to return any three rows that qualify. That's your first, fast query.
Once you add ORDER BY, Postgres has to consider all qualifying rows, sort them and identify the "first" 3 according to your ORDER BY expressions. If substantially more rows qualify that just the three in LIMIT 3 this is consequently substantially more expensive. The query might have to visit millions of rows instead of just a hand full. That's your second, slow query.
It may seem counter-intuitive that the first query gets faster the more rows qualify, while the second gets slower. Makes sense, though, if you think about it.
You can improve performance of the second query dramatically, if you have an index that fits your ORDER BY criteria exactly and does not include too many non-qualifying rows - and Postgres also does not expect too many non-qualifying rows based on current statistics and cost settings.
Estimating the combined selectivity of 4 predicates (2x WHERE, 2x JOIN) isn't easy. Increasing the statistics target for crucial columns might help.
The (missing) output of EXPLAIN (ANALYZE, BUFFERS) in combination with available resources and actual resource settings should provide clues where estimates stray from actual counts, where cost or resource settings might be inappropriate and where different indexes could help.
A shot in the dark:
If you don't have that already, a multicolumn index on content_entry(type, timestamp DESC) would be instrumental for both queries. Or if you always query for type = 3 (and that's not the type of most rows anyway), a partial index would be even more potent:
CREATE INDEX foo ON content_entry (timestamp DESC) WHERE entry = 3;
Related:
Be sure the column content_entry.timestamp is defined NOT NULL, or consider ORDER BY ce.timestamp DESC NULL LAST. Related:
And do you really need to return all columns from 3 tables (SELECT *)?
Upvotes: 3
Related Questions
- PostgreSQL: Terribly slow ORDER BY with primary key as the ordering key
- Postgres SLOWER when a LIMIT is set: how to fix besides adding a dummy `ORDER BY`?
- Multi column order by kills postgresql performance, any way to fix?
- Why does adding ORDER BY drastically speed up query?
- Multiple SQL ORDER BY statements take the same time to execute
- PostgreSQL ORDER BY taking extremely long
- Query with ORDER BY is 13 times as slow when I add LIMIT 1
- How to reduce the costs of an sql select with order by?
- "Order by" degraded performance in sql
- Really long - running query when using order by