Measuring I/O speed with v$event_histogram

Plotting I/O speed with v$event_histogram

The v$event_histogram view displays a histogram of the number of waits, the maximum wait, and total wait time on a wait event basis. Using this view, a histogram showing the frequency of wait events for a range of durations can be created. This information assists in the determination of whether a wait event is a frequent problem that needs addressing or a unique event. The following query, which filters out idle events, can be used to view this type of information:

SELECT
   event,
   wait_time_milli,
   wait_count
FROM
   v$event_histogram
WHERE
   event in
   (SELECT
         name
     FROM
        v$event_name
    WHERE
        wait_class NOT IN ('Idle')
    )
ORDER BY 1,2;

You can also use the v$event_histogram view to plot the distribution of I/O with a simple script:

-- Sequential read wait times
select
   wait_time_milli,
   wait_count
from
   v$event_histogram
where
   event = 'db file sequential read'
order by wait_time_milli;

-- Scattered read wait times (full scans)

select
   wait_time_milli,
   wait_count
from
   v$event_histogram
where
   event = 'db file scattered read'
order by wait_time_milli;

You can then take the output from v$event_histogram and plot the frequencies of all disk I/O times are both scattered and sequential reads.  The wait time buckets are in milliseconds.

It's not uncommon to see a I/O speed distribution like above, with "two curves in one".  The vast majority of I/O completes in under 1ms (cached blocks) while physical disk reads form the second curve starting at I/O speeds comparable to the minimum latency the disk devices (Note: Many disks with on-board RAM caches can return blocks in under 1ms).

Note the "long tail" where the number of waits is asymptotic to the axis.

1  641,363,873 2   25,062,964 4   73,135,151 8   56,894,571 16  74,734,294 32   17,154,196 64   3,775,884 128   719,083 256   15,539 512   4,143 1,024     978 2,048    155 4,096   83 8,192    66 6,384    41 32,768    24 65,536      16 31,072     9 26,2144        5 52,4288      4 1,048,576    4 2,097,152     43

Comparing scattered and sequential read wait latency

Wait Time Sequential Scattered Milliseconds Reads Reads 1  641,363,873 9,843,378 2   25,062,964 3,824,404 4   73,135,151 3,615,427 8   56,894,571 3,411,045 16  74,734,294 3,395,031 32   17,154,196 2,062,995 64   3,775,884 926,992 128   719,083 605,833 256   15,539 30,734 512   4,143 4,004 1,024     978 436 2,048    155 77 4,096   83 31 8,192    66 6

Time-series I/O distribution using dba_hist_system_event instead of v$event_histogram

In Oracle 10g, you can use this script using the dba_hist_system_event table to measure relative disk I/O speed over time:

A  more advanced script like below will compute a suggested value for optimizer_index_cost_adj based in empirical disk read latency:

set pages 80
set lines 130
col c1 heading 'Average Waits for|Full Scan Read I/O' format 999999.999
col c2 heading 'Average Waits for|Index Read I/O' format 999999.999
col c3 heading 'Percent of| I/O Waits|for scattered|Full Scans' format 999.99
col c4 heading 'Percent of| I/O Waits|for sequential|Index Scans' format 999.99
col c5 heading 'Starting|Value|for|optimizer|index|cost|adj' format 99999

select to_char(end_interval_time, 'MM/DD/YYYY') "Date",
       sum(a.time_waited_micro)/sum(a.total_waits)/10000 c1,
       sum(b.time_waited_micro)/sum(b.total_waits)/10000 c2,
       (sum(a.total_waits) / sum(a.total_waits + b.total_waits)) * 100 c3,
       (sum(b.total_waits) / sum(a.total_waits + b.total_waits)) * 100 c4,
       (sum(b.time_waited_micro)/sum(b.total_waits)) /
(sum(a.time_waited_micro)/sum(a.total_waits)) * 100 c5
from dba_hist_system_event a, dba_hist_system_event b, dba_hist_snapshot c
See code depot for full script

In this amazing output, we see the changes to disk I/O latency over time:

                                                   Percent of    Percent of optimizer
                                                   I/O Waits     I/O waits    index
           Average Waits for     Average Waits for for scattered for sequential cost
Date       Full Scan Read I/O    Index Read I/O    Full Scans    Index Scans    adj
---------- ------------------ ----------------- ------------- -------------- ---------
08/10/2006               .901              .119         15.63          84.37  13
08/11/2006               .900              .118         15.54          84.46  13
08/12/2006               .898              .113         14.96          85.04  13
08/13/2006               .910              .103         13.77          86.23  11
08/14/2006               .993              .076         10.64          89.36   8
08/15/2006               .991              .076         10.61          89.39   8

Using a tool to monitor Oracle I/O latency

If you don't like scripts, the WISE tool has all Oracle v$ I/O statistics at your fingertips using the GUI and you can quickly isolate I/O bottlenecks:

Related notes to v$event_histogram on measuring disk I/O speed: