Oracle Consulting Oracle Training Oracle Support Development
Home
Catalog
Oracle Books
SQL Server Books
IT Books
Job Interview Books
eBooks
Rampant Horse Books
911 Series
Pedagogue Books

Oracle Software
image
Write for Rampant
Publish with Rampant
Rampant News
Rampant Authors
Rampant Staff
 Phone
 800-766-1884
Oracle News
Oracle Forum
Oracle Tips
Articles by our Authors
Press Releases
SQL Server Books
image
image

Oracle 11g Books

Oracle tuning

Oracle training

Oracle support

Remote Oracle

STATSPACK Viewer

Privacy Policy

 

 
 

Oracle response time analysis

Article by Rampant author Robin Schumacher

Historically, in trying to achieve maximum database performance, Oracle DBAs and performance analysts have fought an uphill battle to obtain solid response time metrics for system as well as user session activity. The problem facing DBAs has always had two facets: first, determining exactly "where" the database or user sessions have been spending their time; and second, determining the objective nature of the user experience.

Fortunately, those Oracle DBAs who have upgraded to Oracle Database 10g will find major response-time enhancements that allow a much better picture to be presented about system and session-level response-time metrics. Most significantly, the Oracle Automatic Database Diagnostic Monitor (ADDM) provides insights into response times and much more by automatically analyzing collected statistics, identifying problem areas, and even providing recommendations through the Oracle Enterprise Manager Grid Control GUI.

Furthermore, and most relevant to our discussion here, historical mechanisms in Oracle Database 10g allow DBAs to look back in time to perform their own response-time trend analysis, which helps them determine peak and nonpeak transaction/system times as well as locate rogue processes and SQL that elongate batch cycles or ETL jobs.

Starting at the global or system level, DBAs typically want answers to these questions:

- In general, how well is my database running? What defines efficiency?
- What average response time are my users experiencing?
- Which activities affect overall response time the most?

The answers to these questions have been fairly elusive for DBAs before Oracle Database 10g, but now such metrics can be somewhat easy to capture if you happen to be using the latest and greatest Oracle database. First of all, part of the answer to how well, in general, a database is running can be obtained by issuing this query in Oracle Database 10g:

select METRIC_NAME,
VALUE
from SYS.V_$SYSMETRIC
where METRIC_NAME IN ('Database CPU Time Ratio',
'Database Wait Time Ratio') AND
INTSIZE_CSEC =
(select max(INTSIZE_CSEC) from SYS.V_$SYSMETRIC);

METRIC_NAME                    VALUE
------------------------------ ----------
Database Wait Time Ratio         6
Database CPU Time Ratio         94


The Oracle Database 10g V$SYSMETRIC view contains several excellent response-time metrics, two of which are the Database Wait Time Ratio and Database CPU Time Ratio. The query above shows the latest snapshot of these two statistics, which help you determine if your database is currently experiencing a high percentage of waits/bottlenecks vs. smoothly running operations. The Database CPU Time Ratio is calculated by dividing the amount of CPU expended in the database by the amount of "database time," which is defined as the time spent by the database on user-level calls (with instance background process activity being excluded). High values (90-95+ percent) are good and indicate few wait/bottleneck actions, but take this threshold only as a general rule of thumb because every system is different.

You can also take a quick look over the last hour to see if the database has experienced any dips in overall performance by using this query:


select end_time,
value
from sys.v_$sysmetric_history
See code depot for more Schumacher scripts 
where metric_name = 'Database CPU Time Ratio'
order by 1;

END_TIME             VALUE
-------------------- ----------
22-NOV-2004 10:00:38   98
22-NOV-2004 10:01:39   96
22-NOV-2004 10:02:37   99
22-NOV-2004 10:03:38  100
22-NOV-2004 10:04:37   99
22-NOV-2004 10:05:38   77
22-NOV-2004 10:06:36  100
22-NOV-2004 10:07:37   96
22-NOV-2004 10:08:39  100
.

.

And, you can get a good idea of the minimum, maximum, and average values of overall database efficiency by querying the V$SYSMETRIC_SUMMARY view with a query such as this:


select CASE METRIC_NAME
WHEN 'SQL Service Response Time' then 'SQL Service Response Time (secs)'
WHEN 'Response Time Per Txn' then 'Response Time Per Txn (secs)'
ELSE METRIC_NAME
END METRIC_NAME,
CASE METRIC_NAME
WHEN 'SQL Service Response Time' then ROUND((MINVAL / 100),2)
WHEN 'Response Time Per Txn' then ROUND((MINVAL / 100),2)
ELSE MINVAL
END MININUM,
CASE METRIC_NAME
WHEN 'SQL Service Response Time' then ROUND((MAXVAL / 100),2)
WHEN 'Response Time Per Txn' then ROUND((MAXVAL / 100),2)
ELSE MAXVAL
END MAXIMUM,
CASE METRIC_NAME
WHEN 'SQL Service Response Time' then ROUND((AVERAGE / 100),2)
WHEN 'Response Time Per Txn' then ROUND((AVERAGE / 100),2)
ELSE AVERAGE
END AVERAGE
from SYS.V_$SYSMETRIC_SUMMARY
See code depot for more Schumacher scripts
where METRIC_NAME in ('CPU Usage Per Sec',
'CPU Usage Per Txn',
'Database CPU Time Ratio',
'Database Wait Time Ratio',
'Executions Per Sec',
'Executions Per Txn',
'Response Time Per Txn',
'SQL Service Response Time',
'User Transaction Per Sec')
ORDER BY 1


