oracle9i statspack 报告 分析 direct path read 等待事件

Posted 2020-09-21 jzdwajue

DB Name         DB Id    Instance     Inst Num Release     Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
LIXORA          1409317108 LIXORA                1 9.2.0.1.0   NO      lixora-DATA


            Snap Id     Snap Time      Sessions Curs/Sess Comment
            ------- ------------------ -------- --------- -------------------
Begin Snap:      52 06-8月 -15 09:35:04     107     110.9
  End Snap:      53 06-8月 -15 09:49:47     112     106.5
   Elapsed:               14.72 (mins)


Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:       600M      Std Block Size:         8K
           Shared Pool Size:       200M          Log Buffer:    10,240K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:              3,473.25              1,406.83
              Logical reads:              6,959.90              2,819.08
              Block changes:                 15.52                  6.28
             Physical reads:                554.17                224.46
            Physical writes:                391.05                158.39
                 User calls:                 80.09                 32.44
                     Parses:                 13.35                  5.41
                Hard parses:                  1.69                  0.68
                      Sorts:                  6.34                  2.57
                     Logons:                  0.03                  0.01
                   Executes:                167.66                 67.91
               Transactions:                  2.47


  % Blocks changed per Read:    0.22    Recursive Call %:    70.00
 Rollback per transaction %:   79.27       Rows per Sort:  2161.38


Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.54       Redo NoWait %:  100.00
            Buffer  Hit   %:   97.66    In-memory Sort %:   93.03
            Library Hit   %:   98.20        Soft Parse %:   87.35
         Execute to Parse %:   92.04         Latch Hit %:   98.16
Parse CPU to Parse Elapsd %:   19.16     % Non-Parse CPU:   95.76


 Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   86.21   86.82
    % SQL with executions>1:   52.42   54.94
  % Memory for SQL w/exec>1:   49.55   51.72


Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                     % Total
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
direct path read                                   40,202       8,654    51.85
buffer busy waits                                  28,721       2,001    11.99
db file sequential read                            26,887       1,997    11.97
enqueue                                               553       1,702    10.20
db file scattered read                             22,423       1,661     9.95
          -------------------------------------------------------------
Wait Events for DB: LIXORA  Instance: LIXORA  Snaps: 52 -53
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)


                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
direct path read                   40,202          0      8,654    215     18.4
buffer busy waits                  28,721         16      2,001     70     13.2
db file sequential read            26,887          0      1,997     74     12.3
enqueue                               553        553      1,702   3078      0.3
db file scattered read             22,423          0      1,661     74     10.3
log file sync                         493          4        111    224      0.2
direct path write                   1,588          0        100     63      0.7
control file parallel write           243          0         99    408      0.1
log file parallel write               508        439         86    169      0.2
db file parallel write                342        171         80    233      0.2
control file sequential read          318          0         16     51      0.1
library cache pin                     118          0          8     67      0.1
library cache load lock                 6          2          6   1060      0.0
latch free                            679        625          0      1      0.3
row cache lock                          5          0          0     17      0.0
SQL*Net more data to client           871          0          0      0      0.4
SQL*Net break/reset to clien           26          0          0      0      0.0
LGWR wait for redo copy                 1          0          0      0      0.0
SQL*Net message from client        69,253          0     20,459    295     31.8
virtual circuit status                 28         28        840  29999      0.0
SQL*Net message to client          69,269          0          0      0     31.8
SQL*Net more data from clien           21          0          0      0      0.0
          -------------------------------------------------------------
Background Wait Events for DB: LIXORA  Instance: LIXORA  Snaps: 52 -53
-> ordered by wait time desc, waits desc (idle events last)


                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
direct path read                    1,467          0        278    190      0.7
db file scattered read              1,483          0        152    103      0.7
buffer busy waits                   1,441          0        146    102      0.7
control file parallel write           244          0        100    408      0.1
log file parallel write               508        439         85    168      0.2
db file parallel write                344        172         80    233      0.2
db file sequential read               319          0         23     71      0.1
control file sequential read          100          0          6     59      0.0
direct path write                       8          0          0     25      0.0
latch free                             23         22          0      1      0.0
LGWR wait for redo copy                 1          0          0      0      0.0
rdbms ipc message                   2,435      1,959      5,846   2401      1.1
smon timer                              3          3        922 ######      0.0
SQL*Net message from client            32          0          0      1      0.0
SQL*Net message to client              32          0          0      0      0.0


每秒redo 生产仅仅有3.4kb,且系统cpu。 mem 都没有大的开销。
log file parallel write  平均等待168ms ；基本能够表明是系统io负载过高
direct path read  等待过高 正是因为io 负载过高而表征出来;


‘wait time‘= 49982.8604 cs
‘Service Time‘ = 48414 cs
‘Response Time‘ =  98396.8604 cs

--‘Response Time‘ components:---
CPU time                    =49.2%
direct path read            =26.7%
db file sequential read     =7.3%
enqueue                     =6.9%                      
db file scattered read      =3.9%
buffer busy waits           =2.1%


对statspack 具体分析后发现，系统的服务时间占用了49.2%，而cpu的高开销，
也从一个側面表明，应用存在大开销cpu 的操作。这类操作一般可能是排序。或者大量硬解析。
可是top event里并没有看到shared pool 相关的等待事件。


继续看下 SQL ordered by Gets 
                                                     CPU      Elapsd
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
        333,146            7       47,592.3    2.6    43.73 ######### 3804332362
select count(0) from (select LIXORA_QX.*,(SELECT YQLB FROM LIXORA_QX
YQ WHERE LIXORA_HLJ.SEQ_NUMBER = LIXORA_QX.DQYQXH) AS YQLB from T_S
B_QX where (1=1)  order by C_DATE) --果然存在一个排序操作





建议：
1》sql 语句调整，降低排序；能够在c_date 字段上加索引；或者去掉order by

2》更换更高性能的存储