Re: Deterioration in performance when query executed in multi threads - Mailing list pgsql-performance
| From | Igor Neyman |
|---|---|
| Subject | Re: Deterioration in performance when query executed in multi threads |
| Date | |
| Msg-id | A76B25F2823E954C9E45E32FA49D70EC1B7CD26D@mail.corp.perceptron.com Whole thread Raw |
| In response to | Re: Deterioration in performance when query executed in multi threads (Anne Rosset <arosset@collab.net>) |
| Responses |
Re: Deterioration in performance when query executed in
multi threads
(Anne Rosset <arosset@collab.net>)
|
| List | pgsql-performance |
________________________________________
From: Anne Rosset [arosset@collab.net]
Sent: Monday, May 06, 2013 5:51 PM
To: Igor Neyman; ktm@rice.edu
Cc: pgsql-performance@postgresql.org
Subject: RE: [PERFORM] Deterioration in performance when query executed in multi threads
Hi Igor,
Result with enable_nestloop off:
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-----------
Hash Join (cost=49946.49..58830.02 rows=1 width=181) (actual time=2189.474..2664.888 rows=180 loops=1)
Hash Cond: ((item.created_by_id)::text = (sfuser.id)::text)
-> Hash Join (cost=49470.50..58345.53 rows=1 width=167) (actual time=1931.870..2404.745 rows=180 loops=1)
Hash Cond: ((relationship.origin_id)::text = (sfuser2.id)::text)
-> Hash Join (cost=48994.51..57869.52 rows=1 width=153) (actual time=1927.603..2400.334 rows=180 loops=1)
Hash Cond: ((relationship.target_id)::text = (artifact.id)::text)
-> Seq Scan on relationship (cost=0.00..7973.38 rows=240435 width=19) (actual time=0.036..492.442
rows=241285loops=1)
Filter: ((NOT is_deleted) AND ((relationship_type_name)::text = 'ArtifactAssignment'::text))
-> Hash (cost=48994.49..48994.49 rows=1 width=154) (actual time=1858.350..1858.350 rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 34kB
-> Hash Join (cost=47260.54..48994.49 rows=1 width=154) (actual time=1836.495..1858.151 rows=180
loops=1)
Hash Cond: ((field_value4.id)::text = (artifact.customer_fv)::text)
-> Seq Scan on field_value field_value4 (cost=0.00..1443.78 rows=77378 width=9) (actual
time=22.104..30.694rows=77378 loops=1)
-> Hash (cost=47260.52..47260.52 rows=1 width=163) (actual time=1814.005..1814.005
rows=180loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 35kB
-> Hash Join (cost=45526.57..47260.52 rows=1 width=163) (actual
time=1790.908..1813.780rows=180 loops=1)
Hash Cond: ((field_value3.id)::text = (artifact.category_fv)::text)
-> Seq Scan on field_value field_value3 (cost=0.00..1443.78 rows=77378
width=15)(actual time=0.002..9.262 rows=77378 loops=1)
-> Hash (cost=45526.55..45526.55 rows=1 width=166) (actual
time=1790.505..1790.505rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 36kB
-> Hash Join (cost=43792.60..45526.55 rows=1 width=166) (actual
time=1768.362..1790.304rows=180 loops=1)
Hash Cond: ((field_value.id)::text = (artifact.group_fv)::text)
-> Seq Scan on field_value (cost=0.00..1443.78 rows=77378 width=9)
(actualtime=0.002..8.687 rows=77378 loops=1)
-> Hash (cost=43792.58..43792.58 rows=1 width=175) (actual
time=1767.928..1767.928rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 38kB
-> Hash Join (cost=42058.63..43792.58 rows=1 width=175)
(actualtime=1499.822..1767.734 rows=180 loops=1)
Hash Cond: ((field_value2.id)::text =
(artifact.status_fv)::text)
-> Seq Scan on field_value field_value2
(cost=0.00..1443.78rows=77378 width=15) (actual time=0.002..261.082 rows=77378 loops=1)
-> Hash (cost=42058.61..42058.61 rows=1 width=178)
(actualtime=1492.707..1492.707 rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 38kB
-> Hash Join (cost=18039.59..42058.61 rows=1
width=178)(actual time=1175.659..1492.482 rows=180 loops=1)
Hash Cond: ((item.id)::text =
(artifact.id)::text)
-> Hash Join (cost=12112.31..36130.95
rows=30width=128) (actual time=304.035..702.745 rows=1015 loops=1)
Hash Cond: ((item.folder_id)::text =
(folder.id)::text)
-> Seq Scan on item
(cost=0.00..21381.10rows=703322 width=58) (actual time=0.020..382.847 rows=704018 loops=1)
Filter: (NOT is_deleted)
-> Hash (cost=12112.27..12112.27
rows=3width=92) (actual time=189.285..189.285 rows=10 loops=1)
Buckets: 1024 Batches: 1
MemoryUsage: 2kB
-> Hash Join
(cost=195.86..12112.27rows=3 width=92) (actual time=31.304..189.269 rows=10 loops=1)
Hash Cond:
((folder.id)::text= (tracker.id)::text)
-> Hash Join
(cost=8.28..11923.31rows=155 width=65) (actual time=3.195..161.619 rows=612 loops=1)
Hash Cond:
((folder.project_id)::text= (project.id)::text)
-> Seq Scan on
folder (cost=0.00..10858.71 rows=281271 width=32) (actual time=0.017..75.451 rows=280356 loops=1)
-> Hash
(cost=8.27..8.27rows=1 width=42) (actual time=0.041..0.041 rows=1 loops=1)
Buckets: 1024
Batches:1 Memory Usage: 1kB
-> Index Scan
usingproject_path on project (cost=0.00..8.27 rows=1 width=42) (actual time=0.038..0.039 rows=
1 loops=1)
Index
Cond:((path)::text = 'projects.psr-pub-13'::text)
-> Hash
(cost=129.48..129.48rows=4648 width=27) (actual time=27.439..27.439 rows=4648 loops=1)
Buckets: 1024
Batches:1 Memory Usage: 267kB
-> Seq Scan on
tracker (cost=0.00..129.48 rows=4648 width=27) (actual time=19.880..25.635 rows=4648 loops=1)
-> Hash Join (cost=45526.57..47260.52 rows=1 width=163) (actual time=1790.908..1813.780 rows=180 loops=1)
Hash Cond: ((field_value3.id)::text = (artifact.category_fv)::text)
-> Seq Scan on field_value field_value3 (cost=0.00..1443.78 rows=77378
width=15)(actual time=0.002..9.262 rows=77378 loops=1)
-> Hash (cost=45526.55..45526.55 rows=1 width=166) (actual
time=1790.505..1790.505rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 36kB
-> Hash Join (cost=43792.60..45526.55 rows=1 width=166) (actual
time=1768.362..1790.304rows=180 loops=1)
Hash Cond: ((field_value.id)::text = (artifact.group_fv)::text)
-> Seq Scan on field_value (cost=0.00..1443.78 rows=77378 width=9)
(actualtime=0.002..8.687 rows=77378 loops=1)
-> Hash (cost=43792.58..43792.58 rows=1 width=175) (actual
time=1767.928..1767.928rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 38kB
-> Hash Join (cost=42058.63..43792.58 rows=1 width=175)
(actualtime=1499.822..1767.734 rows=180 loops=1)
Hash Cond: ((field_value2.id)::text =
(artifact.status_fv)::text)
-> Seq Scan on field_value field_value2
(cost=0.00..1443.78rows=77378 width=15) (actual time=0.002..261.082 rows=77378 loops=1)
-> Hash (cost=42058.61..42058.61 rows=1 width=178)
(actualtime=1492.707..1492.707 rows=180 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 38kB
-> Hash Join (cost=18039.59..42058.61 rows=1
width=178)(actual time=1175.659..1492.482 rows=180 loops=1)
Hash Cond: ((item.id)::text =
(artifact.id)::text)
-> Hash Join (cost=12112.31..36130.95
rows=30width=128) (actual time=304.035..702.745 rows=1015 loops=1)
Hash Cond: ((item.folder_id)::text =
(folder.id)::text)
-> Seq Scan on item
(cost=0.00..21381.10rows=703322 width=58) (actual time=0.020..382.847 rows=704018 loops=1)
Filter: (NOT is_deleted)
-> Hash (cost=12112.27..12112.27
rows=3width=92) (actual time=189.285..189.285 rows=10 loops=1)
Buckets: 1024 Batches: 1
MemoryUsage: 2kB
-> Hash Join
(cost=195.86..12112.27rows=3 width=92) (actual time=31.304..189.269 rows=10 loops=1)
Hash Cond:
((folder.id)::text= (tracker.id)::text)
-> Hash Join
(cost=8.28..11923.31rows=155 width=65) (actual time=3.195..161.619 rows=612 loops=1)
Hash Cond:
((folder.project_id)::text= (project.id)::text)
-> Seq Scan on
folder (cost=0.00..10858.71 rows=281271 width=32) (actual time=0.017..75.451 rows=280356 loops=1)
-> Hash
(cost=8.27..8.27rows=1 width=42) (actual time=0.041..0.041 rows=1 loops=1)
Buckets: 1024
Batches:1 Memory Usage: 1kB
-> Index Scan
usingproject_path on project (cost=0.00..8.27 rows=1 width=42) (actual time=0.038..0.039 rows=
1 loops=1)
Index
Cond:((path)::text = 'projects.psr-pub-13'::text)
-> Hash
(cost=129.48..129.48rows=4648 width=27) (actual time=27.439..27.439 rows=4648 loops=1)
Buckets: 1024
Batches:1 Memory Usage: 267kB
-> Seq Scan on
tracker (cost=0.00..129.48 rows=4648 width=27) (actual time=19.880..25.635 rows=4648 loops=1)
-> Hash (cost=5527.28..5527.28 rows=32000
width=50)(actual time=788.470..788.470 rows=31183 loops=1)
Buckets: 4096 Batches: 1 Memory
Usage:2662kB
-> Bitmap Heap Scan on artifact
(cost=628.28..5527.28rows=32000 width=50) (actual time=83.568..771.651 rows=31183 loops=1)
Recheck Cond: (priority = 3)
-> Bitmap Index Scan on
artifact_priority (cost=0.00..620.28 rows=32000 width=0) (actual time=82.877..82.877 rows=31260 loops=1
)
Index Cond: (priority = 3)
-> Hash (cost=404.33..404.33 rows=5733 width=32) (actual time=4.232..4.232 rows=5733 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 364kB
-> Seq Scan on sfuser sfuser2 (cost=0.00..404.33 rows=5733 width=32) (actual time=0.006..1.941
rows=5733loops=1)
-> Hash (cost=404.33..404.33 rows=5733 width=32) (actual time=257.485..257.485 rows=5733 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 364kB
-> Seq Scan on sfuser (cost=0.00..404.33 rows=5733 width=32) (actual time=9.555..255.085 rows=5733 loops=1)
SubPlan 1
-> Index Scan using mntr_subscr_user on mntr_subscription (cost=0.00..8.47 rows=1 width=9) (actual
time=0.013..0.013rows=0 loops=180)
Index Cond: ((($0)::text = (object_key)::text) AND ((user_id)::text = 'user1439'::text))
Total runtime: 2666.011 ms
effective_cache_size | 512MB
Thanks,
Anne
--------------------------------------------------------------
Anne,
So, this shows that original execution plan (with nested loops) was not that bad.
Still, considering your hardware config (and I think, you mentioned it's a "dedicated" database server), I'd set:
buffer_cache = 3GB
effective_cache_size = 7GB
buffer_cache is "global" setting and requires Postgres restart after changing in postgresql.conf.
But, besides postgres config parameters, it seems your particular problem is in correct setting of conection pooler.
Igor Neyman
pgsql-performance by date: