Database Wait Statistics – Oracle Database 10g

When a SQL is submitted by a user to Oracle database, it never happens that Oracle will execute the SQL continuously at one go. Oracle process never get to work on the execution of statement without any interruptions. Often the process has to pause or wait for some event or some other resource to be released. Thus active Oracle process is doing one of the following thing at any point of time.

The process is executing the SQL statement.

The process is waiting for something (for example, a resource such as a database buffer or a latch). It could be waiting for an action such as a write to the buffer cache to complete.
That’s why the response time—the total time taken by Oracle to finish work—is correctly
defined as follows:

response time = service time + wait time

So only part of the time is spend by oracle process to actually “do” some thing. Rest of the time process just wait for some resource to get freed up. It can be waiting log writter process or database writter process or any other resources.

The wait event may also be due to unavailable buffers or latches.

Four dynamic performance views contain wait information: V$SESSION, V$SYSTEM_EVENT, V$SESSION_EVENT, and V$SESSION_WAIT. These four views list just about all the events the instance was waiting for and the duration of these waits. Understanding these wait events is essential for resolving performance issues.

There are different wait classes defined in database. Each class will contain different wait events. There are around 860 wait events defined in Oracle database 10g and are classified under different wait classes.

Some of the main wait classes includes:

• Administrative: Waits caused by administrative commands, such as rebuilding an index, for example.
• Application: Waits due to the application code.
• Cluster: Waits related to Real Application Cluster management.
• Commit: Consists of the single wait event log file sync, which is a wait caused by commits in the database.
• Concurrency: Waits for database resources that are used for locking; for example, latches.
• Configuration: Waits caused by database or instance configuration problems, including a low shared-pool memory size, for example.
• Idle: Idle wait events indicate waits that occur when a session isn’t active; for example, the ‘SQL*Net message from client’ wait event.

You can see the complete list of wait classes using V$SESSION_WAIT_CLASS dynamic performance view.

Analyzing Instance Performance

You can check the percentage of time spend by the database in waiting for resource and percentage of time spend by database in actual execution.

SQL> SELECT METRIC_NAME, VALUE
2  FROM V$SYSMETRIC
3  WHERE METRIC_NAME IN (‘Database CPU Time Ratio’,
4  ‘Database Wait Time Ratio’) AND
5  INTSIZE_CSEC =
6  (select max(INTSIZE_CSEC) from V$SYSMETRIC);

METRIC_NAME                                                           VALUE
—————————————————————- ———-
Database Wait Time Ratio                                         15.6260647
Database CPU Time Ratio                                          84.3739353

If the database performance shows that ‘Database Wait Time Ratio’ is greater then ‘Database CPU Time Ratio’ or the value for ‘Database Wait Time Ratio’ is quite significant, then in that case you need to dig inside to get the information about where exactly oracle is waiting. You need to basically find the type of wait. This will give you root cause. Once you get the root cause you can work to fix the same.

you can determine the total waits and percentage of waits by wait class.

SELECT WAIT_CLASS,
TOTAL_WAITS,
round(100 * (TOTAL_WAITS / SUM_WAITS),2) PCT_TOTWAITS,
ROUND((TIME_WAITED / 100),2) TOT_TIME_WAITED,
round(100 * (TIME_WAITED / SUM_TIME),2) PCT_TIME
FROM
(select WAIT_CLASS,
TOTAL_WAITS,
TIME_WAITED
FROM V$SYSTEM_WAIT_CLASS
WHERE WAIT_CLASS != ‘Idle’),
(select sum(TOTAL_WAITS) SUM_WAITS,
sum(TIME_WAITED) SUM_TIME
from V$SYSTEM_WAIT_CLASS
where WAIT_CLASS != ‘Idle’)
ORDER BY PCT_TIME DESC;

