Wait Metrics vs Wait Events
Here is a quick table comparison of different types of metrics views
The first line of the table is the classic wait event and statistic views. The following lines are the metric views. The metric views were introduced in Oracle 10g.
Why Metrics are good
Metric views compute deltas and rates which hugely simplifying the ability to answer simple questions like “what is the I/O rate on my databases right now?” This question, before 10g, was surprisingly tedious to answer. To answer the question one would have to query v$sysstat for example:
Select value from v$sysstat where name=’physical reads’;
but querying v$sysstat just once fails to answer the question but instead answers the question “How much I/O has been done since the database was started?” To answer the original question one would have to query v$sysstat twice and take the delta between the two values:
- Take value at time A
- Take value at time B
- Delta = (B-A)
- and/or get Rate = (B-A)/elapsed time
Getting these deltas and rates could be a pesky task especially working with a customer over the phone. Then 10g Oracle introduced metric tables which answer the questions in one single query .
Using Metrics with Waits
The metric views apply to wait events as well as statistics. In a future posting we will go over statistics. In this posting we will go over wait events. The number of views available to analyze wait events can be confusing. The point of this post is to clarify what the different views available are and how they can be used.
The wait event views are (at system level)
- V$SYSTEM_EVENT – wait events cumulative since startup
- V$EVENTMETRIC – wait event deltas last 60 seconds
- DBA_HIST_SYSTEM_EVENT – wait events by snapshot (hour) for last week, cumulative since startup
The wait events are rolled up in to groups called wait classes. For wait class we have the following views:
- V$SYSTEM_WAIT_CLASS – cumulative since start up
- V$WAITCLASSMETRIC – last 60 seconds deltas
- V$WAITCLASSMETRIC_HISTORY – 60 seconds deltas for last hour
Note: DBA_HIST_WAITCLASSMETRIC_HISTORY is used for alerts and or baselines not everyday values.
Use Wait Event Metrics for Latency
I use wait event metrics for I/O latencies.
It may be surprising that I don’t mention using waits to identify bottlenecks and load on the system. For bottlenecks and load on the system the data in V$ACTIVE_SESSION_HISTORY (ASH) is probably better for a few reasons. One the data in ASH is mult-dimesional so it can be grouped by SQL and Session Also CPU information is derivable from ASH. CPU information is not in the event/waitclass views but is in ASH along with the waits.
The second part, the latencies, specifically I/O latencies, are only available in the wait event and waitclass views (and the filestat views on a per file basis)
User I/O latency with WAIT CLASS
One use of wait metrics is determining the average read I/O for all the various kinds of read I/O and read sizes:
select 10*time_waited/nullif(wait_count,0) avg_io_ms -- convert centi-seconds to milliseconds from v$waitclassmetric m where wait_class_id= 1740759767 -- User I/O / AVG_IO_MS ---------- 8.916
One issue with V$WAITCLASSMETRIC is that the field WAIT_CLASS name is not in the view, so we either have to use the WAIT_CLASS_ID (the hash of the name) as above or join to V$SYSTEM_WAIT_CLASS as below
select 10*m.time_waited/nullif(m.wait_count,0) avgms -- convert centisecs to ms from v$waitclassmetric m, v$system_wait_class n where m.wait_class_id=n.wait_class_id and n.wait_class='User I/O' / AVG_IO_MS ---------- 8.916
Another issue is that the documentation for 11gR2 says that the TIME_WAITED is microseconds but in my tests it’s actually centisecs
desc V$SYSTEM_WAIT_CLASS Name Type ----------------------------------------- ---------------------------- WAIT_CLASS_ID NUMBER WAIT_CLASS# NUMBER WAIT_CLASS VARCHAR2(64) TOTAL_WAITS NUMBER TIME_WAITED NUMBER - centi-seconds
You can get a list of all the WAIT_CLASS names in the view V$SYSTEM_WAIT_CLASS.
select wait_class_id , wait_class from V$SYSTEM_WAIT_CLASS ; WAIT_CLASS_ID WAIT_CLASS ------------- ---------------------------------------------------------------- 1893977003 Other 4217450380 Application 3290255840 Configuration 4166625743 Administrative 3875070507 Concurrency 3386400367 Commit 2723168908 Idle 2000153315 Network 1740759767 User I/O 4108307767 System I/O
Latencies for specific I/O Wait Events
For specific I/O latencies there are two choices – v$eventmetric and v$system_event. With v$system_event it requires running multiple queries and taking the deltas but the deltas are are already calculated in v$eventmetric. Here is an example of getting I/O latencies from v$eventmetric
Latencies in the past minute
col name for a25 select m.intsize_csec, n.name , round(m.time_waited,3) time_waited, m.wait_count, round(10*m.time_waited/nullif(m.wait_count,0),3) avgms from v$eventmetric m, v$event_name n where m.event_id=n.event_id and n.name in ( 'db file sequential read', 'db file scattered read', 'direct path read', 'direct path read temp', 'direct path write', 'direct path write temp', 'log file sync', 'log file parallel write' ) / INTSIZE_CSEC NAME TIME_WAITED WAIT_COUNT AVGMS ------------ ------------------------- ----------- ---------- ---------- 6017 log file parallel write 2.538 4 6.345 6017 log file sync 2.329 1 23.287 6017 db file sequential read 0 0 6017 db file scattered read 0 0 6017 direct path read 0 0 6017 direct path read temp 0 0 6017 direct path write 0 0 6017 direct path write temp 0 0
Latencies averaged over each hour for specific I/O Wait Events
select btime, round((time_ms_end-time_ms_beg)/nullif(count_end-count_beg,0),3) avg_ms from ( select to_char(s.BEGIN_INTERVAL_TIME,'DD-MON-YY HH24:MI') btime, total_waits count_end, time_waited_micro/1000 time_ms_end, Lag (e.time_waited_micro/1000) OVER( PARTITION BY e.event_name ORDER BY s.snap_id) time_ms_beg, Lag (e.total_waits) OVER( PARTITION BY e.event_name ORDER BY s.snap_id) count_beg from DBA_HIST_SYSTEM_EVENT e, DBA_HIST_SNAPSHOT s where s.snap_id=e.snap_id and e.event_name like '%&1%' order by begin_interval_time ) order by btime / BTIME AVG_MS --------------- ---------- 20-JUL-11 06:00 5.854 20-JUL-11 07:00 4.116 20-JUL-11 08:00 21.158 20-JUL-11 09:02 5.591 20-JUL-11 10:00 4.116 20-JUL-11 11:00 6.248 20-JUL-11 12:00 23.634 20-JUL-11 13:00 22.529 20-JUL-11 14:00 21.62 20-JUL-11 15:00 18.038 20-JUL-11 16:00 23.127
What are the sizes of the I/O requests?
One issue with looking at I/O latencies is determining the I/O sizes. It would be awesome if there was a view with I/O counts, sizes and latencies in one place. ASH does have this information but ASH data is weighted to the longer latencies and sizes and not the average. The average sizes have to be gotten from system statistics. The I/O sizes for ‘db file sequential read’ are single block reads so are single value that can be determined , but the other read events can vary in size. To get a general idea of I/O sizes one could just average across all I/O using the system statistics
Average I/O Size (across all I/O waits)
select sum(decode(metric_name,'Physical Reads Per Sec',value,0))*max(intsize_csec)/100 blocks_read, nullif(sum(decode(metric_name,'Physical Read IO Requests Per Sec',value,0)),0)*max(intsize_csec)/100 reads, sum(decode(metric_name,'Physical Reads Per Sec',value,0))/ nullif(sum(decode(metric_name,'Physical Read IO Requests Per Sec',value,0)),0) avg_blocks_read from v$sysmetric where group_id = 2 -- 60 second deltas only (not the 15 second deltas); BLOCKS_READ READS AVG_BLOCKS_READ ----------- ---------- --------------- 4798 4798 1
Load and Bottlenecks
The good thing about wait classes is that they simplify dealing with 1000s of wait events and group them into just a few wait classes. We can get a quick view of load on the system with
select n.wait_class, round(m.time_waited/m.INTSIZE_CSEC,3) AAS from v$waitclassmetric m, v$system_wait_class n where m.wait_class_id=n.wait_class_id and n.wait_class != 'Idle' ; WAIT_CLASS AAS --------------- ---------- Other 0 Application 0 Configuration 0 Administrative 0 Concurrency 0 Commit 0 Network 0 User I/O .149 System I/O .002
but the big drawback with wait event and/or wait class views is that they lack information on CPU load. CPU load can be found in the system statistics but it’s just easier to do it all in one query using v$active_session_history. Here is a query using ASH to calculate AAS load on the database over the last 60 seconds:
select round(count(*)/secs.var,3) AAS, decode(session_state,'ON CPU','CPU',wait_class) wait_class from v$active_session_history ash, (select 60 var from dual) secs where SAMPLE_TIME > sysdate - (secs.var/(24*60*60)) and SESSION_TYPE = 'FOREGROUND' group by decode(session_state,'ON CPU','CPU',wait_class) , secs.var / AAS WAIT_CLASS ---------- --------------- .016 Concurrency .001 Network 0 Other .083 Configuration .001 Administrative .034 CPU 0 System I/O .001 Commit .054 Application 0 User I/O
Though with v$sysmetric it’s pretty easy to join to v$waitclassmetric
select n.wait_class, round(m.time_waited/m.INTSIZE_CSEC,3) AAS from v$waitclassmetric m, v$system_wait_class n where m.wait_class_id=n.wait_class_id and n.wait_class != 'Idle' union select 'CPU', round(value/100,3) AAS from v$sysmetric where metric_name='CPU Usage Per Sec' and group_id=2 ; WAIT_CLASS AAS ---------------------------------------------------------------- ---------- Administrative 0 Application .009 CPU 1.696 Commit 0 Concurrency .001 Configuration 0 Network .002 Other 0 System I/O 0 User I/O 0
and adding v$sysmetric into the query allows me to do something I’ve always wanted which is to include the OS CPU in AAS
select n.wait_class, round(m.time_waited/m.INTSIZE_CSEC,3) AAS from v$waitclassmetric m, v$system_wait_class n where m.wait_class_id=n.wait_class_id and n.wait_class != 'Idle' union select 'CPU', round(value/100,3) AAS from v$sysmetric where metric_name='CPU Usage Per Sec' and group_id=2 union select 'CPU_OS', round((prcnt.busy*parameter.cpu_count)/100,3) - aas.cpu from ( select value busy from v$sysmetric where metric_name='Host CPU Utilization (%)' and group_id=2 ) prcnt, ( select value cpu_count from v$parameter where name='cpu_count' ) parameter, ( select 'CPU', round(value/100,3) cpu from v$sysmetric where metric_name='CPU Usage Per Sec' and group_id=2) aas ; WAIT_CLASS AAS ---------------------------------------------------------------- ---------- Administrative 0 Application 0 CPU .009 CPU_OS .024 Commit 0 Concurrency 0 Configuration 0 Network .002 Other 0 System I/O 0 User I/O 0
One huge loss over using ASH is the loss of the information users waiting for CPU but not running on CPU.
For further reading see
- oramon.sh – shell script to display I/O latency from v$system_event
- Oracle CPU time – how to see Oracle’s usage and demand of CPU
Hi Kyle,
If we calculate the average single block read latency from DBA_HIST_SYSTEM_EVENT (event “db file sequential read”) and compare the result with what we get from OEM metric instance_throughput avg_sync_singleblk_read_latency (for example by selecting from MGMT$METRIC_HOURLY to get the hourly aggregate), would you agree that these should be in the same order of magnitude?
Thanks,
Dirk
Hi Dirk – seems like a reasonable expectation. I would expect the two to be on the same order of magnitude. I don’t know where they are getting avg_sync_singleblk_read_latency from but my guess would be from “db file sequential read”. I think avg_sync_singleblk_read_latency is used for the alerts on slow I/O that show up in ADDM sometimes. Are the two values lining up for you?
– Kyle
Hi Kyle – Thanks for your fast response. According to the Oracle documentation (OEM metric reference manual) the source for avg_sync_singleblk_read_latency is v$sysmetric. The problem is that they are not at all lining up. The manual says that the unit is milliseconds but I have the impression that it might be in seconds. The following output gives a few hours with both the system_event result (only the average in column AVG_AWR) and the OEM avg_sync_singleblk_read_latency results (average, minimum, maximum and stddev) where I already multiplied by 1000:
DAY_HOUR AVG_AWR 1000*O.AVERAGE 1000*O.MINIMUM 1000*O.MAXIMUM STDDEV
———– ———- ————– ————– ————– ———-
20140103 11 2.98452857 0 0 0 0
20140103 12 3.17543701 0 0 0 0
20140103 13 3.37031967 0 0 0 0
20140103 14 2.70659531 0 0 0 0
20140103 15 3.63222293 0 0 0 0
20140103 16 4.48239286 1.14155251 0 6.84931507 .002796221
20140103 17 4.26423932 0 0 0 0
20140103 18 2.76167290 0 0 0 0
20140103 19 5.04911055 0 0 0 0
20140103 20 6.14038053 0 0 0 0
20140103 21 16.6222783 1.68350168 0 10.1010101 .004123720
20140103 22 3.23683648 2.76195298 0 5.46448087 .002461324
20140103 23 1.48303086 0 0 0 0
20140104 00 .200790547 .204044620 0 .705218618 .000321540
20140104 01 .062150495 .335566413 0 1.99203187 .000811544
20140104 02 2.67060558 .641025641 0 3.84615385 .001570186
20140104 03 5.26931969 .538502962 0 3.23101777 .001319057
20140104 04 4.99572549 0 0 0 0
20140104 05 4.89646314 0 0 0 0
20140104 06 2.34470897 2.59031822 0 11.3636364 .004611544
20140104 07 3.74348815 0 0 0 0
By the way, the database this was collected from is a 11.1.0.7 and the OEM version is 12c.
Dirk
Hi Kyle – I found two oracle bugs on MOS that can probably explain the unit-issue: 11781682 and 17299711. But even then the numbers I am getting are not very close, with lots of zero’s reported by OEM.
Dirk
Sorry for the many posts. Found THE main bug: 16310129 AVERAGE SYNCHRONOUS SINGLE BLOCK LATENCY – THROUGHPUT METRIC HAS WRONG UNIT
Hi Dirk, Thanks for all the info on the bugs! – Kyle
Excellent article Kyle, this is very clear and complete like always.
Those views are really a great source to diagnose database performance problems and make it easy to create graph thanks to the sampled data.
Pingback: Graphing Oracle performance metrics with Telegraf, InfluxDB and Grafana | bdt's oracle blog