Re: comparing tkprof results between cursor_sharing = exact or similar

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.

Once you saw that a single query was taking > 13 seconds to (hard) parse, you reached a point where further analysis was not required.

How can you possibly have say a 7 second response time to a submitted request, when you've already used twice that in terms of CPU time, let alone user_io_wait_time.

The initial problem is that of widespread use of literals where the use of bind variables would be appropriate.

Spend some time on Tom Kyte's site at http://asktom.oracle.com.

identify the statements that are being executed most frequently with the greatest number of permutations in the shared_pool (v$sqlstats is nice in 10.2 for this) and change the application code to make proper use of literals and binds.

After you have made proper use of bind variables and have reduced the waits due to excessive hard parsing, consider tuning individual statements.

In the meantime, use cursor_sharing = force and re-gather stats with method_opt=>'FOR ALL COLUMNS SIZE 1' to remove the histograms. Next step might be to determine an overall optimizer_mode.

I haven't seen cursor_sharing work for anything but exact in 10.2 but perhaps this was a platform-specific issue and does not affect Solaris ports.

hth.

-bdbafh Received on Mon Mar 05 2007 - 12:33:26 CST