(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