Skip site navigation (1) Skip section navigation (2)

Re: Unexpected query plan results

From: Anne Rosset <arosset(at)collab(dot)net>
To: Dave Dutcher <dave(at)tridecap(dot)com>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: Re: Unexpected query plan results
Date: 2009-05-29 21:31:57
Message-ID: 4A20544D.9070504@collab.net (view raw or flat)
Thread:
Lists: pgsql-performance
Dave Dutcher wrote:

>>From: Anne Rosset
>>Subject: Re: [PERFORM] Unexpected query plan results
>>    
>>
>>> 
>>>
>>>      
>>>
>>Thank Dave. We are using postgresql-server-8.2.4-1PGDG and 
>>have work-mem set to 20MB.
>>What value would you advise?
>>thanks,
>>
>>Anne
>>    
>>
>
>
>Work-mem is kind of tricky because the right setting depends on how much ram
>your machine has, is the machine dedicated to postgres, and how many
>simultaneous connections you have.  If this is a test server, and not used
>in production, you could just play around with the setting and see if your
>query gets any faster.  
>
>Here are the docs on work mem
>
>http://www.postgresql.org/docs/8.2/interactive/runtime-config-resource.html#
>RUNTIME-CONFIG-RESOURCE-MEMORY
>
>  
>
Thanks Dave.
The result with enable_sort=false is much better (at least the left join 
is not having better result): Now I am getting a 4s runtime.
( I also got the same performance by setting enable_mergejoin to false).

Do you see anything I could do to make it faster?
When the query plan takes a wrong path, is it possible that it is 
because statistics have not been run or updated?

Thanks
Anne


                                                                                                       
QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------
 Hash Join  (cost=9276.24..100313.55 rows=1 width=155) (actual 
time=168.148..4144.595 rows=71 loops=1)
   Hash Cond: ((folder.project_id)::text = (project.id)::text)
   ->  Nested Loop  (cost=9271.96..100302.44 rows=1819 width=167) 
(actual time=168.080..4144.363 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=9271.96..100279.90 rows=1819 width=168) 
(actual time=168.045..4144.249 rows=71 loops=1)
               ->  Nested Loop  (cost=9271.96..99724.69 rows=1819 
width=150) (actual time=168.028..4143.126 rows=71 loops=1)
                     ->  Nested Loop  (cost=9271.96..99198.39 rows=1819 
width=132) (actual time=168.008..4141.973 rows=71 loops=1)
                           ->  Nested Loop  (cost=9271.96..98543.72 
rows=1819 width=131) (actual time=167.989..4140.718 rows=71 loops=1)
                                 ->  Nested Loop  
(cost=9271.96..97889.05 rows=1819 width=144) (actual 
time=167.971..4139.482 rows=71 loops=1)
                                       ->  Nested Loop  
(cost=9271.96..97234.38 rows=1819 width=157) (actual 
time=167.943..4137.998 rows=71 loops=1)
                                             ->  Nested Loop  
(cost=9271.96..92431.80 rows=2796 width=158) (actual 
time=167.893..4136.297 rows=71 loops=1)
                                                   ->  Hash Join  
(cost=9271.96..42281.07 rows=66876 width=70) (actual 
time=125.019..782.122 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.006..211.907 rows=468173 loops=1
)
                                                         ->  Hash  
(cost=8285.92..8285.92 rows=78883 width=27) (actual 
time=124.929..124.929 rows=79488 loops=1)
                                                               ->  Index 
Scan using field_class_idx on field_value field_value2  
(cost=0.00..8285.92 rows=78883 width=27) (ac
tual time=0.040..60.861 rows=79488 loops=1)
                                                                     
Index Cond: ((value_class)::text = 'Open'::text)
                                                   ->  Index Scan using 
item_pk on item  (cost=0.00..0.74 rows=1 width=88) (actual 
time=0.018..0.018 rows=0 loops=184378)
                                                         Index Cond: 
((artifact.id)::text = (item.id)::text)
                                                         Filter: ((NOT 
is_deleted) AND ((folder_id)::text = 'tracker3641'::text))
                                             ->  Index Scan using 
relation_target on relationship  (cost=0.00..1.71 rows=1 width=25) 
(actual time=0.021..0.022 rows=1 loops=7
1)
                                                   Index Cond: 
((artifact.id)::text = (relationship.target_id)::text)
                                                   Filter: ((NOT 
is_deleted) AND ((relationship_type_name)::text = 
'ArtifactAssignment'::text))
                                       ->  Index Scan using 
field_value_pk on field_value field_value4  (cost=0.00..0.35 rows=1 
width=13) (actual time=0.018..0.019 rows=1 lo
ops=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.013..0.014 rows=1 loops=71)
                           Index Cond: ((relationship.origin_id)::text = 
(sfuser2.id)::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)
   ->  Hash  (cost=4.27..4.27 rows=1 width=12) (actual time=0.047..0.047 
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.043 rows=1 loops=1)
               Index Cond: ((path)::text = 
'projects.gl_coconet_performance_improveme'::text)
 Total runtime: 4146.198 ms
(39 rows)






In response to

Responses

pgsql-performance by date

Next:From: Robert HaasDate: 2009-05-29 21:32:54
Subject: Re: Unexpected query plan results
Previous:From: Scott MeadDate: 2009-05-29 19:50:48
Subject: Re: Scalability in postgres

Privacy Policy | About PostgreSQL
Copyright © 1996-2014 The PostgreSQL Global Development Group