Re: Poor query plan chosen in 9.0.3 vs 8.3.7

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Here is the explain analyze output for when enable_material is 'off' and information on the postgresql version, settings and server configuration (I had to send a follow up email due the length of email restrictions on the mailing list.)   

(I apologize for the length of these email messages. And if this message does not get threaded properly as I did not receive a copy of my original message to mailing list)



Explain Analyze output with enable_material='off'
------------------------------------------------------------------------------------------------

Limit  (cost=231785.69..231785.94 rows=101 width=71) (actual time=6616.943..6617.130 rows=101 loops=1)
   ->  Sort  (cost=231785.69..231785.95 rows=104 width=71) (actual time=6616.940..6617.003 rows=101 loops=1)
         Sort Key: material.name
         Sort Method:  top-N heapsort  Memory: 39kB
         ->  Nested Loop Left Join  (cost=239.46..231782.21 rows=104 width=71) (actual time=3.840..6484.883 rows=67044 loops=1)
               Join Filter: ((material.container)::text = 'd938da12-1b43-102d-a8a2-78911b79dd1c'::text)
               ->  Hash Join  (cost=239.46..230812.42 rows=104 width=155) (actual time=3.785..2676.643 rows=67044 loops=1)
                     Hash Cond: ((experimentrun.name)::text = ((material.name)::text || '.xls'::text))
                     ->  Nested Loop  (cost=3.27..230557.06 rows=93 width=129) (actual time=0.170..2502.106 rows=67044 loops=1)
                           ->  Nested Loop  (cost=0.00..229848.97 rows=93 width=137) (actual time=0.153..1368.990 rows=67044 loops=1)
                                 ->  Nested Loop  (cost=0.00..2.33 rows=1 width=74) (actual time=0.016..0.025 rows=1 loops=1)
                                       ->  Seq Scan on containers "c69d129_particle_size_result_fields_5$run$folder$"  (cost=0.00..1.16 rows=1 width=37) (actual time=0.010..0.013 rows=1 loops=1)
                                             Filter: ((entityid)::text = 'd938da12-1b43-102d-a8a2-78911b79dd1c'::text)
                                       ->  Seq Scan on containers "formulations_6$folder$"  (cost=0.00..1.16 rows=1 width=37) (actual time=0.003..0.007 rows=1 loops=1)
                                             Filter: (("formulations_6$folder$".entityid)::text = 'd938da12-1b43-102d-a8a2-78911b79dd1c'::text)
                                 ->  Nested Loop  (cost=0.00..229845.71 rows=93 width=63) (actual time=0.133..1244.558 rows=67044 loops=1)
                                       ->  Seq Scan on c69d129_particle_size_result_fields  (cost=0.00..229742.02 rows=348 width=59) (actual time=0.018..572.402 rows=69654 loops=1)
                                             Filter: (((SubPlan 3))::text = 'd938da12-1b43-102d-a8a2-78911b79dd1c'::text)
                                             SubPlan 3
                                               ->  Index Scan using pk_data on data  (cost=0.00..3.27 rows=1 width=37) (actual time=0.004..0.005 rows=1 loops=69654)
                                                     Index Cond: (rowid = $2)
                                       ->  Index Scan using pk_indexvarchar on indexvarchar  (cost=0.00..0.29 rows=1 width=10) (actual time=0.004..0.006 rows=1 loops=69654)
                                             Index Cond: ((indexvarchar.listid = 17) AND ((indexvarchar.key)::text = (c69d129_particle_size_result_fields.timelabel)::text))
                           ->  Index Scan using pk_experimentrun on experimentrun  (cost=3.27..4.33 rows=1 width=74) (actual time=0.005..0.006 rows=1 loops=67044)
                                 Index Cond: (experimentrun.rowid = (SubPlan 4))
                                 Filter: (((experimentrun.protocollsid)::text ~~ 'urn:lsid:labkey.com:Particle+SizeProtocol.Folder-69:Particle+Size'::text) AND ((experimentrun.container)::text = 'd938da12-1b43-102d-a8a2-7891
1b79dd1c'::text))
                                 SubPlan 4
                                   ->  Index Scan using pk_data on data  (cost=0.00..3.27 rows=1 width=4) (actual time=0.004..0.005 rows=1 loops=67044)
                                         Index Cond: (rowid = $2)
                                 SubPlan 4
                                   ->  Index Scan using pk_data on data  (cost=0.00..3.27 rows=1 width=4) (actual time=0.004..0.005 rows=1 loops=67044)
                                         Index Cond: (rowid = $2)
                     ->  Hash  (cost=226.51..226.51 rows=774 width=96) (actual time=3.587..3.587 rows=1303 loops=1)
                           Buckets: 1024  Batches: 1  Memory Usage: 158kB
                           ->  Seq Scan on material  (cost=0.00..226.51 rows=774 width=96) (actual time=0.071..2.354 rows=1303 loops=1)
                                 Filter: (((container)::text = 'd938da12-1b43-102d-a8a2-78911b79dd1c'::text) AND ((cpastype)::text = 'urn:lsid:labkey.com:SampleSet.Folder-69:Formulations'::text))
               ->  Index Scan using uq_object on object "formulations_6$lsid$_c"  (cost=0.00..2.69 rows=1 width=64) (actual time=0.035..0.036 rows=1 loops=67044)
                     Index Cond: ((material.lsid)::text = ("formulations_6$lsid$_c".objecturi)::text)
               SubPlan 1
                 ->  Index Scan using pk_objectproperty on objectproperty  (cost=0.00..3.31 rows=1 width=13) (actual time=0.005..0.006 rows=1 loops=67044)
                       Index Cond: ((objectid = $0) AND (propertyid = 560))
               SubPlan 2
                 ->  Index Scan using pk_objectproperty on objectproperty  (cost=0.00..3.31 rows=1 width=8) (actual time=0.003..0.004 rows=1 loops=67044)
                       Index Cond: ((objectid = $1) AND (propertyid = 1288))
 Total runtime: 6617.360 ms



Other Information 
------------------------------------------------------------------------------------------------
  • Version: PostgreSQL 9.0.3 on x86_64-unknown-linux-gnu, compiled by GCC gcc (Ubuntu 4.4.3-4ubuntu5) 4.4.3, 64-bit
  • Operating System: Ubuntu 10.04 LTS
  • uname -a = Linux hostname 2.6.32-305-ec2 #9-Ubuntu SMP Thu Apr 15 08:05:38 UTC 2010 x86_64 GNU/Linux
  • Server Information 
    • 4 cores 
    • 8GB of RAM
  • PostgreSQL Configuration Information 
    • max_connections = 50
    • shared_buffers = 2048MB
    • work_mem = 20MB
    • maintenance_work_mem = 1024MB
    • wal_buffers = 4MB
    • checkpoint_segments = 10
    • checkpoint_timeout = 15min
    • random_page_cost = 1.5 and 4.0 (tested with both default and non-default)
    • effective_cache_size = 6144MB
    • join_collapse_limit = 10
    • autovacuum = on
    • All other settings default
    • Vacuum and Analyze is run nightly.


Thank you for any help you might be able to provide. 

Brian Connolly 

[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux