Skip to Main Content

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Neil .

Asked: April 17, 2009 - 9:08 am UTC

Last updated: January 19, 2010 - 4:46 pm UTC

Version: 9208

Viewed 1000+ times

You Asked

Hi Tom,

Please help !

Neil

I am having a problem interpreting a tkprof report.
I have looked in detail at a lot of documentation on this area, particularly looking at "pitfalls" to be wary of and also a lengthy blog of yours. However I cannot make sense of what appears to be a simple issue.

The problem is that when data appears to be coming from the buffer cache it is reported as coming from disk.

I am executing the same statement twice in quick succession. I clear the buffer cache prior to the first execution but not the second.
I disconnect from the DB between executions and create completely separate trace files.

The first execution has elapsed time of 503.81 seconds.
The second execution has elapsed time of 29.70 seconds.

I am assuming that the second execution is so much quicker than the first because of cached data. But I do not understand why the tkprof report shows similar disk reads for both executions. I.e. first execution disk reads = 126865, second = 113832.

I expected to see far fewer disk reads in the second execution.

First execution of statement. Buffer flushed prior to execution.
********************************************************************************

SELECT NVL(SUM(QUANTITY),0)
FROM
 ORDTRAN WHERE TRSTCODE = :B6 AND UNITTYPE = :B5 AND INVCODE = :B4 AND ISSREP
  = 'I' AND NVL (REVERSED, 'N') = 'N' AND NVL(PROC,'N') = 'Y' AND NVL(CONVERT,
  'XX') != 'TO' AND ((NVL(:B3 ,'X') = 'N' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) =
   'M' AND NVL(:B2 ,'X') = SUBSTR(NVL(TRANSFER,'XX'),1,1)) OR (NVL(:B3 ,'X') =
   'S' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) = 'S' AND NVL(:B2 ,'X') =
  SUBSTR(NVL(TRANSFER,'XX'),1,1)) OR (NVL(:B3 ,'X') = 'X' AND NVL(:B2 ,'X') =
  'X' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) NOT IN ('M','S'))) AND
  ((NVL(CONVERT2,'X') NOT IN ('T','C','S') AND DEALDT > :B1 ) OR
  (NVL(CONVERT2,'X') IN ('T','C','S') AND INDATE > :B1 ))


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  19823      2.23       1.97          0          0          0           0
Fetch    19823     44.27     503.81     126865     431479          0       19823
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    39647     46.50     505.78     126865     431479          0       19823

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 60  (FCS)   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
  19823  SORT AGGREGATE (cr=431479 r=126865 w=0 time=503646087 us)
   2680   TABLE ACCESS BY INDEX ROWID ORDTRAN (cr=431479 r=126865 w=0 time=503528337 us)
 880292    INDEX RANGE SCAN ORDTRAN_STATS_IDX (cr=65020 r=8498 w=0 time=8356187 us)(object id 35512)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                    116370        0.06        471.52
  db file parallel read                        1286        0.03          2.39



********************************************************************************
Second execution of statement. Buffer NOT flushed prior to execution.
********************************************************************************

SELECT NVL(SUM(QUANTITY),0)
FROM
 ORDTRAN WHERE TRSTCODE = :B6 AND UNITTYPE = :B5 AND INVCODE = :B4 AND ISSREP
  = 'I' AND NVL (REVERSED, 'N') = 'N' AND NVL(PROC,'N') = 'Y' AND NVL(CONVERT,
  'XX') != 'TO' AND ((NVL(:B3 ,'X') = 'N' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) =
   'M' AND NVL(:B2 ,'X') = SUBSTR(NVL(TRANSFER,'XX'),1,1)) OR (NVL(:B3 ,'X') =
   'S' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) = 'S' AND NVL(:B2 ,'X') =
  SUBSTR(NVL(TRANSFER,'XX'),1,1)) OR (NVL(:B3 ,'X') = 'X' AND NVL(:B2 ,'X') =
  'X' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) NOT IN ('M','S'))) AND
  ((NVL(CONVERT2,'X') NOT IN ('T','C','S') AND DEALDT > :B1 ) OR
  (NVL(CONVERT2,'X') IN ('T','C','S') AND INDATE > :B1 ))


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute  19823      1.62       1.63          0          0          0           0
Fetch    19823     28.97      28.07     113832     430622          0       19823
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    39647     30.59      29.70     113832     430622          0       19823

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 60     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
  19823  SORT AGGREGATE (cr=430622 r=113832 w=0 time=27937352 us)
   2680   TABLE ACCESS BY INDEX ROWID ORDTRAN (cr=430622 r=113832 w=0 time=27840326 us)
 880292    INDEX RANGE SCAN ORDTRAN_STATS_IDX (cr=65020 r=5523 w=0 time=3738183 us)(object id 35512)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                    113146        0.01          3.55
  db file parallel read                         127        0.01          0.03
