High CPU usage on Oracle RAC invistigation with statspack

First lets look at the STATSPACK report:

DB Name DB Id Instance Inst Num Release Cluster Host
———— ———– ———— ——– ———– ——- ————
TEST 1946821013 TEST1 1 9.2.0.4.0 YES aix8u

Elapsed: 38.45 (mins)

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 98.41 Redo NoWait %: 100.00
Buffer Hit %: 98.38 In-memory Sort %: 100.00
Library Hit %: 97.50 Soft Parse %: 84.46
Execute to Parse %: 91.38 Latch Hit %: 96.71
Parse CPU to Parse Elapsd %: 0.32 % Non-Parse CPU: 100.00

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
——————————————– ———— ———– ——–
CPU time 42,809,678 99.94
db file sequential read 14,141,257 7,630 .02
global cache cr request 15,123,911 5,551 .01
buffer busy global CR 6,848,421 4,729 .01
buffer busy waits 7,078,849 3,161 .01
————————————————————-

LOOK FOR RESOURCE INTENSIVE SQL STATEMENTS

In our database, CPU time accounted for 99.94% of elapse time and can be easily identified as a problem area.

Response Time Analysis shows that heaviest time consumer is CPU-related e.g. CPU Other or CPU Parse time or an I/O-related Wait Event e.g. db file sequential read or db file scattered read:

Response Time = Service Time + Wait Time

where Service Time = time spent on the CPU
Wait Time = the sum of time spent on Wait Events

Service Time is comprised of time spent on the CPU for Parsing, Recursive CPU usage (for PLSQL and recursive SQL) and CPU used for execution of SQL statements (CPU Other).

Service Time = CPU Parse + CPU Recursive + CPU Other

where: Service Time = CPU used by this session
CPU Parse = parse time cpu
CPU Recursive = recursive cpu usage

Hence:
CPU other = CPU used by this session – parse time cpu – recursive cpu usage

So in our case:

Instance Activity Stats for DB: TEST Instance: TEST1 Snaps: 19 -20
Statistic Total per Second per Trans
——————————— —————— ————– ————
CPU used by this session 4,280,967,783 1,855,642.7 3,055,651.5
CPU used when call started 223,988 97.1 159.9
parse time cpu 105 0.1 0.1
recursive cpu usage 378,500 164.1 270.2

CPU Other = 4,280,967,783 – 105 – 378,500 = 4,280,589,178 cs
As a percentage:
CPU Other = 4,280,589,178 /4,280,967,783 x99.94 = 99.93%

When CPU Other is a significant component of total Response Time the next step is to find the SQL statements that access the most blocks. Block accesses are also known as Buffer Gets and Logical I/Os.

Note:
- Many DBAs feel that if the data is already contained within the buffer cache the query should be efficient. This could not be further from the truth. Retrieving more data than needed, even from the buffer cache, requires CPU cycles and interprocess IO. Generally speaking, the cost of physical IO is not 10,000 times more expensive. It actually is in the neighborhood of 67 times and actually almost zero if the data is stored in the UNIX buffer cache.

- The statements of interest are those with a large number of gets per execution especially if the number of executions is high.

- High buffer gets generally correlates with heavy CPU usage.

FINDING SQL WITH HIGH CPU OTHER TIME IN STATSPACK

Statspack lists such SQL statements in section SQL ordered by Gets. This section reports the contents of the SQL area ordered by the number of buffer gets and can be used to identify CPU Heavy SQL.

In our case, one of the query is:

SQL ordered by Gets for DB: TEST Instance: TEST1 Snaps: 19 -20
CPU Elapsd
Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value
————— ———— ————– —— ——– ——— ———-
120,631,026 8 15,078,878.3 13.8 767.14 4078.69 3737585952

Find all the queries that accounts for more than 5% of the total gets and verify their query plan. This should serve as a good starting point of a tuning session.

If you enjoyed this post, please consider leaving a comment or subscribing to the RSS feed to have future articles delivered to your feed reader.
Leave a comment

0 Comments.

Leave a Reply

You must be logged in to post a comment.