Parse CPU to Parse Elapsd – What is Wrong with this Quote?

1 09 2011

September 1, 2011

I located another interesting statement in the “Oracle Database 11g Performance Tuning Recipes” book, so I thought that it was time for another blog article that takes a look at a statement from the book.  Chapter 4 of the book is significantly better written (much more accurate) than chapter 3.

To set the stage, let’s take a look at the “Instance Efficiency Percentages” section of two AWR reports that I have collected over the years:

Example #1:

Instance Efficiency Percentages
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
            Buffer  Hit   %:   27.89    In-memory Sort %:  100.00
            Library Hit   %:   91.32        Soft Parse %:   76.52
         Execute to Parse %:   30.71         Latch Hit %:  100.00
Parse CPU to Parse Elapsd %:   10.26     % Non-Parse CPU:   92.99 

Example #2:

Instance Efficiency Percentages
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
               Buffer Hit %:   99.89    In-memory Sort %:  100.00
              Library Hit %:   97.45        Soft Parse %:   97.79
         Execute to Parse %:   97.30         Latch Hit %:   95.31
Parse CPU to Parse Elapsd %:   79.21       Non-Parse CPU:   99.10  

For obvious reasons, it is not a desirable outcome to see that a large percentage of the CPU time consumed by a database instance is used for parsing.  Ideally, most of the CPU time would be consumed actually executing the SQL statements submitted by user sessions.

Now let’s take a look at the quote from Recipe 4-10 on page 133:

“The Parse CPU to Parse Elapsd metric shows how much time the CPU is spending parsing SQL statements. The lower this metric is, the better. In the following example [not quoted], it is about 2%, which is very low. If this metric ever gets to 5%, it may mean investigation is warranted to determine why the CPU is spending this much time simply parsing SQL statements.”

What, if anything, is wrong with the above quote from the book?

The point of blog articles like this one is not to insult authors who have spent thousands of hours carefully constructing an accurate and helpful book, but instead to suggest that readers investigate when something stated does not exactly match what one believes to be true.  It could be that the author “took a long walk down a short pier”, or that the author is revealing accurate information which simply cannot be found through other resources (and may in the process be directly contradicting information sources you have used in the past).  If you do not investigate in such cases, you may lose an important opportunity to learn something that could prove to be extremely valuable.


Actions

Information

13 responses

1 09 2011
Chris Saxon

It’s my understanding that the Parse CPU to Parse Elapsd metric shows how much of the total parse time was spent on CPU. So ideally you’d like this figure to be close to 100%; each percentage drop below this is time you’re spending waiting for something which will slow your parse times. The 2% figure would represent almost the worst case you could have!

The quote appears to suggest that the metric is showing what percentage of your total CPU time was devoted to parsing – if this were the case then lower figures would be better.

2 09 2011
Michael Milligan

I believe Chris is correct. To put it another way, the Parse CPU represents just that, the time spent actually parsing. The Parse Elapsd time represents the sum of 1 – CPU time and 2 – wait time. If the Parse CPU to Parse Elapsd is 100%, that means the CPU time was equal to the total time, meaning there was no wait time at all.

Michael Milligan
Layton, Utah

2 09 2011
Ahmed AANGOUR

2% ?
The quote shows that the CPU time is taking almost none of the total elapsed time for parsing. The elapsed parse time is likely being spent in waits.

2 09 2011
Tony Sleight

Parse CPU to Parse Elapsed is a ratio, so I infer it is the ratio between parse time CPU resource and parse elapsed time. Therefore best case is when ratio = 1 i.e. CPU parse time is the elapsed time. If we talk in seconds and CPU parse = 1, and elapsed = 2, then ratio would be 1/2 = 50%. If CPU = 1 and elapsed = 3, ratio = 1/3 = 33%. So a ratio of 2% = 0.02 = 1/50 which would suggest that 1 second of CPU parse = 50 seconds of elapsed parse time, so 49 seconds of elapsed time must have been spent waiting on something else. So, the figures quoted refer to the value of 1 – Parse CPU to Parse elapsed.

2 09 2011
Log Buffer #236, A Carnival of the Vanities for DBAs | The Pythian Blog

[...] Charles Hooper‘s analytical eye is still on “Oracle Database 11g Performance Tuning Recipes“ book. [...]

2 09 2011
Charles Hooper

I will post my soon to be finialized book review comment for Recipe 4-10 a bit later. So far, the comments attached to this blog article are (quite) a bit more clear and precise than what I have in the book review for this recipe (I would prefer that the review not stretch to 20+ pages).