METRIC_NAME                    MINIMUM    MAXIMUM    AVERAGE
------------------------------ ---------- ---------- ----------
CPU Usage Per Sec                       0          7       1
CPU Usage Per Txn                       1         29       8
Database CPU Time Ratio                61        100      94
Database Wait Time Ratio                0         39       5
Executions Per Sec                      2         60       8
Executions Per Txn                     16        164      41
Response Time Per Txn (secs)            0           .28     .08
SQL Service Response Time (sec          0          0       0
User Transaction Per Sec                0          1       0


The query above contains more response-time metrics than simply the Database CPU and Wait Time Ratios (we'll cover those later), but you can see the benefit in being able to acquire this information. For this particular instance, the average Database CPU Time Ratio is 94, which is well within our acceptable limits.


The next question DBAs pose at the system level involves the average level of response time that their user community is experiencing. (Prior to Oracle Database 10g this type of data was difficult to capture, but not anymore.) The query shown above that interrogates the V$SYSMETRIC_SUMMARY view tells us what we need to know.

If, however, response times are longer than desired, the DBA will then want to know what types of user activities are responsible for making the database work so hard. Again, before Oracle Database 10g, this information was more difficult to acquire, but now the answer is only a query away:

select case db_stat_name
when 'parse time elapsed' then
'soft parse time'
else db_stat_name
end db_stat_name,
case db_stat_name
when 'sql execute elapsed time' then
time_secs - plsql_time
when 'parse time elapsed' then
time_secs - hard_parse_time
else time_secs
end time_secs,
case db_stat_name
when 'sql execute elapsed time' then
round(100 * (time_secs - plsql_time) / db_time,2)
when 'parse time elapsed' then
round(100 * (time_secs - hard_parse_time) / db_time,2)
else round(100 * time_secs / db_time,2)
end pct_time
from
See code depot for more Schumacher scripts
(select stat_name db_stat_name,
round((value / 1000000),3) time_secs
from sys.v_$sys_time_model
where stat_name not in('DB time','background elapsed time',
'background cpu time','DB CPU')),
(select round((value / 1000000),3) db_time
from sys.v_$sys_time_model
where stat_name = 'DB time'),
(select round((value / 1000000),3) plsql_time
from sys.v_$sys_time_model
where stat_name = 'PL/SQL execution elapsed time'),
(select round((value / 1000000),3) hard_parse_time
from sys.v_$sys_time_model
where stat_name = 'hard parse elapsed time')
order by 2 desc;


DB_STAT                       TIME_SECS PCT_TIME
----------------------------- --------- --------
sql execute elapsed time       13263.707 45.84
PL/SQL execution elapsed time  13234.738 45.74
hard parse elapsed time         1943.687  6.72
soft parse time                  520.584  1.8

.
The example output above shows a database that has spent the vast majority of its time handling SQL and PL/SQL requests.

In addition to active time, a DBA will want to know the global wait times as well. Prior to Oracle Database 10g, a DBA had to view individual wait events to understand waits and bottlenecks, but now Oracle provides a summary/rollup mechanism for waits via wait classes:

select WAIT_CLASS,
TOTAL_WAITS,
round(100 * (TOTAL_WAITS / SUM_WAITS),2) PCT_WAITS,
ROUND((TIME_WAITED / 100),2) TIME_WAITED_SECS,
round(100 * (TIME_WAITED / SUM_TIME),2) PCT_TIME
from
(select WAIT_CLASS,
TOTAL_WAITS,
TIME_WAITED
from V$SYSTEM_WAIT_CLASS
See code depot for more Schumacher scripts
where WAIT_CLASS != 'Idle'),
(select sum(TOTAL_WAITS) SUM_WAITS,
sum(TIME_WAITED) SUM_TIME
from V$SYSTEM_WAIT_CLASS
where WAIT_CLASS != 'Idle')
order by 5 desc;

 

WAIT_CLASS      TOTAL_WAITS PCT_WAITS TIME_WAITED_SECS PCT_TIME
--------------- ----------- ---------- ---------------- ----------
User I/O        2245204           7.48    4839.43       54.39
System I/O      2438387           8.12    2486.21       27.94
Application      920385           3.07     513.56        5.77
Other             39962            .13     422.36        4.75
Commit           200872            .67     284.76        3.2
Network        24133213             80.38  162.26        1.82
Concurrency        6867            .02     102.63        1.15
Configuration     39377            .13      86.21         .97

It's much easier to tell now that the bulk of overall wait time is due, for example, to user I/O waits than to try to tally individual wait events to get a global picture. As with response-time metrics, you can also look back in time over the last hour with a query like this one:


select to_char(a.end_time,'DD-MON-YYYY HH:MI:SS') end_time,
b.wait_class,
round((a.time_waited / 100),2) time_waited
from
See code depot for more Schumacher scripts
   sys.v_$waitclassmetric_history a,
   sys.v_$system_wait_class       b
where
   a.wait_class# = b.wait_class#
and
   b.wait_class != 'Idle'
order by 1,2;



END_TIME             WAIT_CLASS      TIME_WAITED
-------------------- --------------- -----------
22-NOV-2004 11:28:37 Application            0
22-NOV-2004 11:28:37 Commit                  .02
22-NOV-2004 11:28:37 Concurrency            0
22-NOV-2004 11:28:37 Configuration          0
22-NOV-2004 11:28:37 Network                 .01
22-NOV-2004 11:28:37 Other                  0
22-NOV-2004 11:28:37 System I/O              .05



You can, of course, just focus on a single SID with the V$SESS_TIME_MODEL view and obtain data for all statistical areas of a session. You can also view current session wait activity using the new wait classes using the following query:


select
   a.sid,
   b.username,
   a.wait_class,
   a.total_waits,
   round((a.time_waited / 100),2) time_waited_secs
from
See code depot for more Schumacher scripts
   sys.v_$session_wait_class a,
   sys.v_$session b
where
   b.sid = a.sid
and
   b.username is not null
and
   a.wait_class != 'Idle'
order by 5 desc;

SID USERNAME   WAIT_CLASS TOTAL_WAITS TIME_WAITED_SECS
--- ---------- --------------- ----------- ----------------
257 SYSMAN     Application          356104    75.22
255 SYSMAN     Commit                14508    25.76
257 SYSMAN     Commit                25026    22.02
257 SYSMAN     User I/O              11924    19.98



After this stage, you can check the standard individual wait events as you've been able to do in earlier versions of Oracle with V$SESSION_WAIT and V$SESSION_EVENT. You'll also find the new wait classes in these two modified views with Oracle Database 10g.
If you need to look back in time to discover what sessions were logged on and consuming the most resources, you can use the following query. In the example below, we're looking at activity from midnight to 5 a.m. on November 21, 2004, that involved user I/O waits:

select
   sess_id,
   username,
   program,
   wait_event,
   sess_time,
   round(100 * (sess_time / total_time),2) pct_time_waited
from
(select a.session_id sess_id,
decode(session_type,'background',session_type,c.username) username,
a.program program,
b.name wait_event,
sum(a.time_waited) sess_time
from sys.v_$active_session_history a,
sys.v_$event_name b,
sys.dba_users c
where
See code depot for more Schumacher scripts
a.event# = b.event# and
a.user_id = c.user_id and
sample_time > '21-NOV-04 12:00:00 AM' and
sample_time < '21-NOV-04 05:00:00 AM' and
b.wait_class = 'User I/O'
group by a.session_id,
decode(session_type,'background',session_type,c.username),
a.program,
b.name),
(select sum(a.time_waited) total_time
from sys.v_$active_session_history a,
sys.v_$event_name b
where a.event# = b.event# and
sample_time > '21-NOV-04 12:00:00 AM' and
sample_time < '21-NOV-04 05:00:00 AM' and
b.wait_class = 'User I/O')
order by 6 desc;

SESS_ID USERNAME PROGRAM    WAIT_EVENT                SESS_TIME PCT_TIME_WAITED
------- -------- ---------- ------------------------- ---------- -------------
242     SYS      exp@RHAT9K db file scattered read       3502978   33.49
242     SYS      oracle@RHA db file sequential read      2368153   22.64
242     SYS      oracle@RHA db file scattered read       1113896   10.65
243     SYS      oracle@RHA db file sequential read       992168    9.49


The Oracle Database 10g V$ACTIVE_SESSION_HISTORY view comes into play here to provide an insightful look back in time at session experiences for a given time period. This view gives you a lot of excellent information without the need for laborious tracing functions. We'll see more use of it in the next section, which deals with analyzing the response times of SQL statements.


SQL Response-Time Analysis

Examining the response time of SQL statements became easier in Oracle9i, and with Oracle Database 10g, DBAs have many tools at their disposal to help them track inefficient database code.

Historically the applicable V$ view here has been V$SQLAREA. Starting with Oracle9i, Oracle added the ELAPSED_TIME and CPU_TIME columns, which have been a huge help in determining the actual end user experience of a SQL statement execution (at least, when dividing them by the EXECUTIONS column, which produces the average amount of time per execution).

In Oracle Database 10g, six new wait-related and timing columns have been added to V$SQLAREA:

APPLICATION_WAIT_TIME
CONCURRENCY_WAIT_TIME
CLUSTER_WAIT_TIME
USER_IO_WAIT_TIME
PLSQL_EXEC_TIME
JAVA_EXEC_TIME

The new columns are helpful in determining, for example, the amount of time that a procedure spends in PL/SQL code vs. standard SQL execution, and if a SQL statement has experienced any particular user I/O waits. For example, a query you could use to find the top five SQL statements with the highest user I/O waits would be:


select *
from
(select
     sql_text,
     sql_id,
     elapsed_time,
     cpu_time,
     user_io_wait_time
  from
see code depot for full script 
     sys.v_$sqlarea
  order by 5 desc)
where rownum < 6;

SQL_TEXT                  SQL_ID       ELAPSED_TIME CPU_TIME  USER_IO_WAIT_TIME
------------------------- ------------ ------------ ---------- ---------------
select /*+ rule */ bucket db78fxqxwxt7 47815369     19000939              3423
SELECT :"SYS_B_0" FROM SY agdpzr94rf6v 36182205     10170226              2649
select obj#,type#,ctime,m 04xtrk7uyhkn 28815527     16768040              1345
select grantee#,privilege 2q93zsrvbdw4 28565755     19619114               803
select /*+ rule */ bucket 96g93hntrzjt 9411028       3754542               606


Of course, getting the SQL statements with the highest elapsed time or wait time is good, but you need more detail to get to the heart of the matter—which is where the V$ACTIVE_SESSION_HISTORY view again comes into play. With this view, you can find out what actual wait events delayed the SQL statement along with the actual files, objects, and object blocks that caused the waits (where applicable).

For example, let's say you've found a particular SQL statement that appears to be extremely deficient in terms of user I/O wait time. You can issue the following query to get the individual wait events associated with the query along with the corresponding wait times, files, and objects that were the source of those waits:

select
   event,
   time_waited,
   owner,
   object_name,
   current_file#,
   current_block#
from
see code depot for full script
   sys.v_$active_session_history a,
   sys.dba_objects b
where
   sql_id = '6gvch1xu9ca3g'
and
   a.current_obj# = b.object_id
and
   time_waited <> 0;

EVENT                      TIME_WAITED OWNER  OBJECT_NAME          file block
------------------------- ----------- ------ --------------------- ---- ------
db file sequential read          27665 SYSMAN MGMT_METRICS_1HOUR_PK    3 29438
db file sequential read           3985 SYSMAN SEVERITY_PRIMARY_KEY     3 52877


Of course, you can use V$ACTIVE_SESSION_HISTORY in a historical fashion to narrow down un-optimized SQL statements for a particular time period. The point is that Oracle Database 10g makes it a lot easier to conduct response-time analysis on SQL statements with simplified data dictionary views, as opposed to the time-consuming trace-and-digest method.
Conclusion

DBAs and performance analysts who manage the performance of Oracle Database 10g will find many of the response-time metrics they've yearned for over the years now at their fingertips in the latest release of Oracle's flagship database. Such statistics will help accelerate the process of finding the proverbial needle in the haystack of large and complex database performance situations.
 

 

   

 Copyright © 1996 -2016 by Burleson. All rights reserved.


Oracle® is the registered trademark of Oracle Corporation. SQL Server® is the registered trademark of Microsoft Corporation. 
Many of the designations used by computer vendors to distinguish their products are claimed as Trademarks