All about Wait Events

What are Wait Events?
Common Wait Events
Wait Event Views
Automatic Workload Repository
Time Model Statistics
Tracing Wait Events
Wait Interface
Query Examples

What are Wait Events?

"Wait Event" Defined

At any given moment, every Oracle process is either busy servicing a request or waiting for something specific to happen. By "busy" we mean that the process wishes to use the CPU. For example, a dedicated server process might be searching the buffer cache to see if a certain data block is in memory. This process would be said to be busy and not waiting. The ARC0 process, meanwhile, might be waiting for LGWR to signal that an online redo log needs archiving. In this case, the ARC0 process is waiting.
By querying v$ views, we can see what events processes are waiting on to an amazing level of detail.

Why Wait Event Information is Useful

Using the wait event interface, you can get insights into where time is being spent. If a report takes four hours to complete, for example, the wait event interface will tell you how much of that four hours was spent waiting for disk reads caused by full table scans, disk reads caused by index lookups, latch contention, and so on.
The wait event interface provides much more information to work with than cache hit ratios do.You get data that can touch upon so many different areas of your database such as disk I/O, latches, parallel processing, network traffic, checkpoints, and row-level locking. At the same time, you get incredible detail such as the file number and block number of a block being read from disk, or the name of a latch being waited on along with the number of retries.


Common Wait Event Names and What They Mean

Although there are many different types of wait events, the majority of them come up very infrequently or tend not to be significant. In practice, only a few dozen wait events tend to be of interest to most DBAs. You'll see different wait events surfacing in different environments based on which Oracle features have been implemented and which capabilities of the database are being taxed the most. For example, the PX wait events won't appear if you aren't using parallel query, and the virtual circuit status wait event won't appear if you are not using the multi-threaded server architecture (or shared server architecture as it is more recently called). Along those lines, the log file sync and enqueue wait events probably won't be prevalent in a primarily read-only system.

If you want a quick instance wide wait event status, showing which events are the biggest contributors to total wait time, you can use the following query :

select event, total_waits,time_waited from V$system_event
  where event NOT IN
  ('pmon timer', 'smon timer', 'rdbms ipc reply', 'parallel deque wait',
  'virtual circuit', '%SQL*Net%', 'client message', 'NULL event')
order by time_waited desc;

EVENT                              TOTAL_WAITS         TIME_WAITED
------------------------          -------------       -------------
db file sequential read              35051309            15965640
latch free                            1373973             1913357
db file scattered read                2958367             1840810
enqueue                                  2837              370871
buffer busy waits                      444743              252664
log file parallel write                146221              123435

Here are some of the most common wait events and what they mean:

1. DB File Scattered Read.
That generally happens during a full scan of a table or Fast Full Index Scans.
As full table scans are pulled into memory, they rarely fall into contiguous buffers but instead are scattered throughout the buffer cache. A large number here indicates that your table may have missing indexes, statistics are not updated or your indexes are not used. Although it may be more efficient in your situation to perform a full table scan than an index scan, check to ensure that full table scans are necessary when you see these waits. Try to cache small tables to avoid reading them in over and over again, since a full table scan is put at the cold end of the LRU (Least Recently Used) list. You can use the report to help identify the query in question and fix it.
The init.ora parameter db_file_multiblock_read_count specifies the maximum numbers of blocks read in that way. Typically, this parameter should have values of 4-16 independent of the size of the database but with higher values needed with smaller Oracle block sizes. If you have a high wait time for this event, you either need to reduce the cost of I/O, e.g. by getting faster disks or by distributing your I/O load better, or you need to reduce the amount of full table scans by tuning SQL statements. The appearance of the‘db file scattered read’ and ‘db file sequential read’events may not necessarily indicate a problem, as IO is a normal activity on a healthy instance. However, they can indicate problems if any of the following circumstances are true:
• The data-access method is bad (that is, the SQL statements are poorly tuned), resulting in unnecessary or inefficient IO operations
• The IO system is overloaded and performing poorly
• The IO system is under-configured for the load
• IO operations are taking too long

If this Wait Event is a significant portion of Wait Time then a number of approaches are possible:
o Find which SQL statements perform Full Table or Fast Full Index scans and tune them to make sure these scans are necessary and not the result of a suboptimal plan.
- The view V$SQL_PLAN view can help:
For Full Table scans:
select sql_text from v$sqltext t, v$sql_plan p
  where t.hash_value=p.hash_value
    and p.operation='TABLE ACCESS'

    and p.options='FULL'
  order by p.hash_value, t.piece;

For Fast Full Index scans:
select sql_text from v$sqltext t, v$sql_plan p
  where t.hash_value=p.hash_value
    and p.operation='INDEX'

    and p.options='FULL SCAN'
  order by p.hash_value, t.piece;

o In cases where such multiblock scans occur from optimal execution plans it is possible to tune the size of multiblock I/Os issued by Oracle by setting the instance parameter DB_FILE_MULTIBLOCK_READ_COUNT so that:
DB_BLOCK_SIZE x DB_FILE_MULTIBLOCK_READ_COUNT = max_io_size of system
Query tuning should be used to optimize online SQL to use indexes.

