The question:
I have read a bunch of resources on the internet and the official documentation of PostgreSQL and I still don’t know how to interpret the result of a EXPLAIN ANALYZE. I’m using PostgreSQL 12.8 and I have the following result when executing the EXPLAIN ANALYZE command:
EDIT with text
QUERY PLAN
------------------------------------------------
Nested Loop (cost=138604.33.. 149260.39 rows=1 width=238) (actual time=448.894.. 162293.701 rows=372 loops=1)
Join Filter: (s.id = setting_aud.id)
Rows Removed by Join Filter: 69006
Buffers: shared hit=38723745
-> Gather (cost=1000.00.. 10052.82 rows=1 width=234) (actual time=0.264..0.799 rows=372 loops=1)
Workers Planned: 2
Workers Launched: 2
Buffers: shared hit=7845
-> Parallel Seq Scan on settings (cost=0.00..9052.72 rows=1 width=234) (actual time=5.367..15.796 rows=124 loops=3)
Filter: (active AND ((type)::text = 'AgePlateLever'::text))
Rows Removed by Filter: 76875
Buffers: shared hit=7845
-> Finalize GroupAggregate (cost=137604.33. . 139076.80 rows=5812 width=12) (actual time=436.029..436.206 rows=186 loops=372)
Group Key: setting_aud.id
Buffers: shared hit=13063859
-> Gather Merge (cost=137604.33..138960.56 rows=11624 width=12) (actual time=436.022..436.121 rows=554 loops=372)
Workers Planned: 2
Workers Launched: 2
Buffers: shared hit=13063859
-> Sort (cost=136604.31..136618.84 rows=5812 width=12) (actual time=431.252..431.278 rows=480 loops=1116)
Sort Key: setting_aud.id
Sort Method: quicksort Memory: 59kB
Worker 0: Sort Method: quicksort Memory: 59kB
Worker 1: Sort Method: quicksort Memory: 59kB
Buffers: shared hit=38715900
-> Partial HashAggregate (cost=136182.79..136240.91 rows=5812 width=12) (actual time=430.954..431.065 rows=741 loops=1116)
Group Key: setting_aud.id
Buffers: shared hit=38709948
-> Parallel Seq Scan on setting_aud (cost=0.00.. 129655.88 rows=1305384 width=12) (actual time=0.017..282.585 rows=1040198 loops=1116)
Filter: ((revision_type <> 2) AND ((type)::text = 'AgeplateLever'::text))
Rows Removed by Filter: 324937
Buffers: shared hit=38709948
Planning Time: 0.332 ms
Execution Time: 162294.083 ms
How can I know where to put indexes looking into these results? How can I know how many iterations are executed in the Nested Loop join?
EDIT 2
I have added the following indexes:
CREATE INDEX setting_type_active_id_idx ON setting (type, active, id);
CREATE INDEX setting_aud_type_revision_type_id_revision_id_idx ON setting_aud (type, revision_type, id, revision_id);
And also executed EXPLAIN with VERBOSE option in order to see more information as suggested by Laurenz Albe, the results now are better:
QUERY PLAN |
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
Merge Join (cost=139152.19..140705.34 rows=1 width=238) (actual time=468.645..470.827 rows=372 loops=1) |
Output: s.id, s.setting_key, s.type, s.cap_id, s.current_value, s.source, s.rationale, s.created_date, s.last_modified_date, s.model_year, s.batch_adjustment_id, s.active, s.last_activated_at, s.setting_metadata_id, (max(setting_aud.revision_id))|
Inner Unique: true |
Merge Cond: (s.id = setting_aud.id) |
Buffers: shared hit=105643 |
-> Index Scan using setting_type_active_id_idx on db_schema.setting s (cost=0.42..8.44 rows=1 width=234) (actual time=0.022..0.385 rows=372 loops=1) |
Output: s.id, s.setting_key, s.type, s.cap_id, s.current_value, s.source, s.rationale, s.created_date, s.last_modified_date, s.model_year, s.batch_adjustment_id, s.active, s.last_activated_at, s.setting_metadata_id |
Index Cond: (((s.type)::text = 'AgePlateLever'::text) AND (s.active = true)) |
Buffers: shared hit=385 |
-> Finalize GroupAggregate (cost=139151.77..140624.24 rows=5812 width=12) (actual time=468.620..470.347 rows=372 loops=1) |
Output: setting_aud.id, max(setting_aud.revision_id) |
Group Key: setting_aud.id |
Buffers: shared hit=105258 |
-> Gather Merge (cost=139151.77..140508.00 rows=11624 width=12) (actual time=468.610..470.165 rows=1109 loops=1) |
Output: setting_aud.id, (PARTIAL max(setting_aud.revision_id)) |
Workers Planned: 2 |
Workers Launched: 2 |
Buffers: shared hit=105258 |
-> Sort (cost=138151.75..138166.28 rows=5812 width=12) (actual time=465.746..465.780 rows=618 loops=3) |
Output: setting_aud.id, (PARTIAL max(setting_aud.revision_id)) |
Sort Key: setting_aud.id |
Sort Method: quicksort Memory: 59kB |
Worker 0: Sort Method: quicksort Memory: 59kB |
Worker 1: Sort Method: quicksort Memory: 59kB |
Buffers: shared hit=105258 |
Worker 0: actual time=463.883..463.923 rows=740 loops=1 |
Buffers: shared hit=34816 |
Worker 1: actual time=465.030..465.070 rows=740 loops=1 |
Buffers: shared hit=37348 |
-> Partial HashAggregate (cost=137730.24..137788.36 rows=5812 width=12) (actual time=465.461..465.568 rows=741 loops=3) |
Output: setting_aud.id, PARTIAL max(setting_aud.revision_id) |
Group Key: setting_aud.id |
Buffers: shared hit=105242 |
Worker 0: actual time=463.576..463.685 rows=740 loops=1 |
Buffers: shared hit=34808 |
Worker 1: actual time=464.728..464.834 rows=740 loops=1 |
Buffers: shared hit=37340 |
-> Parallel Seq Scan on db_schema.setting_aud (cost=0.00..131129.27 rows=1320193 width=12) (actual time=0.017..304.923 rows=1052528 loops=3) |
Output: setting_aud.id, setting_aud.revision_id |
Filter: ((setting_aud.revision_type <> 2) AND ((setting_aud.type)::text = 'AgePlateLever'::text)) |
Rows Removed by Filter: 328028 |
Buffers: shared hit=105242 |
Worker 0: actual time=0.006..303.967 rows=1044836 loops=1 |
Buffers: shared hit=34808 |
Worker 1: actual time=0.013..304.850 rows=1117851 loops=1 |
Buffers: shared hit=37340 |
Planning Time: 0.234 ms |
Execution Time: 470.919 ms |
Now is using index scan for setting table, but why is still doing a Parallel Seq Scan on setting_aud and not an index scan? Why the loops were reduced?
The Solutions:
Below are the methods you can try. The first solution is probably the best. Try others if the first one doesn’t work. Senior developers aren’t just copying/pasting – they read the methods carefully & apply them wisely to each case.
Method 1
The only potential place where an index could help is
-> Parallel Seq Scan on setting_aud (cost=0.00.. 129655.88 rows=1305384 width=12) (actual time=0.017..282.585 rows=1040198 loops=1116)
Filter: ((revision_type <> 2) AND ((type)::text = 'AgeplateLever'::text))
Rows Removed by Filter: 324937
Buffers: shared hit=38709948
But an index won’t really help much here, because only few rows are filtered out. What might help is adding all required columns to the index so you can get an index-only scan, but to determine which columns those are you would need the result of EXPLAIN (VERBOSE).
However, the main problem is probably the misestimate on the scan on setting (124 instead of 1), which leads the optimizer to choose a nested loop join, so that setting_aud is scanned 1116 times. to fix that, try to improve the estimate:
-
Perhaps
ANALYZE settingis already enough. -
If not, improve the statistics:
ALTER TABLE setting ALTER type SET STATISTICS 1000; ANALYZE setting; -
If that is still not enough, try extended statistics:
CREATE STATISTICS some_name (dependencies) ON type, active FROM setting; ANALYZE setting;
Then hopefully a hash or merge join will be chosen, and the performance will improve.
All methods was sourced from stackoverflow.com or stackexchange.com, is licensed under cc by-sa 2.5, cc by-sa 3.0 and cc by-sa 4.0