WAIT_CLASS           TOTAL_WAITS PCT_TOTWAITS TOT_TIME_WAITED   PCT_TIME
——————– ———– ———— ————— ———-
System I/O                180300        19.96          3008.8      49.53
Commit                     67855         7.51         1302.46      21.44
User I/O                  291565        32.28         1056.55      17.39
Application                 3637           .4          596.66       9.82
Other                      15388          1.7            67.4       1.11
Concurrency                 1264          .14           38.12        .63
Network                   343169        37.99            3.86        .06
Configuration                 22            0               1        .02

8 rows selected.

In the above output percentage of time waited (last column) is more important and gives the correct picture of the impact due to wait. Example if we see total number of Network waits are large but the actual percentage of time contributed to the wait is very less (0.06%).

The key dynamic performance tables for finding wait information are the V$SYSTEM_EVENT, V$SESSION_EVENT, V$SESSION_WAIT, and the V$SESSION views. The first two views show the waiting time for different events.

V$SYSTEM_EVENT

The V$SYSTEM_EVENT view shows the total time waited for all the events for the entire system since the instance started up. The view doesn’t focus on the individual sessions experiencing waits, and therefore it gives you a high-level view of waits in the system. You can use this view to find out that the top instance-wide wait events are. You can calculate the top n waits in the system by dividing the event’s wait time by the total wait time for all events.

select EVENT, TOTAL_WAITS, TIME_WAITED, WAIT_CLASS from V$SYSTEM_EVENT
where wait_class != ‘Idle’
order by time_waited desc;

EVENT                          TOTAL_WAITS TIME_WAITED WAIT_CLASS
—————————— ———– ———– ——————–
log file parallel write             128953      210308 System I/O
log file sync                        67904      130313 Commit
db file sequential read             259065       73686 User I/O
enq: TX – row lock contention          226       59080 Application
control file parallel write          28282       57929 System I/O
db file parallel write               19155       32924 System I/O
db file scattered read               31841       30925 User I/O
os thread startup                       95        3262 Concurrency
rdbms ipc reply                        485        2116 Other
PX Deq: Signal ACK                    1971        1103 Other
local write wait                       245         864 User I/O

we can get the session level waits for each event using V$SESSION_EVENT view. In this view the TIME_WAITED is the wait time per session.

V$SESSION_EVENT

select sid, EVENT, TOTAL_WAITS, TIME_WAITED, WAIT_CLASS
from V$SESSION_EVENT
where WAIT_CLASS != ‘Idle’
order by TIME_WAITED;

  SID EVENT                          TOTAL_WAITS TIME_WAITED WAIT_CLASS
———- —————————— ———– ———– ————
390 os thread startup                       55      1918   Concurrency
393 db file sequential read              10334      4432   User I/O
396 db file parallel write                8637      14915  System I/O
397 db file parallel write               10535      18035  System I/O
394 control file parallel write          28294      57928  System I/O
395 log file parallel write             129020      210405 System I/O

As we can see from above output that session 395 is having maximum wait time because of system I/O. Here system I/O is the I/O because of background processes like DBWR and LGWR etc.

You can get all the database wait events from V$EVENT_NAME and the related meaning of all the wait events available in oracle 10g by checking this documentation link.

V$SESSION_WAIT

The third dynamic view is the V$SESSION_WAIT view, which shows the current waits or just completed waits for sessions. The information on waits in this view changes continuously based on the types of waits that are occurring in the system. The real-time information in this view provides you with tremendous insight into what’s holding up things in the database right now. The
V$SESSION_WAIT view provides detailed information on the wait event, including details such as file number, latch numbers, and block number. This detailed level of information provided by the V$SESSION_WAIT view enables you to probe into the exact bottleneck that’s slowing down the database. The low-level information helps you zoom in on the root cause of performance problems.

SQL> select sid, event, WAIT_CLASS, WAIT_TIME, SECONDS_IN_WAIT, STATE from v$session_wait
2  where wait_class != ‘Idle’;

       SID EVENT                          WAIT_CLASS            WAIT_TIME
