RE: Parsing Problem - I think

From: Jonathan Lewis <>
Date: Fri, 28 Mar 2014 09:15:04 +0000
Message-ID: <CE70217733273F49A8A162EE074F64D901DE64DC_at_exmbx05.thus.corp>

So this statement appears to be responsible for less than 9% of your total CPU usage, and less than 25% of the CPU usage captured in SQL statements.

Take a closer look at the CPU intensive statements; have a look at the "parse" statistics in the "Instance Activity", and start doing some regular checks through v$sql or v$sqlstats etc. for statements which are CPU intensive for a while and then disappear.

I think it's reasonably likely that you have a CPU utilisation problem, and the nature of our work means your CPUs behave more like 4 than 32 - with the side effect that you see lots of time wasted on spinning and queueing

Jonathan Lewis

Jonathan Lewis

From: [] on behalf of Fred Tilly [] Sent: 28 March 2014 08:26
Subject: Re: Parsing Problem - I think


The summary shows for SQL ordered by CPU:

  • Captured SQL account for 36.7% of Total CPU Time (s): 22,086
  • Captured PL/SQL account for 0.2% of Total CPU Time (s): 22,086



From: Jonathan Lewis <> To: Fred Tilly <>; "" <> Sent: Thursday, 27 March 2014, 11:54
Subject: RE: Parsing Problem - I think

Please send replies through oracle-l

This statement alone doesn't look as if it's responsible for the CPU starvation - but it may be one of several, and there may be others that disappear from the library cache between snapshots. Check the summary figures for the section (if they exist) showing what percentage has been captured.

Since you've got some stats you've got the SQL in the AWR, even when you don't report the buffer gets, so you can run off the awrsqrpt.sql script (or use the OEM drill down) to get the full stats and variant plans if there are any for the period when the query does much less work.

Jonathan Lewis

From: Fred Tilly [] Sent: 27 March 2014 11:46
To: Jonathan Lewis
Subject: Re: Parsing Problem - I think

Hi Jonathan,

Thanks for looking at this. I was convinced it was a parsing problem.

I have looked at the highest sql in terms of CPU utilization and the details are below

CPU Time (s)    Executions      CPU per Exec (s)        %Total  Elapsed Time (s)        %CPU    %IO     SQL Id  SQL Module      SQL Text
1,945.27        3,615   0.54    8.81    2,938.09
        66.21   0.00    38bgfuur8mv7t<UrlBlockedError.aspx>

If I look at when the system is performing normally the same sql has

CPU Time (s) Executions CPU per Exec (s) %Total Elapsed Time (s) %CPU %IO SQL Id SQL Module SQL Text 72.35 3,287 0.02 1.86 72.97 100.51 0.00 38bgfuur8mv7t<UrlBlockedError.aspx>

My cpu per exec has increased dramtically.

Normally I would then look at the gets and on the poor performance report it shows

Buffer Gets     Executions      Gets per Exec   %Total  Elapsed Time (s)        %CPU    %IO     SQL Id  SQL Module      SQL Text
592,696 3,615   163.95  0.89    2,938.09        66.2    0       38bgfuur8mv7t<UrlBlockedError.aspx>

To me 163 gets per execution is not high.

The good awr report does not show the gets for the statement.



From: Jonathan Lewis <> To: Fred Tilly <> Cc:
Sent: Thursday, 27 March 2014, 9:04
Subject: Re: Parsing Problem - I think

So CORES=4 and CPUs = 8, and load at end of period = 8.

I'm always cautious about trusting the capacity of multi-threading CPUs, and with your figures and symptoms I'd spend a little time looking at "SQL ordered by CPU" to see if the latch/mutex/library cache problem was a side effect of CPU starvation due to CPU-intensive SQL.


Jonathan Lewis

Author: Oracle Core (Apress 2011)

  • Original Message ----- From: "Fred Tilly" <<>> To: <<>> Sent: Tuesday, March 25, 2014 2:02 PM Subject: Re: Parsing Problem - I think

Hi Jonathan,

Here is what the OS Stats say.

Operating System Statistics
* *TIME statistic values are diffed. All others display actual values. End Value is displayed if different
* ordered by statistic type (CPU Use, Virtual Memory, Hardware Config), Name
End Value


BUSY_TIME 2,740,786
IDLE_TIME 8,659,884
SYS_TIME 2,306,362
USER_TIME 434,424
LOAD 1 8
OS_CPU_WAIT_TIME 1,920,500
VM_IN_BYTES 65,536



From: Jonathan Lewis <<>> To: "<>" <<>> Sent: Tuesday, 25 March 2014, 13:24
Subject: RE: Parsing Problem - I think

Your "non-hard" parse time look pretty high given the small number of "soft" parses you are doing, so the first thing I'd do is look at the number of CPU cores you actually have. It's possible that you're multi-threading on a much smaller number of cores than Oracle is reporting as "CPUs" - with the result that an parse contention (latches, mutexes) is being exaggerated as soon as the CPU load gets anywhere near the number of cores.

What does the full set of OS Stats" look like ?

Jonathan Lewis<>

From:<> [<>] on behalf of Fred Tilly [<>] Sent: 25 March 2014 12:29
To:<> Subject: Parsing Problem - I think

Hi All,

Looking at an AWR report from a customer site where they have had some very slow performance.

Server is 32 CPU and 26GB running Oracle

AWR is over 1 hour and shows:

Parses: 22.6 0.5
Hard parses: 5.1 0.1

Elapsed: 59.37 (mins)
DB Time: 587.12 (mins)

Buffer Nowait %: 100.00 Redo NoWait %: 100.00 Buffer Hit %: 99.91 In-memory Sort %: 100.00 Library Hit %: 94.89 Soft Parse %: 77.60 Execute to Parse %: 92.71 Latch Hit %: 99.95 Parse CPU to Parse Elapsd %: 57.49 % Non-Parse CPU: 54.03

Top 5 Timed Foreground Events
Avg wait (ms)
% DB time
Wait Class
DB CPU 22,086 62.70
cursor: pin S wait on X 12 705 58760 2.00 Concurrency log file sync 142,183 469 3 1.33 Commit
db file sequential read 48,259 155 3 0.44 User I/O buffer busy waits 2,144 129 60 0.37 Concurrency

Statistic Name
Time (s)
% of DB Time
DB CPU 22,086.13 62.70
parse time elapsed 19,559.05 55.52
hard parse elapsed time 18,490.89 52.49
sql execute elapsed time 15,126.32 42.94

From the information in the AWR report I do not appear to be parsing a lot of statements per second, but my hard parse time seems really high.

What else do I need to look at to get to the bottom of this issue.



No virus found in this message.
Checked by AVG -
Version: 2014.0.4354 / Virus Database: 3722/7247 - Release Date: 03/25/14
Received on Fri Mar 28 2014 - 10:15:04 CET

Original text of this message