Re: performance with query

From: Alberto Dalmaso <dalmaso(at)clesius(dot)it>
To: pgsql-performance(at)postgresql(dot)org
Subject: Re: performance with query
Date: 2009-06-16 14:45:53
Message-ID: 1245163553.5027.33.camel@dalmaso-opensuse.cl
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

> What version of PostgreSQL?
8.3 that comes with opensuse 11.1
>
> What OS?
Linux, opensuse 11.1 64 bit
>
> What does the hardware look like? (CPUs, drives, memory, etc.)
2 * opteron dual core 8 GB RAM, 70 GB SCSI U320 RAID 1
>
> Do you have autovacuum running? What other regular maintenance to you
> do?
YES, autovacuum and analyze are running, the only other activity is the
wal backup
>
> What does your postgresql.conf file look like? (If you can strip out
> all comments and show the rest, that would be great.)

I'll post only the value I've changed

shared_buffers = 1536MB
temp_buffers = 5MB
max_prepared_transactions = 30

work_mem = 50MB # I've lot of work in order by
maintenance_work_mem =50MB
max_stack_depth = 6MB

max_fsm_pages = 160000
max_fsm_relations = 5000

wal_buffers = 3072kB

enable_bitmapscan = on
enable_hashagg = on
enable_hashjoin = off
enable_indexscan = on
enable_mergejoin = on
enable_nestloop = off
enable_seqscan = off
enable_sort = off
enable_tidscan = on

effective_cache_size = 3600MB

geqo = off
default_statistics_target = 100

>
> With that as background, if you can show us the schema for the
> table(s) involved and the text of a query, along with the EXPLAIN
> ANALYZE output (or just EXPLAIN, if the query runs too long to get the
> EXPLAIN ANALYZE results) that would allow us to wee where things are
> going wrong. Please show this information without setting any of the
> optimizer options off; but then, as a diagnostic step, *also* show
> EXPLAIN ANALYZE results when you set options to a configuration that
> runs faster.
>
> -Kevin

The problem is that in the simply query it uses mergejoin instead of
nastedloop (obvious for the parameters I set) but in this situation in
becomes very very slow (15 sec vs 5 ms when I set to off mergejoin).

That is the explain of the complex query that works with more than
acceptable performance