———- —————————— ——————– ———-
SECONDS_IN_WAIT STATE
————— ——————-
337 SQL*Net message to client      Network                      -1
0 WAITED SHORT TIME

Here wait time -1 means that session has waited for less then 1/100th of a second.
You can get the complete wait information for a particular session using V$SESSION view. You can get SQLID of the sql, which is causing wait.

V$SESSION

For getting the wait statistics you can go with the following methodology.

• First, look at the V$SYSTEM_EVENT view and rank the top wait events by the total amount of time waited, as well as the average wait time for that event.
• Next, find out more details about the specific wait event that’s at the top of the list. You can check V$WAITSTAT view for the same. Check the type of wait this view is showing. If the wait is due to undo header or undo block then wait is related to undo segment.
• Finally, use the V$SESSION view to find out the exact objects that may be the source of a problem. For example, if you have a high amount of db file scattered read-type waits, the V$SESSION view will give you the file number and block number involved in the wait events.

In V$SESSION we have a column called BLOCKING_SESSION_STATUS. IF this column value is ‘valid’, then we can presume that corresponding session is getting blocked.

V$SESSION_WAIT_HISTORY

The V$SESSION_WAIT_HISTORY view holds information about the last ten wait events for each active session. The other wait-related views, such as the V$SESSION and the V$SESSION_WAIT, show you only the wait information for the most recent wait. This may be a short wait, thus escaping your scrutiny.

SQL> select sid from v$session_wait_history
2  where wait_time = (select max(wait_time) from v$session_wait_history);

      SEQ# EVENT                            P1         P2         P3  WAIT_TIME
———- ———————— ———- ———- ———- ———-
1 rdbms ipc message            180000          0          0     175787
2 rdbms ipc message            180000          0          0     175787
3 rdbms ipc message            180000          0          0      60782
4 rdbms ipc message            180000          0          0     175787
5 rdbms ipc message            180000          0          0     138705
6 db file sequential read           1        368          1          0
7 rdbms ipc message            180000          0          0     158646
8 db file sequential read           1        368          1          0
9 db file sequential read           1         73          1          0
10 db file sequential read           1         30          1          0

Note that a zero value under the WAIT_TIME column means that the session is waiting for a specific wait event. A nonzero value represents the time waited for the last event.

V$ACTIVE_SESSION_HISTORY

The V$SESSION_WAIT view tells you what resource a session is waiting for. The V$SESSION view also provides significant wait information for active sessions. However, neither of these views provides you with historical information about the waits in your instance. Once the wait is over, you can no longer view the wait information using the V$SESSION_WAIT view. The waits are so fleeting that by the time you query the views, the wait in most times is over. The new Active Session History (ASH) feature, by recording session information, enables you to go back in time and review the history of a performance bottleneck in your database. Although the AWR provides hourly snapshots
of the instance by default, you won’t be able to analyze events that occurred five or ten minutes ago, based on AWR data. This is where the ASH information comes in handy. ASH samples the V$SESSION view every second and collects the wait information for all active sessions. An active session is defined as a session that’s on the CPU or waiting for a resource. You can view the ASH session statistics through the view V$ACTIVE_SESSION_HISTORY, which contains a single row for each active session in your instance. ASH is a rolling buffer in memory, with older information being overwritten by new session data. Every 60 minutes,the MMON background process flushes filtered ASH data to disk, as part of the hourly AWR snapshots. If the ASH buffer is full, the MMNL background process performs the flushing of data. Once the ASH data is flushed to disk, you won’t be able to see it in the V$ACTIVE_SESSION_HISTORY view. You’ll now have to use the DBA_HIST_ACTIVE_SESS_HISTORY view to look at the historical data.

obtaining the objects with highest waits

SELECT a.current_obj#, o.object_name, o.object_type, a.event,
SUM(a.wait_time +
a.time_waited) total_wait_time
FROM v$active_session_history a,
dba_objects o
WHERE a.sample_time between sysdate – 30/2880 and sysdate
AND a.current_obj# = o.object_id
GROUP BY a.current_obj#, o.object_name, o.object_type, a.event
ORDER BY total_wait_time;

 OBJECT_NAME                OBJECT_TYPE         EVENT                  TOTAL_WAIT_TIME
——————–       ——————- ———————– —————-
FND_LOGINS                 TABLE               db file sequential read   47480
KOTTB$                     TABLE               db file sequential read   48077
SCHEDULER$_WINDOW          TABLE               db file sequential read   49205
ENG_CHANGE_ROUTE_STEPS_TL  TABLE               db file sequential read   52534
JDR_PATHS_N1               INDEX               db file sequential read   58888
MTL_ITEM_REVISIONS_B       TABLE               SQL*Net more data to client

select p1text, p1, p2text, p2, p3text, p3, a.event
from v$active_session_history a
WHERE a.sample_time between sysdate – 30/2880 and sysdate
AND a.current_obj# = 1938000

P1TEXT     P1          P2TEXT     P2   P3TEXT          P3  EVENT
——–   —         ——- ——- ———— —— ————————
file#      71          block#    4389  blocks           1  db file sequential read
file#      187         block#   89977  blocks           1  db file sequential read
file#      80          block#   79301  blocks           1  db file sequential read
driver id  675562835   #bytes       1  0
file#      11          block#     831  blocks           1  db file sequential read
driver id  675562835   #bytes       1  0

so we can see few history wait events for a particular object in database. We can get the segment stats for this object. Finally we can got to some conclusing and implementaing the solution to reduce the wait. For example if it is a ‘db file sequential read’ wait then

• Increase buffer cache size, but this wont help much. For this to do, you need to check cache miss percentages.
• Check the query and optimize it, so that it can read less number of blocks
• Increase freelists for that segment

some important wait events

The following query lists the most important wait events in your database in the last 15 minutes:

SELECT a.event,
SUM(a.wait_time +
a.time_waited) total_wait_time
FROM v$active_session_history a
WHERE a.sample_time between
sysdate – 30/2880 and sysdate
GROUP BY a.event
ORDER BY total_wait_time DESC;

EVENT                                                            TOTAL_WAIT_TIME
—————————————————————- —————
enq: TX – row lock contention                                          877360289
816854999
TCP Socket (KGAS)                                                       13787430
SQL*Net break/reset to client                                            6675324
db file sequential read                                                  2318850
control file parallel write                                              1790011
log file parallel write                                                  1411201
db file scattered read                                                     62132
os thread startup                                                          39640
null event                                                                     0

Users with the Most Waits

The following query lists the users with the highest wait times within the last 15 minutes:

SELECT s.sid, s.username,
SUM(a.wait_time +
a.time_waited) total_wait_time
FROM v$active_session_history a,
v$session s
WHERE a.sample_time between sysdate – 30/2880 and sysdate
AND a.session_id=s.sid
GROUP BY s.sid, s.username
ORDER BY total_wait_time DESC;

       SID USERNAME                       TOTAL_WAIT_TIME
———- —————————— —————
773 APPS                                 877360543
670 APPS                                 374767126
797                                       98408003
713 APPS                                  97655307
638 APPS                                  53719218
726 APPS                                  39072236
673 APPS                                  29353667
762 APPS                                  29307261
746 APPS                                  29307183
653 APPS                                  14677170
675 APPS                                  14676426

Identifying SQL with the Highest Waits

Using the following query, you can identify the SQL that’s waiting the most in your instance with in last 15 mins

SELECT a.user_id,d.username,s.sql_text,
SUM(a.wait_time + a.time_waited) total_wait_time
FROM v$active_session_history a,
v$sqlarea s,
dba_users d
WHERE a.sample_time between sysdate – 30/2880 and sysdate
AND a.sql_id = s.sql_id
AND a.user_id = d.user_id
GROUP BY a.user_id,s.sql_text, d.username;