Take another look at the description provided in the quote, and take a closer look at the Non-Parse CPU statistic in the Instance Efficiency Percentages samples.

Is there anything else about the statistics in this section of an AWR/Statspack Report that might be useful? How about the Buffer Hit %?

2 09 2011
Houri Mohamed

If Parse CPU to Parse Elapsd metric equals 2% then this means that for every CPU second spent parsing we spent about 100/2= 50 seconds wall clock time parsing. Ideally we would not spend time waiting for something and hence the metric should show 100%. This fact is already indicated in the AWR Instance Efficiency Percentages (Target 100%).

However, Jonathan Lewis wrote a blog article warning us about jumping to conclusion when using the Instance Efficiency Percentage without considering at least the load profile and, particularly, its “per second” figures

http://jonathanlewis.wordpress.com/2006/12/27/analysing-statspack-2/

2 09 2011
Charles Hooper

Mohamed,

Nice find for a blog article that directly references the Parse CPU to Parse Elapsd metric. You probably noticed that I intentionally erased the “(Target 100%)” from the posted sample Instance Efficiency Percentages sections that are included in this blog article – just to see if anyone would notice.

I thought for sure that someone would provide a link to AskTom. I found the following thread link yesterday:

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

In the above thread is the following Instance Efficiency Percentages output:

Buffer Nowait %:             99.98    Redo NoWait %:    100.00 
Buffer Hit %:                99.91    In-memory Sort %:  99.88 
Library Hit %:               99.89    Soft Parse %:      99.23 
Execute to Parse %:          75.94    Latch Hit %:       99.94 
Parse CPU to Parse Elapsd %:  0.00    % Non-Parse CPU:   93.89 

According to the quote from the book, the above Parse CPU to Parse Elapsd metric would be infinitely better than either of the two sample Instance Efficiency Percentages sections that I included in the blog article. :-)

5 09 2011
Dom Brooks

There was a bug in 11gR1 reporting that ratio incorrectly as 0.00%.
See http://orastory.wordpress.com/2008/05/16/bug-in-11g-awr-report/

5 09 2011
Charles Hooper

Dom,

Thank you for solving that mystery… 3 years before the question was asked on AskTom.

3 09 2011
Charles Hooper

Chris, Michael, Ahmed, Tony, and Mohamed – very good answers and together will provide a lot of help to readers of this book. This blog article and the attached comments are just another example of an error in a book being reworked into an opportunity for learning.

As promised, my explanation that will appear in the formal book review:

Recipe 4-10 incorrectly states that the “Parse CPU to Parse Elapsd” statistic found in an AWR report is “how much time the CPU is spending parsing SQL statements…” The book’s definition of this statistic is incorrect – the statistic actually indicates delays (wait events) in the parsing of SQL statements, very likely due to contention between sessions (or possibly excessive competition for the server’s CPUs, however such competition probably would not be captured in an Oracle wait event). Ideally, this statistic in an AWR report should be close to 100%. It appears that the book authors attempted to describe the “PARSE TIME CPU” statistic, which is not found in this section of an AWR report, or attempted to describe a derivative of the “Non-Parse CPU” statistic which does appear in the Instance Efficiency Percentages section of an AWR report (page 133-134).

11 07 2012
Paul

I think “however such competition probably would not be captured in an Oracle wait event” IMO needs a little clarifying..

Millsap teaches that CPU starvation causes inflated wait times [ the waiting session not only waits for event completion as usual, but also must wait longer for its turn on CPU which can inflate the wait time ( WILL inflate the wait time on a CPU starved system ) ], however in support of your statement, a session that is trying to get a latch can also spend significant CPU time spinning between latch waits, which time would not be recorded in any wait event.

Thanks for this blog..

11 07 2012
Charles Hooper

Paul,

Nice catch. Yes, clarification was necessary, thanks.

On a CPU starved server, db file sequential read waits (along with other waits) will very likely require longer to complete. Cary Millsap’s book also essentially mentioned that the log file sync wait event is one of the first wait events that shows signs of CPU starvation. The second half of your statement is what I was trying to state – the spin while trying to acquire a latch consumes CPU cycles, but the time in the spin will not be registered to a wait event.

Your comment demonstrates one of the benefits of this blog – readers of the blog help to improve the clarity (and occasionally accuracy) of the articles, and occasionally take the articles into an interesting, tangent topic.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s




Follow

Get every new post delivered to your Inbox.

Join 142 other followers

%d bloggers like this: