Database Journal
MS SQL Oracle DB2 Access MySQL PostgreSQL Sybase PHP SQL Etc SQL Scripts & Samples Links Database Forum

» Database Journal Home
» Database Articles
» Database Tutorials
MS SQL
Oracle
DB2
MS Access
MySQL
» RESOURCES
Database Tools
SQL Scripts & Samples
Links
» Database Forum
» Sitemap
Free Newsletters:
DatabaseDaily  
News Via RSS Feed


follow us on Twitter
Database Journal |DBA Support |SQLCourse |SQLCourse2
 

Featured Database Articles

Oracle

Posted Mar 10, 2005

Oracle: Collecting Real Time Wait Events - Page 2

By DatabaseJournal.com Staff


By Alexander Bubernak

Collecting Real Time Wait Events

The scenario from my example below is taken at a time when multiple users have called in complaining about performance for the past 10 minutes of running their application.

The examples here are just a brief overview of how to use collected real time wait event data.

Note: Parameter timed_statistics must be set to true to collect timing of wait events.

Let's create a table to store real time wait events for session information.

/*
   Author: Alex Bubernak
   This will create 
     real_time_session_waits table
*/

drop table real_time_session_waits
/
create table real_time_session_waits
( snap_tm date not null,
  seq# number not null,
  sid number not null,
  event varchar2(64) not null,
  p1 number,
  p2 number,
  p3 number,
  wait_time number,
  seconds_in_wait number,
 object_id number )
tablespace tools
/

Run the following anonymous SQL block to insert wait events for a given time period. For our example, we will use a 30-second sampling.

SQL> @collect_rt_waits
SQL> Enter time is seconds to run: 30

collect_rt_waits.sql

/*
   Author: Alex Bubernak

   This script will select from v$session_wait and v$session to 
   insert real-time wait event statistics in user created table.
   Inserts are run every second until run time is exceeded or
   you can modify dbms_lock.sleep(n) to any time you prefer.

   Remove truncate command to keep history.
   Modify script to only collect waits for a single session if
   necessary.

  Instructions:
  SQL> collect_rt_waits.sql
  SQL> Enter time in seconds to run: 30

*/
accept tm prompt 'Enter time in seconds to run: '
variable tm_t number;

truncate table real_time_session_waits -- comment out to keep history
/

declare

iteration number;
start_time date;

begin
 :tm_t := '&&tm';
 select sysdate into start_time from dual;

   iteration := 24*60*60/:tm_t;
 while sysdate < start_time+1/iteration loop
    insert into real_time_session_waits (SNAP_TM, 
                                 SEQ#,       
				 SID,            
				 EVENT,          
				 P1,             
				 P2,             
				 P3,             
				 WAIT_TIME,      
				 SECONDS_IN_WAIT,
				 OBJECT_ID )
				select 	sysdate,
                                        a.seq#,
					a.sid,
					a.event,
					a.p1,
					a.p2,
					a.p3,
					a.wait_time,
					a.seconds_in_wait,
					b.row_wait_obj#
				from v$session_wait a,
				     v$session b
				where a.sid = b.sid
                                -- and a.sid = 'session id' -- only insert a single session
				and a.event not in
				         ('pmon timer',
				          'rdbms ipc message',
				          'smon timer',
				          'dispatcher timer',
				          'Null event',
				          'parallel query dequeue wait',
				          'parallel query idle wait - Slaves',
				          'pipe get',
				          'PL/SQL lock timer',
				          'slave wait',
				          'virtual circuit status',
				          'lock element cleanup',
				          'WMON goes to sleep'
				          );
   dbms_lock.sleep(1); -- sleep for one second before checking and inserting next record. 
-- Can take this out for more detail or change value for longer 
-- runs.
 end loop;
commit;
end;
/

Let's display wait event counts and time by session and for our example filter idle events. Note: Remember what was said previously about idle events.

wait_cnt_by_sess.sql

/* 
   Author: Alex Bubernak
   Script displays wait event count and time for each sessions 
   completed wait event
*/
set linesize 150
col sid format 99999 heading "Session ID"
col event format a45 heading "Wait Event"
col cnt heading "Wait Count"
col wait heading "Wait time(cs)"
col pct format 999.99 heading "% of Time"
select sid,event, count(*) cnt, sum(wait_time) wait 
from real_time_session_waits
where wait_time > 0 -- this will limit wait times from sessions that have completed event and are > 1 sc.
-- and sid = 81 -- change to limit by sid
-- filter out idle events
and event not in ('SQL*Net break/reset to client',
	 	  'SQL*Net message to client',
		  'SQL*Net message from client',
		  'SQL*Net more data to client')
group by sid,event
order by wait
/
Session ID Wait Event                        Wait Count Wait time(cs)
---------- --------------------------------- ---------- -------------
         4 control file parallel write                1             0
        82 free buffer waits                          1             0
       139 db file sequential read                   14             1
       105 latch free                                15             1
        81 buffer busy waits                          1             1
        48 db file sequential read                   19             1
        41 db file sequential read                   28             2
        88 latch free                                18             2
       132 db file sequential read                   20             2
        81 db file sequential read                   19            11
         2 db file parallel write                    18            20
       143 latch free                                20           127
       133 db file sequential read                    9          1098
        82 db file sequential read                   10          1525
       172 db file sequential read                   10          1755
        81 db file sequential read                   20          2298

We see that session 81 waited 20 times for 'db file sequential read' for almost 23 seconds of the 30 second sampling.

Now let's modify the script to filter for session 81.

Session ID Wait Event                        Wait Count Wait time(cs)
---------- --------------------------------- ---------- -------------
        81 latch free                                 1             3
        81 buffer busy waits                          1             5
        81 db file sequential read                   20          2298

We can see three wait events with the most significant and largest amount of time are for 'db file sequential read' for the 30-second timeframe. The SQL statement involved should be analyzed to eliminate any unnecessary IOs, possibly spread IO across multiple volumes, partition the object if possible, etc.

From the above examples, we can see where the bottleneck in the session is, for the given timeframe. In the above, you can join REAL_TIME_SESSION_WAITS.OBJECT_ID with DBA_OBJECTS.DATA_OBJECT_ID to find the object or objects involved. In this case the P(n) columns would also be able to tell you what objects are involved when joined with DBA_EXTENTS.

SELECT  owner, segment_type, segment_name 
        FROM     dba_extents 
        WHERE    file_id = 'P1 value'
        AND      'P2 value' BETWEEN block_id AND block_id + blocks - 1;

We could also look at V$SESSION_EVENT for wait event statistics for the life of the session.

select 	event,
            total_waits,
	time_waited 
from v$session_event
where sid = 81
order by time_waited
/
EVENT                               TOTAL_WAITS TIME_WAITED
----------------------------------- ----------- -----------
buffer busy waits                            15           0
wait list latch free                          2           3
SQL*Net message to client                 41715           5
db file parallel read                         8           8
free buffer waits                             3          41
direct path read                           2001          47
log buffer space                              7         110
log file sync                                53         148
db file sequential read                      98        5568
latch free                                33361        6157
db file scattered read                    63065       10374
SQL*Net message from client               41714       79457

As you can see 'db file sequential read' is shown as a less significant wait event compared to the other three top events. This is not saying that the other events should not be examined, but that the problem was most noticeable to the users with a high 'db file sequential read' wait event time.

The above example only shows you a small piece of how to collect and use real time wait events.

Summary

Real time wait events are an excellent way of troubleshooting a problem as it is happening and are easier to setup and collect compared to 10046 event tracing. It does not have the accuracy or as much detail as the 10046 event, but can be a quick method to troubleshoot a problem as it is happening.



Oracle Archives

Comment and Contribute

 


(Maximum characters: 1200). You have characters left.

 

 




Latest Forum Threads
Oracle Forum
Topic By Replies Updated
Oracle Data Mining: Classification jan.hasller 0 July 5th, 07:19 AM
Find duplicates - Unique IDs Lava 5 July 2nd, 08:30 AM
no matching unique or primary key rcanter 1 April 25th, 12:32 PM
Update values of one table based on condition of values in other table using Trigger Gladiator 3 February 29th, 06:01 PM