5 Replies Latest reply: Apr 1, 2009 11:12 PM by 521578 RSS

    async disk IO in TOP 5 timed event

    user00726
      Hi all,

      I took a statspack report and i found that in the Top 5 timed event we are getting
      async disk io 
      Tablespace IO Stats for DB: ac  Instance: ac11  Snaps: 101 -102
      ->ordered by IOs (Reads + Writes) desc
      
      Tablespace
      ------------------------------
                       Av      Av     Av                    Av        Buffer Av Buf
               Reads Reads/s Rd(ms) Blks/Rd       Writes Writes/s      Waits Wt(ms)
      -------------- ------- ------ ------- ------------ -------- ---------- ------
      data
             252,567      87    4.9     2.2       17,615        6        393   18.4
      dataNRO
              97,326      34    3.1     3.7          255        0          0    0.0
      dataWRO
              18,237       6    3.6     3.5          595        0          0    0.0
      dataCRO
              10,157       4    4.8     1.8           63        0         22    3.2
      UNDOTBS1
                   3       0   10.0     1.0        4,733        2          1    0.0
      dataERO
               2,906       1    4.2     4.7          237        0          0    0.0
      MFXPIMA
                 895       0    6.3     1.0          300        0          0    0.0
      INDX
                 852       0   15.7     1.0          250        0          0    0.0
      SYSTEM
                 228       0   11.3     1.8           72        0          0    0.0
      dataHO
                   1       0   50.0     1.0            1        0          0    0.0
      dataOTH
                   1       0    0.0     1.0            1        0          0    0.0
      CWMLITE
                   1       0    0.0     1.0            1        0          0    0.0
      DRSYS
                   1       0    0.0     1.0            1        0          0    0.0
      ODM
                   1       0    0.0     1.0            1        0          0    0.0
      RACCONFIG
                   1       0  100.0     1.0            1        0          0    0.0
      TEMPSCHEMA
                   1       0   90.0     1.0            1        0          0    0.0
      TOOLS
                   1       0    0.0     1.0            1        0          0    0.0
      UNDOTBS2
                   1       0   80.0     1.0            1        0          0    0.0
      UNDOTBS3
                   1       0   10.0     1.0            1        0          0    0.0
      USERS
                   1       0    0.0     1.0            1        0          0    0.0
      XDB
                   1       0    0.0     1.0            1        0          0    0.0
                -------------------------------------------------------------
      File IO Stats for DB: ac  Instance: ac11  Snaps: 101 -102
      ->ordered by Tablespace, File
      
      Tablespace               Filename
      ------------------------ ----------------------------------------------------
                       Av      Av     Av                    Av        Buffer Av Buf
               Reads Reads/s Rd(ms) Blks/Rd       Writes Writes/s      Waits Wt(ms)
      -------------- ------- ------ ------- ------------ -------- ---------- ------
      data                   /dev/vx/rdsk/racdg/orcl_raw_data01
             252,567      87    4.9     2.2       17,615        6        393   18.4
      
      dataCRO                /dev/vx/rdsk/racdg/orcl_raw_caddatacro
              10,157       4    4.8     1.8           63        0         22    3.2
      
      dataERO                /dev/vx/rdsk/racdg/orcl_raw_dataero
               2,906       1    4.2     4.7          237        0          0
      
      dataHO                 /dev/vx/rdsk/racdg/orcl_raw_dataho
                   1       0   50.0     1.0            1        0          0
      
      dataNRO                /dev/vx/rdsk/racdg/orcl_raw_datanro
              97,326      34    3.1     3.7          255        0          0
      
      dataOTH                /dev/vx/rdsk/racdg/orcl_raw_dataoth
                   1       0    0.0     1.0            1        0          0
      
      dataWRO                /dev/vx/rdsk/racdg/orcl_raw_datawro
              18,237       6    3.6     3.5          595        0          0
      
      CWMLITE                  /dev/vx/rdsk/racdg/orcl_raw_cwmlite
                   1       0    0.0     1.0            1        0          0
      
      DRSYS                    /dev/vx/rdsk/racdg/orcl_raw_drsys
                   1       0    0.0     1.0            1        0          0
      
      INDX                     /dev/vx/rdsk/racdg/orcl_raw_indx01
                 852       0   15.7     1.0          250        0          0
      
      MFXPIMA                  /dev/vx/rdsk/racdg/orcl_raw_mfxpima
                 895       0    6.3     1.0          300        0          0
      
      ODM                      /dev/vx/rdsk/racdg/orcl_raw_odm
                   1       0    0.0     1.0            1        0          0
      
      RACCONFIG                /dev/vx/rdsk/racdg/orcl_raw_racconfig
                   1       0  100.0     1.0            1        0          0
      
      SYSTEM                   /dev/vx/rdsk/racdg/orcl_raw_system01
                 228       0   11.3     1.8           72        0          0
      
      TEMPSCHEMA               /dev/vx/rdsk/racdg/orcl_raW_tempschema
                   1       0   90.0     1.0            1        0          0
      
      TOOLS                    /dev/vx/rdsk/racdg/orcl_raw_tools
                   1       0    0.0     1.0            1        0          0
      
      UNDOTBS1                 /dev/vx/rdsk/racdg/orcl_raw_undotbs1
                   3       0   10.0     1.0        4,733        2          1    0.0
      
      UNDOTBS2                 /dev/vx/rdsk/racdg/orcl_raw_undotbs2
      File IO Stats for DB: ac  Instance: ac11  Snaps: 101 -102
      ->ordered by Tablespace, File
      
      Tablespace               Filename
      ------------------------ ----------------------------------------------------
                       Av      Av     Av                    Av        Buffer Av Buf
               Reads Reads/s Rd(ms) Blks/Rd       Writes Writes/s      Waits Wt(ms)
      -------------- ------- ------ ------- ------------ -------- ---------- ------
                   1       0   80.0     1.0            1        0          0
      
      UNDOTBS3                 /dev/vx/rdsk/racdg/orcl_raw_example
                   1       0   10.0     1.0            1        0          0
      
      USERS                    /dev/vx/rdsk/racdg/orcl_raw_users
                   1       0    0.0     1.0            1        0          0
      
      XDB                      /dev/vx/rdsk/racdg/orcl_raw_xdb
                   1       0    0.0     1.0            1        0          0
      
                -------------------------------------------------------------
      Can anybody suggest me what we are facing this proble and what is the soln for the same although we are using SAN and our DB is ORacle 9.2.0.6 on sun box
        • 1. Re: async disk IO in TOP 5 timed event
          P.Forstmann
          Please post full header from Statspack report up to and including "Top 5 timed events" section and the number of CPU on the system hosting the database.
          • 2. Re: async disk IO in TOP 5 timed event
            user00726
            We are having a 2 cpu on the system
            STATSPACK report for
            
            DB Name         DB Id    Instance     Inst Num Release     Cluster Host
            ------------ ----------- ------------ -------- ----------- ------- ------------
            ac          1372079993 ac11              1 9.2.0.6.0   YES     ac1
            
                          Snap Id     Snap Time      Sessions Curs/Sess Comment
                        --------- ------------------ -------- --------- -------------------
            Begin Snap:       101 01-Apr-09 13:10:01    1,112     130.8
              End Snap:       102 01-Apr-09 13:58:14    1,112     132.3
               Elapsed:               48.22 (mins)
            
            Cache Sizes (end)
            ~~~~~~~~~~~~~~~~~
                           Buffer Cache:     4,288M      Std Block Size:          8K
                       Shared Pool Size:       608M          Log Buffer:        977K
            
            Load Profile
            ~~~~~~~~~~~~                            Per Second       Per Transaction
                                               ---------------       ---------------
                              Redo size:             28,267.55              2,373.20
                          Logical reads:              5,172.08                434.22
                          Block changes:                195.00                 16.37
                         Physical reads:                351.31                 29.49
                        Physical writes:                  8.34                  0.70
                             User calls:                109.01                  9.15
                                 Parses:                 13.71                  1.15
                            Hard parses:                  0.29                  0.02
                                  Sorts:                  4.53                  0.38
                                 Logons:                  0.06                  0.01
                               Executes:                142.12                 11.93
                           Transactions:                 11.91
            
              % Blocks changed per Read:    3.77    Recursive Call %:     72.11
             Rollback per transaction %:    0.64       Rows per Sort:    104.78
            
            Instance Efficiency Percentages (Target 100%)
            ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                        Buffer Nowait %:  100.00       Redo NoWait %:    100.00
                        Buffer  Hit   %:   93.21    In-memory Sort %:    100.00
                        Library Hit   %:   99.62        Soft Parse %:     97.87
                     Execute to Parse %:   90.35         Latch Hit %:     99.94
            Parse CPU to Parse Elapsd %:   52.84     % Non-Parse CPU:     99.69
            
             Shared Pool Statistics        Begin   End
                                           ------  ------
                         Memory Usage %:   90.10   90.77
                % SQL with executions>1:   71.19   72.64
              % Memory for SQL w/exec>1:   72.21   73.13
            
            Top 5 Timed Events
            ~~~~~~~~~~~~~~~~~~                                                     % Total
            Event                                               Waits    Time (s) Ela Time
            -------------------------------------------- ------------ ----------- --------
            CPU time                                                        4,356    55.57
            async disk IO                                     233,930         986    12.58
            db file sequential read                           185,633         984    12.55
            global cache cr request                           487,188         524     6.68
            db file scattered read                            180,026         428     5.46
                      -------------------------------------------------------------
            • 3. Re: async disk IO in TOP 5 timed event
              Timur Akhmadeev
              Why do you think that async disk IO waits are causing any real performance troubles to your end users? Have you confirmed this with [SQL trace|http://www.oracle-base.com/articles/10g/SQLTrace10046TrcsessAndTkprof10g.php]?

              I would say that your system is more CPU-bound, and most likely it may cause some performance problems rather than IO. See: you have 2 CPU (is it 2 cores in total?) and 48.22 min statspack report. It means that you have 96.44 min CPU time in total. According to statistics, your system used 72.6 min of CPU, i.e. on average it would be 75% CPU utilization, accounted for 56% of total system-wide response times.

              If your 2 CPU are actually multi-core, than figures would be different. But anyway, you should check real end-user experience via SQL trace rather than system-wide statspack reports.
              • 4. Re: async disk IO in TOP 5 timed event
                601585
                I believe that you're on 9i database.

                Metalink note# 170357.1 is great documentation on this wait event.



                ================================
                Dion Cho - Oracle Performance Storyteller

                http://dioncho.wordpress.com (english)
                http://ukja.tistory.com (korean)
                ================================
                • 5. Re: async disk IO in TOP 5 timed event
                  521578
                  Hi,

                  The shared pool size seems too small..

                  Regards
                  ans