Monday, November 13, 2006

Diagnosing unshared SQL in 10g

One of the ways to increase scalability and throughput of an application is to see to it that SQL statements are shared and reduce the number of children of sql statements. In versions prior to 10g the view V$SQL_SHARED_CURSOR would aid in diagnosing why sql statements were not being shared.In 10g there is a new event called CURSORTRACE which aids in the same.

Let us take the following simple sql statement.

SESSION1>> select count(*) from dept;

COUNT(*)
----------
4

SESSION1>> select sql_text, hash_value,address from v$sqlarea where sql_text like 'select count(*) from dept%';

SQL_TEXT HASH_VALUE ADDRESS
----------------------------------- ---------- --------
select count(*) from dept 761178024 19156098

This the first child of the above sql statement with all 'N's

SESSION1>> select * from v$sql_shared_cursor where address = '19156098';

SQL_ID ADDRESS CHILD_AD CHILD_NUMBER U S O O S L S E B P I S T A B D L T
------------- -------- -------- ------------ - - - - - - - - - - - - - - - - - -
R I I R L I O S M U T N F A I T D L D B P C S R P T M B M R O P M F L
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
1jrz3ucqpx9x8 19156098 1CEFB584 0 N N N N N N N N N N N N N N N N N N
N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N

Now let us open a new session and issue the above sql statement but see to it that the cursor is not shared

SESSION2>>alter session set optimizer_mode='RULE';

Session altered.

SESSION2>>select count(*) from dept;

COUNT(*)
----------
4

Check from Session 1 how many children have been generated
SESSION1>>select * from v$sql_shared_cursor where address = '19156098';

SQL_ID ADDRESS CHILD_AD CHILD_NUMBER U S O O S L S E B P I S T A B D L T
------------- -------- -------- ------------ - - - - - - - - - - - - - - - - - -
R I I R L I O S M U T N F A I T D L D B P C S R P T M B M R O P M F L
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
1jrz3ucqpx9x8 19156098 1CEFB584 0 N N N N N N N N N N N N N N N N N N
N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N

1jrz3ucqpx9x8 19156098 1BA90164 1 N N N N N N N N N N N N N N N N N N
N N N N N N N N N N N N N N N N N N N N N N N N N N N N N N Y N N N N

As expected we have one more child caused by the OPTIMIZER_MODE_MISMATCH which we
forced.

SESSION2>>alter session set events 'immediate trace name cursortrace level 612, address 761178024';

==> 761178024 is the hash value of the sql statement.

Session altered.

SESSION2>>select count(*) from dept;

COUNT(*)
----------
4

SESSION2>>alter session set optimizer_mode='FIRST_ROWS_1';

Session altered.

SESSION2>>select count(*) from dept;

COUNT(*)
----------
4

The resultant trace file generated in user_dump_dest will throw more
light into why the sql statement is not shared.

Here is a snippet from the trace file

*************************************************************************
PARSING SQLTEXT=select count(*) from dept
SQLHASH=2d5ea7a8
Checking for already pinned child.
No valid child pinned
Parent 1EA853E8(19156098) ready for search
kksSearchChildList outside while loop
kksCheckCursor: next child is #1
kksCheckCursor: pinning child #1 in shared mode 1eb62650 1ba90164
Compilation environment difference Failed sharing : 0
optimizer_mode = first_rows_1 rule
sqlstat_enabled = false true
SQL pgadep:0 pgapls:0 user
Failed sharing : Compilation environment mismatch
kksUnlockChild: releasing child
*************************************************************************

2 comments:

Tatjana (Tanja) Kane said...

That is a great example of the cursortrace event!

Thanks for publishing it.

Fairlie Rego said...

Thanks Tanya