In my last
article, I discussed how to install Oracle's Statspack Utility; a free tool
for monitoring your Oracle database instance. That article also discussed how
to generate a Statspack Report. This article will help you interpret a lot of
the information you will find in a statspack report.
The beginning of the statspack report shows you some basic information about
your instance including the database name, instance name, DB ID, version, host
and the start and end times of the snapshots used in your report. Here is an
example:
STATSPACK report for
DB Name DB Id Instance Inst Num Release Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
ORCL 2586436430 ORCL 1 9.2.0.4.0 NO localhost
Snap Id Snap Time Sessions Curs/Sess Comment
------- ------------------ -------- --------- -------------------
Begin Snap: 4873 13-Dec-05 05:00:05 110 37.4
End Snap: 4875 13-Dec-05 07:00:04 651 203.7
Elapsed: 119.98 (mins)
The next section, Cache Sizes, shows you some of your instance settings including: Buffer Cache (DB_CACHE_SIZE), Standard Block Size (DB_BLOCK_SIZE),
Shared Pool Size (SHARED_POOL_SIZE), and Log Buffer (LOG_BUFFER). These are all instance parameters which you can modify in your spfile/pfile.
:
Cache Sizes (end)
~~~~~~~~~~~~~~~~~
Buffer Cache: 3,008M Std Block Size: 8K
Shared Pool Size: 1,920M Log Buffer: 10,240K
The "Load Profile" section shows you the load on your instance per second and per transaction. You can compare this section between two Statspack Reports to see
how the load on your instance is increasing or decreasing over time.
- Redo Size & Block Changes Increase: If you see an increase here then more DML statements are taking place (meaning your users are doing more INSERTs, UPDATEs, and DELETEs than before.
Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 352,535.71 8,517.66
Logical reads: 202,403.30 4,890.29
Block changes: 2,713.47 65.56
Physical reads: 44.22 1.07
Physical writes: 27.46 0.66
User calls: 787.32 19.02
Parses: 301.40 7.28
Hard parses: 0.05 0.00
Sorts: 317.78 7.68
Logons: 0.10 0.00
Executes: 2,975.84 71.90
Transactions: 41.39
% Blocks changed per Read: 1.34 Recursive Call %: 87.43
Rollback per transaction %: 27.56 Rows per Sort: 7.22
The "Instance Efficiency Percentages" section is very useful. It gives you an overview of your instance health. Anytime you make instance parameter changes
you should take a look to see if this affects your instance efficiency in any way. Here is a description of some of the fields
(Note, as stated in the statspack report, your goal here is to have these percentages be as close to 100% as possible):
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 99.98 In-memory Sort %: 100.00
Library Hit %: 100.04 Soft Parse %: 99.98
Execute to Parse %: 89.87 Latch Hit %: 94.99
Parse CPU to Parse Elapsd %: 75.19 % Non-Parse CPU: 99.46
This section is crucial in determining what some of the performance drains in your database are. It will actually tell you the amount
of time the instance spent waiting. Here are some common reasons for high wait events:
- DB file scattered read:
This can be seen fairly often. Usually, if this number is high, then it means there are a lot of full tablescans going on. This could be because you need indexes
or the indexes you do have are not not being used.
- DB file sequential read:
This could indicate poor joining orders in your SQL or waiting for writes to 'temp' space. It could mean that a lot of index reads/scans are going on.
Depending on the problem it may help to tune PGA_AGGREGATE_TARGET and/or DB_CACHE_SIZE.
- CPU Time:
This could be completely normal. However, if this is your largest wait event then it could mean that you have some CPU intensive SQL going on.
You may want to examine some of the SQL further down in the Statspack report for SQL statements that have large CPU Time.
- SQL*Net more data to client:
This means the instance is sending a lot of data to the client. You can decrease this time by having the client bring back less data.
Maybe the application doesn't need to bring back as much data as it is.
- log file sync:
A Log File Sync happens each time a commit takes place. If there are a lot of waits in this area then you may want to examine your application
to see if you are committing too frequently (or at least more than you need to).
- Logfile buffer space:
This happens when the instance is writing to the log buffer faster than the log writer process can actually write it to the redo logs. You could try getting faster disks
but you may want to first try increasing the size of your redo logs; that could make a big difference (and doesn't cost much).
- Logfile switch:
This could mean that your committed DML is waiting for a logfile switch to occur. Make sure your filesystem where your archive logs reside are not getting full.
Also, the DBWR process may not be fast enough for your system so you could add more DBWR processes or make your redo logs larger so log switches are not needed as much.
Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
db file sequential read 187,787 906 88.60
SQL*Net more data to client 49,707 57 5.55
CPU time 54 5.33
log file parallel write 1,011 2 .22
latch free 6,226 2 .16
-------------------------------------------------------------
The following sections show you the Top SQL (or 'worst performing' SQL) grouped by four sections: Buffer Gets, Disk Reads, Executions, and Parse Counts.
You'll want to review the top SQL statements in each of these sections to see if they can be tuned better. These sections are a great way to how many times the SQL is being executed,
how much CPU time is being used to execute them, and the total time for the statement to execute.
SQL ordered by Parse Calls for DB: ORCL Instance: ORCL Snaps: 4873 -4875
-> End Parse Calls Threshold: 1000
% Total
Parse Calls Executions Parses Hash Value
------------ ------------ -------- ----------
144,300 144,300 6.65 4199666855
Module: JDBC Thin Client
select parameter, value from nls_session_parameters
Note: If you take the hash value for the SQL statement, then
you run the ORACLE_HOME/rdbms/admin/sprepsql.sql script, and enter the hash value when it prompts you it will pull up the Execution Plan for that SQL statement.
Pretty Cool!
This section may provide some insight into some potential performance problems that were not as easily visible from previous sections in the report. This section
is also useful when comparing statspack reports from the same timeframes on different days.
These sections help give you some visibility into I/O rolled up to the tablespace level and I/O stats on your data files.
Tablespace IO Stats for DB: ORCL Instance: ORCL Snaps: 4873 -4875
->ordered by IOs (Reads + Writes) desc
Tablespace
------------------------------
Av Av Av Av Buffer Av Buf
Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms)
-------------- ------- ------ ------- ------------ -------- ---------- ------
UNDOTBS
146 0 5.8 1.0 117,119 16 50,681 1.3
APP1
19,395 3 10.5 1.0 32,613 5 1,886 2.8
INDEX1
36,919 5 0.7 6.3 977 0 526 5.0
APP2
6,969 1 11.7 1.0 13,559 2 2,513 2.5
SYSTEM
15,056 2 0.8 1.8 360 0 13 3.8
I hope this article helps you increase your ability to
interpret Statspack Reports as it is an extremely useful tool for the Oracle
DBA.
~ Troy Campano ~
|