Re: In what circumstances might optimizer not choose the lowest cost?

  • From: Kim Berg Hansen <kibeha@xxxxxxxxx>
  • To: Stefan Koehler <contact@xxxxxxxx>
  • Date: Wed, 21 Jan 2015 12:59:35 +0100

An update after some more testing:


10053 trace reveals several "New AP rejected: guess used for New but not
for Current Best" when it tests range scan access path on the FBI.
As the check constraint adds a predicate that is an equality predicate on
the leading index component of the other index, this matches the situation
described by Jonathan in this link (
https://jonathanlewis.wordpress.com/2010/09/07/cbo-surprise-3/ ) he sent.
Thanks Jonathan.

Underneath that seems to be same cause as note/bug "CBO may not choose best
index for single table access with unpeeked bind/function (Doc ID
4112254.8)" sent by Mauro.
That the optimizer "distrusts" range scan "guesses" (where it does not have
a peeked bind value) and prefers other access methods if those do not
involve "guesses".

I tested the fix for this with alter session set events '38068 trace name
context forever, level 100' - and it worked ! Thanks Mauro.
(Now I "just" need to decide whether this is OK to set systemwide or not ;-)


So the real root cause is that the optimization in my case seems to be
before bind variables are set, so this optimizer rule of not trusting range
scan guesses for unpeeked binds is used.
Good fix would have been to fix it so the binds were set before
optimization, but that is not possible, alas :-(
So my best workaround (for fixing more than just this single query) seems
to be setting event 38068 to tell the optimizer, that it is OK to trust
range scan guesses for unpeeked binds.


@Stefan:

If I do a 10046 trace, I get a sequence of events in the trace file like
this:

PARSING IN CURSOR #140551365170880
PARSE #140551365170880
(some parse/exec/fetch/close of recursive SQL)
CLOSE #140551365170880
PARSING IN CURSOR #140551365170880
PARSE #140551365170880
(some parse/exec/fetch/close of recursive SQL)
BINDS #140551365170880
EXEC #140551365170880
FETCH #140551365170880
...
FETCH #140551365170880
STAT #140551365170880
...
CLOSE #140551365170880


The first PARSING IN, PARSE, CLOSE I believe is done for "describing".
Then actual call with PARSING IN, PARSE, BINDS, EXEC, FETCH, CLOSE.

If I try 10046 together with 10053, all the 10053 trace lines in the trace
file happen just before the PARSING IN CURSOR# lines and the BINDS # lines
are much later.
In the 10053 trace lines I also spot:

*******************************************
Peeked values of the binds in SQL statement
*******************************************
----- Bind Info (kkscoacd) -----
 Bind#0
  oacdty=01 mxl=2000(256) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=1000000 frm=01 csi=31 siz=4000 off=0
  No bind buffers allocated
 Bind#1
  oacdty=01 mxl=2000(256) mxlc=00 mal=00 scl=00 pre=00
  oacflg=01 fl2=1000000 frm=01 csi=31 siz=0 off=2000
  No bind buffers allocated


So I'm pretty sure the way our kernel C code is made, it does NOT do the
correct thing to get OCI to do deferred optimization.

I'll just have to live with workarounds and beware of funny stuff happening
with "unpeeked binds" ;-)


Thanks for everyones help - it's been very illuminating :-)



Regards


Kim Berg Hansen

http://dspsd.blogspot.com
kibeha@xxxxxxxxx
@kibeha



On Wed, Jan 21, 2015 at 10:31 AM, Stefan Koehler <contact@xxxxxxxx> wrote:

> Hi Kim,
> that application behavior sounds strange indeed as no two PARSE calls are
> required with deferred optimization. We also need to differ the common used
> expression "parsing" for both activities "parsing" and "optimizing".
>
> Parsing = Oracle checks if the SQL statement is a valid one (syntactic
> analysis). Afterwards it checks and figures out things like object types,
> columns in object types, constraints, triggers, indexes, privileges, etc.
> (semantic analysis). Both together is called parsing.
>
> Optimizing = After the statement is parsed, the optimizer starts its work
> by gathering stats and doing its arithmetic.
>
> As you can see what is commonly named as "parsing a SQL" is a two step
> approach in reality. So usually your statement is parsed, then the binds are
> assigned and then it is optimized.
>
> Tom Kyte also described this deferred optimization on his website:
>
> https://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:104931400346587790#5203655900346507293
>
> .. prepareStatement (this does the parse UP TO but not including
> optimization)
> .. bind
> .. bind
> .. bind
> .. execute (this will optimize if necessary and then run the sql)
> .. close
>
> So your app is broken in general (with OCI 10), if your root cause is
> based on non existence binds by optimization (no bind peeking), but as far
> as i
> understand you have a valid work around for your critical SQL :-))
>
> Best Regards
> Stefan Koehler
>
> Freelance Oracle performance consultant and researcher
> Homepage: http://www.soocs.de
> Twitter: @OracleSK
>
>
> > Kim Berg Hansen <kibeha@xxxxxxxxx> hat am 20. Januar 2015 um 19:30
> geschrieben:
> >
> >  Stefan,
> >
> >  I am not 100% sure what actually happens.
> >
> >  This old ERP system is called XAL, the kernel is written in C using OCI
> libraries (originally written with OCI version 7, now recompiled with OCI
> > version 10, and any newer will not be produced.) The kernel is running
> on HP-UX.
> >
> >  The ERP system has it's own legacy language, which the kernel
> transforms to SQL. Those cursors behave reasonably well and the kernel also
> reuses
> > these cursors with new content in bind variables rather than
> close/open/close/open.
> >
> >  But the cursors I need to use when I have to perform joins is a kind of
> "prepared statement". I build a string in this legacy language and call a
> > "sqlexecute" function. I do not use bind variables explicitly, but a
> literal value in the string that is put inside special comments ( like
> > /*XAL_STR(*/'literal'/*)*/ ) will be pulled out of the string by the
> kernel at runtime and placed in bind variables.
> >
> >  When tracing, it appears that this "sqlexecute" function parses the
> statement TWICE before executing. I think it does a parse first (with empty
> > bind variables) in order to "describe" columns and retrieve datatypes of
> the columns of the query. And then it re-parses before executing with
> > contents in bind variables. So my theory is that the first parse makes
> the hard parse (defeating bind variable peeking) and the second is simply
> > soft parsing (and therefore doesn't peek at the actual bind variable
> content.)
> >
> >  What OCI calls it actually performs I cannot see and I cannot influence
> it. But bear in mind that the OCI calls used are calls that worked in
> > version 7. It may have been recompiled (or re-linked) for OCI libraries
> version 10, but I think it highly unlikely that they actually changed the
> > OCI calls used back then.
> >
> >  But going too far out that line of exploration will get a bit far away
> from the original question :-)
> >
> >  Regards
> >  Kim Berg Hansen
> >
> >  http://dspsd.blogspot.com
> >  kibeha@xxxxxxxxx <mailto:kibeha@xxxxxxxxx>
> >  @kibeha
>

Other related posts: