Wait Interface and Events on 10g

In Oracle Database 10g, the wait interface has been radically redesigned to provide more information with less DBA intervention. In this article, we will explore those new features and see how they aid us in the diagnosis of performance problems. For most of the performance problems, you will get an extended analysis from Automatic Database Diagnostic Manager (ADDM), but for immediate problems not yet captured by ADDM, the wait interface provides valuable data for diagnosis.

Enhanced Session Waits

The first enhancement involves V$SESSION_WAIT itself. It's best explained through an example.
Let's imagine that your user has complained that her session is hanging. You found out the session's SID and selected the record from the view V$SESSION_WAIT for that SID. The output is shown below.
SID                      : 269
SEQ# : 56
EVENT : enq: TX - row lock contention
P1TEXT : name|mode
P1 : 1415053318
P1RAW : 54580006
P2TEXT : usn<<16 | slot
P2 : 327681
P2RAW : 00050001
P3TEXT : sequence
P3 : 43
P3RAW : 0000002B
WAIT_CLASS_ID : 4217450380
WAIT_CLASS# : 1
WAIT_CLASS : Application
WAIT_TIME : -2
SECONDS_IN_WAIT : 0
STATE : WAITED UNKNOWN TIME
Note the columns shown in bold; of those columns, WAIT_CLASS_ID, WAIT_CLASS#, and WAIT_CLASS are new in 10g. The column WAIT_CLASS indicates the type of the wait that must be either addressed as a valid wait event or dismissed as an idle one. In the above example, the wait class is shown as Application, meaning that it's a wait that requires your attention.

This column highlights those few records that could prove most relevant for your tuning. For example, you could use a query like the following to get the wait sessions for events.
select wait_class, event, sid, state, wait_time, seconds_in_wait
from v$session_wait
order by wait_class, event, sid
/
Here is a sample output:
WAIT_CLASS  EVENT                       SID STATE                WAIT_TIME SECONDS_IN_WAIT
---------- -------------------- ---------- ------------------- ---------- ---------------
Application enq: TX - 269 WAITING 0 73
row lock contention
Idle Queue Monitor Wait 270 WAITING 0 40
Idle SQL*Net message from client 265 WAITING 0 73
Idle jobq slave wait 259 WAITING 0 8485
Idle pmon timer 280 WAITING 0 73
Idle rdbms ipc message 267 WAITING 0 184770
Idle wakeup time manager 268 WAITING 0 40
Network SQL*Net message to client 272 WAITED SHORT TIME -1 0
Here you can see that several events (such as Queue Monitor Wait and JobQueue Slave) are clearly classified as Idle events. You could eliminate them as nonblocking waits; however, sometimes these "idle" events can indicate an inherent problem. For example, the SQL*Net-related events may indicate high network latency, among other factors.
The other important thing to note is the value of WAIT_TIME as -2. Some platforms such as Windows do not support a fast timing mechanism. If the initialization parameter TIMED_STATISTICS isn't set on those platforms, accurate timing statistics can't be determined. In such cases, a very large number is shown in this column in Oracle9i, which clouds the issue further. In 10g, the value -2 indicates this condition—the platform does not support a fast timing mechanism and TIMED_STATISTICS is not set. (For the remainder of the article, we will assume the presence of a fast timing mechanism.)


Sessions Show Waits Too
Remember the long-standing requirement to join V$SESSION_WAIT to V$SESSION in order to get the other details about the session? Well, that's history. In 10g, the view V$SESSION also shows the waits shown by V$SESSION_WAIT. Here are the additional columns of the view V$SESSION that show the wait event for which the session is currently waiting.
EVENT#                     NUMBER
EVENT VARCHAR2(64)
P1TEXT VARCHAR2(64)
P1 NUMBER
P1RAW RAW(4)
P2TEXT VARCHAR2(64)
P2 NUMBER
P2RAW RAW(4)
P3TEXT VARCHAR2(64)
P3 NUMBER
P3RAW RAW(4)
WAIT_CLASS_ID NUMBER
WAIT_CLASS# NUMBER
WAIT_CLASS VARCHAR2(64)
WAIT_TIME NUMBER
SECONDS_IN_WAIT NUMBER
STATE VARCHAR2(19)
The columns are identical to those in V$SESSION_WAIT and display the same information, eliminating the need to look in that view. So, you need to check only one view for any sessions waiting for any event.

