System-Level Response-Time Analysis
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?
1) 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
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 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 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 0DBA will then want to know what types of user activities are responsible for making the database work so hard.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 (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 .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 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 22-NOV-2004 11:28:37 User I/O 0 .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 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 . . .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 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.49The 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 AnalysisExamining 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
select *
from
(select sql_text,
sql_id,
elapsed_time,
cpu_time,
user_io_wait_time
from 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 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 unoptimized 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
