Unexpected query plan results

From: Anne Rosset <arosset(at)collab(dot)net>
To: pgsql-performance(at)postgresql(dot)org
Subject: Unexpected query plan results
Date: 2009-05-28 22:46:43
Message-ID: 4A1F1453.1010901@collab.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hi,
We have one query which has a left join. If we run this query without
the left join, it runs slower than with the left join.

-query with the left join:

EXPLAIN ANALYZE
SELECT
artifact.id AS id,
artifact.priority AS priority,
item.title AS title,
item.name AS name,
field_value2.value AS status,
field_value3.value AS category,
sfuser.username AS submittedByUsername,
sfuser.full_name AS submittedByFullname,
sfuser2.username AS assignedToUsername,
sfuser2.full_name AS assignedToFullname,
item.version AS version
FROM
sfuser sfuser,
relationship relationship,
item item,
field_value field_value3,
sfuser sfuser2,
project project,
field_value field_value2,
field_value field_value,
artifact artifact,
folder folder,
field_value field_value4
WHERE
artifact.id=item.id
AND item.folder_id=folder.id
AND folder.project_id=project.id
AND artifact.group_fv=field_value.id
AND artifact.status_fv=field_value2.id
AND artifact.category_fv=field_value3.id
AND artifact.customer_fv=field_value4.id
AND item.created_by_id=sfuser.id
AND relationship.is_deleted=false
AND relationship.relationship_type_name='ArtifactAssignment'
AND relationship.origin_id=sfuser2.id
AND artifact.id=relationship.target_id
AND item.is_deleted=false
AND project.path='projects.gl_coconet_performance_improveme'
AND item.folder_id='tracker3641'
AND folder.path='tracker.perf_test'
AND (field_value2.value_class='Open');

-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hash Join (cost=47645.19..89559.37 rows=1 width=155) (actual time=4411.623..6953.329 rows=71 loops=1)
Hash Cond: ((folder.project_id)::text = (project.id)::text)
-> Nested Loop (cost=47640.91..89553.64 rows=384 width=167) (actual time=4411.558..6953.136 rows=71 loops=1)
-> Index Scan using folder_pk on folder (cost=0.00..4.35 rows=1 width=26) (actual time=0.029..0.032 rows=1 loops=1)
Index Cond: ('tracker3641'::text = (id)::text)
Filter: ((path)::text = 'tracker.perf_test'::text)
-> Nested Loop (cost=47640.91..89545.46 rows=384 width=168) (actual time=4411.525..6953.052 rows=71 loops=1)
-> Nested Loop (cost=47640.91..89434.35 rows=384 width=150) (actual time=4411.508..6952.049 rows=71 loops=1)
-> Nested Loop (cost=47640.91..89296.15 rows=384 width=149) (actual time=4411.489..6950.823 rows=71 loops=1)
-> Nested Loop (cost=47640.91..89157.95 rows=384 width=162) (actual time=4411.469..6949.629 rows=71 loops=1)
-> Nested Loop (cost=47640.91..89019.74 rows=384 width=175) (actual time=4411.443..6948.289 rows=71 loops=1)
-> Nested Loop (cost=47640.91..88464.52 rows=1819 width=157) (actual time=4411.418..6947.188 rows=71 loops=1)
-> Merge Join (cost=47640.91..83661.94 rows=2796 width=158) (actual time=4411.355..6945.443 rows=71 loops=1)
Merge Cond: ((item.id)::text = "inner"."?column7?")
-> Index Scan using item_pk on item (cost=0.00..176865.31 rows=97498 width=88) (actual time=117.304..2405.060 rows=71 loops=1)
Filter: ((NOT is_deleted) AND ((folder_id)::text = 'tracker3641'::text))
-> Sort (cost=47640.91..47808.10 rows=66876 width=70) (actual time=4273.919..4401.387 rows=168715 loops=1)
Sort Key: (artifact.id)::text
-> Hash Join (cost=9271.96..42281.07 rows=66876 width=70) (actual time=124.119..794.667 rows=184378 loops=1)
Hash Cond: ((artifact.status_fv)::text = (field_value2.id)::text)
-> Seq Scan on artifact (cost=0.00..25206.14 rows=475614 width=69) (actual time=0.008..214.459 rows=468173 loops=1)
-> Hash (cost=8285.92..8285.92 rows=78883 width=27) (actual time=124.031..124.031 rows=79488 loops=1)
-> Index Scan using field_class_idx on field_value field_value2 (cost=0.00..8285.92 rows=78883 width=27) (actual time=0.049..60.599 rows=79488 loops=1)
Index Cond: ((value_class)::text = 'Open'::text)
-> Index Scan using relation_target on relationship (cost=0.00..1.71 rows=1 width=25) (actual time=0.022..0.022 rows=1 loops=71)
Index Cond: ((artifact.id)::text = (relationship.target_id)::text)
Filter: ((NOT is_deleted) AND ((relationship_type_name)::text = 'ArtifactAssignment'::text))
-> Index Scan using sfuser_pk on sfuser (cost=0.00..0.29 rows=1 width=42) (actual time=0.013..0.013 rows=1 loops=71)
Index Cond: ((item.created_by_id)::text = (sfuser.id)::text)
-> Index Scan using field_value_pk on field_value field_value4 (cost=0.00..0.35 rows=1 width=13) (actual time=0.017..0.017 rows=1 loops=71)
Index Cond: ((artifact.customer_fv)::text = (field_value4.id)::text)
-> Index Scan using field_value_pk on field_value (cost=0.00..0.35 rows=1 width=13) (actual time=0.015..0.015 rows=1 loops=71)
Index Cond: ((artifact.group_fv)::text = (field_value.id)::text)
-> Index Scan using field_value_pk on field_value field_value3 (cost=0.00..0.35 rows=1 width=27) (actual time=0.015..0.015 rows=1 loops=71)
Index Cond: ((artifact.category_fv)::text = (field_value3.id)::text)
-> Index Scan using sfuser_pk on sfuser sfuser2 (cost=0.00..0.28 rows=1 width=42) (actual time=0.012..0.012 rows=1 loops=71)
Index Cond: ((relationship.origin_id)::text = (sfuser2.id)::text)
-> Hash (cost=4.27..4.27 rows=1 width=12) (actual time=0.048..0.048 rows=1 loops=1)
-> Index Scan using project_path on project (cost=0.00..4.27 rows=1 width=12) (actual time=0.041..0.042 rows=1 loops=1)
Index Cond: ((path)::text = 'projects.gl_coconet_performance_improveme'::text)
Total runtime: 6966.099 ms

