Oracle Signature Analysis of Wait Events
from http://www.dba-oracle.com/oracle10g_tuning/t_waits_events_signatures.htm
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_schedulerpackage
§ 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 fromdba_hist_waitstat and dba_hist_active_sess_history. This allows the identification of the exact objects that are experiencing wait events.
< wait_time_detail.sql
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 calledv$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 thewrh$_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:
< ash_datafile_waits.sql
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 spacewait 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:
< ash_user_wait_time.sql
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
浙公网安备 33010602011771号