********************************************************************************

and Tom said...

the second physical IO's you did were not *true* physical IO's - they were physical IO's we submitted to the operating system and it read it not from disk the second time - but from the OS file system cache (you have a secondary SGA there - the file system cache).

http://asktom.oracle.com/pls/ask/search?p_string=%22secondary+sga%22

for more information there.


We cannot tell at the Oracle level if we did a 'true' physical IO or a 'fake one' from the file system cache - they look the same to us.


I will make a comment on your row source operation - whenever you see something like this:

   2680   TABLE ACCESS BY INDEX ROWID     <=== small number output
 880292    INDEX RANGE SCAN               <=== big number output


You know that you can make that perform radically better. Most of your IO is against the table. From the index we found 880,292 POSSIBLE rows (the index didn't have enough information to process more of the where clause). Out of the 880,292 POSSIBLE rows - a mere 2,680 of them were found to actually satisfy the where clause!!!

Now the first time you ran the query, you did 118,367 physical IO's against the table - if you ask me, the MOST you should have done is 2,680 (and probably FAR FAR fewer than that!) We should have found only 2,680 rows in the index and then would only have to go to the table that many times at most.


So, let's look at your query:

SELECT NVL(SUM(QUANTITY),0)
FROM
 ORDTRAN
WHERE TRSTCODE = :B6
  AND UNITTYPE = :B5
  AND INVCODE = :B4
  AND ISSREP = 'I'
  AND NVL (REVERSED, 'N') = 'N'
  AND NVL(PROC,'N') = 'Y'
  AND NVL(CONVERT, 'XX') != 'TO'
  AND (
      (NVL(:B3 ,'X') = 'N' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) = 'M' AND NVL(:B2 ,'X') = SUBSTR(NVL(TRANSFER,'XX'),1,1))    OR (NVL(:B3 ,'X') = 'S' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) = 'S' AND NVL(:B2 ,'X') = SUBSTR(NVL(TRANSFER,'XX'),1,1))    OR (NVL(:B3 ,'X') = 'X' AND NVL(:B2 ,'X') = 'X' AND SUBSTR(NVL(TRANSFER,'XX'),2,1) NOT IN ('M','S'))
      )
  AND (
      (NVL(CONVERT2,'X') NOT IN ('T','C','S') AND DEALDT > :B1 )
   OR (NVL(CONVERT2,'X') IN ('T','C','S') AND INDATE > :B1 )
      )



well, nvl(proc,'N') = 'Y' is the same as proc = 'Y', so get rid of that NVL()

nvl(:b3,'X') = 'N' is the same as :b3 = 'N' ....

in fact, review all of your NVL's, you don't need many of them (fear of null, sigh...)

SUBSTR(NVL(TRANSFER,'XX'),2,1) = 'M'

should just be

substr( transfer, 2, 1 ) = 'M' (if transfer were NULL, that will not evaluate to true - just like substr(nvl(),2,1) = 'M' would not evaluate to true)


But anyway, I don't know what your index is on currently, but if you indexed

trstcode,unittype,invcode,issrep,proc,nvl(reversed,'N')

we would be able to use that as the index key and probably would find far far fewer than 880,000 possible rows. Make the index more selective!




Rating

  (4 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

More questions :)

A reader, April 18, 2009 - 7:01 am UTC


Hi Tom,

Great insights there. Was just wondering why just the columns below:

trstcode,unittype,invcode,issrep,proc,nvl(reversed,'N')

Why not : CONVERT / CONVERT2 / TRANSFER / INDATE / DEALDT as well?

Thanks.


Tom Kyte
April 20, 2009 - 11:00 am UTC

because of the or's in there

but, if you still find that the index returns 100,000's of rows - and the table only returns 2,000 - then we would consider adding them so we can hit the index more and avoid the table altogether until we KNOW we need a row.

I just wanted to have things in the index initially that could be used to ACCESS() the data, we can add things to FILTER() the data as needed

Use of NVLs

Logan Palanisamy, April 21, 2009 - 7:07 pm UTC

Tom,

In the SQL above, isn't NVL(REVERSED, 'N') = 'N' the same as REVERSED IS NULL?

Tom Kyte
April 22, 2009 - 2:02 pm UTC

no, it is the same as

(reversed = 'N' or reversed is null)

thanks for the response

Neil Pither, April 22, 2009 - 2:08 pm UTC

Tom,

Thanks a lot for the answer regarding the secondary sga.
This explains the anomaly I am seeing in the tkprof reports. I.e. the disk reads seemingly so fast.

I will now proceed with caution when clearing the buffer cache and interpreting the results of the tkprof report.

I suppose, even without clearing the Oracle buffer cache this anomaly could arise. Unlikely though as, if data is not hot in the Oracle cache, it is unlikely to be hot in the OS cache.

With regard to the actual statement and the interpretation of the results, I realised that the number of rows returned by the index was excessive. I added the column INDATE to an existing index and this improved performance dramatically returning just 5270 rows in the range scan rather than 880,000.

Thanks also for your analysis and comments regarding the actual statement. This is very helpful.
Tom Kyte
April 24, 2009 - 4:26 pm UTC

... I will now proceed with caution when clearing the buffer cache ...

i would not bother clearing the cache (it'll never be empty in real life, just as fake to have it empty) unless you wanted to see the MAXIMUM number of physical IO's something might do - that would be the only use of that.


... I suppose, even without clearing the Oracle buffer cache this anomaly could
arise. ...

absolutely, happens all of the time. That is why the secondary sga links I pointed to often reference "raw versus cooked". Many people have heard "raw faster than cooked file systems", so they blindly switch over only to find "raw is slower", but it isn't that raw is slower but rather the cooked file system was using that secondary SGA and if they increased the size of their buffer cache, raw would have been faster.


venkat, January 19, 2010 - 2:48 am UTC

Hi Tom,

Could you please explain how the Disk and Query will impact and how to reduce these numbers. For my query These two are big in number.

Regards,
Venkat
Tom Kyte
January 19, 2010 - 4:46 pm UTC

well disk is physical IO, physical IO is not fast. a read from disk is slower than a read from cache (typically, not always, but typically)

query is a logical IO - a get from the buffer cache - that takes hundreds/thousands of cpu instructions and needs to get latches (locks) on the buffer cache so it can lead to contention and lots of cpu usage.

To reduce them, you tune. No one can give you a cookbook for that (if you want it to be automated, 10g has that capability - the sql tuning advisor, access advisor and the like all exist and tune your sql using thousands of rules).

For example, if your query is:

select * from big_table where some_column = 5;

then maybe tuning it would be "add an index on some_column"
or maybe tuning it would be "use parallel query"
or maybe tuning it would be "partition the data using list partitions on some_column"

and so on - you have to have a broad understanding of how things work - and then you can use that knowledge to intelligently apply one of the features of the database.

No shortcuts that I'm aware of.

read
http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:7381085186834

more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's latest video and Chris's latest video from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.

More to Explore

Performance

Get all the information about database performance in the Database Performance guide.