True Session Wait Activity in Oracle 10g

Thursday Aug 5th 2004 by James Koopmann

Catching a session waiting on a resource used to be hit or miss. James Koopmann examines how Oracle 10g expedites this process.

Catching a session waiting on a resource used to be hit or miss. Let's take a look at how Oracle has helped give us a better mousetrap for seeing the waits experienced by sessions.

It used to be that a DBA would sit in front of the terminal screen and continually hit the ENTER key to watch activity in the V$SESSION_WAIT view to try and get a glimpse of the bottleneck and wait activity for connected sessions. This in itself was a very tedious task and honestly I would often get paranoid that I would miss some valuable information if I did not hit the ENTER key fast enough and thus I would never see the important wait event. Yes there was the V$SESSION_EVENT view that gave us a total for all waits but we never knew when the wait might have occurred. DBAs very quickly got smarter and started to sample the data in the V$SESSION_WAIT table and write it out to another table or dump it to an external list file. This was fine but the overhead of actually creating and then running the task that would populate these statistics could get high, and management of the task could get tedious.

To the Rescue

With Oracle 10g this has all been nicely taken over for us. Oracle will now sample data through internal kernel code for statistics similar to what was seen in the V$SESSION_WAIT view and store it in a limited amount of buffer space, 2 Meg per CPU. We can view these statistics by querying the new V$ACTIVE_SESSION_HISTORY view. The V$ACTIVE_SESSION_HISTORY view contains one row of sampled activity for each session that was active, either on the CPU or actually waiting for a resource. As this buffer gets full, because of the activity on the system, Oracle will move the captured statistics to disk as part of the Automatic Workload Repository (AWR) snapshot mechanism and it will now be available through the DBA_HIST_ACTIVE_SESS_HISTORY view. When querying for current information, depending on the activity of your system, you may need to go to both views to construct a valid picture of what has happened. The important thing to remember here is that this is historical activity of the waits that have occurred for SQL executed and we can now go back in time and look at what was the true cause of performance bottlenecks. Be forewarned that since the statistics are stored in the rotating buffer and are only moved to the DBA_HIST_ACTIVE_SESS_HISTORY through a snapshot, you may loose statistics. In addition, when the snapshot mechanism (AWR) does kick in and does its work to move database statistics between V$ACTIVE_SESSION_HISTORY and DBA_HIST_ACTIVE_SESS_HISTORY, it only takes a sampling of the data in V$ACTIVE_SESS_HISTORY for the snapshot. Furthermore, when AWR does kick in, it only takes a sampling of the data in V$ACTIVE_SESS_HISTORY for the snapshot. What this means is that you need to either catch what you want in the V$ACTIVE_SESS_HISTORY view before a snapshot or have your own scrapping utility again. For this reason, this article will only be concerned with querying off of the V$ACTIVE_SESS_HISTORY view to show a few ways you might want to query for information that had not been available before.

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.

  1  select active_session_history.event,
  2         sum(active_session_history.wait_time +
  3             active_session_history.time_waited) ttl_wait_time
  4    from v$active_session_history active_session_history
  5   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
  6* group by active_session_history.event
  7  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.

  1  select sesion.sid,
  2         sesion.username,
  3         sum(active_session_history.wait_time +
  4             active_session_history.time_waited) ttl_wait_time
  5    from v$active_session_history active_session_history,
  6         v$session sesion
  7   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
  8     and active_session_history.session_id = sesion.sid
  9  group by sesion.sid, sesion.username
 10* 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.

  1  select active_session_history.user_id,
  2         dba_users.username,
  3         sqlarea.sql_text,
  4         sum(active_session_history.wait_time +
  5             active_session_history.time_waited) ttl_wait_time
  6    from v$active_session_history active_session_history,
  7         v$sqlarea sqlarea,
  8         dba_users
  9   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
 10     and active_session_history.sql_id = sqlarea.sql_id
 11     and active_session_history.user_id = dba_users.user_id
 12  group by active_session_history.user_id,sqlarea.sql_text, dba_users.username
 13* 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.

  1  select dba_objects.object_name,
  2         dba_objects.object_type,
  3         active_session_history.event,
  4         sum(active_session_history.wait_time +
  5             active_session_history.time_waited) ttl_wait_time
  6    from v$active_session_history active_session_history,
  7         dba_objects
  8   where active_session_history.sample_time between sysdate - 60/2880 and sysdate
  9     and active_session_history.current_obj# = dba_objects.object_id
 10  group by dba_objects.object_name, dba_objects.object_type, active_session_history.event
 11* 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

The new information that Oracle has given us through the V$ACTIVE_SESSION_HISTORY view is invaluable. Now we can really zero in on those resources, session, users, SQL statements, and objects that are causing our systems to be resource intensive. By reducing the resource usage, you can in fact tune your systems better.

» See All Articles by Columnist James Koopmann

Mobile Site | Full Site
Copyright 2017 © QuinStreet Inc. All Rights Reserved