Re: TKPROF question

  • From: "Jonathan Lewis" <jonathan@xxxxxxxxxxxxxxxxxx>
  • To: <oracle-l@xxxxxxxxxxxxx>
  • Date: Tue, 23 Mar 2004 18:47:01 -0000

I'd be looking to prove that the figure was a bug.
It's 3,288 seconds - and it doesn't tie up with
your totals at all.

If you've found the actual line, can you extract
a couple of hundred lines either side of it, and
check above and below for lines with
    a) tim =
    b) Other lines for the same cursor number
        (the N of WAIT #N).

tim= is a timestamp in microseconds - do the
bracketing tim= lines cater for 3,288,000,000
microseconds elapsed.

Do previous lines for the same cursor - if nearby -
make sense ?

If you want to check on the block, you've got
the p1, p2 values from the global cache cr request,
    alter system dump data file {p1} block {p2}
and check for a line which identifies the block
as a branch block or a leaf block.

NB  If it's the block after the segment header,
it's the index root block.

Regards

Jonathan Lewis
http://www.jlcomp.demon.co.uk

The Co-operative Oracle Users' FAQ
http://www.jlcomp.demon.co.uk/faq/ind_faq.html

April 2004 Iceland
June  2004      UK - Optimising Oracle Seminar


----- Original Message ----- 
From: "Jamadagni, Rajendra" <Rajendra.Jamadagni@xxxxxxxx>
To: "Oracle List (E-mail)" <oracle-l@xxxxxxxxxxxxx>
Sent: Tuesday, March 23, 2004 4:16 PM
Subject: RE: TKPROF question


Never mind ... found it now I have to find out why the he11 it waited that
long on one block .... and this block is from one index. now how do I find
what type of block is this? branch? data?

Why would there be a cr wait of 3288.24 (seconds?/cent-seconds?) if so, it
doesn't match with the summary ...

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current
rows
------- ------  -------- ---------- ---------- ---------- ----------  ------
----
Parse        6      0.02       0.01          0          0          0
0
Execute      7      0.02    1244.27     503009   11062603          0
4
Fetch        2      0.00       0.00          0          3          0
1
------- ------  -------- ---------- ---------- ---------- ----------  ------
----
total       15      0.04    1244.29     503009   11062606          0
5

Misses in library cache during parse: 5
Misses in library cache during execute: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total
Waited
  ---------------------------------------- 
 Waited  ----------  ------------
  SQL*Net message to client                       8        0.00
0.00
  SQL*Net message from client                     8        0.00
0.00
  library cache lock                             27        0.00
0.00
  row cache lock                                  1        0.00
0.00
  log file sync                                   1        0.00
0.00


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current
rows
------- ------  -------- ---------- ---------- ---------- ----------  ------
----
Parse       36      0.04       0.06          0         85          0
0
Execute     84    243.62    1244.11     502996   11062248      41821
20188
Fetch       91      0.02       0.14         17        423          0
67
------- ------  -------- ---------- ---------- ---------- ----------  ------
----
total      211    243.68    1244.32     503013   11062756      41821
20255

Misses in library cache during parse: 24

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total
Waited
  ---------------------------------------- 
 Waited  ----------  ------------
  library cache lock                             37        0.00
0.00
  row cache lock                                 34        0.00
0.01
  db file sequential read                    492883        0.16
975.74
  global cache cr request                    239402     3288.24
3368.37
  library cache pin                               1        0.00
0.00
  direct path write                            1267        0.00
0.07
  global cache s to x                           155        0.00
0.04
  direct path read                             1582        0.01
0.72
  db file scattered read                         45        0.07
0.38
  global cache open s                             3        0.00
0.00
  global cache open x                            45        0.00
0.01

   13  user  SQL statements in session.
   30  internal SQL statements in session.
   43  SQL statements in session.
****************************************************************************
****

I am confused ... any help/ponters is greatly appreciated.


----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at //www.freelists.org/archives/oracle-l/
FAQ is at //www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

Other related posts: