Re: strange tkprof output for SQLs - II

Hello Mogens,

I saw this problem whether or not shared pool was flushed for PL/SQLs.

Here are my observations for SQLs!!! and PL/SQLs:

• Enabling sql trace from current session: When a cursor is closed after their child recursive statements, their recursive statistics parsed after the statement are included in parent's statistics. Recursive statements parsed before the statement are not included.
• Enabling sql trace from other session after a while(after the parenet statement is parsed): Recursive statistics are not included in parent statement. But tkprof doesn't use exac values in raw trace file. If they are not included, why doesn't tkprof return exac values in raw trace files ? I'll debug tkprof if it calls Oracle's kernel function to see if tkprof is just a simple formatter or calculates something that I'm missing.

I did not understand this is expected behavior or not. I would like to know statistics in raw trace files are inclusive or exclusive.

I'm facing diffierent behaviors for this problem. I've opened an iTAR.

thanks in advance...

Mogens Nørgaard wrote:

> Danisment - isn't it always "alter system flush shard_pool"? I thought so...
>
> Danisment Gazi Unal (Unal Bilisim) wrote:
>
> >Hello,
> >
> >I did 2 tests for PL/SQL and SQL statements. This is the test for
> >SQL.
> >
> >Here are the steps:
> >
> >SQL > alter session flush shared_pool;
> >SQL > alter session set sql_trace=true;
> >SQL > insert into test select * from test;
> >SQL > alter session set sql_trace=false;
> >
> >
> >FROM DICTIONARY:
> >
> >SVRMGR> select
> >SQL_TEXT,DISK_READS,BUFFER_GETS,ROWS_PROCESSED,COMMAND_TYPE from v$sql
> >where sql_text like 'insert into test select * from test%';
> >
> >SQL_TEXT DISK_READS BUFFER_GET ROWS_PROCE
> >COMMAND_TY
> >------------------------------------- ---------- ---------- ----------
> >----------
> >insert into test select * from test 345 1014
> >8192 2
> >1 row selected.
> >
> >
> >FROM RAW TRACE FILE:
> >
> >PARSING IN CURSOR #1 len=36 dep=0 uid=5 oct=2 lid=5 tim=2795932206
> >hv=895761708 ad='5083d50c'
> >insert into test select * from test
> >END OF STMT
> >PARSE #1:c=7,e=28,p=17,cr=42,cu=2,mis=1,r=0,dep=0,og=4,tim=2795932206
> >.
> >other recursive statements.
> >.
> >. near end of file
> >EXEC
> >#1:c=28,e=258,p=328,cr=597,cu=373,mis=0,r=8192,dep=0,og=4,tim=2795932464
> >
> >
> >
> >BUFFER GETS IN RAW TRACE FILE:
> >cr: 597 + 42 = 639
> >cu: 373 + 2 = 375
> >
> >Buffer gets = 639 + 375 = 1014, which is same as v$sql.BUFFER_GETS
> >
> >
> >DISK_READS IN RAW TRACE FILE:
> >
> >p: 17 + 328 = 345, which is same as v$sql.DISK_READS.
> >
> >According to these test, results in dictionary and raw trace files are
> >same. But tkprof formats as below:
> >
> >
> >insert into test select * from test
> >
> >
> >call count cpu elapsed disk query
> >current rows
> >------- ------ -------- ---------- ---------- ---------- ----------
> >----------
> >Parse 1 0.00 0.02 17 42
> >1 0
> >Execute 1 0.12 1.86 91 126
> >356 8192
> >Fetch 0 0.00 0.00 0 0
> >0 0
> >------- ------ -------- ---------- ---------- ---------- ----------
> >----------
> >total 2 0.12 1.88 108 168
> >357 8192
> >
> >
> >DISK_READS = 108
> >BUFFER GETS = 168 + 357 = 525
> >
> >Question:
> >
> >Which one is correct ? Dictionary/raw trace file or tkprof results ?
> >
> >My comment:
> >
> >I guess, tkprof substructs child recursive statements from parent user
> >statement ? Why ? This is not a PL/SQL statement ? So, statistics are
> >already not included in parent statement ? I guess statistics in raw
> >trace files are inclusive statistics which include statistics of their
> >child statements according to call orders of kernel calls. But is this
> >expected behavior.
> >
> >Thanks in advance...
> >
> >--
> >Danisment Gazi Unal
> >http://www.unal-bilisim.com
> >
> >
>
> --
> Please see the official ORACLE-L FAQ: http://www.orafaq.com
> --
> Author: Mogens =?ISO-8859-1?Q?N=F8rgaard?=
> INET: mln_at_miracleas.dk
>
> Fat City Network Services -- (858) 538-5051 FAX: (858) 538-5051
> San Diego, California -- Public Internet access / Mailing Lists
> --------------------------------------------------------------------
> To REMOVE yourself from this mailing list, send an E-Mail message
> to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
> the message BODY, include a line containing: UNSUB ORACLE-L
> (or the name of mailing list you want to be removed from). You may
> also send the HELP command for other information (like subscribing).

--
Danisment Gazi Unal
http://www.unal-bilisim.com



-- 
Please see the official ORACLE-L FAQ: http://www.orafaq.com
-- 
Author: Danisment Gazi Unal
  INET: dunal_at_unal-bilisim.com

Fat City Network Services    -- (858) 538-5051  FAX: (858) 538-5051
San Diego, California        -- Public Internet access / Mailing Lists
--------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: ListGuru_at_fatcity.com (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from).  You may
also send the HELP command for other information (like subscribing).