Re: Help trying to tune query that executes 40x slower

Hugo,

I think your problem is with the MRS_TRANSACTION TRANS table. It is
not joining anything when declared, but later it is joining thru a LEFT
JOIN of the REPL_DATA_OWNER_RSDNC table. In fact I'm not sure that this
table is really needed. I would suggest rewriting your FROM clause. It
appears a little busy and includes additional filters that are taken
care of in the WHERE clause.

What are the table layouts and what fields are indexed?

Hugo Ferreira wrote:

>Hi there :-)
>
>I'm really, really having trouble with this query... It is a part of,
>hmmm... 200 similar querys that I dinyamically build and run in a
>stored procedure. This one, for example, takes 27seconds to run. The
>whole stored procedure executes in about 15minutes. This is too much
>when compared to the exact same database, with the same indexes and
>same data running under SqlServer 2000, which takes 21seconds to run
>the whole batch.
>
>Any help would be extremely appreciated. I've also tried to tune up
>the configuration
>
>insert into MRS_REPLICATION_OUT select 514, 10000168, C.contxt_id,
>C.contxt_elmt_ix, CAST(null as NUMERIC(18)), CAST(null as
>NUMERIC(18)), CAST(null as NUMERIC(18)), CAST(null as NUMERIC(18)),
>CAST(null as NUMERIC(18)), null, 1 from c2iedm.CONTXT as P inner join
>c2iedm.CONTXT_ELMT as C on (P.contxt_id=C.contxt_id) inner join
>MRS_REPLICATION_OUT as S on S.ent_id=10000029 and (CAST(P.contxt_id AS
>numeric(18)) = S.pk1) inner join MRS_TRANSACTION TRANS on
>TRANS.trans_id=514 left join NON_REPL_DATA_OWNER NRDO on
>NRDO.non_repl_data_owner_id=C.owner_id left join REPL_DATA_OWNER_RSDNC
>RDOR on RDOR.owner_id=C.owner_id and
>RDOR.rsdnc_node_id=TRANS.recv_node_id left join MRS_REPLICATION_OUT
>OUT on OUT.trans_id=514 and OUT.ent_id=10000168 and ((CAST(C.contxt_id
>AS numeric(18)) = OUT.pk1 AND CAST(C.contxt_elmt_ix AS numeric(18)) =
>OUT.pk2)) inner join MRS_TRANSACTION RED_TRANS on
>TRANS.prov_node_id=RED_TRANS.prov_node_id and
>TRANS.recv_node_id=RED_TRANS.recv_node_id left join
>MRS_REPLICATION_OUT RED_OUT on RED_TRANS.cat_code = 'OUT' and
>RED_TRANS.trans_type in ('X01', 'X02') and
>RED_TRANS.trans_id=RED_OUT.trans_id where S.age=0 and S.trans_id=514
>and (NRDO.non_repl_data_owner_id is null) AND (RDOR.repl_data_owner_id
>is null) AND (OUT.trans_id is null) AND (RED_OUT.trans_id is null);
>
>This kind of inserts generate few rows. Between 8k and 15k for this particular
>insert, and about 20k for the whole batch. If I try to run a batch
>to generate about 50k rows, then I'll be stuck here for more that 45h.
>Compare this to 12minutes when running SqlServer 2000.
>
>Here is the result of explain analyze:
>
>"Merge Left Join (cost=1338.32..1377.99 rows=45 width=32) (actual
>time=719.000..26437.000 rows=14862 loops=1)"
>" Merge Cond: ("outer".trans_id = "inner".trans_id)"
>" Join Filter: (("outer".cat_code = 'OUT'::bpchar) AND
>(("outer".trans_type = 'X01'::bpchar) OR ("outer".trans_type =
>'X02'::bpchar)))"
>" Filter: ("inner".trans_id IS NULL)"
>" -> Sort (cost=1067.36..1067.47 rows=45 width=56) (actual
>time=719.000..735.000 rows=14862 loops=1)"
>" Sort Key: red_trans.trans_id"
>" -> Merge Join (cost=851.66..1066.12 rows=45 width=56)
>(actual time=407.000..673.000 rows=14862 loops=1)"
>" Merge Cond: ("outer".recv_node_id = "inner".recv_node_id)"
>" Join Filter: ("outer".prov_node_id = "inner".prov_node_id)"
>" -> Nested Loop Left Join (cost=847.14..987.28
>rows=3716 width=60) (actual time=407.000..610.000 rows=14862 loops=1)"
>" Join Filter: ((("outer".contxt_id)::numeric(18,0)
>= "inner".pk1) AND (("outer".contxt_elmt_ix)::numeric(18,0) =
>"inner".pk2))"
>" Filter: ("inner".trans_id IS NULL)"
>" -> Merge Left Join (cost=718.22..746.87
>rows=3716 width=60) (actual time=407.000..563.000 rows=14862 loops=1)"
>" Merge Cond: (("outer".recv_node_id =
>"inner".rsdnc_node_id) AND ("outer".owner_id = "inner".owner_id))"
>" Filter: ("inner".repl_data_owner_id IS NULL)"
>" -> Sort (cost=717.19..726.48 rows=3716
>width=74) (actual time=407.000..423.000 rows=14862 loops=1)"
>" Sort Key: trans.recv_node_id, c.owner_id"
>" -> Nested Loop Left Join
>(cost=1.01..496.84 rows=3716 width=74) (actual time=0.000..312.000
>rows=14862 loops=1)"
>" Join Filter:
>("inner".non_repl_data_owner_id = "outer".owner_id)"
>" Filter:
>("inner".non_repl_data_owner_id IS NULL)"
>" -> Nested Loop
>(cost=0.00..412.22 rows=3716 width=74) (actual time=0.000..186.000
>rows=14862 loops=1)"
>" -> Seq Scan on
>mrs_transaction trans (cost=0.00..2.05 rows=1 width=28) (actual
>time=0.000..0.000 rows=1 loops=1)"
>" Filter: (trans_id =
>514::numeric)"
>" -> Nested Loop
>(cost=0.00..373.01 rows=3716 width=46) (actual time=0.000..139.000
>rows=14862 loops=1)"
>" Join Filter:
>("outer".contxt_id = "inner".contxt_id)"
>" -> Nested Loop
>(cost=0.00..4.81 rows=1 width=16) (actual time=0.000..0.000 rows=4
>loops=1)"
>" Join Filter:
>(("inner".contxt_id)::numeric(18,0) = "outer".pk1)"
>" -> Index
>Scan using ix_mrs_replication_out_all on mrs_replication_out s
>(cost=0.00..3.76 rows=1 width=16) (actual time=0.000..0.000 rows=4
>loops=1)"
>" Index
>Cond: ((ent_id = 10000029::numeric) AND (age = 0::numeric) AND
>(trans_id = 514::numeric))"
>" -> Seq Scan
>on contxt p (cost=0.00..1.02 rows=2 width=16) (actual
>time=0.000..0.000 rows=2 loops=4)"
>" -> Seq Scan on
>contxt_elmt c (cost=0.00..275.31 rows=7431 width=46) (actual
>time=0.000..7.500 rows=7431 loops=4)"
>" -> Materialize
>(cost=1.01..1.02 rows=1 width=12) (actual time=0.000..0.001 rows=1
>loops=14862)"
>" -> Seq Scan on
>non_repl_data_owner nrdo (cost=0.00..1.01 rows=1 width=12) (actual
>time=0.000..0.000 rows=1 loops=1)"
>" -> Sort (cost=1.03..1.03 rows=2 width=42)
>(actual time=0.000..0.000 rows=2 loops=1)"
>" Sort Key: rdor.rsdnc_node_id, rdor.owner_id"
>" -> Seq Scan on repl_data_owner_rsdnc
>rdor (cost=0.00..1.02 rows=2 width=42) (actual time=0.000..0.000
>rows=2 loops=1)"
>" -> Materialize (cost=128.92..128.93 rows=1
>width=42) (actual time=0.000..0.000 rows=0 loops=14862)"
>" -> Seq Scan on mrs_replication_out "out"
>(cost=0.00..128.92 rows=1 width=42) (actual time=0.000..0.000 rows=0
>loops=1)"
>" Filter: ((trans_id = 514::numeric)
>AND (ent_id = 10000168::numeric))"
>" -> Sort (cost=4.52..4.73 rows=84 width=52) (actual
>time=0.000..15.000 rows=1 loops=1)"
>" Sort Key: red_trans.recv_node_id"
>" -> Seq Scan on mrs_transaction red_trans
>(cost=0.00..1.84 rows=84 width=52) (actual time=0.000..0.000 rows=1
>loops=1)"
>" -> Sort (cost=270.96..277.78 rows=2728 width=10) (actual
>time=0.000..5255.000 rows=8932063 loops=1)"
>" Sort Key: red_out.trans_id"
>" -> Seq Scan on mrs_replication_out red_out
>(cost=0.00..115.28 rows=2728 width=10) (actual time=0.000..0.000
>rows=602 loops=1)"
>"Total runtime: 27094.000 ms"
>
>Once again, thanks in advance.
>
>Hugo Ferreira
>--
>GPG Fingerprint: B0D7 1249 447D F5BB 22C5 5B9B 078C 2615 504B 7B85
>
>---------------------------(end of broadcast)---------------------------
>TIP 3: if posting/reading through Usenet, please send an appropriate
> subscribe-nomail command to majordomo(at)postgresql(dot)org so that your
> message can get through to the mailing list cleanly
>
>
>
>