I have a generated query from an ORM that selects data from a nested join on a junction table.
When executing it looks like it performs a full table scan on a table with >55 million records resulting in a slow execution time.
My expectation was that it would perform the filtering first then lookup by index for the join.
Here is the query: (additional columns have been removed for brevity)
SELECT e."SnapshotId" FROM "EFACSnapshot" AS e LEFT JOIN ( SELECT e0."SnapshotId" FROM "EFACSnapshotVector3" AS e0 INNER JOIN "Vector3" AS v3 ON e0."Vector3Id" = v3."Vector3Id" ) AS t ON e."SnapshotId" = t."SnapshotId" WHERE e."ClientId" = 386707Query Plan
[ { "Plan": { "Node Type": "Hash Join", "Join Type": "Right", "Startup Cost": 1814295.06, "Total Cost": 2160533.66, "Plan Rows": 6020, "Plan Width": 4, "Actual Startup Time": 97144.904, "Actual Total Time": 111542.936, "Actual Rows": 155, "Actual Loops": 1, "Output": [ "e."SnapshotId"" ], "Hash Cond": "(e0."SnapshotId" = e."SnapshotId")", "Shared Hit Blocks": 2, "Shared Read Blocks": 358552, "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": 163599, "Temp Written Blocks": 163473, "Plans": [ { "Node Type": "Hash Join", "Parent Relationship": "Outer", "Join Type": "Inner", "Startup Cost": 1811166.81, "Total Cost": 2152829.01, "Plan Rows": 1204320, "Plan Width": 4, "Actual Startup Time": 94371.544, "Actual Total Time": 110790.36, "Actual Rows": 1204320, "Actual Loops": 1, "Output": [ "e0."SnapshotId"" ], "Hash Cond": "(e0."Vector3Id" = v3."Vector3Id")", "Shared Hit Blocks": 2, "Shared Read Blocks": 358548, "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": 163599, "Temp Written Blocks": 163473, "Plans": [ { "Node Type": "Seq Scan", "Parent Relationship": "Outer", "Relation Name": "EFACSnapshotVector3", "Schema": "public", "Alias": "e0", "Startup Cost": 0, "Total Cost": 18553.2, "Plan Rows": 1204320, "Plan Width": 8, "Actual Startup Time": 0.007, "Actual Total Time": 1936.546, "Actual Rows": 1204320, "Actual Loops": 1, "Output": [ "e0."Vector3Id"", "e0."SnapshotId"" ], "Shared Hit Blocks": 1, "Shared Read Blocks": 6509, "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": "Hash", "Parent Relationship": "Inner", "Startup Cost": 904608.36, "Total Cost": 904608.36, "Plan Rows": 55256836, "Plan Width": 4, "Actual Startup Time": 94369.276, "Actual Total Time": 94369.276, "Actual Rows": 55256837, "Actual Loops": 1, "Output": [ "v3."Vector3Id"" ], "Hash Buckets": 262144, "Hash Batches": 64, "Original Hash Batches": 64, "Peak Memory Usage": 30422, "Shared Hit Blocks": 1, "Shared Read Blocks": 352039, "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": 159326, "Plans": [ { "Node Type": "Seq Scan", "Parent Relationship": "Outer", "Relation Name": "Vector3", "Schema": "public", "Alias": "v3", "Startup Cost": 0, "Total Cost": 904608.36, "Plan Rows": 55256836, "Plan Width": 4, "Actual Startup Time": 0.012, "Actual Total Time": 50954.107, "Actual Rows": 55256837, "Actual Loops": 1, "Output": [ "v3."Vector3Id"" ], "Shared Hit Blocks": 1, "Shared Read Blocks": 352039, "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": "Hash", "Parent Relationship": "Inner", "Startup Cost": 3112.53, "Total Cost": 3112.53, "Plan Rows": 1257, "Plan Width": 4, "Actual Startup Time": 3.052, "Actual Total Time": 3.052, "Actual Rows": 31, "Actual Loops": 1, "Output": [ "e."SnapshotId"" ], "Hash Buckets": 1024, "Hash Batches": 1, "Original Hash Batches": 1, "Peak Memory Usage": 2, "Shared Hit Blocks": 0, "Shared Read Blocks": 4, "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 Heap Scan", "Parent Relationship": "Outer", "Relation Name": "EFACSnapshot", "Schema": "public", "Alias": "e", "Startup Cost": 26.02, "Total Cost": 3112.53, "Plan Rows": 1257, "Plan Width": 4, "Actual Startup Time": 3.008, "Actual Total Time": 3.026, "Actual Rows": 31, "Actual Loops": 1, "Output": [ "e."SnapshotId"" ], "Recheck Cond": "(e."ClientId" = 386707)", "Rows Removed by Index Recheck": 0, "Shared Hit Blocks": 0, "Shared Read Blocks": 4, "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", "Index Name": ""IX_EFACSnapshot_ClientId"", "Startup Cost": 0, "Total Cost": 25.71, "Plan Rows": 1257, "Plan Width": 0, "Actual Startup Time": 2.593, "Actual Total Time": 2.593, "Actual Rows": 31, "Actual Loops": 1, "Index Cond": "(e."ClientId" = 386707)", "Shared Hit Blocks": 0, "Shared Read Blocks": 3, "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 } ] } ] } ] }, "Triggers": [], "Total Runtime": 111549.609 }]All referenced columns appear to have the correct foreign key and indexing setup.
Could someone explain why a full table scan is being performed and how I can adjust the query to prevent that?
Thanks!
Advertisement
Answer
JSON format is not very readable by humans, you would probably be better off with text format (the default) for your plan.
"Plan Rows": 1257,"Actual Rows": 31,
So e."ClientId" = 386707 yields 40 times fewer rows than it thought it would. Which means it thinks the nested loop would be about 40 times more expensive than it actually is. It is not surprising the planner makes the wrong choice (well, assuming it is the wrong choice, we don’t actually know that).
Why is that stat off by so much? Are your stats way out of date? Do a VACUUM ANALYZE on “EFACSnapshot” and see if things look better after that. If nothing changes, then I’d want to see the data select * from pg_stats where relname='EFACSnapshot' and attname='ClientId', as well as knowing the PostgreSQL version and the setting of default_statistics_target