聯機記錄檔過小引發的log file 相關等待

Oracle 聯機重做記錄檔記錄了資料庫的所有變化(DML,DDL或管理員對資料所作的結構性更改等)，用於對於意外刪除或宕機利用記錄檔實現資料恢複來確保資料的完整性。但不合理的聯機記錄檔規劃將引發日誌相關的等待事件。下面是這樣一個來自生產環境中的例子。

1、故障描述

--客戶描述該資料庫晚上用於實現資料同步以及匯總，以前一直工作的比較良好，隨著需要同步的數量量的增大，最近變得越來越慢。
--下面我們首先取了客戶晚8點至第二天7點的awr report。

WORKLOAD REPOSITORY report for

DB Name        DB Id    Instance    Inst Num Release    RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
ST990        2152526631 ST990              1 10.2.0.3.0  NO  v2011db02p

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:    21787 21-Feb-13 20:00:22        50      19.5
  End Snap:    21798 22-Feb-13 07:00:47        44      20.0
  Elapsed:              660.42 (mins)
  DB Time:              928.06 (mins)

--從上面的awr report 可知，單一實例，10.2.0.3版本，期間的會話數也不多
--Elapsed < DB Time
--Elapsed Time=(20130222 07:00:00 - 20130221 20:00:00)≈ 660
--DB Time=928.06 ,運行環境為16核CPU, 660*16=10560, cpu花費了928.06分鐘在處理Oralce非空閑等待和運算上
--從上可知，整個系統還是比較空閑

--下面來看看top event
Top 5 Timed Events                                        Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait  Call
Event                                Waits    Time (s)  (ms)  Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                        20,673          37.1
log file parallel write              27,399      4,797    175    8.6 System I/O
control file parallel write          13,428      4,688    349    8.4 System I/O
log file sync                        19,564      3,795    194    6.8    Commit
db file scattered read          26,651,537      3,439      0    6.2  User I/O

--從上面的top event事件上來看，log file相關等待事件表現明顯
--log file parallel write等待事件總等待次數27,399 總等待時間4,797/60=79.95(min),超出一個小時，相當可觀
--其次是control file parallel write與log file sync事件的相關等待

--下面是等待事件的detail資訊
Wait Events                          DB/Inst: ST1200/ST1200  Snaps: 21787-21798
-> 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)

                                            %Time  Total Wait    wait    Waits
Event                                Waits  -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ------ ----------- ------- ---------
log file parallel write              27,399    .0      4,797    175      1.1
control file parallel write          13,428    .0      4,688    349      0.5
log file sync                        19,564  10.6      3,795    194      0.8
db file scattered read          26,651,537    .0      3,439      0  1,049.4
db file sequential read          6,682,373    .0      1,567      0    263.1
log file switch (checkpoint          1,091  92.9      1,019    934      0.0
Datapump dump file I/O              633,458    .0        286      0      24.9
log file switch completion              332  31.6        183    552      0.0
log buffer space                        255  47.8        155    608      0.0
free buffer waits                    2,409  99.5        120      50      0.1
buffer busy waits                      145  62.8          96    664      0.0

1 2 3 下一頁