A different filter value results in a different (slower) query plan
0
votes
1
answer
72
views
I am executing the following query in Postgres 15 with the Timescale extension on an alerts table to get the latest alert for a username.
EXPLAIN ANALYZE
SELECT *
FROM alerts_alerts
WHERE username IN ('')
ORDER BY timestamp DESC
LIMIT 1
For most usernames, the query executes quickly, under 150ms. However, for some usernames, it takes longer. Almost all databases have around the same number of alerts, around 450, and most of them have fairly recent data, all within the past 6 months.
Here's the
Explain Analyze
for the problematic username:
~~~none
"Limit (cost=0.29..2262.68 rows=1 width=86) (actual time=36129.346..36129.370 rows=1 loops=1)"
" -> Custom Scan (ChunkAppend) on alerts_alerts (cost=0.29..2262.68 rows=1 width=86) (actual time=36129.344..36129.368 rows=1 loops=1)"
" Order: alerts_alerts.""timestamp"" DESC"
" -> Index Scan using _hyper_1_234_chunk_alerts_alerts_timestamp_idx_1 on _hyper_1_234_chunk (cost=0.29..2262.68 rows=1 width=89) (actual time=5.795..5.796 rows=0 loops=1)"
" Filter: ((username)::text = 'username_long_query'::text)"
" Rows Removed by Filter: 30506"
" -> Index Scan using _hyper_1_233_chunk_alerts_alerts_timestamp_idx_1 on _hyper_1_233_chunk (cost=0.29..4337.82 rows=1 width=91) (actual time=11.112..11.112 rows=0 loops=1)"
" Filter: ((username)::text = 'username_long_query'::text)"
" Rows Removed by Filter: 59534"
[ ... Cut redundant log lines here ... ]
" -> Index Scan using _hyper_1_156_chunk_alerts_alerts_timestamp_idx_1 on _hyper_1_156_chunk (cost=0.42..11418.54 rows=2591 width=80) (never executed)"
" Filter: ((username)::text = 'username_long_query'::text)"
" -> Index Scan using _hyper_1_155_chunk_alerts_alerts_timestamp_idx_1 on _hyper_1_155_chunk (cost=0.29..7353.95 rows=749 width=84) (never executed)"
" Filter: ((username)::text = 'username_long_query'::text)"
[ ... Cut redundant log lines here ... ]
"Planning Time: 13.154 ms"
"Execution Time: 36129.923 ms"
~~~
Now, this is the Explain Analyze
for the usernames that execute quickly:
~~~none
"Limit (cost=471.73..471.73 rows=1 width=458) (actual time=1.672..1.691 rows=1 loops=1)"
" -> Sort (cost=471.73..472.76 rows=414 width=458) (actual time=1.671..1.689 rows=1 loops=1)"
" Sort Key: _hyper_1_234_chunk.""timestamp"" DESC"
" Sort Method: top-N heapsort Memory: 27kB"
" -> Append (cost=0.29..469.66 rows=414 width=457) (actual time=1.585..1.654 rows=210 loops=1)"
" -> Index Scan using _hyper_1_234_chunk_alerts_alerts_fleet_a3933a38_1 on _hyper_1_234_chunk (cost=0.29..2.49 rows=1 width=372) (actual time=0.006..0.007 rows=0 loops=1)"
" Index Cond: ((username)::text = 'username_value'::text)"
" -> Index Scan using _hyper_1_233_chunk_alerts_alerts_fleet_a3933a38_1 on _hyper_1_233_chunk (cost=0.29..2.37 rows=1 width=385) (actual time=0.006..0.006 rows=0 loops=1)"
" Index Cond: ((username)::text = 'username_value'::text)"
[ ... Cut redundant log lines here ... ]
" -> Seq Scan on _hyper_1_83_chunk (cost=0.00..1.12 rows=1 width=504) (actual time=0.013..0.013 rows=0 loops=1)"
" Filter: ((username)::text = 'username_value'::text)"
" Rows Removed by Filter: 10"
" -> Seq Scan on _hyper_1_81_chunk (cost=0.00..1.12 rows=1 width=504) (actual time=0.009..0.009 rows=0 loops=1)"
" Filter: ((username)::text = 'username_value'::text)"
" Rows Removed by Filter: 10"
"Planning Time: 899.811 ms"
"Execution Time: 2.613 ms"
~~~
Preliminary research suggests doing maintenance on the database table. After executing the vacuum command, the queries were executed again but the results did not change.
It should also be noted that there are other usernames that use the "problematic" planning, but the execution time is still quick.
Not sure how to resolve this discrepancy in query execution time. It could be useful to add another index, but as I'm new to PostgreSQL, I'm currently not sure about the best approach to this.
Asked by Razgriz
(113 rep)
May 24, 2024, 11:41 AM
Last activity: May 27, 2024, 06:34 AM
Last activity: May 27, 2024, 06:34 AM