-same query but without the left join

EXPLAIN ANALYZE
SELECT
artifact.id AS id,
artifact.priority AS priority,
item.title AS title,
item.name AS name,
field_value2.value AS status,
field_value3.value AS category,
sfuser.username AS submittedByUsername,
sfuser.full_name AS submittedByFullname,
sfuser2.username AS assignedToUsername,
sfuser2.full_name AS assignedToFullname,
item.version AS version ,
mntr_subscription.user_id AS monitoringUserId
FROM
sfuser sfuser,
relationship relationship,
item item,
field_value field_value3,
sfuser sfuser2,
project project,
field_value field_value2,
field_value field_value,
artifact artifact
LEFT JOIN
mntr_subscription mntr_subscription
ON
mntr_subscription.object_key=artifact.id AND ((mntr_subscription.user_id='17272')),
folder folder,
field_value field_value4
WHERE
artifact.id=item.id
AND item.folder_id=folder.id
AND folder.project_id=project.id
AND artifact.group_fv=field_value.id
AND artifact.status_fv=field_value2.id
AND artifact.category_fv=field_value3.id
AND artifact.customer_fv=field_value4.id
AND item.created_by_id=sfuser.id
AND relationship.is_deleted=false
AND relationship.relationship_type_name='ArtifactAssignment'
AND relationship.origin_id=sfuser2.id
AND artifact.id=relationship.target_id
AND item.is_deleted=false
AND project.path='projects.gl_coconet_performance_improveme'
AND item.folder_id='tracker3641'
AND folder.path='tracker.perf_test'
AND (field_value2.value_class='Open');

