Signature Analysis of Wait Events
There are many more benefits that can be achieved using information
provided by the ASH as it is a useful tool for database activity
analysis and performance tuning. The two sample analytical reports
below make use of the ASH
v$active_session_history
view.
Signature analysis is an important area of Oracle tuning and one
that especially applies to time-series wait event analysis. Just as
Socrates said “Know Thy Self” the Oracle DBA must “Know thy
Database”. Signature analysis is ideal for wait event tuning
particularly in the areas of:
§
Spotting hidden trends
§
Allowing holistic tuning
§
Allowing just-in-time anticipation and self-tuning
using the
dbms_scheduler package
§
Allowing adjustment of object characteristics such as
freelists, file placement, caching, and block population
The following
wait_time_detail.sql
script compares the wait event values from
dba_hist_waitstat and
dba_hist_active_sess_history.
This allows the identification of the exact objects that are
experiencing wait events.
set pages 999
set lines 80
break on snap_time skip 2
col snap_time heading 'Snap|Time' format a20
col file_name heading 'File|Name' format a40
col object_type heading 'Object|Type' format a10
col object_name heading 'Object|Name' format a20
col wait_count heading 'Wait|Count' format 999,999
col time heading 'Time' format 999,999
select
to_char(begin_interval_time,'yyyy-mm-dd hh24:mi') snap_time,
-- file_name,
object_type,
object_name,
wait_count,
time
from
dba_hist_waitstat wait,
dba_hist_snapshot snap,
dba_hist_active_sess_history ash,
dba_data_files df,
dba_objects obj
where
wait.snap_id = snap.snap_id
and
wait.snap_id = ash.snap_id
and
df.file_id = ash.current_file#
and
obj.object_id = ash.current_obj#
and
wait_count > 50
order by
to_char(begin_interval_time,'yyyy-mm-dd hh24:mi'),
file_name
;
This script is enabled to join into the
dba_data_files view to
get the file names associated with the wait event. This is a very
powerful script that can be used to quickly drill in to find the
cause of specific waits. Below is a sample output:
SQL> @wait_time_detail
This will compare values from dba_hist_waitstat E "dba_hist_waitstat"
with
detail information from dba_hist_active_sess_history E "dba_hist_active_sess_history"
.
Snap Object Object Wait
Time Type Name Count Time
-------------------- ---------- ------------------- --------
2004-02-28 01:00 TABLE ORDOR 4,273 67
INDEX PK_CUST_ID 12,373 324
INDEX FK_CUST_NAME 3,883 17
INDEX PK_ITEM_ID 1,256 967
2004-02-29 03:00 TABLE ITEM_DETAIL 83 69
2004-03-01 04:00 TABLE ITEM_DETAIL 1,246 45
2004-03-01 21:00 TABLE CUSTOMER_DET 4,381 354
TABLE IND_PART 117 15
2004-03-04 01:00 TABLE MARVIN 41,273 16
TABLE FACTOTUM 2,827 43
TABLE DOW_KNOB 853 6
TABLE ITEM_DETAIL 57 331
TABLE HIST_ORD 4,337 176
TABLE TAB_HIST 127 66
The first analytic trend report yields total wait times by the hour
of a day. The following script shows when database sessions have to
wait for resources that decrease response time:
select
TO_CHAR(h.sample_time,'HH24') "Hour",
Sum(h.wait_time/100) "Total Wait Time (Sec)"
from
v$active_session_history h,
v$event_name n
where
h.session_state = 'ON CPU'
and
h.session_type = 'FOREGROUND'
and
h.event_id = n.EVENT_ID
and
n.wait_class <> 'Idle'
group by
TO_CHAR(h.sample_time,'HH24');
The output of this query might look like the results listed below,
and it shows a distinct signature, or repeating wait event pattern
within the database.
This signature will be valid for the entire range of ASH snapshots
that the DBA chooses to retain. Many DBA’s will retain several
months’ worth of ASH data so they can perform system-wide wait event
tuning.
Hr Total Wait Time (Sec)
-- ---------------------
1 219
2 302,998
3 60,982
4 169,716
5 39,593
6 299,953
7 122,933
8 5,147
From the above listing, it appears that the database had the most
wait times at 12AM and 4PM as shown in the graph in Figure 16.10.
Figure 16.10:
Aggregate total waits by hour
of the day
Most Oracle databases also have daily signatures with regularly
repeating trends in wait events. In the same manner, the following
query that reports total wait times by the day of the week could be
run:
<
ash_wait_time_by_day.sql
select
TO_CHAR(h.sample_time,'Day') "Hour",
sum(h.wait_time/100) "Total Wait Time (Sec)"
from
v$active_session_history h,
v$event_name n
where
h.session_state = 'ON CPU'
and
h.session_type = 'FOREGROUND'
and
h.event_id = n.EVENT_ID
and
n.wait_class <> 'Idle'
group by
TO_CHAR(h.sample_time,'Day');
This query produces a listing that looks like the one shown below:
Hour Total Wait Time (Sec)
--------- ---------------------
Monday 679,089
Tuesday 141,142
Wednesday 181,226
Thursday 241,711
Friday 319,023
Saturday 93,362
Sunday 81,086
From this output, it is clear that the database is most stressed on
Monday, and the numbers can be visualized by pasting them into a
spreadsheet and plotting them with the chart wizard as shown in
Figure 16.11.
Figure 16.11:
Wait signature by day of the
week
The results from the two above trend reports allow the DBA to
further investigate ASH data in order to get more detailed
information. The query below retrieves a list of wait events that
had high wait time from 12AM to 1PM.
A previous report on the same system showed that sessions
experienced high wait times during this time period.
<
ash_total_event_wait_time.sql
select
h.event "Wait Event",
SUM(h.wait_time/100) "Wait Time (Sec)"
from
v$active_session_history h,
v$event_name n
where
h.session_state = 'ON CPU'
and
h.session_type = 'FOREGROUND'
and
h.event_id = n.EVENT_ID
and
to_char(h.sample_time,'HH24') = '12'
and
n.wait_class <> 'Idle'
group by
h.event
order by
2 DESC;
This query returns results that look like the following, showing
aggregate totals for important wait events.
Wait Event Wait Time (Sec)
------------------------------ ---------------
buffer busy waits 522,152
db file sequential read 299,572
SQL*Net more data to client 317
SQL*Net more data from client 201
SQL*Net message to client 55
From the listing above, the DBA can conclude that between 12AM and
1PM the database sessions waited most for
buffer busy waits and
db file sequential read
events indicating table access by index.
After these results are acquired, the DBA can determine what SQL
statements were issued during this time period and probably find
ones that may cause buffer cache contention or heavy disk read
access.
The ASH provides the Oracle DBA with the ability to build different
trend reports in order to observe database activity from various
points of view.
The AWR repository stores snapshots for the ASH view called
v$active_session_history
in its internal table
wrh$_active_session_history.
This table is available to DBAs through the
dba_hist_active_sess_history
view. The AWR does not store snapshots of ASH activity on a
continuous basis. This means that the
wrh$_active_session_history
table stores sessions’ activity records that were in the SGA
circular buffer at the time the AWR snapshot was taken.
This data archiving approach does not allow the DBA to monitor
activity for particular sessions because the AWR misses all the
activity that occurred in the session during the period of time
between two AWR snapshots.
However, trend reports based on data exposed by
dba_hist_active_sess_history
view can be built. The following sections will present information
on valuable trend analysis that can be performed against the AWR
concerning ASH activity.
It is possible to identify hot datafiles or database objects that
were accessed by sessions more frequently than others. These hot
datafiles or database objects could be candidates for additional
tuning investigations. The following query shows hot datafiles that
caused the most wait times during access:
select
f.file_name “Data File”,
COUNT(*) “Wait Number”,
SUM(h.time_waited ) “Total Time Waited”
from
v$active_session_history h,
dba_data_files f
where
h.current_file# = f.file_id
group by
f.file_name
order by 3 DESC;
This query produces output like the following:
Data File Wait Number Total Time Waited
-------------------------------------- ----------- -----------------
D:\ORACLE\ORADATA\DBDABR\SYSAUX01.DBF 153 11,169,771
D:\ORACLE\ORADATA\DBDABR\SYSTEM01.DBF 222 6,997,212
D:\ORACLE\ORADATA\DBDABR\UNDOTBS01.DBF 45 1,758,065
The datafile named
d:\oracle\oradata\dbdabr\sysaux01.dbf
had the highest wait time during access to its data.
This might indicate the need to further investigate SQL statements
that are accessing data within this datafile or the need to spread
its content between several datafiles, thus eliminating a possible
hot spot.
The Oracle multiple data buffers or the KEEP pool could also be used
to reduce waits on these objects by caching them in the data
buffers. If there are high waits on in-buffer reads, the SQL that
accesses the hot object needs to be tuned to reduce the amount of
logical I/O.
The next query against the
dba_hist_active_sess_history
view reports a list of resources that were in high demand in the
last hour. This query does not reflect idle wait events.
select
e.name "Wait Event",
SUM(h.wait_time + h.time_waited ) "Total Wait Time"
from
v$active_session_history h,
v$event_name e
where
h.event_id = e.event_id
and
e.wait_class <> 'Idle'
group by
e.name
order by 2 DESC;
This query produces a listing like the one below, showing aggregate
wait time for each event:
Wait Event Total Wait Time
------------------------------ ---------------
log buffer space 9,638,484
db file sequential read E "db
file sequential read" 8,442,918
log file switch completion 5,231,711
write complete waits 5,200,368
db file scattered read 4452,153
process startup 3623,464
rdbms ipc reply 917,765
log file sync 662,224
latch free 550,241
latch: library cache 370,696
db file parallel write 364,641
free buffer waits 319,151
latch: redo allocation 64,984
LGWR wait for redo copy 63,647
read by other session 52,757
log file sequential read 46,126
null event 33,011
log file parallel write 26,280
SQL*Net E "SQL*Net" more data to client 8,894
latch: cache buffers chains 7,005
control file sequential read 3,966
direct path read temp 395
direct path write temp 229
SQL*Net E "SQL*Net" message to client 74
From the listing above, one can see that the DBA has an issue with
the
log buffer space wait
event that may indicate the need to increase the
log_buffer parameter
to increase the cache in order to minimize this possible
bottleneck.
Using the AWR ASH view, the DBA can also retrieve a list of database
users who have experienced high wait times during the time period
between any two snapshots. The following query can be used to
identify these target users:
select
s.sid,
s.username,
sum(h.wait_time + h.time_waited ) "total wait time"
from
v$active_session_history h,
v$session s,
v$event_name e
where
h.session_id = s.sid
and
e.event_id = h.event_id
and
e.wait_class <> 'Idle'
and
s.username IS NOT NULL
group by
s.sid, s.username
order by 3;
This sample output shows the total wait time, both by process ID
(SID) and by individual users.
SID USERNAME total wait time
---------- --------------- ---------------
261 SYS 1,537,288
259 SYS 12,247,007
254 SYS 18,640,736
The next sample query against the AWR ASH table shows a list of
database objects that caused the most wait times during time
interval stored in AWR. Idle wait times are not included in the
output.
<
ash_object_wait_time.sql
select
o.owner,
o.object_name,
o.object_type,
SUM(h.wait_time + h.time_waited ) "total wait time"
from
v$active_session_history h,
dba_objects o,
v$event_name e
where
h.current_obj# = o.object_id
and
e.event_id = h.event_id
and
e.wait_class <> 'Idle'
group by
o.owner,
o.object_name,
o.object_type
order by 4 DESC;
This report produces a list of hot objects which might be candidates
for further tuning investigations:
Object Object
OWNER Name Type total wait time
-------------------- -------------------- ---------- ---------------
SYSMAN MGMT_OMS_PARAMETERS TABLE 1,1232E+10
SYS SCHEDULER$_WINDOW_DE TABLE 2989867
TAILS
SYSMAN MPVV_PK INDEX 1333198
SYSMAN MGMT_DELTA_ENTRY_SHO INDEX 835641
ULD_BE_UK
SYSMAN MGMT_DB_LATEST_HDM_F TABLE 397504
INDINGS
SYS CDEF$ TABLE 116853
SYS I_LINK1 INDEX 46922
SYS SYS_IOT_TOP_8542 INDEX 25469
SYS I_COM1 INDEX 24908
SYS I_CDEF3 INDEX 23125
SYSMAN MGMT_DB_LATEST_HDM_F INDEX 11325
INDINGS
SYS I_OBJ2 INDEX 5953
SYS WRH$_ACTIVE_SESSION_ TABLE 304
HISTORY_BL
SYSTEM SQLPLUS_PRODUCT_PROF TABLE 3
ILE
SEE CODE DEPOT FOR FULL SCRIPTS
and include the URL for the page.
