Unexpected query plan results

From: Anne Rosset
Subject: Unexpected query plan results
Date: ,
Msg-id: 4A1F1453.1010901@collab.net
(view: Whole thread, Raw)
Responses: Re: Unexpected query plan results  ("Dave Dutcher")
Re: Unexpected query plan results  (Robert Haas)
List: pgsql-performance

Tree view

Unexpected query plan results  (Anne Rosset, )
 Re: Unexpected query plan results  ("Dave Dutcher", )
  Re: Unexpected query plan results  (Anne Rosset, )
   Re: Unexpected query plan results  ("Dave Dutcher", )
    Re: Unexpected query plan results  (Scott Mead, )
    Re: Unexpected query plan results  (Anne Rosset, )
     Re: Unexpected query plan results  (Robert Haas, )
 Re: Unexpected query plan results  (Robert Haas, )
  Re: Unexpected query plan results  (Anne Rosset, )
   Re: Unexpected query plan results  (Robert Haas, )
    Re: Unexpected query plan results  (Anne Rosset, )
     Re: Unexpected query plan results  (Robert Haas, )
      Re: Unexpected query plan results  (Anne Rosset, )
       Re: Unexpected query plan results  ("Dave Dutcher", )
        Re: Unexpected query plan results  (Anne Rosset, )
       Re: Unexpected query plan results  (Robert Haas, )
        Re: Unexpected query plan results  (Віталій Тимчишин, )
         Re: Unexpected query plan results  (Robert Haas, )
        Re: Unexpected query plan results  (Anne Rosset, )
         Re: Unexpected query plan results  (Robert Haas, )

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=71loops=1) 
                           ->  Nested Loop  (cost=47640.91..89157.95 rows=384 width=162) (actual
time=4411.469..6949.629rows=71 loops=1) 
                                 ->  Nested Loop  (cost=47640.91..89019.74 rows=384 width=175) (actual
time=4411.443..6948.289rows=71 loops=1) 
                                       ->  Nested Loop  (cost=47640.91..88464.52 rows=1819 width=157) (actual
time=4411.418..6947.188rows=71 loops=1) 
                                             ->  Merge Join  (cost=47640.91..83661.94 rows=2796 width=158) (actual
time=4411.355..6945.443rows=71 loops=1) 
                                                   Merge Cond: ((item.id)::text = "inner"."?column7?")
                                                   ->  Index Scan using item_pk on item  (cost=0.00..176865.31
rows=97498width=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.387rows=168715 loops=1) 
                                                         Sort Key: (artifact.id)::text
                                                         ->  Hash Join  (cost=9271.96..42281.07 rows=66876 width=70)
(actualtime=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=475614width=69) (actual time=0.008..214.459 rows=468173 loops=1) 
                                                               ->  Hash  (cost=8285.92..8285.92 rows=78883 width=27)
(actualtime=124.031..124.031 rows=79488 loops=1) 
                                                                     ->  Index Scan using field_class_idx on
field_valuefield_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=1width=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)
(actualtime=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=1width=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)
(actualtime=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)
(actualtime=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.012rows=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=1loops=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=71loops=1) 
                           ->  Nested Loop  (cost=117.16..102259.33 rows=384 width=174) (actual time=392.239..3408.734
rows=71loops=1) 
                                 ->  Nested Loop  (cost=117.16..102121.13 rows=384 width=187) (actual
time=392.220..3407.479rows=71 loops=1) 
                                       ->  Nested Loop  (cost=117.16..101565.91 rows=1819 width=169) (actual
time=392.195..3406.360rows=71 loops=1) 
                                             ->  Nested Loop  (cost=117.16..96763.32 rows=2796 width=170) (actual
time=392.150..3404.791rows=71 loops=1) 
                                                   ->  Merge Join  (cost=117.16..89555.79 rows=19888 width=169) (actual
time=392.092..3403.281rows=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.63rows=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.033rows=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=97498width=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.35rows=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=1width=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)
(actualtime=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=1width=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)
(actualtime=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)
(actualtime=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.012rows=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


pgsql-performance by date:

From: Greg Smith
Date:
Subject: Re: Scalability in postgres
From: Grzegorz Jaśkiewicz
Date:
Subject: Re: Scalability in postgres