Wait Events

Wait Event General Area Possible Causes Look for / Examine

buffer busy waits

Buffer cache, DBWR

Depends on buffer type. For example, waits for an index block may be caused by a primary key that is based on an ascending sequence.

Examine V$SESSION while the problem is occurring to determine the type of block in contention.

free buffer waits

Buffer cache, DBWR, I/O

Slow DBWR (possibly due to I/O?)

Cache too small

Examine write time using operating system statistics. Check buffer cache statistics for evidence of too small cache.

db file scattered read

I/O, SQL statement tuning

Poorly tuned SQL

Slow I/O system

Investigate V$SQLAREA to see whether there are SQL statements performing many disk reads. Cross-check I/O system and V$FILESTAT for poor read time.

db file sequential read

I/O, SQL statement tuning

Poorly tuned SQL

Slow I/O system

Investigate V$SQLAREA to see whether there are SQL statements performing many disk reads. Cross-check I/O system and V$FILESTAT for poor read time.

enqueue waits (waits starting with enq:)

Locks

Depends on type of enqueue

Look at V$ENQUEUE_STAT.

library cache latch waits: library cache, library cache pin, and library cache lock

Latch contention

SQL parsing or sharing

Check V$SQLAREA to see whether there are SQL statements with a relatively high number of parse calls or a high number of child cursors (column VERSION_COUNT). Check parse statistics in V$SYSSTAT and their corresponding rate for each second.

log buffer space

Log buffer, I/O

Log buffer small

Slow I/O system

Check the statistic redo buffer allocation retries in V$SYSSTAT. Check configuring log buffer section in configuring memory chapter. Check the disks that house the online redo logs for resource contention.

log file sync

I/O, over- committing

Slow disks that store the online logs

Un-batched commits

Check the disks that house the online redo logs for resource contention. Check the number of transactions (commits + rollbacks) each second, from V$SYSSTAT.

buffer busy waits

posted Jul 27, 2011, 1:28 PM by Sachchida Ojha   [ updated Jul 27, 2011, 1:29 PM by Sachchida Ojha ]

This wait indicates that there are some buffers in the buffer cache that multiple processes are attempting to access concurrently. Query V$WAITSTAT for the wait statistics for each class of buffer. Common buffer classes that have buffer busy waits include data block, segment header, undo header, and undo block.

Check the following V$SESSION_WAIT parameter columns:


P1 - File ID
P2 - Block ID
P3 - Class ID

Causes
To determine the possible causes, first query V$SESSION to identify the value of ROW_WAIT_OBJ# when the session waits for buffer busy waits. For example: SELECT row_wait_obj# FROM V$SESSION WHERE EVENT = 'buffer busy waits';

To identify the object and object type contended for, query DBA_OBJECTS using the value for ROW_WAIT_OBJ# that is returned from V$SESSION. For example: SELECT owner, object_name, subobject_name, object_type FROM DBA_OBJECTS WHERE data_object_id = &row_wait_obj;

Identifying sessions to Trace

posted Jul 27, 2011, 11:27 AM by Sachchida Ojha   [ updated Jul 27, 2011, 11:27 AM by Sachchida Ojha ]

It is expected that the session/s to be traced have already been identified using information elsewhere in this set of articles. Below is a reminder of some of the forms of statement which may be used when isolating a session to be traced:

Finding user/s of a particular SQL statement given the "ADDRESS" and "HASH_VALUE" from V$SQLAREA:

  SELECT s.sid , s.serial#, s.status, s.server, s.username
    FROM v$session s
   WHERE s.sql_address='&ADDRESS'
     AND s.sql_hash_value='&HASH_VALUE'
  ;

Finding the SID/SERIAL# of a user showing a particular type of wait:

  SELECT s.sid , s.serial#, s.status, s.server, s.username, 
	e.event, e.time_waited
    FROM v$session_event e, v$session s
   WHERE e.sid=s.sid
     AND e.event like '&WAITEVENT_TO_CHECK'
     AND e.time_waited > '&WAIT_TIME_THRESHOLD'
  ;
  
  ( or use e.total_waits > '&NUM_WAITS_THRESHOLD')

  Eg: Replace &WAITEVENT_TO_CHECK with "buffer busy waits" to show
      sessions exhibiting lots of buffer busy waits.

Finding the SID/SERIAL# of a user showing a particular count for a given statistic:

  SELECT s.sid , s.serial#, s.status, s.server, s.username, 
	 n.name, t.value
    FROM v$statname n, v$sesstat t, v$session s
   WHERE t.sid=s.sid
     AND t.statistic#=n.statistic#
     AND n.name like '&STATISTIC_TO_CHECK'
     AND t.value > '&VALUE_THRESHOLD'
  ;
  
  Eg: Replace &STATISTIC_TO_CHECK with "sorts (disk)" to show sessions 
      exhibiting lots of disk sorts.

Tracing your own Session

To start tracing your own session simply execute the PL/SQL call:
  DBMS_SUPPORT.START_TRACE; 

Tracing another Session

Once a session has been isolated then you need to know the SID of the target session (and possibly the SERIAL#). To start tracing the target session simply call:
  DBMS_SUPPORT.START_TRACE_IN_SESSION( SID , NULL );

If it is important to capture an exact session you should specify both the SID and SERIAL# . Eg:

  DBMS_SUPPORT.START_TRACE_IN_SESSION( SID , SERIAL# );

This PL/SQL procedure will ask the target session to start writing trace output. The trace may NOT start immediately as there are certain points in the Oracle code where a session checks to see if it has been asked to do something (like writing trace output) - the target session only starts tracing once it has seen the request.

Stopping Trace

To stop tracing in your own session call:
  DBMS_SUPPORT.STOP_TRACE;

To stop tracing another session call:

  DBMS_SUPPORT.STOP_TRACE_IN_SESSION( SID , NULL );

Trace Output File Format

Output files contain RAW trace output and can be found in the USER_DUMP_DEST directory for user sessions and BACKGROUND_DUMP_DEST for background processes. A summary of the RAW format can be found in Note:39817.1 . In this section we mention some of the important points about the trace file along with some tools which can be used to interpret the output for you.

Raw Trace File

The raw trace file is described in Note:39817.1. Important points to note are:
  1. Most lines refer to a CURSOR number. Eg: PARSING IN CURSOR #3
  2. EXECutes, FETCHes and WAITs are recorded against a cursor. The information applies to the most recently parsed statement within that cursor.
    Eg: FETCH #3 indicates a fetch from the most recently parsed and executed statement in cursor 3.
  3. All timing information in the trace file is in 1/100ths of a second.
  4. A time of ZERO in the trace file indicates LESS THAN 1/100th of a second.
  5. The information in the WAIT lines is the same as is found in V$EVENT_NAME (or V$SESSION_WAIT).

    Eg: WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25

    implies a wait while using cursor #1 for "db file scattered read" V$EVENT_NAME shows P1 is "file#", P2 is "block#" and P3 is "blocks" so in this case this indicates a wait for a read to complete from file# 4, block#1435 for 25 blocks. The WAIT took 5/100 seconds or 50mS to complete.
  6. STAT lines indicate that the cursor has been closed. From Oracle 7.3.3 onwards the STAT lines give the ACTUAL execution plan for the statement.
Example
There are many ways to process a raw trace file but most require text processing filters such as GREP, AWK, NAWK, SED or PERL to extract the required information. As an example consider that several sessions have been showing waits for 'buffer busy waits'. By tracing a session the actual waits are written to the trace file. These could then be processed to list the file# and block# being waited for.
  Eg: In Unix one could process the waits using a command like: 

	grep 'buffer busy waits' trace_file | \
	 awk ' { print substr($0,9); } ' | \
	 sort > sorted_buffer_wait_list
The actual waits may then be mapped back to an object using SQL like:
  SELECT segment_owner, segment_name
    FROM dba_extents 
   WHERE file_id=&FILE_ID 
     AND &BLOCK_ID between block_id and block_id+blocks-1

I/O-related Wait Events

posted Jul 27, 2011, 10:33 AM by Sachchida Ojha   [ updated Jul 27, 2011, 11:24 AM by Sachchida Ojha ]

I/O-related Wait Events that occur most often in Oracle databases together with reference notes describing each wait. 

Datafile I/O-Related Wait Events:


'db file sequential read' Note:34559.1
'db file scattered read' Note:34558.1
'db file parallel read'
'direct path read' Note:50415.1
'direct path write' Note:50416.1
'direct path read (lob)'
'direct path write (lob)'
Controlfile I/O-Related Wait Events:
'control file parallel write'
'control file sequential read'
'control file single write'

Redo Logging I/O-Related Wait Events:

'log file parallel write' Note:34583.1
'log file sync' Note:34592.1
'log file sequential read'
'log file single write'
'switch logfile command'
'log file switch completion'
'log file switch (clearing log file)'
'log file switch (checkpoint incomplete)'
'log switch/archive'
'log file switch (archiving needed)'

Buffer Cache I/O-Related Wait Events:

'db file parallel write' Note:34416.1
'db file single write'
'write complete waits'
'free buffer waits'

db file sequential read:

A sequential read operation reads data into contiguous memory (usually a single-block read with p3=1, but can be multiple blocks). Single block I/Os are usually the result of using indexes. This event is also used for rebuilding the controlfile and reading datafile headers (P2=1). In general, this event is indicative of disk contention on index reads.

db file scattered read:

Similar to db file sequential reads, except that the session is reading multiple data blocks and scatters them into different discontinuous buffers in the SGA. This statistic is NORMALLY indicating disk contention on full table scans. Rarely, data from full table scans could be fitted into a contiguous buffer area, these waits would then show up as sequential reads instead of scattered reads.

The following query shows average wait time for sequential versus scattered reads:

prompt "AVERAGE WAIT TIME FOR READ REQUESTS"
select a.average_wait "SEQ READ", b.average_wait "SCAT READ"
from sys.v_$system_event a, sys.v_$system_event b
where a.event = 'db file sequential read' and b.event = 'db file scattered read';
use v$session_wait View to find information about Waiting:
Parameters:
P1 = file#
P2 = block#
P3 = blocks


file# : This is the file# of the file that Oracle is trying to read
block# : This is the starting block number in the file from where Oracle starts reading the blocks.
blocks : This parameter specifies the number of blocks that Oracle is trying to read from the file# starting at block#.
This is usually "1" but if P3 > 1 then this is a multiblock read. Multiblock "db file sequential read"s may be seen in earlier Oracle versions when reading from a
SORT (TEMPORARY) segments.

We can see this wait event on v$session_event View:

SELECT sid, total_waits, time_waited FROM v$session_event WHERE event='db file sequential read' and total_waits> 0 ORDER BY 3,2;

SID TOTAL_WAITS TIME_WAITED
---------- ----------- -----------
310 1 0
1871 1 0
1238 2 0
5263 2 0
4650 5 0
3403 1 1
1555 2 1
1566 3 1
3412 3 1
2491 3 1
4025 4 1


SQL>SELECT SID, EVENT, P1, P2 , P3 FROM v$session_wait where event='db file sequential read' ;

SID EVENT P1 P2 P3
---------- -------------------------------------------------- ---------- ---------- ----------
1874 db file sequential read 418 2502194 1
2474 db file sequential read 66 20134 1
2478 db file sequential read 435 268260 1
4343 db file sequential read 420 485693 1

SQL>SELECT tablespace_name, file_name FROM dba_data_files WHERE file_id = 418;

TABLESPACE_NAME FILE_NAME
------------------------------ ----------------------------------------------------------------------
TS_ARBINET_DATA +TDB1_DATA/tdb1/datafile/ts_arbinet_data.378.751650823

block# ->
If the file is NOT a TEMPFILE then the following query should show the name and type of the segment:

SYS@TDB1 SQL>SELECT owner , segment_name , segment_type FROM dba_extents WHERE file_id = 46 AND 2502194 BETWEEN block_id AND block_id + blocks-1;

no rows selected


About Partition use:

SELECT owner , segment_name , segment_type, partition_name FROM dba_extents WHERE file_id = 46 AND 6072 BETWEEN block_id AND block_id + blocks -1

OWNER SEGMENT_NAME SEGMENT_TYPE PARTITION_NAME
------------------------------ ---------------- ------------------ -------------------
USER XXX TABLE PARTITION SYS_P1852


When see waiting time "db file sequential read" event, we should investigate V$SQLAREA to see SQL statements performing many disk reads. Cross-check I/O
system and V$FILESTAT for poor read time.

We can reduce a waiting:
- Check SQL statements [use index scans] , Tune SQL Statements.
- Check buffer cache, A larger buffer cache can help; (increase SGA)
- Partition TABLE and INDEX , that can help to reduce the amount of data you need to look at.

1-3 of 3