Re: Help trying to tune query that executes 40x slower - Mailing list pgsql-performance

From Jim Johannsen
Subject Re: Help trying to tune query that executes 40x slower
Date
Msg-id 422FAC50.4060500@gvtc.com
Whole thread Raw
In response to Help trying to tune query that executes 40x slower than in SqlServer  (Hugo Ferreira <bytter@gmail.com>)
List pgsql-performance
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@postgresql.org so that your
>      message can get through to the mailing list cleanly
>
>
>
>


pgsql-performance by date:

Previous
From: David Brown
Date:
Subject: Re: index scan on =, but not < ?
Next
From: Mischa
Date:
Subject: Multi-line requests in COPY ... FROM STDIN