Обсуждение: Two different execution plans for similar requests

Hi, and why do you think this is a problem?

The explain plan is expected to change for different parameter values,
that's OK. The merge in the first query is expected to produce
significantly more rows (91774) than the other one (229). That's why the
second query chooses nested loop instead of merge join ...

But it's difficult to say if those plans are OK, as you have posted just
EXPLAIN output - please, provide 'EXPLAIN ANALYZE' output so that we can
see if the stats are off.

regards
Tomas

> *Hi all !

>
> Postgresql (8.2) has as a strange behaviour in some of my environments.
> *
> *A request follows two execution plans ( but not always !!! ). I encounter
> some difficulties to reproduce the case.*
>
> *J-2*
> Aggregate  (*cost=2323350.24..2323350.28 rows=1 width=24*)
>   ->  Merge Join  (cost=2214044.98..2322432.49 rows=91774 width=24)
>         Merge Cond: ((azy_header.txhd_azy_nr = azy_detail.txhd_azy_nr) AND
> ((azy_header.till_short_desc)::text = inner"."?column8?") AND
> ((azy_header.orgu_xxx)::text = "inner"."?column9?") AND
> ((azy_header.orgu_xxx_cmpy)::text = "inner"."?column10?"))"
>         ->  Sort  (cost=409971.56..410050.39 rows=31532 width=77)
>               Sort Key: azy_queue.txhd_azy_nr,
> (azy_queue.till_short_desc)::text, (azy_queue.orgu_xxx)::text,
> (azy_queue.orgu_xxx_cmpy)::text
>               ->  Nested Loop  (cost=0.00..407615.41 rows=31532 width=77)
>                     ->  Nested Loop  (cost=0.00..70178.58 rows=52216
> width=46)
>                           Join Filter: (((azy_queue.orgu_xxx_cmpy)::text =
> (firma_session.orgu_xxx_cmpy)::text) AND ((azy_queue.orgu_xxx)::text =
> (firma_session.orgu_xxx)::text))
>                           ->  Seq Scan on firma_session
> (cost=0.00..599.29
> rows=401 width=25)
>                                 Filter: ((cssn_trading_date >=
> '20110226'::bpchar) AND (cssn_trading_date <= '20110226'::bpchar))
>                           ->  Index Scan using azyq_ix2 on azy_queue
> (cost=0.00..165.92 rows=434 width=41)
>                                 Index Cond: (azy_queue.cssn_session_id =
> firma_session.cssn_session_id)
>                     ->  Index Scan using txhd_pk on azy_header
> (cost=0.00..6.44 rows=1 width=31)
>                           Index Cond: (((azy_queue.orgu_xxx_cmpy)::text =
> (azy_header.orgu_xxx_cmpy)::text) AND ((azy_queue.orgu_xxx)::text =
> (azy_header.orgu_xxx)::text) AND ((azy_queue.till_short_desc)::text =
> (azy_header.till_short_desc)::text) AND (azy_queue.txhd_azy_nr =
> azy_header.txhd_azy_nr))
>                           Filter: (txhd_voided = 0::numeric)
>         ->  Sort  (cost=1804073.42..1825494.05 rows=8568252 width=55)
>               Sort Key: azy_detail.txhd_azy_nr,
> (azy_detail.till_short_desc)::text, (azy_detail.orgu_xxx)::text,
> (azy_detail.orgu_xxx_cmpy)::text
>               ->  Seq Scan on azy_detail  (cost=0.00..509908.30
> rows=8568252
> width=55)
>                     Filter: (txde_item_void = 0::numeric)
>
>
>
> *J-1*
> Aggregate  (*cost=10188.38..10188.42 rows=1 width=24*)
>   ->  Nested Loop  (cost=0.00..10186.08 rows=229 width=24)
>         ->  Nested Loop  (cost=0.00..2028.51 rows=79 width=77)
>               ->  Nested Loop  (cost=0.00..865.09 rows=130 width=46)
>                     Join Filter: (((azy_queue.orgu_xxx_cmpy)::text =
> (firma_session.orgu_xxx_cmpy)::text) AND ((azy_queue.orgu_xxx)::text =
> (firma_session.orgu_xxx)::text))
>                     ->  Seq Scan on firma_session  (cost=0.00..599.29
> rows=1
> width=25)
>                           Filter: ((cssn_trading_date >=
> '20110227'::bpchar)
> AND (cssn_trading_date <= '20110227'::bpchar))
>                     ->  Index Scan using azyq_ix2 on azy_queue
> (cost=0.00..258.20 rows=434 width=41)
>                           Index Cond: (azy_queue.cssn_session_id =
> firma_session.cssn_session_id)
>               ->  Index Scan using txhd_pk on azy_header  (cost=0.00..8.93
> rows=1 width=31)
>                     Index Cond: (((azy_queue.orgu_xxx_cmpy)::text =
> (azy_header.orgu_xxx_cmpy)::text) AND ((azy_queue.orgu_xxx)::text =
> (azy_header.orgu_xxx)::text) AND ((azy_queue.till_short_desc)::text =
> (azy_header.till_short_desc)::text) AND (azy_queue.txhd_azy_nr =
> azy_header.txhd_azy_nr))
>                     Filter: (txhd_voided = 0::numeric)
>         ->  Index Scan using txde_pk on azy_detail  (cost=0.00..102.26
> rows=50 width=55)
>               Index Cond: (((azy_detail.orgu_xxx_cmpy)::text =
> (azy_header.orgu_xxx_cmpy)::text) AND ((azy_detail.orgu_xxx)::text =
> (azy_header.orgu_xxx)::text) AND ((azy_detail.till_short_desc)::text =
> (azy_header.till_short_desc)::text) AND (azy_detail.txhd_azy_nr =
> azy_header.txhd_azy_nr))
>               Filter: (txde_item_void = 0::numeric)
>
>
>
> *
> Where shall I investigate ?*
> Thanks for your help
>

> I've already used an 'EXPLAIN ANALYZE' to post the message. So I don't
> clearly understand what you are expecting for, when you tell me to provide
> 'EXPLAIN ANALYZE'  (please excuse me for the misunderstood)

No, you haven't. You've provided 'EXPLAIN' output, but that just prepares
an execution plan and displays it. So it shows just estimates of row
counts etc. and not actual values.

Do the same thing but use 'EXPLAIN ANALYZE' instead of 'EXPLAIN' - it will
run the query and provide more details about it (run time for each node,
actual number of rows etc.).

Anyway the sudden changes of estimated costs are suspicious ...

Tomas

Sorry ! The command I use is 'EXPLAIN ANALYZE'
I can't do better ...

2011/3/1 <tv@fuzzy.cz>

> I've already used an 'EXPLAIN ANALYZE' to post the message. So I don't

> clearly understand what you are expecting for, when you tell me to provide
> 'EXPLAIN ANALYZE'  (please excuse me for the misunderstood)

No, you haven't. You've provided 'EXPLAIN' output, but that just prepares
an execution plan and displays it. So it shows just estimates of row
counts etc. and not actual values.

Do the same thing but use 'EXPLAIN ANALYZE' instead of 'EXPLAIN' - it will
run the query and provide more details about it (run time for each node,
actual number of rows etc.).

Anyway the sudden changes of estimated costs are suspicious ...

Tomas

On Tue, Mar 1, 2011 at 4:44 AM, Joby Joba <jobyjoba59@gmail.com> wrote:
> Me again !  I have checked this question of 'explain analyze' and I
> understand now.
>
> When the problem occured I have run a 'EXPLAIN'
>
> I have run the request again to open this case using 'EXPLAIN ANALYZE' but I
> didn't reproduce the case. That's why I sent the other trace but it doesn't
> countain the information you are asking for.
> So Tomas, you were right !
>
> All apologies !!!!! (I'm confused)
>
>
> But the problem still not resolved .....

What exactly is the problem? Is one version of this plan slow? Which
one? If you can't reproduce with EXPLAIN ANALYZE (which actually runs
the query), how are you reproducing this?

---
Maciek Sakrejda | System Architect | Truviso

1065 E. Hillsdale Blvd., Suite 215
Foster City, CA 94404
(650) 242-3500 Main
www.truviso.com