2. DB File Sequential Read.
Is the wait that comes from the physical side of the database. It related to memory starvation and non selective index use. Sequential read is an index read followed by table read because it is doing index lookups which tells exactly which block to go to.
This could indicate poor joining order of tables or un-selective indexes in your SQL or
waiting for writes to TEMP space (direct loads, Parallel DML (PDML) such as parallel updates. 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.
The sequential read event identifies Oracle reading blocks sequentially, i.e. one after each other. It is normal for this number to be large for a high-transaction, well-tuned system, but it can indicate problems in some circumstances. You should correlate this wait statistic with other known issues within the report, such as inefficient SQL. Check to ensure that index scans are necessary, and check join orders for multiple table joins. The DB_CACHE_SIZE will also be a determining factor in how often these waits show up. Problematic hash-area joins should show up in the PGA memory, but they're also memory hogs that could cause high wait numbers for sequential reads. They can also show up as direct path read/write waits. These circumstances are usually interrelated. When they occur in conjunction with the appearance of the 'db file scattered read' and 'db file sequential read' in the Top 5 Wait Events section, first you should examine the SQL Ordered by Physical Reads section of the report, to see if it might be helpful to tune the statements with the highest resource usage.
It could be because the indexes are fragmented. If that is the case, rebuilding the index will compact it and will produce to visit less blocks.
Then, to determine whether there is a potential I/O bottleneck, examine the OS I/O statistics for corresponding symptoms. Also look at the average time per read in the Tablespace and File I/O sections of the report. If many I/O-related events appear high in the Wait Events list, re-examine the host hardware for disk bottlenecks and check the host-hardware statistics for indications that a disk reconfiguration may be of benefit.
Block reads are fairly inevitable so the aim should be to minimize unnecessary I/O. I/O for sequential reads can be reduced by tuning SQL calls that result in full table scans and using the partitioning option for large tables.

3. Free Buffer Waits.
When a session needs a free buffer and cannot find one, it will post the database writer process asking it to flush dirty blocks (No place to put a new block). Waits in this category may indicate that you need to increase the DB_BUFFER_CACHE, if all your SQL is tuned. Free buffer waits could also indicate that unselective SQL is causing data to flood the buffer cache with index blocks, leaving none for this particular statement that is waiting for the system to process. This normally indicates that there is a substantial amount of DML (insert/update/delete) being done and that the Database Writer (DBWR) is not writing quickly enough; the buffer cache could be full of multiple versions of the same buffer, causing great inefficiency. To address this, you may want to consider accelerating incremental checkpointing, using more DBWR processes, or increasing the number of physical disks. To investigate if this is an I/O problem, look at the report I/O Statistics. Increase the DB_CACHE_SIZE; shorten the checkpoint; tune the code to get less dirty blocks, faster I/O, use multiple DBWR’s.

4. Buffer Busy Waits. A buffer busy wait happens when multiple processes concurrently want to modify the same block in the buffer cache. This typically happens during massive parallel inserts if your tables do not have free lists and it can happen if you have too few rollback segments. Buffer busy waits should not be greater than 1 percent. Check the Buffer Wait Statistics section (or V$WAITSTAT) to find out if the wait is on a segment header. If this is the case, increase the freelist groups or increase the pctused to pctfree gap. If the wait is on an undo header, you can address this by adding rollback segments; if it's on an undo block, you need to reduce the data density on the table driving this consistent read or increase the DB_CACHE_SIZE. If the wait is on a data block, you can move data to another block to avoid this hot block, increase the freelists on the table, or use Locally Managed Tablespaces (LMTs). If it's on an index block, you should rebuild the index, partition the index, or use a reverse key index. To prevent buffer busy waits related to data blocks, you can also use a smaller block size: fewer records fall within a single block in this case, so it's not as "hot." When a DML (insert/update/ delete) occurs, Oracle writes information into the block, including all users who are "interested" in the state of the block (Interested Transaction List, ITL). To decrease waits in this area, you can increase the initrans, which will create the space in the block to allow multiple ITL slots. You can also increase the pctfree on the table where this block exists (this writes the ITL information up to the number specified by maxtrans, when there are not enough slots built with the initrans that is specified). Buffer busy waits can be reduced by using reverse-key indexes for busy indexes and by partitioning busy tables.
Buffer Busy Wait on Segment Header – Add freelists (if inserts) or freelist groups (esp. RAC). Use ASSM.
Buffer Busy Wait on Data Block – Separate ‘hot’ data; potentially use reverse key indexes; fix queries to reduce the blocks popularity, use smaller blocks, I/O, Increase initrans and/or maxtrans (this one’s debatable). Reduce records per block
Buffer Busy Wait on Undo Header – Add rollback segments or increase size of segment area (auto undo) 
Buffer Busy Wait on Undo block – Commit more (not too much) Larger rollback segments/area. Try to fix the SQL.


5. Latch Free
.
Latches are low-level queuing mechanisms (they're accurately referred to as mutual exclusion mechanisms) used to protect shared memory structures in the system global area (SGA). Latches are like locks on memory that are very quickly obtained and released. Latches are used to prevent concurrent access to a shared memory structure. If the latch is not available, a latch free miss is recorded. Most latch problems are related to the failure to use bind variables (library cache latch), redo generation issues (redo allocation latch), buffer cache contention issues (cache buffers LRU chain), and hot blocks in the buffer cache (cache buffers chain). There are also latch waits related to bugs; check MetaLink for bug reports if you suspect this is the case. When latch miss ratios are greater than 0.5 percent, you should investigate the issue. If latch free waits are in the Top 5 Wait Events or high in the complete Wait Events list, look at the latch-specific sections of the report to see which latches are contended for.

6. Enqueue. An enqueue is a lock that protects a shared resource. Locks protect shared resources, such as data in a record, to prevent two people from updating the same data at the same time application, e.g. when a select for update is executed.. An enqueue includes a queuing mechanism, which is FIFO (first in, first out). Note that Oracle's latching mechanism is not FIFO. Enqueue waits usually point to the ST enqueue, the HW enqueue, the TX4 enqueue, and the TM enqueue. The ST enqueue is used for space management and allocation for dictionary-managed tablespaces. Use LMTs, or try to preallocate extents or at least make the next extent larger for problematic dictionary-managed tablespaces. HW enqueues are used with the high-water mark of a segment; manually allocating the extents can circumvent this wait. TX4s are the most common enqueue waits. TX4 enqueue waits are usually the result of one of three issues. The first issue is duplicates in a unique index; you need to commit/rollback to free the enqueue. The second is multiple updates to the same bitmap index fragment. Since a single bitmap fragment may contain multiple rowids, you need to issue a commit or rollback to free the enqueue when multiple users are trying to update the same fragment. The third and most likely issue is when multiple users are updating the same block. If there are no free ITL slots, a block-level lock could occur. You can easily avoid this scenario by increasing the initrans and/or maxtrans to allow multiple ITL slots and/or by increasing the pctfree on the table. Finally, TM enqueues occur during DML to prevent DDL to the affected object. If you have foreign keys, be sure to index them to avoid this general locking issue.
Enqueue - ST Use LMT’s or pre-allocate large extents
Enqueue - HW Pre-allocate extents above HW (high water mark.)
Enqueue – TX Increase initrans and/or maxtrans (TX4) on (transaction) the table or index.  Fix locking issues if TX6.  Bitmap (TX4) & Duplicates in Index (TX4).
Enqueue - TM Index foreign keys; Check application (trans. mgmt.) locking of tables.  DML Locks.

7. Log Buffer Space
Look at increasing log buffer size. This wait occurs because you are writing the log buffer faster than LGWR can write it to the redo logs, or because log switches are too slow. To address this problem, increase the size of the redo log files, or increase the size of the log buffer, or get faster disks to write to. You might even consider using solid-state disks, for their high speed.

The session is waiting for space in the log buffer. (Space becomes available only after LGWR has written the current contents of the log buffer to disk.) This typically happens when applications generate redo faster than LGWR can write it to disk.

8. Log File Switch
log file switch (checkpoint incomplete): May indicate excessive db files or slow IO subsystem
log file switch (archiving needed):  Indicates archive files are written too slowly
log file switch completion: May need more log files per
May indicate excessive db files or slow IO subsystem. All commit requests are waiting for "logfile switch (archiving needed)" or "logfile switch (chkpt. Incomplete)." Ensure that the archive disk is not full or slow. DBWR may be too slow because of I/O. You may need to add more or larger redo logs, and you may potentially need to add database writers if the DBWR is the problem.

9. Log File Sync
Could indicate excessive commits. A Log File Sync happens each time a commit (or rollback) 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). When a user commits or rolls back data, the LGWR flushes the session's redo from the log buffer to the redo logs. The log file sync process must wait for this to successfully complete. To reduce wait events here, try to commit more records (try to commit a batch of 50 instead of one at a time, use BULKS, , for example). Put redo logs on a faster disk, or alternate redo logs on different physical disks (with no other DB Files, ASM, etc) to reduce the archiving effect on LGWR. Don't use RAID 5, since it is very slow for applications that write a lot; potentially consider using file system direct I/O or raw devices, which are very fast at writing information. The associated event, ‘log buffer parallel write’ is used by the redo log writer process, and it will indicate if your actual problem is with the log file I/O. Large wait times for this event can also be caused by having too few CPU resources available for the redolog writer process.

10. Idle Event. There are several idle wait events listed after the output; you can ignore them. Idle events are generally listed at the bottom of each section and include such things as SQL*Net message to/from client and other background-related timings. Idle events are listed in the stats$idle_event table.

11. global cache cr request: (OPS) This wait event shows the amount of time that an instance has waited for a requested data block for a consistent read and the transferred block has not yet arrived at the requesting instance. See Note 157766.1 'Sessions Wait Forever for 'global cache cr request' Wait Event in OPS or RAC'. In some cases the 'global cache cr request' wait event may be perfectly normal if large buffer caches are used and the same data is being accessed concurrently on multiple instances.  In a perfectly tuned, non-OPS/RAC database, I/O wait events would be the top wait events but since we are avoiding I/O's with RAC and OPS the 'global cache cr request' wait event often takes the place of I/O wait events.

12. library cache pin: Library cache latch contention may be caused by not using bind variables. It is due to excessive parsing of SQL statement.
The session wants to pin an object in memory in the library cache for examination, ensuring no other processes can update the object at the same time. This happens when you are compiling or parsing a PL/SQL object or a view.

13. CPU time
This is not really a wait event (hence, the new name), but rather the sum of the CPU used by this session, or the amount of CPU time used during the snapshot window. In a heavily loaded system, if the CPU time event is the biggest event, that could point to some CPU-intensive processing (for example, forcing the use of an index when a full scan should have been used), which could be the cause of the bottleneck. When CPU Other is a significant component of total Response Time the next step is to find the SQL statements that access the most blocks. Block accesses are also known as Buffer Gets and Logical I/Os. The report lists such SQL statements in section SQL ordered by Gets.

14. DB File Parallel Read  If you are doing a lot of partition activity then expect to see that wait even. it could be a table or index partition. This Wait Event is used when Oracle performs in parallel reads from multiple datafiles to non-contiguous buffers in memory (PGA or Buffer Cache). This is done during recovery operations or when buffer prefetching is being used as an optimization i.e. instead of performing multiple single-block reads. If this wait is an important component of Wait Time, follow the same guidelines as 'db file sequential read'.
This may occur during recovery or during regular activity when a session batches many single block I/O requests together and issues them in parallel.

15. PX qref latch  Can often mean that the Producers are producing data quicker than the Consumers can consume it. Maybe we could increase parallel_execution_message_size to try to eliminate some of these waits or we might decrease the degree of parallelism. If the system workload is high consider to decrease the degree of parallelism. If you have DEFAULT parallelism on your object  you can decrease the value of PARALLEL_THREADS_PER_CPU.  Have in mind  DEFAULT degree = PARALLEL_THREADS_PER_CPU * #CPU's 

16. Log File Parallel Write. It occurs when waiting for writes of REDO records to the REDO log files to complete. The wait occurs in log writer (LGWR) as part of normal activity of copying records from the REDO log buffer to the current online log. The actual wait time is the time taken for all the outstanding I/O requests to complete. Even though the writes may be issued in parallel, LGWR needs to wait for the last I/O to be on disk before the parallel write is considered complete. Hence the wait time depends on the time it takes the OS to complete all requests.
Log file parallel write waits can be reduced by moving log files to the faster disks and/or separate disks where there will be less contention.

17. 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.

18. SQL*Net message to client
The “SQL*Net message to client” Oracle metric indicates the server (foreground process) is sending a message to the client, and it can be used to identify throughput issues over a network, especially distributed databases with slow database links. The SQL*Net more data to client event happens when Oracle writes multiple data buffers (sized per SDU) in a single logical network call.

19. enq: TX - row lock contention:
Oracle keeps data consistency with the help of locking mechanism. When a particular row is being modified by the process, either through Update/ Delete or Insert operation, oracle tries to acquire lock on that row. Only when the process has acquired lock the process can modify the row otherwise the process waits for the lock. This wait situation triggers this event. The lock is released whenever a COMMIT is issued by the process which has acquired lock for the row. Once the lock is released, processes waiting on this event can acquire lock on the row and perform DML operation

20. direct Path writes: You wont see them unless you are doing some appends or data loads. The session has issued asynchronous I/O requests that bypass the buffer cache and is waiting for them to complete. These wait events often involve temporary segments, sorting activity, parallel query or hash joins.


21. direct Path reads / direct path writes: Could happen if you are doing a lot of parallel query activity. The session has issued asynchronous I/O requests that bypass the buffer cache and is waiting for them to complete. These wait events often involve temporary segments, sorting activity, parallel query or hash joins. Usually sorting to Temp. Can also be parallel query. Could also be insert append, etc Adjust PGA_AGGREGATE_TARGET to fix it.

22. write complete waits: The session is waiting for a requested buffer to be written to disk; the buffer cannot be used while it is being written.


23. direct path read temp or direct path write temp: This wait event shows Temp file activity (sort,hashes,temp tables, bitmap) check pga parameter or sort area or hash area parameters. You might want to increase them


24. Undo segment extension: The session is waiting for an undo segment to be extended or shrunk. If excessive, tune undo


25. wait for a undo record: Usually only during recovery of large transactions, look at turning off parallel undo recovery.


26. Control File Parallel Write: The session has issued multiple I/O requests in parallel to write blocks to all control files, and is waiting for all of the writes to complete.


27. Control File Sequential Read: The session is waiting for blocks to be read from a control file.


28. DB File Parallel Write: The process, typically DBWR, has issued multiple I/O requests in parallel to write dirty blocks from the buffer cache to disk and is waiting for all requests to complete.


29. Library Cache load lock: The session is waiting for the opportunity to load an object or a piece of an object into the library cache. (Only one process can load an object or a piece of an object at a time.)


30. log file sequential read: The session is waiting for blocks to be read from the online redo log into memory. This primarily occurs at instance startup and when the ARCH process archives filled online redo logs.





There are several wait events that we call "idle events" because each of these wait events typically occurs when the Oracle process has nothing to do and is waiting for somebody to give it a task. Idle events are usually not very interesting from a tuning standpoint, so we usually overlook them when evaluating data extracted from the wait event interface. The common idle events are as follows:

Idle Events
client message PX Deq: Execute Reply
dispatcher timer PX Deq: Execution Msg
gcs for action PX Deq: Signal ACK
gcs remote message PX Deq: Table Q Normal
ges remote message PX Deque wait
i/o slave wait PX Idle Wait
jobq slave wait queue messages
lock manager wait for remote message rdbms ipc message
null event slave wait
parallel query dequeue smon timer
pipe get SQL*Net message from client
PL/SQL lock timer SQL*Net message to client
pmon timer SQL*Net more data from client
PX Deq Credit: need buffer virtual circuit status
PX Deq Credit: send blkd wakeup time manager


What Wait Event Information Does Not Provide

If an Oracle process has work to do but,  must wait for something to happen before it can continue, then the process will be waiting on a non-idle wait event. If a process has nothing to do, it will be waiting on an idle wait event. So what happens if a process has work to do and is busy doing it? When a process is busy, there will be no information in the wait event interface since the process is not waiting.

When we look at the wait event information extracted from an Oracle instance, we see detailed information about how many times and how much time was spent waiting for specific events to occur. But we do not see anything about the time periods in which the process requested use of the CPU. This means that the wait event interface is not able to provide information about the following:

This is important to keep in mind because there is an easy trap to fall into. You could be troubleshooting a very slow SELECT statement and learn from the wait event interface that the process does not have significant wait events when running the query. This could lead you to think that the statement is optimal, and that it just takes a long time to run. In fact, however, the query might be performing huge numbers of logical reads and the number of buffer gets could be reduced by rewriting the query.

When Oracle needs to access a data block and the block is already in the buffer cache, a logical read occurs with no physical read. The process is able to read the block without the occurrence of any wait events. Large amounts of CPU time could be consumed on significant numbers of logical reads, and the wait event interface will have nothing to show for the elapsed time.
Statement parsing and spinning while waiting for a latch to become available are two other examples of activities not accounted for by the wait event interface. An Oracle process uses CPU time while parsing a statement or spinning on a busy latch; since no waiting is involved, the wait event interface does not have anything to report.
In Statspack, the report that lists wait event information also lists CPU usage. This is very helpful information. It allows us to easily compare time spent waiting to time spent processing, so we know where to focus our tuning efforts. However, it should be pointed out that the CPU usage information in this section of the Statspack report does not come from the wait event interface. Instead, Statspack merges data collected from the wait event interface with CPU usage information collected from the v$sysstat dynamic performance view.

A Note About the timed_statistics Parameter

The Oracle kernel is capable of timing many activities including wait events. When timed_statistics is set to FALSE, all times in the wait event interface will appear as zero. You may enable timed statistics collection at the instance or the session level with the following commands:

You may enable timed statistics at the instance level on the next and all subsequent instance restarts by adding the following line to the instance parameter file:

        timed_statistics = true

In practice, the overhead of collecting timed statistics is extremely small, so by default this parameter is set to TRUE.


Wait Event Views

There are two common ways of collecting wait event information: the Oracle extended trace (10046 event) and using V$ views; we will focus on this one
Any user with the SELECT ANY TABLE system privilege or the SELECT_CATALOG_ROLE role can query the v$ views. Only users who can connect to the database as SYSDBA or execute the DBMS_SUPPORT or DBMS_SYSTEM packages can activate wait event tracing in other database sessions.
Oracle provides a number of views to aid in tuning; a few are:
    * V$SYSTEM_EVENT, which gives you total system waits for an event since database startup.
    * V$SESSION_EVENT, All waits the session encountered so far at the session level.
    * V$SESSION_WAIT gives you what an active session is waiting on at that point in time.
    * V$SESSION, which gives you session information and has a column ROW_WAIT_OBJ# that tells you the object involved when joined with OBJECT_ID or DATA_OBJECT_ID in DBA_OBJECTS. 

There are several V$ views for tracking history called V$%_HISTORY, including V$ACTIVE_SESSION_HISTORY (ASH), which samples non-idle wait events every second and new columns in V$SESSION to combine information in V$SESSION_WAIT.  The information is held for 30 minutes, then is stored in AWR: DBA_HIST_ACTIVE_SESS_HIST


The V$SYSTEM_EVENT View
The v$system_event view shows one row for each wait event name, along with the total number of times a process has waited for this event, the number of timeouts, the total amount of time waited, and the average wait time. All of these figures are cumulative for all Oracle processes since the instance started. Wait events that have not occurred at least once since instance startup do not appear in this view. The v$system_event view has the following columns:

Name                                      Null?    Type
----------------------------------------- -------- ------------------
EVENT VARCHAR2(64)
TOTAL_WAITS NUMBER
TOTAL_TIMEOUTS NUMBER
TIME_WAITED NUMBER
AVERAGE_WAIT NUMBER
TIME_WAITED_MICRO NUMBER
TOTAL_WAITS_FG NUMBER
TOTAL_TIMEOUTS_FG NUMBER
TIME_WAITED_FG NUMBER
AVERAGE_WAIT_FG NUMBER
TIME_WAITED_MICRO_FG NUMBER
EVENT_ID NUMBER
WAIT_CLASS_ID NUMBER
WAIT_CLASS# NUMBER
WAIT_CLASS VARCHAR2(64)

EVENT = The name of the wait event. You can see a list of all wait event names known to your Oracle kernel with the following query:
        SELECT name FROM v$event_name order by 1;
TOTAL_WAITS = The total number of times a process has waited for this event since instance startup.
TOTAL_TIMEOUTS = The total number of times a process encountered a timeout while waiting for an event. When a process begins to wait for an event, it specifies a timeout period after which the operating system should wake it up if the event has not yet transpired. For example, when an Oracle process issues an I/O request to read a block from a data file (the db file sequential read wait event), the process sets a timeout of one second. Usually the I/O request will complete in less than one second and no timeout will occur. But if the read should take longer than one second for whatever reason, a timeout will occur and the process will wake up. The process might do some minor housekeeping, but it will likely just begin another timeout period of one second and continue waiting for the same event.
TIME_WAITED and AVERAGE_WAIT show the cumulative (sum) and average time spent by processes waiting for this event, in centiseconds. Multiply these figures by 100 in order to get the wait time in seconds. These two columns will show as zero if timed statistics are not enabled.
TIME_WAITED_MICRO is the same as TIME_WAITED, except that the time is in microseconds. Multiply this figure by 1000000 in order to get the wait time in seconds.

Consider the following query from v$system_event:

set linesize 180
select substr(event,1,40) event, total_waits, total_timeouts, 100*time_waited Time_Waited_Sec, 100*average_wait Average_Wait_Sec
FROM v$system_event
WHERE event IN ('SQL*Net message from client', 'smon timer', 'db file sequential read', 'log file parallel write');

EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED_SEC AVERAGE_WAIT_SEC
---------------------------------------- ----------- -------------- --------------- ----------------
log file parallel write 768 0 1596.92 60
db file sequential read 5190 0 286.57 72
smon timer 15 8 1306738.37 1605427
SQL*Net message from client 266 0 16189800 60864
Since instance startup, processes on this system have waited a total of 286.57 seconds while reading single data file blocks from disk, and over 1,596 seconds (26 minutes) while writing redo to the online redo logs. A huge amount of time has been spent waiting on the smon timer and SQL*Net message from client events, but these are both idle wait events so we don't worry about them. (The SMON process spends a lot of time sleeping between consecutive checks of the system, and many dedicated server processes spend a lot of their time waiting for the application to submit a SQL statement for processing.)

The V$SESSION_EVENT View
The v$session_event view is a lot like the v$system_event view, except that it shows separate rows of information for each Oracle process. As with v$system_event, event names do not appear in this view if the process has not waited for them at least once. Also, when an Oracle process terminates (as in the case of when a user logs off the database) all of the rows in v$session_event for that process permanently disappear. The v$session_event view has the following columns:

 Name                                      Null?    Type
----------------------------------------- -------- -------------
SID NUMBER
EVENT VARCHAR2(64)
TOTAL_WAITS NUMBER
TOTAL_TIMEOUTS NUMBER
TIME_WAITED NUMBER
AVERAGE_WAIT NUMBER
MAX_WAIT NUMBER
TIME_WAITED_MICRO NUMBER
EVENT_ID NUMBER
WAIT_CLASS_ID NUMBER
WAIT_CLASS# NUMBER
WAIT_CLASS VARCHAR2(64)

SID = Session ID. You can query v$session in order to determine the SID of the session whose wait events you want to investigate
EVENT = The name of the wait event, e.g. "library cache lock"
TOTAL_WAITS = total number of times this session has waited
TOTAL_TIMEOUTS = total no. of times timeouts occurred for this
TIME_WAITED = the total time (in 100th of sec) waited
AVERAGE_WAIT = the average wait per wait
MAX_WAIT = indicates the maximum amount of time the process had to wait for the event. Like TIME_WAITED and AVERAGE_WAIT, the unit of measure is centiseconds and will display as zero if timed statistics are not enabled
TIME_WAITED_MICRO = same as time_waited; but in micro seconds
EVENT_ID = the event ID of the event
WAIT_CLASS_ID = the class of the waits
WAIT_CLASS#
WAIT_CLASS

Note = V$EVENT_NAME has the event details  joined on EVENT# column

Consider the following query which displays all wait event information for the current SQL*Plus session:

SELECT event, total_waits, time_waited_micro, max_wait
FROM v$session_event
WHERE SID = (SELECT sid FROM v$session WHERE audsid = USERENV ('sessionid'));

EVENT TOTAL_WAITS TIME_WAITED_MICRO MAX_WAIT
------------------------------ ----------- ----------------- ----------
log file sync 1 19629 2
db file sequential read 3 26128 1
db file scattered read 678 1154632 8
SQL*Net message to client 76 352 0
SQL*Net more data to client 1 63 0
SQL*Net message from client 75 1118656279 26930
SQL*Net break/reset to client 4 22281 2

You can see that the Oracle process serving this session has spent 1.180760 seconds waiting for disk I/O. Although there have been 76 instances where the process waited for the networking software to allow it to send a message to the client (the SQL*Plus program), each of these waits was shorter than the 0.01 second resolution of the MAX_WAIT column in v$session_event. (All 76 waits combined added up to only 0.000352 seconds.) Far and away, the Oracle process has spent the vast majority of its time (over 18 minutes) waiting for a SQL statement to be entered at the SQL*Plus prompt.


The V$SESSION_WAIT View
The v$session_wait view shows one row for each Oracle process. The row indicates the name of the wait event and additional parameters that provide further information about exactly what the process is waiting for (or information about the most recent wait event if the process is not currently waiting). While the v$system_event and v$session_event views show cumulative wait event information, the v$session_wait view shows information as of the present moment only. The v$session_wait view has the following columns:

 Name                                      Null?    Type
----------------------------------------- -------- ----------------
SID NUMBER
SEQ# NUMBER
EVENT VARCHAR2(64)
P1TEXT VARCHAR2(64)
P1 NUMBER
P1RAW RAW(8)
P2TEXT VARCHAR2(64)
P2 NUMBER
P2RAW RAW(8)
P3TEXT VARCHAR2(64)
P3 NUMBER
P3RAW RAW(8)
WAIT_CLASS_ID NUMBER
WAIT_CLASS# NUMBER
WAIT_CLASS VARCHAR2(64)
WAIT_TIME NUMBER
SECONDS_IN_WAIT NUMBER
STATE VARCHAR2(19)
WAIT_TIME_MICRO NUMBER
TIME_REMAINING_MICRO NUMBER
TIME_SINCE_LAST_WAIT_MICRO NUMBER
SID - Session ID.
SEQ# - Sequence number that uniquely identifies the wait event. This sequence is incremented with each wait event completion.
EVENT - Name of wait event.
P1TEXT - A description of what the P1 value is used for. Not reliable, use PARAMETER(n) value from V$EVENT_NAME to determine.
P1 - This value definition is dependent on the event. Use PARAMETER1 value from V$EVENT_NAME to describe what this value is used for.
P1RAW - Same value as P1 except in hexadecimal format.
P2TEXT - A description of what the P2 value is used for. Not reliable, use PARAMETER(n) value from V$EVENT_NAME to determine.
P2 - This value definition is dependent on the event. Use PARAMETER2 value from V$EVENT_NAME to describe what this value is used for.
P2RAW - Same value as P2 except in hexadecimal format.
P3TEXT - A description of what the P3 value is used for. Not reliable, use PARAMETER(n) value from V$EVENT_NAME to determine.
P3 - This value definition is dependent on the event. Use PARAMETER3 value from V$EVENT_NAME to describe what this value is used for.
P3RAW - Same value as P3 except in hexadecimal format.
WAIT_CLASS_ID - ID of the wait class. Column is in 10g.
WAIT_CLASS# - Number of the class. Column is in 10g.
WAIT_CLASS - The name of the wait class (Idle, Network, System I/O, etc.). Column is in 10g.
WAIT_TIME - The last amount of time that the session waited for an event. A 0 value means the session is currently waiting on the event. This value of 0 will not increase until the session completes the wait event. Time is in centiseconds.
SECONDS_IN_WAIT - If WAIT_TIME equals 0, then this is the number of seconds spent waiting on the event so far. This can give you complicated results when a timeout occurs like with enqueues because it will reset to 0, but this is beyond the scope of this article.
STATE - State of the wait event: WAIT_TIME=0 - WAITING, the process is in the state of waiting on an event. WAIT_TIME=-1 - WAITED SHORT TIME, wait time completed in less than a centisecond. WAIT_TIME=-2 - WAITED UNKOWN TIME, duration of wait is unknown because TIME_STATISTICS was set to false. WAIT_TIME>0 - WAITED KNOWN TIME, wait completed. WAIT_TIME is the duration of the wait event in centiseconds.

The following query shows the parameters associated with the db file scattered read wait event:

SELECT *    
FROM v$event_name
WHERE name = 'db file scattered read';

EVENT# NAME PARAMETER1 PARAMETER2 PARAMETER3
---------- ---------------------- ------------ ----------- -----------
188 db file scattered read file# block# blocks

This tells us that when a process is waiting for a multi-block read from disk to complete (as in the case of a full table scan where the data blocks were not already in the buffer cache), we can see the file from which the blocks are being read as well as the starting block and number of blocks.

The following query was run while a session was performing a full table scan:

set linesize 32000
SELECT sid,seq#,substr(event,1,35) event, p1text, p1, p2text, p2, p3text, p3, wait_time, seconds_in_wait, state
FROM v$session_wait WHERE sid = 442;

SID SEQ# EVENT
---------- ---------- ------------------------------
P1TEXT P1 P1RAW
------------------------------ ---------- --------
P2TEXT P2 P2RAW
------------------------------ ---------- --------
P3TEXT P3 P3RAW WAIT_TIME SECONDS_IN_WAIT
------------------------------ ---------- -------- ---------- ---------------
STATE
-------------------
442 303 db file scattered read
file# 17 00000011
block# 2721 00000AA1
blocks 8 00000008 -1 0
WAITED SHORT TIME

You can see that the process was not waiting at the moment this query was run, but its last wait had been for an I/O request to read eight blocks from file 17 starting at block 2721. That I/O request had completed in less than 0.01 second. (Note the -1 in the WAIT_TIME column when the STATE is WAITED SHORT TIME.) Why did Oracle choose to read eight blocks at a time? Because the db_file_multiblock_read_count instance parameter was set to eight.
For most wait events this view is sufficient, but it is hardly a robust tuning tool for at least two important reasons:
    * The view is a snapshot of the present. When the waits cease to exist, the history of those waits experienced by the session earlier disappears too, making after-effect diagnosis difficult. V$SESSION_EVENT provides cumulative but not very detailed data.
    * V$SESSION_WAIT contains information only about wait events; for all other relevant information such as the userid and terminal you have to join it with the view V$SESSION.


The V$SESSION View
Oracle provides an interface to check what these values are . useful work, idle time and waits.
The information is available in V$SESSION
-  EVENT = shows what the session is/was stuck on
-  SECONDS_IN_WAIT = shows the waits right now
- WAIT_TIME = shows the last wait time
-  STATE - shows what is the session doing now
            - WAITING. The session is waiting on that event right now
                    -  The amount of time it has been waiting so far is shown under SECONDS_IN_WAIT
            - WAITED KNOWN TIME. The session waited for some time on that event, but not just now
                    -  The amount of time it had waited is shown under WAIT_TIME
            - WAITED SHORT TIME. The session waited for some time on that event, but it was too short to be recorded
                    - WAIT_TIME shows -1

Wait Time Accounting

Value of STATE ---> WAITING = check SECONDS_IN_WAIT
                           ---> WAITED KNOWN TIME = check WAIT_TIME
                          ---> WAITED SHORT TIME = WAIT_TIME is -1

set linesize 200
set pagesize 100
select sid, substr(event,1,40) Event, state, wait_time, seconds_in_wait
  from v$session ;
       SID EVENT                                    STATE                WAIT_TIME SECONDS_IN_WAIT
---------- ---------------------------------------- ------------------- ---------- ---------------
         1 rdbms ipc message                        WAITING                      0               1
         2 DIAG idle wait                           WAITING                      0               1
         3 rdbms ipc message                        WAITING                      0               2
         4 rdbms ipc message                        WAITING                      0               1
         5 Streams AQ: qmn coordinator idle wait    WAITING                      0              27
         7 jobq slave wait                          WAITING                      0               0
        10 Streams AQ: waiting for time management  WAITING                      0             727
        63 smon timer                               WAITING                      0             275
        64 DIAG idle wait                           WAITING                      0               1
        65 rdbms ipc message                        WAITING                      0               2
        66 rdbms ipc message                        WAITING                      0               2
        68 Space Manager: slave idle wait           WAITING                      0               2
       125 pmon timer                               WAITING                      0               0
       126 rdbms ipc message                        WAITING                      0               0
       127 rdbms ipc message                        WAITING                      0            1426
       128 rdbms ipc message                        WAITING                      0               1
       130 SQL*Net message from client              WAITED KNOWN TIME            1               0
       187 VKTM Logical Idle Wait                   WAITING                      0            5089
       188 rdbms ipc message                        WAITING                      0               2
       189 rdbms ipc message                        WAITING                      0               1
       190 rdbms ipc message                        WAITING                      0               1
       191 jobq slave wait                          WAITING                      0               0
       194 rdbms ipc message                        WAITING                      0               1
       196 Streams AQ: qmn slave idle wait          WAITING                      0              27

Two additional columns have been added to v$session that are helpful for wait event analysis: blocking_session and blocking_session_status.
The blocking_session column contains the session id (SID) of the holder of the resource that the waiting session is waiting for. The blocking_session_status column indicates the validity of the contents of the blocking_session column.
If blocking_session_status is VALID, a valid SID is present in the blocking_session column. We can find out who is holding the lock very quickly:

SELECT sid, blocking_session, username, blocking_session_status status
FROM v$session
WHERE blocking_session_status = 'VALID';

SID BLOCKING_SESSION USERNAME STATUS
--- ---------------- -------- -----------
154 157 TSUTTON VALID

If we combine this with the wait event information available in v$session, we see:

SELECT sid, blocking_session, username, event, seconds_in_wait siw
FROM v$session
WHERE blocking_session_status = 'VALID';

SID BLOCKING_SESSION USERNAME EVENT SIW
--- ---------------- -------- ------------------------------ ---
154 157 TSUTTON enq: TX - row lock contention 318


The V$EVENT_NAME View
The v$event_name view shows reference information rather than up-to-the-moment information about instance performance. This view shows one row for each wait event known to the Oracle kernel. Associated with each wait event are up to three parameters-additional pieces of information that provide more detail about a wait situation. This view displays the definition of P(n) columns from V$SESSION_WAIT and can be joined on the NAME column.
The v$event_name view has the following columns:

 Name                                      Null?    Type
----------------------------------------- -------- -------------
EVENT# NUMBER
EVENT_ID NUMBER
NAME VARCHAR2(64)
PARAMETER1 VARCHAR2(64)
PARAMETER2 VARCHAR2(64)
PARAMETER3 VARCHAR2(64)
WAIT_CLASS_ID NUMBER
WAIT_CLASS# NUMBER
WAIT_CLASS VARCHAR2(64)

EVENT# = Number of the wait event.
NAME = Name of the event.
PARAMETER1 = Description of the value for P1.
PARAMETER2 = Description of the value for P2.
PARAMETER3 = Description of the value for P3.
WAIT_CLASS_ID = ID of the wait class
WAIT_CLASS# = Number of the class.
WAIT_CLASS = The name of the wait class (Idle, Network, System I/O, etc.)

The v$system_event and v$session_event views show cumulative information about past waits in summary form, leaving out parameter information from each individual wait.
As we will see in the next sections, wait event parameters come into play in the v$session_wait view and wait event trace files.


The V$SESSION_WAIT_HISTORY View
The v$session_wait_history view, helps by showing the last ten wait events each session has experienced.
The columns in v$session_wait_history are:

DESC v$session_wait_history
Name Null? Type
----------------------------------------- -------- ----------------------------
SID NUMBER
SEQ# NUMBER
EVENT# NUMBER
EVENT VARCHAR2(64)
P1TEXT VARCHAR2(64)
P1 NUMBER
P2TEXT VARCHAR2(64)
P2 NUMBER
P3TEXT VARCHAR2(64)
P3 NUMBER
WAIT_TIME NUMBER
WAIT_COUNT NUMBER

As an example, the following query shows the ten most recent wait events for a session:

SELECT sid, seq#, event, wait_time, p1, p2, p3 
FROM v$session_wait_history
WHERE sid = 154
ORDER BY seq#;

SID SEQ# EVENT WAIT_TIME P1 P2 P3
--- ---- ------------------------ ---------- ------ ------ ------
154 1 db file sequential read 28 4 3547 1
154 2 log buffer space 18 0 0 0
154 3 log buffer space 36 0 0 0
154 4 db file sequential read 0 4 3559 1
154 5 db file sequential read 0 4 1272 1
154 6 db file sequential read 0 4 3555 1
154 7 log buffer space 9 0 0 0
154 8 db file sequential read 0 4 3551 1
154 9 db file sequential read 6 4 1268 1
154 10 log buffer space 8 0 0 0
The seq# column is supposed to show the chronological sequence of the wait events, with 1 being the most recent wait event in the session. Note that this seq# value differs from the seq# column in v$session, which is incremented for each wait experienced by the session throughout the life of the session.

In the above query, we see that the session’s most recent waits alternated between single-block disk reads and log buffer space. This makes sense, since the SQL that the session was performing looked like:

INSERT INTO table1 (column1, column2) 
SELECT column1, column2
FROM table2
WHERE ...

From this list of recent waits, we can also drill down to get more detail. The p1 and p2 values for db file sequential read indicate the file and block numbers being read, so we can quickly determine what segment was being read.


The V$EVENT_HISTOGRAM View

The columns of v$event_histogram are:

SQL> DESCRIBE v$event_histogram
Name Null? Type
----------------------------------------- -------- ----------------------------
EVENT# NUMBER
EVENT VARCHAR2(64)
WAIT_TIME_MILLI NUMBER
WAIT_COUNT NUMBER

The v$system_event view shows the number of waits, total time waited, and average wait time for a given wait event name (system-wide since instance startup). However, this aggregation can cloud the picture, because a small number of long waits can skew the data. For example, consider the following query from v$system_event:

SELECT event, total_waits, time_waited, average_wait
FROM v$system_event
WHERE event = 'enq: TX - row lock contention';

EVENT TOTAL_WAITS TIME_WAITED AVERAGE_WAIT
----------------------------- ----------- ----------- ------------
enq: TX - row lock contention 17218 2101966 122

We see that there have been 17,218 waits and that the average wait time was 1.22 seconds, but we have no idea how the wait times are distributed. Were all of these waits roughly the same length? Were most of them under one second long and a few really long waits threw off the average? We can’t tell from v$system_event. However, we can look at v$event_histogram for a more complete picture:

SELECT event, wait_time_milli, wait_count
FROM v$event_histogram
WHERE event = 'enq: TX - row lock contention';

EVENT WAIT_TIME_MILLI WAIT_COUNT
----------------------------- --------------- ----------
enq: TX - row lock contention 1 833
enq: TX - row lock contention 2 635
enq: TX - row lock contention 4 372
enq: TX - row lock contention 8 395
enq: TX - row lock contention 16 781
enq: TX - row lock contention 32 3729
enq: TX - row lock contention 64 3050
enq: TX - row lock contention 128 410
enq: TX - row lock contention 256 47
enq: TX - row lock contention 512 46
enq: TX - row lock contention 1024 37
enq: TX - row lock contention 2048 3
enq: TX - row lock contention 4096 6880

We see that very few of the waits were anywhere near 1.22 seconds. Nearly 60% of the waits were less than 0.128 seconds (with most of those between 16 milliseconds and 64 milliseconds), and most of the remaining waits were between 2.048 seconds and 4.096 seconds (at which point some timed out and started new waits). In this way, the v$event_histogram view gives us a more accurate picture of wait times summarized by event name.


The V$SYSTEM_WAIT_CLASS and V$SESSION_WAIT_CLASS View

The two new views v$system_wait_class and v$session_wait_class enable us to get system and session wait information summarized by wait classes. This gives us a higher level view of what is happening in the system or session, rather than focusing on individual events. The views are roughly equivalent to the views v$system_event and v$session_event, except that they roll up the events by wait class. The wait times are expressed in centiseconds since instance startup for v$system_wait_class and centiseconds since session connection for v$session_wait_class.

The following queries show how much time (in centiseconds) has been spent on waits in each class across the system since instance start and for one specific session since that session began:

SELECT wait_class, time_waited
FROM v$system_wait_class
ORDER BY time_waited DESC;

WAIT_CLASS TIME_WAITED
------------- -----------
Idle 777450022
System I/O 1261584
User I/O 116667
Configuration 116481
Application 72301
Other 12432
Commit 3496
Concurrency 319
Network 1

SELECT wait_class, time_waited
FROM v$session_wait_class
WHERE sid = 154
ORDER BY time_waited DESC;

WAIT_CLASS TIME_WAITED
------------- -----------
Idle 612453
User I/O 1500
Configuration 28
Commit 11
Other 0
Application 0
Network 0

Since the wait times shown in these views are aggregations since system or session startup, these views are best used by taking samples and comparing the results to determine waits over a period of time. For instance, you could get data for the entire instance at time T1:

DROP TABLE swc_snap;
CREATE TABLE swc_snap AS
SELECT wait_class, total_waits, time_waited
FROM v$system_wait_class;

And then, at time T2 a while later, get a summary of waits between T1 and T2:

SELECT a.wait_class, (a.time_waited - b.time_waited) tm_waited
FROM v$system_wait_class a, swc_snap b
WHERE a.wait_class = b.wait_class
AND a.total_waits > NVL (b.total_waits, 0)
ORDER BY tm_waited DESC;

WAIT_CLASS TM_WAITED
--------------- ----------
Idle 255767
Application 171
System I/O 156
User I/O 44
Other 21
Commit 13
Network 1


The V$SESSION_WAIT_HISTORY View (Active Session History)

The v$session_wait_history view makes it a little easier to catch detailed information by preserving the last ten waits for each session. But what if you want detailed information about a session’s waits for a period further back in time? This is where the Active Session History feature of Oracle 10g—ASH for short—comes in handy. ASH makes detailed information about a sampling of waits encountered by all sessions available to us for a very long time.

The background daemon process called MMNL queries v$session once each second and stores information about all active sessions in a circular buffer in memory accessible by a new view called v$active_session_history. How far back you can look at sessions in this view depends on session activity and how much memory Oracle allocated for ASH. Oracle’s goal is to keep at least a few hours of session data available in this view. The v$active_session_history view includes much of the detailed wait event information shown in v$session:

SQL> DESC v$active_session_history
Name Null? Type
----------------------------------------- -------- ----------------------------
SAMPLE_ID NUMBER
SAMPLE_TIME TIMESTAMP(3)
SESSION_ID NUMBER
SESSION_SERIAL# NUMBER
USER_ID NUMBER
SQL_ID VARCHAR2(13)
SQL_CHILD_NUMBER NUMBER
SQL_PLAN_HASH_VALUE NUMBER
SQL_OPCODE NUMBER
SERVICE_HASH NUMBER
SESSION_TYPE VARCHAR2(10)
SESSION_STATE VARCHAR2(7)
QC_SESSION_ID NUMBER
QC_INSTANCE_ID NUMBER
EVENT VARCHAR2(64)
EVENT_ID NUMBER
EVENT# NUMBER
SEQ# NUMBER
P1 NUMBER
P2 NUMBER
P3 NUMBER
WAIT_TIME NUMBER
TIME_WAITED NUMBER
CURRENT_OBJ# NUMBER
CURRENT_FILE# NUMBER
CURRENT_BLOCK# NUMBER
PROGRAM VARCHAR2(48)
MODULE VARCHAR2(48)
ACTION VARCHAR2(32)
CLIENT_ID VARCHAR2(64)

As you can see, v$active_session_history captures the essential wait-related data from v$session. It also captures useful information about the SQL statement currently being executed, as well as current object number, file, and block being accessed. When a wait that was sampled by ASH completes, Oracle fills in the time_waited column for the row in v$active_session_history with the actual duration of the wait.

The AWR writes data from v$active_session_history to disk at regular intervals, preserving one sample every ten seconds from each active session. So, active session information remains accessible—although with less detail—even after the data has aged out of v$active_session_history.

Because ASH is always “on,” you always have access to detailed information about waits encountered in sessions within the last few hours. This means that if a user complains about a performance problem, you may be able to query v$active_session_history and gain insight into the problem without having to initiate an extended SQL trace or start a close watch of v$session while they reproduce the problem.

An important thing to keep in mind about v$active_session_history, however, is that it is populated by sampling v$session once each second. A session may encounter many different waits during a one second period, but only the one wait that was in progress when ASH collected its sample will be recorded in v$active_session_history. For this reason, ASH is valuable for general aggregate queries but not for precise counting of individual events or determining minimum or maximum wait times. Statistically speaking, the data collected by ASH is probably more accurate over a larger time interval and/or number of sessions.

For example, you might query v$active_session_history to see what percentage of time over the last two hours a particular group of sessions spent waiting on disk reads. However, using this view to determine how many disk read waits a session encountered in the last minute probably will not yield very accurate results.

Even though ASH data is only a sampling of active sessions, the information can prove to be quite useful. For example, the following query shows that sessions running the ARXENV application over the last two hours encountered a great deal of row-level lock contention:

SELECT DECODE (session_state, 'WAITING', event, NULL) event,
session_state, COUNT(*), SUM (time_waited) time_waited
FROM v$active_session_history
WHERE module = 'ARXENV'
AND sample_time > SYSDATE - (2/24)
GROUP BY DECODE (session_state, 'WAITING', event, NULL), session_state;

EVENT SESSION_STATE COUNT(*) TIME_WAITED
------------------------------ ------------- -------- -----------
ON CPU 124 0
log file sync WAITING 2 52686
db file scattered read WAITING 2 28254
db file sequential read WAITING 1 6059
control file sequential read WAITING 1 9206
SQL*Net break/reset to client WAITING 1 9140
enq: TX - row lock contention WAITING 922 930864016

In addition to running queries against the v$active_session_history view, you can use Enterprise Manager to run reports that will display ASH data.

Although ASH runs on all Oracle databases by default, you are not allowed to query the v$active_session_history view (or run the corresponding reports in Enterprise Manager) unless you have purchased the Diagnostic Pack.



Automatic Workload Repository(AWR)

Another significant facility relevant to the wait event interface it’s the Automatic Workload Repository—or AWR for short. AWR is basically a next-generation Statspack. By default, AWR collects an hourly snapshot of database performance information, storing the data in tables in the SYS schema. AWR is configured automatically when you create an Oracle database. You can call the dbms_workload_repository package to collect a snapshot on demand, purge a snapshot or range of snapshots, or change the snapshot interval or retention period. (By default snapshots are collected at the top of each hour and are purged after seven days.)

AWR collects the same type of data that Statspack does—including system-level statistics, resource-intensive SQL, and of course instance-wide wait event information. AWR also collects data such as time model statistics (which we will discuss in the next section). As an aside, Statspack also collects a lot of this new information, including time model statistics.

You can generate an AWR report of database activity between two snapshots by running the awrrpt.sql script in the rdbms/admin directory under $ORACLE_HOME. This script offers reports formatted as plain text or HTML. The reports will look familiar if you have used Statspack before. You can use Enterprise Manager to generate AWR reports as well.

AWR offers many benefits over Statspack. For one, it is more tightly integrated into the Oracle kernel, reducing resource requirements and overhead when collecting snapshots. AWR snapshots also include ASH data from v$active_session_history, providing session-level information to complement the system-level data collection familiar to Statspack users.

Data collected by AWR is made easily accessible via views with names that start DBA_HIST. This enables you to write your own reports that extract just the data you need to address a specific situation, if for some reason you don’t find what you need in the standard AWR report. For example, the following query displays the two most recent snapshot IDs:

SELECT snap_id, substr(begin_interval_time,1,25) Begin_Interval, substr(end_interval_time,1,25) End_Interval
FROM (SELECT snap_id, begin_interval_time, end_interval_time
FROM dba_hist_snapshot
ORDER BY end_interval_time DESC)
WHERE ROWNUM <= 2;

SNAP_ID BEGIN_INTERVAL_TIME END_INTERVAL_TIME
---------- ------------------------- -------------------------
362 10-MAR-05 04.00.02.018 PM 10-MAR-05 05.00.36.581 PM
361 10-MAR-05 03.00.25.885 PM 10-MAR-05 04.00.02.018 PM

Just like ASH, you are not allowed to query the AWR views (or run AWR reports) unless you have licensed the Diagnostic Pack. Because AWR consumes system resources when collecting snapshots and uses up storage in the SYSAUX tablespace, you may want to disable the collection of AWR snapshots if you are not licensed to use AWR. This may be done by using the dbms_workload_repository package. If AWR is not available to you, Statspack is still a good way to go.


Time Model Statistics

Oracle has a concept called Time Model Statistics. This information provides yet another way to see how time is spent, and with greater detail than was available previously. The v$sys_time_model view shows time model statistics for the entire system since instance startup, while the v$sess_time_model view shows time model statistics for each session since session start. The columns in these two views are as follows:

DESC v$sys_time_model
Name Null? Type
---------------------------------------- -------- ---------------------------
STAT_ID NUMBER
STAT_NAME VARCHAR2(64)
VALUE NUMBER

DESC v$sess_time_model
Name Null? Type
---------------------------------------- -------- ---------------------------
SID NUMBER
STAT_ID NUMBER
STAT_NAME VARCHAR2(64)
VALUE NUMBER

A sample query from v$sys_time_model shows the following:

SELECT stat_name, value / 1000000 seconds
FROM v$sys_time_model
ORDER BY seconds DESC;

STAT_NAME SECONDS
------------------------------------------------ ----------
DB time 80970.190
sql execute elapsed time 75057.271
DB CPU 44448.628
background elapsed time 29333.160
PL/SQL execution elapsed time 8824.538
background cpu time 5170.311
parse time elapsed 1270.147
hard parse elapsed time 838.068
PL/SQL compilation elapsed time 176.731
sequence load elapsed time 112.334
connection management call elapsed time 44.644
failed parse elapsed time 11.946
hard parse (sharing criteria) elapsed time 5.579
hard parse (bind mismatch) elapsed time 4.610
failed parse (out of shared memory) elapsed time 0.000
Java execution elapsed time 0.000
inbound PL/SQL rpc elapsed time 0.000

This query shows us a lot more information about how Oracle sessions have spent their time (categorically) than v$sysstat and v$sesstat do. Of course, we have to know how to interpret this information before we can put it to work for us. Values in these views are shown in microseconds, and they do not include background processes unless “background” appears in the statistic name. The “DB time” statistic shows elapsed time spent on database calls (user processes only). This amounts to time spent on the CPU or waiting on non-idle wait events. For a description of the other time model statistics, see the v$sess_time_model view listing in the Database Reference manual.

From this query, among many other useful facts, we can see that no time has been spent executing Java, very little time has been spent hard parsing or compiling PL/SQL, background processes have used about 10% of the CPU time, and about 11% of the elapsed time for user sessions was spent on PL/SQL execution.




Tracing Wait Event Activity (SYSTEM EVENT 10046)
DBA's should be familiar with the SQL trace facility built into Oracle.

The extended SQL trace facility, also known as event 10046, allows us to capture in a trace file detailed information about every wait event encountered by a database session.
By using the commands below, you can enable SQL trace for your session:

Using the TOP Unix command or the v$session view you can check the SID and SERIAL# number of the session to monitor.
select sid, serial#, substr(terminal,1,10) terminal, substr(program,1,40) program
from v$session
where terminal in('OCR04','IMGSVR')
-- where username = 'FRAUDGUARD';;

Then, you activate the trace by using the package dbms_monitor. This package, among many other things, makes it very easy to turn extended SQL trace on and off in any Oracle session. With one easy to remember call, you can turn extended SQL trace on or off, with wait events and/or bind variables captured in the trace file:

SQL> DESC dbms_monitor
...
PROCEDURE SESSION_TRACE_DISABLE
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SESSION_ID BINARY_INTEGER IN DEFAULT
SERIAL_NUM BINARY_INTEGER IN DEFAULT
PROCEDURE SESSION_TRACE_ENABLE
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SESSION_ID BINARY_INTEGER IN DEFAULT
SERIAL_NUM BINARY_INTEGER IN DEFAULT
WAITS BOOLEAN IN DEFAULT
BINDS BOOLEAN IN DEFAULT
If the session_id parameter is not specified or set to NULL, your own session will be traced. Thus, the following two statements should be equivalent:

Instead of enabling extended SQL trace for a specific Oracle session, you can enable it for a specific client identifier or combination of service, module, and action. Any time any Oracle session has the specified client identifier or combination of service, module, and action, the session will be traced. Sessions can set or clear their client identifier at will by calling the dbms_session package, and they can set their module and action by calling the dbms_application_info package.

Suppose a web-based application uses a pool of 30 database connections to serve user requests and maintains a current_sessions table to keep track of the state of each end-user session. When a user clicks a button in their browser window, the application server receives the HTTP request and hands it off to an application server process. The application server process grabs a free database connection from the pool and accesses the database as necessary to service the request. It is likely that subsequent requests from the same user will be processed using different database connections.

With dbms_monitor, the application could be modified in a way to make extended SQL trace a whole lot easier. We mentioned that the application uses the current_sessions table to maintain state for each end user session. Each time the application server grabs a database connection from the pool, it could set the client identifier for the Oracle session to the session_id from the current_sessions table before doing any database access for that end user session. Then the application could clear the client identifier before returning the database connection to the pool. The Oracle calls could look like this:

EXECUTE dbms_session.set_identifier ('session_id174837492748');
...do the work for this end user session...
EXECUTE dbms_session.clear_identifier

To trace this end user session, we could now call the dbms_monitor package like this:

EXECUTE dbms_monitor.client_id_trace_enable ('session_id174837492748', waits=>TRUE, binds=>TRUE);

This call to dbms_monitor will cause each Oracle process to write extended SQL trace data to a trace file for all calls that occur while the client identifier for the session is set to the specified value. However, each Oracle process will write to its own trace file. This will cause the trace data to be split over multiple files. To address this problem, Oracle 10g provides a new command-line utility called trcsess. The trcsess utility reads multiple trace files and consolidates entries from the various files that meet the specified criteria into one trace file that can be processed by TKPROF. To consolidate the trace data for our current example, we could use the following commands:

$ cd $ORACLE_BASE/admin/$ORACLE_SID/udump
$ trcsess output=/home/rschrag/case1403/case1403-trial1.trc clientid=session_id174837492748

In this way the dbms_monitor package and trcsess utility make it a lot easier to collect extended SQL trace data from an end user’s session when connection pooling or other session aggregation techniques are used by the application server tier.


Example using SID and SERIAL
TURN ON:    exec dbms_monitor.session_trace_enable(&SID, &SERIAL, waits=> true, binds=> true)
/* code to be traced executes during this time window */
TURN OFF:     exec
exec dbms_monitor.session_trace_disable(&SID, &SERIAL)

Example using Service or Module:
BEGIN
-->Enable/Disable Client Identifier Trace.
DBMS_MONITOR.client_id_trace_enable (client_id => ‘my_id’);
DBMS_MONITOR.client_id_trace_disable (client_id => ‘my_id’); 

-->Enable/Disable Service, Module and Action Trace.
DBMS_MONITOR.serv_mod_act_trace_enable (service_name=>'my_service'); 
DBMS_MONITOR.serv_mod_act_trace_enable (service_name=>'my_service', module_name=>'my_module');
DBMS_MONITOR.serv_mod_act_trace_enable (service_name=>'my_service',module_name=>‘my_module’,action_name=>'INSERT'); 
DBMS_MONITOR.serv_mod_act_trace_disable (service_name=>'my_service',module_name=>'my_module',action_name =>'INSERT');

-->Enable/Disable Session Trace . 
DBMS_MONITOR.session_trace_enable;
DBMS_MONITOR.session_trace_enable(session_id => 12, serial_num => 1011); 
DBMS_MONITOR.session_trace_disable(session_id => 12, serial_num => 1011);
END;
/

With the DBMS_MONITOR package, Oracle offers a fully supported means of activating and deactivating diagnostic data collection for a specific business action (or actions) you want to trace.

Then you can run TKPROF to translate the trace file created before into a readable output file. This step can optionally create a SQL script that stores the statistics in the database.
tkprof trace_file  file_name sys=no explain=user/passwd@connection

When SQL trace is enabled for a session, the Oracle process writes detailed trace information (including timing data if timed statistics are enabled) to a trace file in a directory specified by the user_dump_dest instance parameter. These trace files are plain text files and human readable, but rather tedious and repetitive. You can optionally run trace files through a processor such as TKPROF instead of looking at them directly.
Oracle has the ability to direct a process to include additional information in the trace file, including wait event information. In earlier releases of Oracle, we activated the wait event tracing facility by setting debug event 10046. Debug event 10046 still works in Oracle 9i, but recent releases of Oracle include a PL/SQL package built-in that gives a more friendly means for activating wait event tracing.
Setting debug events allows a DBA to instruct an Oracle instance to take on a special, atypical behavior. Debug events can be used, for example, to cause Oracle to write a system level dump file whenever an ORA-0600 error occurs or skip over corrupted blocks in a table when performing a full table scan. Most debug events should never be set unless you are directed to do so by Oracle Support. Some debug events can put your database at risk.
Debug event 10046 affects the amount of information written to trace files. It is a very safe debug event, and one of the few that you are allowed to set without special permission from Oracle Support. Debug event 10046 can be set to the following values:

Debug Event Setting Effect
10046 trace name context forever, level 1 Enables ordinary SQL trace
10046 trace name context forever, level 4 Enables SQL trace with bind variable values included in trace file
10046 trace name context forever, level 8 Enables SQL trace with wait event information included in trace file
10046 trace name context forever, level 12 Equivalent of level 4 and level 8 together
10046 trace name context off Turns off tracing

You can set the 10046 debug event to trace your session and collect wait event information in the trace file with either of the following commands:

You can set the 10046 debug event to trace another session on the database with any of the following commands:
Find the session:
set linesize 150
column Name format a14
column SID format 9999
column PID format 99999
column TERM format a15
column OSUSER format a15
column Program format a15
column Stats format a10
column Logon_time format a20
select a.username Name, a.sid SID, a.serial#, b.spid PID,
       SUBSTR(A.TERMINAL,1,9) TERM, SUBSTR(A.OSUSER,1,9) OSUSER,
       substr(a.program,1,10) Program, a.status Status,
       to_char(a.logon_time,'MM/DD/YYYY hh24:mi') Logon_time
from v$session a, v$process b
where a.paddr = b.addr
  and a.serial# <> '1'
  and a.status = 'ACTIVE'
  and a.username like upper('%&user%') -- if you want to filter by username
order by a.logon_time;

Once you have the SID and SERIAL# of the session you can use some Oracle supplied packages.
-- set timed statistics at user session level if not set at system level.
execute sys.dbms_system.set_boo_param_in_session(&&SID, &&SERIAL,'timed_statistics',true);

--set max dump file size if not set at system level.
execute sys.dbms_system.set_in_param_in_session(&&SID, &&SERIAL, 'max_dump_file_size',10000000);
   
-- activate level 8 extended SQL tracing.
execute sys.dbms_system.set_ev(&&SID, &&SERIAL, 10046, 8, ' ');
or
execute sys.dbms_support.start_trace_in_session (
&&SID, &&SERIAL)


******* run all of your processing here *******

-- disables extended SQL tracing.
execute sys.dbms_system.set_ev(&&SID, &&SERIAL, 10046, 0, ' ');
or
execute sys.dbms_support.stop_trace_in_session (
&&SID, &&SERIAL)

Calling DBMS_SUPPORT as shown here is equivalent to activating debug event 10046 at level 8. You may include optional additional parameters in the procedure call to activate level 4 or 12. The DBMS_SUPPORT package is not installed in the database by default. You need to run the dbmssupp.sql script found in the rdbms/admin directory as SYS before you can call DBMS_SUPPORT.
It should also be pointed out that the SET_EV procedure in the DBMS_SYSTEM package is not officially supported by Oracle Corporation-they prefer that you use DBMS_SUPPORT instead. The reason is that DBMS_SYSTEM.SET_EV allows you to set any debug event in any session. As mentioned above some debug events can potentially be dangerous, and DBMS_SYSTEM.SET_EV lets you set such events in any session.
Unlike timed statistics, tracing consumes a significant amount of system resources. Therefore it is important to use the tracing facility sparingly. Trace only the sessions you need to trace, and only for as long as you need. Turn off tracing as soon as it is no longer needed with any of the following commands:

When you set debug event 10046 to a level of 8 or 12 (or call START_TRACE or START_TRACE_IN_SESSION in DBMS_SUPPORT), the Oracle process will write a line into the trace file every time it finishes waiting for an event. The line in the trace file will contain almost the same information that would have appeared in the v$session_wait view, but perhaps in a slightly less friendly format. You can also see in the trace file which cursor (and therefore which SQL statement) the wait event was associated with.
Here is an excerpt from a trace file generated by setting debug event 10046 to level 12 on an Oracle 8i database:

        =====================
PARSING IN CURSOR #1 len=80 dep=0 uid=502 oct=3 lid=502
tim=2293771931 hv=2293373707 ad='511dca20'
SELECT /*+ FULL */ SUM (LENGTH(notes))
FROM customer_calls
WHERE status = :x
END OF STMT
PARSE #1:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=0,tim=2293771931
BINDS #1:
bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0
size=24 offset=0
bfp=09717724 bln=22 avl=02 flg=05
value=43
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=2293771931
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=675562835 p2=1 p3=0
WAIT #1: nam='db file scattered read' ela= 3 p1=17 p2=923 p3=8
WAIT #1: nam='db file scattered read' ela= 1 p1=17 p2=931 p3=8
WAIT #1: nam='db file scattered read' ela= 2 p1=17 p2=939 p3=8
WAIT #1: nam='db file sequential read' ela= 0 p1=17 p2=947 p3=1
WAIT #1: nam='db file scattered read' ela= 3 p1=17 p2=1657 p3=8
WAIT #1: nam='db file scattered read' ela= 1 p1=17 p2=1665 p3=8
WAIT #1: nam='db file scattered read' ela= 2 p1=17 p2=1673 p3=8
WAIT #1: nam='db file scattered read' ela= 0 p1=17 p2=1681 p3=8
WAIT #1: nam='db file scattered read' ela= 3 p1=17 p2=1761 p3=8
WAIT #1: nam='db file scattered read' ela= 1 p1=17 p2=1769 p3=8
WAIT #1: nam='db file scattered read' ela= 1 p1=17 p2=1777 p3=8
WAIT #1: nam='db file scattered read' ela= 0 p1=17 p2=1785 p3=8
WAIT #1: nam='db file scattered read' ela= 2 p1=17 p2=1841 p3=8
WAIT #1: nam='db file scattered read' ela= 1 p1=17 p2=1849 p3=8

The "ela=" figures indicate the duration of the wait. In trace files generated by Oracle 8i and earlier, the elapsed time is shown in centiseconds. Beginning in Oracle 9i, the elapsed time is shown in microseconds.
You can see that when the session executed the query, there was a wait shorter than one centisecond for a message to be sent to the client, followed by a bunch of waits for I/O requests against file 17. Most of the I/O requests were multi-block reads, reading eight blocks at a time while performing a full table scan of the CUSTOMER_CALLS table.
You can probably imagine how large and overwhelming trace files can get when anything but a trivial application is traced. This is why Oracle provides the TKPROF utility. TKPROF takes a trace file as input and generates a nicely formatted, easy to read report. Unfortunately, the TKPROF that comes with Oracle 8i and earlier releases ignores wait event information written in the trace file. To analyze the wait event information collected by a trace in an Oracle 8i or earlier environment, you will need to either pore through the trace file manually or write your own trace file parser and formatter. (We've heard of people writing perl scripts to do this, but we have never come across them.)
The TKPROF utility that comes with Oracle 9i is capable of reporting wait event information summarized by distinct statement. By default Oracle 9i TKPROF ignores wait event information in the trace file as earlier releases did. However, if the "waits=yes" command line argument is provided, a separate table of wait event statistics will appear in the report for each distinct statement. Here is a sample excerpt from a TKPROF report showing wait event information:

        ********************************************************************************
SELECT A.customer_id, A.customer_name, COUNT (*) purchases,
MAX (B.transaction_date) last_purchase_date
FROM customers A, purchase_history B
WHERE B.customer_id = A.customer_id
GROUP BY A.customer_id, A.customer_name
ORDER BY A.customer_id

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.06 0.12 0 27 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1461 21.41 25.80 7801 5905 5 21893
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1463 21.47 25.93 7801 5932 5 21893

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 17

Rows Row Source Operation
------- ---------------------------------------------------
21893 SORT GROUP BY
1525494 HASH JOIN
31212 TABLE ACCESS FULL CUSTOMERS
1525494 INDEX FAST FULL SCAN PURCHASE_HISTORY_PK (object id 7824)

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1461 0.00 0.00
db file sequential read 4 0.00 0.01
db file scattered read 750 0.07 2.25
direct path write 271 0.83 2.79
direct path read 254 0.00 0.01
SQL*Net message from client 1461 1.28 22.40
********************************************************************************

You can see that the query was parsed and executed once, and there were 1461 fetches to read 21893 rows. The Oracle process used 21.47 CPU seconds and 25.93 seconds of elapsed time to parse, execute, and fetch the query. The elapsed time was greater than the CPU time because the Oracle process had to wait on several wait events. The listing at the bottom of the report shows the process waited on network roundtrips to the client and reads and writes to disk.
All of these waits seem to make sense: There was one network roundtrip to the client for each fetch call, and it took SQL*Plus a long time (over 22 seconds) to display the 21,893 rows of data on my display. The db file sequential reads and db file scattered reads resulted from the table access and index fast full scan. The direct path writes and reads resulted from the hash join and sort operations. If you add the CPU time of 21.47 seconds and the wait times (5.06 seconds not including the SQL*Net message from client waits) you come up with an elapsed time of 26.53 seconds. However, the report shows the total elapsed time as 25.93 seconds. This is a good example of the round-off error that is not unusual when thousands of very short time intervals are added together.
In some situations you may not be able to identify exactly which session to trace. This happens frequently when your database is supporting a web application that has frequent short connections, or an application server tier that maintains a pool of database connections all logged on as the same Oracle user. You may have a specific query you want to collect wait event information for, but you may not know which session will be executing the query. One way to deal with this situation is to trace all of the sessions being started by your application for a brief period. This can be done easily with the following SQL*Plus script:

SPOOL traceall.sql
SET HEADING OFF FEEDBACK OFF
SELECT 'EXECUTE SYS.dbms_system.set_ev (' || TO_CHAR (sid) ||
', ' || TO_CHAR (serial#) || ', 10046, 8, '''')'
FROM v$session
WHERE username = 'WEB_USER';
SPOOL OFF
SET FEEDBACK ON
@traceall.sql

This script will start wait event tracing on all sessions connected to the database as the WEB_USER user. To stop tracing simply change the 8 after the 10046 to a 0 and run the script again. You should think about how many sessions this script will trace and how that will affect server load before running on a production system.
After you've traced a number of sessions, you can scan the trace files for occurrences of a specific query with a command like the following:

        grep -n 1234567890 *.trc

Replace 1234567890 with the hash value or address of the statement you are interested in. (You can get these values by querying v$sql.) The output of the above grep command will tell you which trace files the query appears in and on which lines. You can then go to that point in the trace files and get detailed wait event information.
Trace files are easiest to work with when you use a dedicated server connection to the database. If you connect to the database using Oracle's shared server architecture then different SQL statements may be executed by different server processes. Each server process writes to its own trace file. Thus the trace information for the session can be spread over several trace files.



Wait Interface
In the latest versions of Oracle, 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.

Using the v$session_wait and v$session_event performance views, you could now discover on what the database was spending its time.
The following example reports 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.
Example 1: Buffer Busy Waits > 10000 in v$session_event.
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;
                                                    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

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 279

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

SEGMENT_NAME SEGMENT_TYPE
------------------------------ ---------------
X TABLE

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 15

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 sysdate
order 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

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.


Query examples

What resource is currently in high demand?

While we have always been able to look at the system or a currently running session as a whole and see the resources that are in most use through the V$SYSTEM_EVENT and V$SESSTAT views, we really have not ever had a good way to determine for a current time frame what the resources being used were. This query will give you for the last 30 minutes those resources that are in high demand on your system.

select active_session_history.event,
       sum(active_session_history.wait_time + active_session_history.time_waited) ttl_wait_time
  from v$active_session_history active_session_history
  where active_session_history.sample_time between sysdate - 60/2880 and sysdate
  group by active_session_history.event
  order by 2;

Wait Event                     TTL_WAIT_TIME
------------------------------ -------------
SQL*Net message to client                  4
null event                                 5
LGWR wait for redo copy                  161
ksfd: async disk IO                      476
direct path read                       30025
latch: cache buffers chains            33258
direct path write                      93564
log file sequential read              178662
db file sequential read               458653
log file sync                         612660
control file single write            1127626
read by other session                2024242
db file parallel write               2278618
control file parallel write          3091888
enq: CF - contention                 4108238
rdbms ipc reply                      4283877
db file scattered read               4357653
class slave wait                     5123780
control file sequential read         6971659
rdbms ipc message                   11899157
jobq slave wait                     14732974
log file parallel write             15310721
log buffer space                    21405250
SQL*Net message from client         26272575
log file switch completion          66115558
enq: HW - contention               100841479
buffer busy waits                  114070065


What user is waiting the most?
Again, the power in this SQL query is that we are now able to determine what user is consuming the most resource at a point in time, independent of the total resources that the user has used. You can now, with this query, answer the question of who is waiting the most for resources at a point in time. If a user calls you up on the phone and says they are experiencing delays, you can use this query to verify that they are actually waiting in the database for a result set for a given time period. This SQL is written for a 30-minute interval from current system time so you may need to change.

select sesion.sid, sesion.username,
       sum(active_session_history.wait_time + active_session_history.time_waited) ttl_wait_time
    from v$active_session_history active_session_history, v$session sesion
   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
     and active_session_history.session_id = sesion.sid
  group by sesion.sid, sesion.username
 order by 3;

  SID User       TTL_WAIT_TIME
----- ---------- -------------
  135 SCOTT           91167481
  149 SCOTT          107409491
  153 SCOTT          110796799


What SQL is currently using the most resources?
This query will get you started in the proper direction of zeroing in on what SQL statement is consuming the most resource wait times on your system. No longer do you have to go to the V$SQLAREA and try to pick out the top 10 or 20 SQL hogs on your system by disk reads or executions. Now you really know what SQL statements are consuming resources and waiting the most. These are the SQL that you really need to tune because the fact that a SQL statement performs 20,000 reads does not mean that it is a bottleneck in your system.

select active_session_history.user_id, dba_users.username, sqlarea.sql_text,
       sum(active_session_history.wait_time + active_session_history.time_waited) ttl_wait_time
    from v$active_session_history active_session_history, v$sqlarea sqlarea, dba_users
   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
     and active_session_history.sql_id = sqlarea.sql_id
     and active_session_history.user_id = dba_users.user_id
  group by active_session_history.user_id,sqlarea.sql_text, dba_users.username
order by 4;

USER_ID User   SQL_TEXT                                                TTL_WAIT_TIME
------- ------ -----------------------------------------------------   -------------
     57 SCOTT  insert into sys.sourcetable (select * from sys.source$)     304169752


What object is currently causing the highest resource waits?
This is a great query. Now we can actually see which objects a SQL statement is hitting. Moreover, if you take a further look at the V$ACTIVE_SESSION_HISTORY view you will see that you can tailor this query to report on the actual blocks that are being accessed within the objects for the SQL statement. This is great help in determining if you may need to reorg your object or redistribute to reduce the contention on that object.

set linesize 90
col object_name heading 'Object|Name'       format a27
col c2 heading 'Object|Type'                format a20
col c3 heading 'Event|Name'                 format a30
col c4 heading 'Total|Wait Time|(in secs)'  format 999,999

select obj.object_name ,
       obj.object_type c2,
       active_session_history.event c3,
       round((sum(active_session_history.wait_time + active_session_history.time_waited)/ 100),2)  c4
    from v$active_session_history active_session_history, dba_objects obj
   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
     and active_session_history.current_obj# = obj.object_id
  group by obj.object_name, obj.object_type, active_session_history.event
  order by 4;
 

OBJECT_NAME    OBJECT_TYPE  Wait Event                     TTL_WAIT_TIME
-------------- ------------ ------------------------------ -------------
SOURCE$         TABLE       ksfd: async disk IO                       23
SOURCETABLE     TABLE       ksfd: async disk IO                      453
SOURCETABLE     TABLE       latch: cache buffers chains            33258
SOURCETABLE     TABLE       db file scattered read                 82593
SOURCETABLE     TABLE       db file sequential read               111202
SOURCETABLE     TABLE       control file parallel write           137237
SOURCETABLE     TABLE       read by other session                 165501
SOURCETABLE     TABLE       log file sync                         612660
SOURCE$         TABLE       log buffer space                      932308
SOURCETABLE     TABLE       control file sequential read         1428575
SOURCE$         TABLE       log file switch completion           1856281
SOURCE$         TABLE       read by other session                1858741
SOURCE$         TABLE       db file scattered read               4275060
SOURCETABLE     TABLE       rdbms ipc reply                      4283877
SOURCETABLE     TABLE       log buffer space                    14152000
SOURCE$         TABLE       enq: HW - contention                25483656
SOURCETABLE     TABLE       log file switch completion          59228080
SOURCETABLE     TABLE       enq: HW - contention                75357823
SOURCETABLE     TABLE       buffer busy waits                  114055403


Who is Locking
Find out which session is locking a record
select blocking_session, blocking_instance, seconds_in_wait
from v$session
where sid = &SID;


Find out who is holding the lock
V$SESSION Columns
-  SID = the SID
-  SERIAL# = Serial# of the session
-  MACHINE = the client that created the session
-  TERMINAL = terminal of the client
-  PROGRAM = the client program, e.g. TOAD.EXE
-  STATUS = Active/Inactive
-  SQL_ID = the SQL_ID
-  PREV_SQL_ID = the previous SQL

Getting the SQL
select sql_text, sql_fulltext
from v$sql
where sql_id = &SQLID;

Full Code
select SQL_TEXT
from v$sqltext
where sql_id =
&SQLID
order by piece ;