Oracle Scratchpad

July 2, 2013

12c I/O debug

Filed under: 12c,Oracle,Troubleshooting — Jonathan Lewis @ 6:05 pm BST Jul 2,2013

By my count there are 109 new v$ and gv$ dynamic performance views in 12c (so far) – and Glen Fawcett has posted a short note on a group that may be of particular benefit to anyone who finds they really have to delve into esoteric I/O problems from time to time. For the less exotic, there’s v$io_outliers and v$lgwrio_outliers which give details about any very slow I/Os – for the more exotic there’s v$kernel_io_outliers – which is the really fascinating one.

Here’s a short session capture focused on v$io_outliers:


SQL> select function_name, wait_event, count(*) from v$io_outlier group by function_name, wait_event;

FUNCTION_NAME      WAIT_EVENT                                                         COUNT(*)
------------------ ---------------------------------------------------------------- ----------
Direct Writes                                                                                1
DBWR                                                                                        11
Buffer Cache Reads db file parallel read                                                     1
Others             control file parallel write                                              32
Others                                                                                      34
Buffer Cache Reads                                                                          10

6 rows selected.

SQL> select io_size, io_latency from v$io_outlier
  2  where wait_event = 'control file parallel write'
  3  order by io_latency;

   IO_SIZE IO_LATENCY
---------- ----------
        16        514
        16        533
        16        545
        16        552
        16        557
        16        588
        16        629
        16        632
        16        639
        16        654
        16        717
        16        739
        16        793
        16        851
        16        859
        16        872
        16        965
        16       1074
        16       1261
        16       1513
        16       2020
        16       2699
        16       3756
        16       3986
        16       4379
        16       4518
        16       4757
        16       4908
        16       9817
        16      10279
        16      13883
        16    2924040

32 rows selected.

SQL> select * from v$event_histogram where event = 'control file parallel write';

WAIT_TIME_MILLI WAIT_COUNT LAST_UPDATE_TIME                        CON_ID
--------------- ---------- ----------------------------------- ----------
              1       6903 02-JUL-13 08.34.51.556059 AM +01:00          0
              2      67990 02-JUL-13 08.36.06.643280 AM +01:00          0
              4       5839 02-JUL-13 08.36.00.635787 AM +01:00          0
              8        909 02-JUL-13 08.32.17.999903 AM +01:00          0
             16        404 02-JUL-13 08.26.17.019774 AM +01:00          0
             32        375 02-JUL-13 08.20.16.049842 AM +01:00          0
             64        316 02-JUL-13 08.25.35.997658 AM +01:00          0
            128        154 02-JUL-13 07.50.17.522235 AM +01:00          0
            256         43 02-JUL-13 07.50.17.268394 AM +01:00          0
            512         37 02-JUL-13 07.50.21.405903 AM +01:00          0
           1024         31 01-JUL-13 01.46.43.419938 PM +01:00          0
           2048          3 02-JUL-13 07.50.14.716905 AM +01:00          0
           4096          2 01-JUL-13 06.47.38.055541 AM +01:00          0
           8192          5 02-JUL-13 06.12.18.501807 AM +01:00          0
          16384          2 01-JUL-13 01.09.21.839019 PM +01:00          0
          32768          1 30-JUN-13 02.39.07.008164 AM +01:00          0
          65536          0                                              0
         131072          0                                              0
         262144          0                                              0
         524288          0                                              0
        1048576          0                                              0
        2097152          0                                              0
        4194304          1 01-JUL-13 11.17.20.600514 AM +01:00          0

23 rows selected.

Unfortunately, although the figures are close, a quick check on the v$event_histogram ranges ending 4096, 8192, 16384 and 32767 don’t quite match the precision figures given in v$io_outlier – there’s a little slippage across the boundaries.

Footnote: looking at the gv$ definitions – v$lgwrio_outlier and v$io_outlier differ only in whether they include or exclude “io_component_id” number 2 (the lgwr component).

4 Comments »

  1. Hi Jonathan,
    have you ever get the view v$kernel_io_outliers working and populating values? I have tried several cases on Solaris 11.1 (Oracle Virtual Box / VDI / SATA) and Oracle 12.1.0.1 on ZFS now, but the view or better said X$KSFDKLL never contains any data like the other two views (V$IO_OUTLIER / V$LGWRIO_OUTLIER). The oracle user is also able to run DTrace for proc, user and kernel.

    The official documentation states “Use this view to see the individual kernel components of I/Os for which there are any occasional delays in serving disk I/O requests by the storage subsystem” and i found some more information in this presentation (http://de.slideshare.net/franmod/oow-ppt-2 / Slide 58) about “additional added DTrace I/O events”. Is it possible that this works with specific storage devices only (like SCSI) and not in general as some columns in view v$kernel_io_outliers are also related to SCSI devices?

    I hoped that this view includes information about the whole kernel stack like “VFS -> ZFS -> ZIO -> VDEV -> BDEV -> SCSI -> and so on” (SETUP_LATENCY = VFS to BDEV and so on) in case of I/O issues (as it is also mentioned in the official Oracle documentation like “Use this view to see the individual kernel components of I/Os”), but unfortunately it seems not like that in general :-((

    Am i missing anything / doing something wrong here or is this really not that useful?

    Thanks.

    Best Regards
    Stefan

    Comment by Stefan Koehler — July 10, 2013 @ 11:08 am BST Jul 10,2013 | Reply

    • ** UPDATE **
      I have even tried it with SCSI storage devices and reconfigured the zpool in Virtual Box, but there are still no values populated.

      —————————-8<———————————————-
      root@SOL:~# cfgadm -al
      Ap_Id Type Receptacle Occupant Condition
      c8 scsi-bus connected configured unknown
      c8::dsk/c8t0d0 disk connected configured unknown

      root@SOL:~# zpool status oracle
      pool: oracle
      state: ONLINE
      scan: none requested
      config:
      NAME STATE READ WRITE CKSUM
      oracle ONLINE 0 0 0
      c8t0d0 ONLINE 0 0 0

      root@SOL:~# zfs list
      NAME USED AVAIL REFER MOUNTPOINT
      oracle 5,42G 23,9G 354K /oracle
      oracle/S12CDB 1,17G 23,9G 1,17G /oracle/S12CDB
      oracle/S12DB 921M 23,9G 921M /oracle/S12DB
      oracle/rdbms 3,35G 23,9G 89K /oracle/rdbms
      oracle/rdbms/12101 3,35G 23,9G 3,35G /oracle/rdbms/12101
      —————————-8<———————————————-

      It seems like there needs to be done some undocumented steps to get it working, it is just useful in a rare storage constellation or currently not working at all.

      Regards
      Stefan

      Comment by Stefan Koehler — July 10, 2013 @ 12:06 pm BST Jul 10,2013 | Reply

      • Stefan,

        Thanks for your efforts, and letting us know your results.

        To date I’ve not seen anything in this view, although I had seen results in the other two views.
        You could try dropping a comment on Glen Fawcett’s blog – he’s probably the most likely person to be able to give you an answer, and if he does we’d love to hear it.

        Comment by Jonathan Lewis — July 10, 2013 @ 9:06 pm BST Jul 10,2013 | Reply

  2. […] of time to complete. This will be essential diagnostics feature. But, many people complained that V$KERNEL_IO_OUTLIER is always empty. This was enough for me to start investigating […]

    Pingback by V$KERNEL_IO_OUTLIER | Latch, mutex and beyond — September 20, 2013 @ 10:11 pm BST Sep 20,2013 | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

The Rubric Theme. Blog at WordPress.com.

Follow

Get every new post delivered to your Inbox.

Join 3,910 other followers