Let's revisit the original problem: The session with SID 269 was waiting for the event enq: TX - row lock contention, indicating that it is waiting for a lock held by another session. To diagnose the problem, you must identify that other session. But how do you do that? In Oracle9i and below, you might have to write a complicated (and expensive) query to get the SID of the lock holding session. In 10g, all you have to do is issue the following query:
select BLOCKING_SESSION_STATUS, BLOCKING_SESSION
from v$session
where sid = 269;

BLOCKING_SE BLOCKING_SESSION
----------- ----------------
VALID 265
There it is: the session with SID 265 is blocking the session 269. Could it be any easier?

How Many Waits?

The user is still in your cubicle because her question is still not answered satisfactorily. Why has her session taken this long to complete? You can find out by issuing:
select * from v$session_wait_class where sid = 269;
The output comes back as:
SID SERIAL# WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS    TOTAL_WAITS TIME_WAITED
---- ------- ------------- ----------- ------------- ----------- -----------
269 1106 4217450380 1 Application 873 261537
269 1106 3290255840 2 Configuration 4 4
269 1106 3386400367 5 Commit 1 0
269 1106 2723168908 6 Idle 15 148408
269 1106 2000153315 7 Network 15 0
269 1106 1740759767 8 User I/O 26 1
Note the copious information here about the session's waits. Now you know that the session has waited 873 times for a total of 261,537 centi-seconds for application-related waits, 15 times in network-related events, and so on. Extending the same principle, you can see the system-wide statistics for wait classes with the following query. Again, the time is in centi-seconds.
select * from v$system_wait_class;

WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS TOTAL_WAITS TIME_WAITED
------------- ----------- ------------- ----------- -----------
1893977003 0 Other 2483 18108
4217450380 1 Application 1352 386101
3290255840 2 Configuration 82 230
3875070507 4 Concurrency 80 395
3386400367 5 Commit 2625 1925
2723168908 6 Idle 645527 219397953
2000153315 7 Network 2125 2
1740759767 8 User I/O 5085 3006
4108307767 9 System I/O 127979 18623
Most problems do not occur in isolation; they leave behind tell-tale clues that can be identified by patterns. The pattern can be seen from a historical view of the wait classes as follows.
select * from v$waitclassmetric;
This view stores the statistics related to wait classes over the last minute.
select wait_class#, wait_class_id, 
average_waiter_count "awc", dbtime_in_wait,
time_waited, wait_count
from v$waitclassmetric;

WAIT_CLASS# WAIT_CLASS_ID AWC DBTIME_IN_WAIT TIME_WAITED WAIT_COUNT
----------- ------------- ---- -------------- ----------- ----------
0 1893977003 0 0 0 1
1 4217450380 2 90 1499 5
2 3290255840 0 0 4 3
3 4166625743 0 0 0 0
4 3875070507 0 0 0 1
5 3386400367 0 0 0 0
6 2723168908 59 0 351541 264
7 2000153315 0 0 0 25
8 1740759767 0 0 0 0
9 4108307767 0 0 8 100
10 2396326234 0 0 0 0
11 3871361733 0 0 0 0
Note the WAIT_CLASS_ID and related statistics. For the value 4217450380, we saw that the 2 sessions waited for this class in the last minute for a total of 5 times and for 1,499 centi-seconds. But what is this wait class? You can get that information from V$SYSTEM_WAIT_CLASS as shown above—it's the class Application. Note the column named DBTIME_IN_WAIT, a very useful one, it shows the time spent inside the database.

Everyone Leaves a Trail

Finally the user leaves and you breathe a sigh of relief. But you may still want to get to the bottom of what different waits contributed to the problem in her session in the first place. Sure, you can easily get the answer by querying V$SESSION_WAIT—but unfortunately, the wait events are not present now and hence the view does not have any records of them. What would you do?

In 10g, a history of the session waits is maintained automatically for the last 10 events of active sessions, available through the view V$SESSION_WAIT_HISTORY. To find out these events, you would simply issue:
select event, wait_time, wait_count
from v$session_wait_history
where sid = 265;

EVENT WAIT_TIME WAIT_COUNT
------------------------------ ---------- ----------
log file switch completion 2 1
log file switch completion 1 1
log file switch completion 0 1
SQL*Net message from client 49852 1
SQL*Net message to client 0 1
enq: TX - row lock contention 28 1
SQL*Net message from client 131 1
SQL*Net message to client 0 1
log file sync 2 1
log buffer space 1 1
When the sessions become inactive or disconnected, the records disappear from that view. However, the history of these waits is maintained in AWR tables for further analysis. The view that shows the session waits from the AWR is V$ACTIVE_SESSION_HISTORY.