------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Nested Loop (cost=117.16..102664.10 rows=1 width=167) (actual time=392.383..3412.452 rows=71 loops=1)
Join Filter: ((folder.project_id)::text = (project.id)::text)
-> Index Scan using project_path on project (cost=0.00..4.27 rows=1 width=12) (actual time=0.040..0.041 rows=1 loops=1)
Index Cond: ((path)::text = 'projects.gl_coconet_performance_improveme'::text)
-> Nested Loop (cost=117.16..102655.03 rows=384 width=179) (actual time=392.331..3412.303 rows=71 loops=1)
-> Index Scan using folder_pk on folder (cost=0.00..4.35 rows=1 width=26) (actual time=0.034..0.036 rows=1 loops=1)
Index Cond: ('tracker3641'::text = (id)::text)
Filter: ((path)::text = 'tracker.perf_test'::text)
-> Nested Loop (cost=117.16..102646.84 rows=384 width=180) (actual time=392.293..3412.193 rows=71 loops=1)
-> Nested Loop (cost=117.16..102535.74 rows=384 width=162) (actual time=392.276..3411.189 rows=71 loops=1)
-> Nested Loop (cost=117.16..102397.53 rows=384 width=161) (actual time=392.258..3409.958 rows=71 loops=1)
-> Nested Loop (cost=117.16..102259.33 rows=384 width=174) (actual time=392.239..3408.734 rows=71 loops=1)
-> Nested Loop (cost=117.16..102121.13 rows=384 width=187) (actual time=392.220..3407.479 rows=71 loops=1)
-> Nested Loop (cost=117.16..101565.91 rows=1819 width=169) (actual time=392.195..3406.360 rows=71 loops=1)
-> Nested Loop (cost=117.16..96763.32 rows=2796 width=170) (actual time=392.150..3404.791 rows=71 loops=1)
-> Merge Join (cost=117.16..89555.79 rows=19888 width=169) (actual time=392.092..3403.281 rows=71 loops=1)
Merge Cond: ((artifact.id)::text = (item.id)::text)
-> Merge Left Join (cost=117.16..52509.18 rows=475614 width=81) (actual time=0.050..715.999 rows=380704 loops=1)
Merge Cond: ((artifact.id)::text = "inner"."?column3?")
-> Index Scan using artifact_pk on artifact (cost=0.00..51202.63 rows=475614 width=69) (actual time=0.014..424.003 rows=380704 loops=1)
-> Sort (cost=117.16..117.30 rows=58 width=25) (actual time=0.033..0.033 rows=0 loops=1)
Sort Key: (mntr_subscription.object_key)::text
-> Index Scan using mntr_subscr_usrevt on mntr_subscription (cost=0.00..115.46 rows=58 width=25) (actual time=0.018..0.018 rows=0 loops=1)
Index Cond: ((user_id)::text = '17272'::text)
-> Index Scan using item_pk on item (cost=0.00..176865.31 rows=97498 width=88) (actual time=116.898..2404.612 rows=71 loops=1)
Filter: ((NOT is_deleted) AND ((folder_id)::text = 'tracker3641'::text))
-> Index Scan using field_value_pk on field_value field_value2 (cost=0.00..0.35 rows=1 width=27) (actual time=0.019..0.019 rows=1 loops=71)
Index Cond: ((artifact.status_fv)::text = (field_value2.id)::text)
Filter: ((value_class)::text = 'Open'::text)
-> Index Scan using relation_target on relationship (cost=0.00..1.71 rows=1 width=25) (actual time=0.020..0.020 rows=1 loops=71)
Index Cond: ((artifact.id)::text = (relationship.target_id)::text)
Filter: ((NOT is_deleted) AND ((relationship_type_name)::text = 'ArtifactAssignment'::text))
-> Index Scan using sfuser_pk on sfuser (cost=0.00..0.29 rows=1 width=42) (actual time=0.013..0.014 rows=1 loops=71)
Index Cond: ((item.created_by_id)::text = (sfuser.id)::text)
-> Index Scan using field_value_pk on field_value field_value4 (cost=0.00..0.35 rows=1 width=13) (actual time=0.015..0.016 rows=1 loops=71)
Index Cond: ((artifact.customer_fv)::text = (field_value4.id)::text)
-> Index Scan using field_value_pk on field_value (cost=0.00..0.35 rows=1 width=13) (actual time=0.015..0.015 rows=1 loops=71)
Index Cond: ((artifact.group_fv)::text = (field_value.id)::text)
-> Index Scan using field_value_pk on field_value field_value3 (cost=0.00..0.35 rows=1 width=27) (actual time=0.015..0.015 rows=1 loops=71)
Index Cond: ((artifact.category_fv)::text = (field_value3.id)::text)
-> Index Scan using sfuser_pk on sfuser sfuser2 (cost=0.00..0.28 rows=1 width=42) (actual time=0.012..0.012 rows=1 loops=71)
Index Cond: ((relationship.origin_id)::text = (sfuser2.id)::text)
Total runtime: 3413.006 ms
(43 rows)

I am having a hard time to understand why the query runs faster with the
left join.

Can you help me understanding how that is possible?

Thanks,
Anne

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Flavio Henrique Araque Gurgel 2009-05-29 00:26:32 Re: Continuent (was: Postgres Clustering)
Previous Message Fabrix 2009-05-28 22:13:41 Re: Scalability in postgres