Oracle, History and the Wait Interface
If you have been working with Oracle for more than a few weeks, you’ve likely heard of the Oracle Wait Interface. If you are not yet familiar with it, there is a wealth of information available for it. A couple of the early papers on this subject are listed in the references section at the end of this article.
If you are familiar with Oracle Wait Interface, it’s time to learn about it again. Why? Because it’s out of date, as of version 10g of Oracle.
So that we can all be on familiar ground for the duration of this article, let’s consider some of the basics of the wait interface.
Back to the Basics
In the beginning there was Oracle 6 (or 5, or 4, or maybe even version 3 if you’re willing to admit to working with Oracle for that long). Oracle had created a mighty database, and saw that it was good.
Something was missing however. When the database was not performing as expected, something was needed to help determine on what the database was spending its time.
Then the v$session_wait and v$session_event performance views were created, the main components of the Oracle Wait Interface.
Using these views, you could now discover on what the database was spending its time. Refer to Example 1 for a report of all sessions that currently have more than 10000 buffer busy waits as seen in v$session_event. This view records the cumulative time that each session was spent waiting on a particular event.
TIME AVG
TOTAL TOTAL WAITED WAIT
USER SID EVENT WAITS TIMEOUTS SECONDS 100ths
----- ---- -------------------- ------ -------- -------- ------
MYAPP 25 buffer busy waits 12407 1 21 0
62 buffer busy waits 27117 0 43 0
77 buffer busy waits 11096 2 14 0
85 buffer busy waits 54095 1 56 0
87 buffer busy waits 44871 0 51 0
Example 1: Buffer Busy Waits > 10000 in v$session_event.
The following report is produced by the SQL in Listing 1:
select
sess.username,
sess.sid,
se.event,
se.total_waits,
se.total_timeouts,
se.time_waited/100 time_waited,
se.average_wait
from v$session_event se, v$session sess
where event like '%buffer busy%'
and sess.sid = se.sid
and sess.username is not null
and se.total_waits > 10000
order by username, sid
/
Listing 1: SQL to show buffer busy waits.
Even more interesting is the information provided by the v$session_wait view. This view provides data on waits as they happen. Oracle publishes the information needed to decode the wait data provided in the P1, P2, and P3 columns in the Oracle Reference Manual.
Using our example of buffer busy waits, you can determine on which objects in the database the waits are occurring. Example 2 shows the output from v$session_wait when buffer busy waits are encountered:
USERNAME EVENT SID P1 P2
---------- ----------------- --- -- ---
JKSTILL buffer busy waits 162 4 2791 row selected.
Example 2: Buffer busy wait in v$session_wait.
Using the information provided in the Oracle Reference Manual (refer to the references at the end of this article) you can use the information in the P1 and P2 columns to determine what object and block is causing the buffer busy waits. The SQL script in Listing 2 will determine which file, segment, and segment type in which the hot block is located.
col cfileid new_value ufileid noprint col cblockid new_value ublockid noprint prompt File ID: set term off feed off select '&1' cfileid from dual; set feed on term on prompt Block ID: set term off feed off select '&2' cblockid from dual; set feed on term on select file_name "FILE FOR BLOCK" from dba_data_files where file_id = &ufileid / col segment_name format a30 col segment_type format a15 select segment_name, segment_type from dba_extents where file_id = &ufileid and &ublockid between block_id and block_id + blocks - 1 / undef 1 2
Listing 2: In which table is the hot block?
The output for this query is shown in Example 3. From this, you can see the file referred to by P1, but more importantly, you can see that that buffer busy waits on occurring on table X:
FILE FOR BLOCK ---------------------------------------- /u01/app/oracle/oradata/ts02/users01.dbf 1 row selected. SEGMENT_NAME SEGMENT_TYPE ------------------------------ --------------- X TABLE 1 row selected.
Example 3: Hotblock search results.
The ability to diagnose in real time what is causing waits in the database appears to be a valuable diagnostic tool, and in fact, it is. The problem with capturing these in real time, though, is that they often happen much too fast for you to catch by running a SQL query. You may see some of the waits, but may miss many as well. Databases work on a clock that measures time in microseconds or less, while your fingers can only rerun a query a few times per second.
Many enterprising folks have written tools to capture the data from v$session_wait by rerunning the query frequently inside a loop. This will still miss many wait events and leave you with incomplete data, in addition to placing an extra load on your already busy database.
This is where Oracle 10g comes to the rescue. Now, in addition to the venerable wait interface that was introduced in Oracle 7, Oracle 10g includes Active Session History, or ASH.
By querying ASH views, you can now capture not only the current wait event, but the 10 most recent wait events for each session in the database. While this does not eliminate missing events — more than 10 events can easily occur between executions of the query — it does provide a much better picture of what wait events are occurring per session.
By querying the v$session_wait_history view, it becomes apparent that buffer busy waits on table X are not the only events on which the session is waiting (Example 4 tells the tale). The SQL can be seen in Listing 3:
select
s.sid
, s.username username
, e.event event
, e.p1
, e.p2
--, e.wait_time
from v$session s, v$session_wait_history e
where s.username is not null
and s.sid = e.sid
order by s.sid, s.username, e.seq#;
Listing 3: Display session wait history.
TIME
SID USERNAME EVENT P1 P2 WAITED
--- -------- ------------------------------ ---------- ------ ------
144 JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL latch: cache buffers chains 1533685692 116 15
...
162 JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL latch: cache buffers chains 1533685692 116 0
JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL buffer busy waits 2 11820 15
JKSTILL latch: cache buffers chains 1533685692 116 0
JKSTILL latch: cache buffers chains 1533685692 116 15
JKSTILL buffer busy waits 4 279 15
JKSTILL latch: cache buffers chains 1533685692 116 1530 rows selected.
Example 4: Session wait history.
The output from v$session_wait_history makes it clear that buffer busy waits on table X are not the only problem here. There are also buffer busy waits on the UNDO segment, shown as P1=2 and P2=11820 in the output. Also seen are many more waits on the cache buffers chain latch than buffer busy waits, which account for more of the wait time than do the buffers busy waits.
So far, so good. Querying only the v$session_wait view, I could determine that waits were occurring on the table X. Using the v$session_wait_history view, it became obvious that this was only part of the problem.
Carrying it further, the v$active_session_history view is the ASH counterpart to the v$session_event view. By querying it, a more detailed picture emerges. Listing 4 details the SQL used to create the output of Example 5:
col sample_time format a9 col event_name format a25 col p1 format 9999999999 col p2 format 99999 col p3 format 99999 col wait_time format 99999 head 'WAIT|TIME' col time_waited format 999999 head 'TIME|WAITED' set pagesize 60 set linesize 120 select to_char(h.sample_time,'mi:ss.ff3') sample_time , e.name event_name , h.p1 , h.p2 --, h.p3 , h.session_state , h.wait_time , time_waited from v$active_session_history h, v$event_name e where session_id = 162 and session_serial# = 4743 and e.event_id = h.event_id and h.sample_time between sysdate - ( 55/1440 ) and sysdat eorder by h.seq# /
Listing 4: Query v$active_session_history.
SAMPLE_TI EVENT_NAME P1 P2 SESSION TIME --------- ------------------------- ----------- ------ ------- ------ 25:22.012 db file sequential read 2 10459 ON CPU 15 25:23.032 db file sequential read 2 15130 ON CPU 18 25:24.052 db file sequential read 2 12535 ON CPU 23 25:25.072 latch: cache buffers chai 1533685692 116 WAITING 0 ns ... 25:58.782 buffer busy waits 4 279 WAITING 0 ... 26:22.272 db file sequential read 2 794 ON CPU 22 26:23.292 latch: cache buffers chai 1533685692 116 WAITING 0 ns ... 26:43.722 db file sequential read 2 1041 ON CPU 22 81 rows selected.
Example 5: v$active_session_history output.
Example 5 provides a more complete picture of the waits that have occurred than was ever possible using the old-style wait interface that was available in Oracle versions 7 — 9i.
As a diagnostic tool, it is far more capable than the previous wait interface. I’ve only scratched the surface here in showing what information can be acquired with ASH views.
To ASH or Not to ASH
So, should you use ASH?
If I’m asking that question, there must be a catch, right?
Yes, there is.
ASH is a component of the Enterprise Manager Diagnostic Pack. A close examination of the Oracle license reveals that to the use the ASH views, including the examples shown in this article, you must license the Diagnostics Pack as a separately licensed option when used in production systems.
As of this writing, the Diagnostic Pack licenses are $60.00 per user or $3000.00 US per CPU. Also included under the umbrella of the Diagnostics Pack license are the Automatic Workload Repository, or AWR, and the Automatic Database Diagnostic Monitor, also known as ADDM .
If you are already planning to license the Diagnostics Pack to obtain ADDM and/or AWR, then the ASH views will be yours to use.
If you have no current plans to license the Diagnostics Pack, there is scant justification for doing so just to obtain the ASH views.
Why is that?
Though there is a great deal of diagnostic information available in the ASH views, Oracle already has been providing this level of detail and more for troubleshooting purposes since Oracle version 7 via the 10046 database event.
The 10046 trace event has been widely used for several years to generate the detailed performance data that is needed to accurately diagnose and troubleshoot Oracle performance problems.
Not only may the 10046 trace be used to diagnose problems, the data it provides may be used to focus on fixing the performance problems that will have the greatest overall impact, as well as making it possible to predict just how much time will be saved by doing so.
Summary
The ASH views are a great diagnostic tool to put in your Oracle troubleshooting toolbox. If however you can’t justify the cost just to obtain access to the ASH views, there are still plenty of tools at your disposal.
References
Oracle Wait Reference (sign-in required)
“Direct Contention Identification Using Oracle’s Session Wait Virtual Views,” by Craig Shallahamer
“Yet Another Performance Profiling Method,” by Anjo Kolk, Shari Yamaguchi, and Jim Viscusi
“Optimizing Oracle Performance,” by Cary Millsap and Jeff Holt (Most complete treatment of using 10046 trace files.)
“How to Activate SQL Extended Trace” (10046 trace)
--
Jared Still is a DBA at RadiSys, an embedded solution provider. Jared has been an IT professional for 22 years, the last 10 of which have been as an Oracle DBA. He is the author of several Oracle articles and is co-author of Perl for Oracle DBAs.
Contributors : Jared Still
Last modified 2005-04-19 08:26 AM