Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> Re: comparing tkprof results between cursor_sharing = exact or similar

Re: comparing tkprof results between cursor_sharing = exact or similar

From: Charles Hooper <hooperc2000_at_yahoo.com>
Date: 4 Mar 2007 19:34:18 -0800
Message-ID: <1173065658.411528.285240@p10g2000cwp.googlegroups.com>


On Mar 4, 10:01 pm, Tasm <t..._at_tasm.com> wrote:
> 10.2.0.2 on Sun Solaris
> All base tables and indexes have been analyzed.
>
> I'm trying to tune some SQL that comes from the application. Unfortunately it
> is a really complex view, which joins 7 tables, and doesn't use bind variables.
> The following is from tkprof
>
> SELECT * from complex_vw where col = 27 ;
>
> call count cpu elapsed disk query current rows
> ------- ------ ----- ------- ---- ----- ------- ----
> Parse 1 13.86 13.64 0 0 0 0
> Execute 1 0.00 0.00 0 0 0 0
> Fetch 1 0.31 0.31 0 6817 0 0
> ------- ------ ----- ------- ---- ----- ------- ----
> total 3 14.17 13.95 0 6817 0 0
>
> Misses in library cache during parse: 1
> Optimizer mode: ALL_ROWS
>
> The above results appear 9 times through the tkprof file.
>
> OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current rows
> ------- ----- ---- ------- ---- ----- ------- ----
> Parse 90 0.01 0.00 0 0 0 0
> Execute 90 0.02 0.02 0 0 0 0
> Fetch 90 0.00 0.00 0 180 0 90
> ------- ----- ---- ------- ---- ----- ------- ----
> total 270 0.03 0.03 0 180 0 90
>
> Misses in library cache during parse: 0
>
> 1 session in tracefile.
> 14 user SQL statements in trace file.
> 90 internal SQL statements in trace file.
> 104 SQL statements in trace file.
> 15 unique SQL statements in trace file.
> 2003 lines in trace file.
> 127 elapsed seconds in trace file.
>
> Every time the where clause changes it has to parse it again and thus another
> 13.86 seconds is consumed.
>
> So, I set cursor_sharing = similar and I get the following:
>
> SELECT * from complex_vw where col = :"SYS_B_0" ;
>
> call count cpu elapsed disk query current rows
> ------- ------ ------ ------- ---- ------ ------- ----
> Parse 9 0.03 0.01 0 0 0 0
> Execute 9 127.74 126.10 0 0 0 0
> Fetch 9 14.26 14.85 338 905595 0 0
> ------- ------ ------ ------- ---- ------ ------- ----
> total 27 142.03 140.97 338 905595 0 0
>
> Misses in library cache during parse: 9
> Misses in library cache during execute: 9
> Optimizer mode: ALL_ROWS
>
> OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current rows
> ------- ------ ---- ------- ---- ----- ------- ----
> Parse 168 0.04 0.04 0 0 0 0
> Execute 545 0.28 0.24 0 0 0 0
> Fetch 1232 0.10 0.09 0 2261 0 2085
> ------- ------ ---- ------- ---- ----- ------- ----
> total 1945 0.42 0.39 0 2261 0 2085
>
> Misses in library cache during parse: 26
> Misses in library cache during execute: 26
>
> 1 session in tracefile.
> 14 user SQL statements in trace file.
> 545 internal SQL statements in trace file.
> 559 SQL statements in trace file.
> 32 unique SQL statements in trace file.
> 11231 lines in trace file.
> 141 elapsed seconds in trace file.
>
> My question is why does Execute cpu value go up to 127.74 seconds when it is
> using bind variables (with changing values). If I execute the same query over
> and over (with the same bind variable value) then it executes sub second.
>
> The explain plans between
>
> cursor_sharing = exact or similar
>
> is the same.
>
> I realise that the query is returning 0 rows, but even when it returns 4 rows
> it takes just as long to run.

Explain plans do not always show accurate plans when bind variables are involved - so the actual execution plan in the second case may in fact be different from the execution plan in the first case. Perform a 10053 trace to see the actual execution plan.

So, why did the elapsed parse time decrease from 13.64 seconds to 0.01 seconds, and execute time increase from 0.00 to 126.10? When CURSOR_SHARING is set to SIMILAR, Oracle potentially needs to reparse the SQL statement on every execution. TKPROF is showing 9 executions - 126.10 / 9 = 14.01 seconds per parse, which is fairly close to the 13.64 second parse time in the first example.

You might want to try CURSOR_SHARING=FORCE, fix the application, add hints to the SQL statment so that Oracle does not need to spend as much time resolving execution plans, or see if the complex view can be simplified.

Charles Hooper
PC Support Specialist
K&M Machine-Fabricating, Inc. Received on Sun Mar 04 2007 - 21:34:18 CST

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US