"Merge Right Join (cost=508603077.17..508603195.59 rows=1 width=227)"
" Merge Cond: (ve_edil_rendite.id_domanda = domande.id_domanda)"
" -> GroupAggregate (cost=0.00..105.51 rows=1031 width=11)"
" -> Index Scan using pk_ve_edil_rendite on ve_edil_rendite
(cost=0.00..86.84 rows=1157 width=11)"
" -> Materialize (cost=508603077.17..508603077.18 rows=1 width=195)"
" -> Nested Loop (cost=506932259.90..508603077.17 rows=1
width=195)"
" -> Merge Join (cost=406932259.90..408603074.89 rows=1
width=188)"
" Merge Cond: (domande.id_domanda =
c_elaout_7.id_domanda)"
" -> Merge Join (cost=406932259.90..408188339.97
rows=1 width=240)"
" Merge Cond: (c_elaout_5.id_domanda =
domande.id_domanda)"
" -> Merge Join (cost=3895.15..1259628.81
rows=138561 width=41)"
" Merge Cond: (edil_veneto.id_domanda =
c_elaout_5.id_domanda)"
" -> Merge Join
(cost=1123.18..372710.75 rows=98122 width=29)"
" Merge Cond:
(edil_veneto.id_domanda = c_elaout_6.id_domanda)"
" -> Index Scan using
"IDX_pk_Edil_Veneto" on edil_veneto (cost=0.00..11825.14 rows=232649
width=17)"
" -> Index Scan using
"IDX_3_c_elaout" on c_elaout c_elaout_6 (cost=0.00..359914.34
rows=98122 width=12)"
" Index Cond:
((c_elaout_6.node)::text = 'contributo_sociale'::text)"
" -> Index Scan using "IDX_3_c_elaout"
on c_elaout c_elaout_5 (cost=0.00..887091.20 rows=245306 width=12)"
" Index Cond:
((c_elaout_5.node)::text = 'contributo'::text)"
" -> Materialize
(cost=406928364.74..406928364.75 rows=1 width=199)"
" -> Nested Loop
(cost=402583154.89..406928364.74 rows=1 width=199)"
" Join Filter:
((r_enti.codice_ente)::text = (r_luoghi.cod_catastale)::text)"
" -> Merge Join
(cost=202583154.89..206928031.60 rows=1 width=198)"
" Merge Cond:
(domande.id_domanda = c_elaout_4.id_domanda)"
" -> Merge Join
(cost=202583154.89..206425374.54 rows=1 width=186)"
" Merge Cond:
(domande.id_domanda = c_elain_3.id_domanda)"
" -> Merge Join
(cost=201328203.80..205170407.27 rows=41 width=138)"
" Merge Cond:
(domande.id_domanda = c_elain_7.id_domanda)"
" -> Merge Join
(cost=201328203.80..204498966.35 rows=93 width=126)"
" Merge
Cond: (domande.id_domanda = c_elain_9.id_domanda)"
" -> Merge
Join (cost=201322293.83..203828121.81 rows=424 width=114)"
"
Merge Cond: (domande.id_domanda = c_elain_8.id_domanda)"
" ->
Nested Loop (cost=201318498.02..203164011.74 rows=2431 width=102)"
"
-> Merge Join (cost=101318498.02..103147289.10 rows=2431 width=79)"
"
Merge Cond: (domande.id_domanda = doc.id)"
"
-> Merge Join (cost=101318487.80..103060677.64 rows=2493 width=75)"
"
Merge Cond: (domande.id_domanda = c_elain_1.id_domanda)"
"
-> Merge Join (cost=101316002.90..102447327.03 rows=15480 width=63)"
"
Merge Cond: (domande.id_domanda = c_elain.id_domanda)"
"
-> Merge Join (cost=101314975.72..101780946.74 rows=88502 width=51)"
"
Merge Cond: (c_elain_2.id_domanda = domande.id_domanda)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_2
(cost=0.00..461104.96 rows=129806 width=12)"
"
Index Cond: ((node)::text = 'N_componenti'::text)"
"
-> Sort (cost=101314967.66..101316800.15 rows=732995 width=39)"
"
Sort Key: domande.id_domanda"
"
-> Merge Join (cost=119414.31..1243561.32 rows=732995 width=39)"
"
Merge Cond: (domande.id_dichiarazione =
generiche_data_nascita_piu_anziano.id_dichiarazione)"
"
-> Merge Join (cost=18770.82..1126115.64 rows=123933 width=39)"
"
Merge Cond: (domande.id_dichiarazione = c_elaout.id_domanda)"
"
-> Index Scan using "IDX_5_domande" on domande (cost=0.00..91684.40
rows=31967 width=27)"
"
Index Cond: (id_servizio = 11002)"
"
Filter: (id_ente > 0)"
"
-> Index Scan using "IDX_2_c_elaout" on c_elaout
(cost=0.00..1031179.16 rows=805279 width=12)"
"
Filter: ((c_elaout.node)::text = 'ISEE'::text)"
"
-> Materialize (cost=100643.49..106653.58 rows=601009 width=12)"
"
-> Subquery Scan generiche_data_nascita_piu_anziano
(cost=0.00..100042.48 rows=601009 width=12)"
"
-> GroupAggregate (cost=0.00..94032.39 rows=601009 width=12)"
"
-> Index Scan using "IDX_1_componenti" on componenti
(cost=0.00..76403.45 rows=2023265 width=12)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain (cost=0.00..665581.51
rows=188052 width=12)"
"
Index Cond: ((c_elain.node)::text = 'VSE'::text)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_1
(cost=0.00..613000.48 rows=173074 width=12)"
"
Index Cond: ((c_elain_1.node)::text = 'AffittoISEE'::text)"
"
-> Index Scan using pk_doc on doc (cost=0.00..81963.12 rows=1847118
width=4)"
"
Filter: (doc.id_tp_stato_doc = 1)"
"
-> Index Scan using "IDX_pk_R_Enti" on r_enti (cost=0.00..6.87 rows=1
width=31)"
"
Index Cond: (r_enti.id_ente = domande.id_ente)"
" ->
Index Scan using "IDX_1_c_elain" on c_elain c_elain_8
(cost=0.00..663631.02 rows=187497 width=12)"
"
Index Cond: ((c_elain_8.node)::text = 'Spese'::text)"
" -> Index
Scan using "IDX_2_c_elain" on c_elain c_elain_9 (cost=0.00..670253.16
rows=235758 width=12)"
"
Filter: ((c_elain_9.node)::text = 'Mesi'::text)"
" -> Index Scan
using "IDX_2_c_elain" on c_elain c_elain_7 (cost=0.00..670253.16
rows=474845 width=12)"
" Filter:
((c_elain_7.node)::text = 'Affitto'::text)"
" -> Materialize
(cost=1254951.09..1254963.95 rows=1286 width=48)"
" -> Merge Join
(cost=2423.84..1254949.80 rows=1286 width=48)"
" Merge
Cond: (c_elain_3.id_domanda = c_elaout_1.id_domanda)"
" -> Merge
Join (cost=1094.64..606811.53 rows=1492 width=36)"
"
Merge Cond: (c_elain_3.id_domanda = c_elaout_3.id_domanda)"
" ->
Merge Join (cost=224.20..182997.39 rows=2667 width=24)"
"
Merge Cond: (c_elain_3.id_domanda = c_elaout_2.id_domanda)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_3
(cost=0.00..74101.14 rows=19621 width=12)"
"
Index Cond: ((node)::text = 'Solo_anziani'::text)"
"
-> Index Scan using "IDX_3_c_elaout" on c_elaout c_elaout_2
(cost=0.00..108761.74 rows=28155 width=12)"
"
Index Cond: ((c_elaout_2.node)::text = 'ise_fsa'::text)"
" ->
Index Scan using "IDX_3_c_elaout" on c_elaout c_elaout_3
(cost=0.00..423543.07 rows=115886 width=12)"
"
Index Cond: ((c_elaout_3.node)::text = 'incidenza'::text)"
" -> Index
Scan using "IDX_3_c_elaout" on c_elaout c_elaout_1
(cost=0.00..647740.85 rows=178481 width=12)"
"
Index Cond: ((c_elaout_1.node)::text = 'isee_fsa'::text)"
" -> Index Scan using
"IDX_3_c_elaout" on c_elaout c_elaout_4 (cost=0.00..502312.35
rows=137879 width=12)"
" Index Cond:
((c_elaout_4.node)::text = 'esito'::text)"
" -> Seq Scan on r_luoghi
(cost=100000000.00..100000200.84 rows=10584 width=11)"
" -> Index Scan using "IDX_3_c_elaout" on c_elaout
c_elaout_7 (cost=0.00..414451.53 rows=113348 width=12)"
" Index Cond: ((c_elaout_7.node)::text =
'contributo_regolare'::text)"
" -> Index Scan using "IDX_pk_VE_EDIL_tp_superfici" on
ve_edil_tp_superfici (cost=0.00..2.27 rows=1 width=11)"
" Index Cond: (ve_edil_tp_superfici.id_tp_superficie
= edil_veneto.id_tp_superficie)"

and that is the explain of the too slow simple query

"Merge Join (cost=0.00..1032305.52 rows=4 width=12)"
" Merge Cond: (domande.id_dichiarazione = c_elaout.id_domanda)"
" -> Index Scan using "IDX_8_domande" on domande (cost=0.00..8.39
rows=1 width=4)"
" Index Cond: (id_domanda = 4165757)"
" -> Index Scan using "IDX_2_c_elaout" on c_elaout
(cost=0.00..1030283.89 rows=805279 width=12)"
" Filter: ((c_elaout.node)::text = 'Invalido'::text)"

this cost 15 sec

with mergejoin to off:

"Nested Loop (cost=100000000.00..100000022.97 rows=4 width=12)"
" -> Index Scan using "IDX_8_domande" on domande (cost=0.00..8.39
rows=1 width=4)"
" Index Cond: (id_domanda = 4165757)"
" -> Index Scan using "IDX_2_c_elaout" on c_elaout (cost=0.00..14.54
rows=4 width=12)"
" Index Cond: (c_elaout.id_domanda = domande.id_dichiarazione)"
" Filter: ((c_elaout.node)::text = 'Invalido'::text)"

this cost 15 msec!!!

This query work fine even with
set enable_mergejoin='on';
set enable_nestloop='on';

"Nested Loop (cost=0.00..22.97 rows=4 width=12) (actual
time=10.110..10.122 rows=1 loops=1)"
" -> Index Scan using "IDX_8_domande" on domande (cost=0.00..8.39
rows=1 width=4) (actual time=0.071..0.075 rows=1 loops=1)"
" Index Cond: (id_domanda = 4165757)"
" -> Index Scan using "IDX_2_c_elaout" on c_elaout (cost=0.00..14.54
rows=4 width=12) (actual time=10.029..10.031 rows=1 loops=1)"
" Index Cond: (c_elaout.id_domanda = domande.id_dichiarazione)"
" Filter: ((c_elaout.node)::text = 'Invalido'::text)"
"Total runtime: 10.211 ms"

but in this situation the previous kind of query doesn't arrive at the
end and the plan becomes:
"Merge Right Join (cost=100707011.72..100707130.15 rows=1 width=227)"
" Merge Cond: (ve_edil_rendite.id_domanda = domande.id_domanda)"
" -> GroupAggregate (cost=0.00..105.51 rows=1031 width=11)"
" -> Index Scan using pk_ve_edil_rendite on ve_edil_rendite
(cost=0.00..86.84 rows=1157 width=11)"
" -> Materialize (cost=100707011.72..100707011.73 rows=1 width=195)"
" -> Nested Loop (cost=100689558.36..100707011.72 rows=1
width=195)"
" -> Nested Loop (cost=100689558.36..100706997.17 rows=1
width=247)"
" -> Nested Loop (cost=100689558.36..100706982.62
rows=1 width=235)"
" Join Filter: ((r_enti.codice_ente)::text =
(r_luoghi.cod_catastale)::text)"
" -> Nested Loop (cost=689558.36..706649.48
rows=1 width=234)"
" -> Nested Loop
(cost=689558.36..706647.20 rows=1 width=227)"
" -> Nested Loop
(cost=689558.36..706632.65 rows=1 width=215)"
" -> Nested Loop
(cost=689558.36..706618.10 rows=1 width=203)"
" Join Filter:
(domande.id_domanda = edil_veneto.id_domanda)"
" -> Index Scan using
"IDX_pk_Edil_Veneto" on edil_veneto (cost=0.00..11825.14 rows=232649
width=17)"
" -> Materialize
(cost=689558.36..689558.37 rows=1 width=186)"
" -> Nested Loop
(cost=100643.49..689558.36 rows=1 width=186)"
" ->
Nested Loop (cost=100643.49..689543.81 rows=1 width=174)"
" ->
Nested Loop (cost=100643.49..689530.86 rows=1 width=162)"
"
-> Nested Loop (cost=100643.49..689517.93 rows=1 width=150)"
"
-> Nested Loop (cost=100643.49..689505.01 rows=1 width=138)"
"
-> Nested Loop (cost=100643.49..689490.46 rows=1 width=126)"
"
-> Nested Loop (cost=100643.49..688816.73 rows=44 width=114)"
"
-> Merge Join (cost=100643.49..657277.54 rows=2431 width=102)"
"
Merge Cond: (domande.id_dichiarazione =
generiche_data_nascita_piu_anziano.id_dichiarazione)"
"
-> Nested Loop (cost=0.00..549096.04 rows=412 width=102)"
"
-> Nested Loop (cost=0.00..547345.02 rows=106 width=90)"
"
-> Nested Loop (cost=0.00..546615.85 rows=106 width=67)"
"
-> Nested Loop (cost=0.00..545694.51 rows=109 width=63)"
"
-> Nested Loop (cost=0.00..537605.96 rows=621 width=51)"
"
-> Nested Loop (cost=0.00..487675.59 rows=3860 width=39)"
"
-> Index Scan using "IDX_5_domande" on domande (cost=0.00..91684.40
rows=31967 width=27)"
"
Index Cond: (id_servizio = 11002)"
"
Filter: (id_ente > 0)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_2
(cost=0.00..12.37 rows=1 width=12)"
"
Index Cond: (((c_elain_2.node)::text = 'N_componenti'::text) AND
(c_elain_2.id_domanda = domande.id_domanda))"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_1
(cost=0.00..12.92 rows=1 width=12)"
"
Index Cond: (((c_elain_1.node)::text = 'AffittoISEE'::text) AND
(c_elain_1.id_domanda = domande.id_domanda))"
"
-> Index Scan using "IDX_1_c_elain" on c_elain (cost=0.00..13.01
rows=1 width=12)"
"
Index Cond: (((c_elain.node)::text = 'VSE'::text) AND
(c_elain.id_domanda = domande.id_domanda))"
"
-> Index Scan using pk_doc on doc (cost=0.00..8.44 rows=1 width=4)"
"
Index Cond: (doc.id = domande.id_domanda)"
"
Filter: (doc.id_tp_stato_doc = 1)"
"
-> Index Scan using "IDX_pk_R_Enti" on r_enti (cost=0.00..6.87 rows=1
width=31)"
"
Index Cond: (r_enti.id_ente = domande.id_ente)"
"
-> Index Scan using "IDX_2_c_elaout" on c_elaout (cost=0.00..16.47
rows=4 width=12)"
"
Index Cond: (c_elaout.id_domanda = domande.id_dichiarazione)"
"
Filter: ((c_elaout.node)::text = 'ISEE'::text)"
"
-> Materialize (cost=100643.49..106653.58 rows=601009 width=12)"
"
-> Subquery Scan generiche_data_nascita_piu_anziano
(cost=0.00..100042.48 rows=601009 width=12)"
"
-> GroupAggregate (cost=0.00..94032.39 rows=601009 width=12)"
"
-> Index Scan using "IDX_1_componenti" on componenti
(cost=0.00..76403.45 rows=2023265 width=12)"
"
-> Index Scan using "IDX_1_c_elain" on c_elain c_elain_3
(cost=0.00..12.96 rows=1 width=12)"
"
Index Cond: (((c_elain_3.node)::text = 'Solo_anziani'::text) AND
(c_elain_3.id_domanda = domande.id_domanda))"
"
-> Index Scan using "IDX_3_c_elaout" on c_elaout c_elaout_2
(cost=0.00..15.30 rows=1 width=12)"
"
Index Cond: (((c_elaout_2.node)::text = 'ise_fsa'::text) AND
(c_elaout_2.id_domanda = domande.id_domanda))"
"
-> Index Scan using "IDX_2_c_elaout" on c_elaout c_elaout_3
(cost=0.00..14.54 rows=1 width=12)"
"
Index Cond: (c_elaout_3.id_domanda = domande.id_domanda)"
"
Filter: ((c_elaout_3.node)::text = 'incidenza'::text)"
"
-> Index Scan using "IDX_2_c_elain" on c_elain c_elain_9
(cost=0.00..12.91 rows=1 width=12)"
"
Index Cond: (c_elain_9.id_domanda = domande.id_domanda)"
"
Filter: ((c_elain_9.node)::text = 'Mesi'::text)"
"
-> Index Scan using "IDX_2_c_elain" on c_elain c_elain_8
(cost=0.00..12.91 rows=1 width=12)"
"
Index Cond: (c_elain_8.id_domanda = domande.id_domanda)"
"
Filter: ((c_elain_8.node)::text = 'Spese'::text)"
" ->
Index Scan using "IDX_2_c_elain" on c_elain c_elain_7 (cost=0.00..12.91
rows=3 width=12)"
"
Index Cond: (c_elain_7.id_domanda = domande.id_domanda)"
"
Filter: ((c_elain_7.node)::text = 'Affitto'::text)"
" -> Index
Scan using "IDX_2_c_elaout" on c_elaout c_elaout_1 (cost=0.00..14.54
rows=1 width=12)"
"
Index Cond: (c_elaout_1.id_domanda = domande.id_domanda)"
"
Filter: ((c_elaout_1.node)::text = 'isee_fsa'::text)"
" -> Index Scan using
"IDX_2_c_elaout" on c_elaout c_elaout_7 (cost=0.00..14.54 rows=1
width=12)"
" Index Cond:
(c_elaout_7.id_domanda = domande.id_domanda)"
" Filter:
((c_elaout_7.node)::text = 'contributo_regolare'::text)"
" -> Index Scan using
"IDX_2_c_elaout" on c_elaout c_elaout_6 (cost=0.00..14.54 rows=1
width=12)"
" Index Cond:
(c_elaout_6.id_domanda = domande.id_domanda)"
" Filter:
((c_elaout_6.node)::text = 'contributo_sociale'::text)"
" -> Index Scan using
"IDX_pk_VE_EDIL_tp_superfici" on ve_edil_tp_superfici (cost=0.00..2.27
rows=1 width=11)"
" Index Cond:
(ve_edil_tp_superfici.id_tp_superficie = edil_veneto.id_tp_superficie)"
" -> Seq Scan on r_luoghi
(cost=100000000.00..100000200.84 rows=10584 width=11)"
" -> Index Scan using "IDX_2_c_elaout" on c_elaout
c_elaout_5 (cost=0.00..14.54 rows=1 width=12)"
" Index Cond: (c_elaout_5.id_domanda =
domande.id_domanda)"
" Filter: ((c_elaout_5.node)::text =
'contributo'::text)"
" -> Index Scan using "IDX_2_c_elaout" on c_elaout
c_elaout_4 (cost=0.00..14.54 rows=1 width=12)"
" Index Cond: (c_elaout_4.id_domanda =
domande.id_domanda)"
" Filter: ((c_elaout_4.node)::text = 'esito'::text)"

Really thanks for your interest and your help!

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Matthew Wakeling 2009-06-16 14:58:56 Re: performance with query
Previous Message Tom Lane 2009-06-16 14:36:57 Re: Yet another slow nested loop