log buffer及日誌管理深入分析及效能調整（六）

的等待事件

等待事件

當使用者發出提交或回滾語句時會觸發LGWR將重做記錄寫入聯機日誌檔案，這種觸發LGWR的方式叫做同步寫（sync writes）觸發，而其他剩下的觸發LGWR的方式叫做後臺寫（background writes）。log file sync等待事件只與sync writes有關，而log file parallel write等待事件只與background writes有關。

舉例來說，一個使用者程式可能進行一個非常大的事務，該事務會產生非常多的重做記錄，從而引起很多的background writes。不過，使用者session所執行的事務永遠不會等待這些background writes完成以後才繼續進行。一旦使用者程式提交或回滾了事務，那麼使用者程式將觸發LGWR，並且等待log file sync等待事件，一直等到LGWR將當前的重做記錄，包括提交或回滾標記全都寫入聯機日誌檔案裡為止。在這個日誌同步（log synchronization）的過程中（將日誌緩衝區中的重做記錄寫入聯機日誌檔案的過程通常也叫做日誌同步過程），LGWR程式等待sync write結束，這時它的等待事件為：log file parallel write，而使用者session也在等待sync write結束，而這時它等待的等待事件為：log file sync事件。

一旦程式開始等待log file sync事件，用兩種方式退出該等待：

<!--[if !supportLists]--&gt1)    <!--[endif]--&gt當日志緩衝區裡的重做記錄都寫入聯機日誌檔案以後，由LGWR觸發，告訴前臺程式。

<!--[if !supportLists]--&gt2)    <!--[endif]--&gt當等待事件超時(通常是1秒)時，前臺程式檢查當前的log SCN，來判斷當前程式的提交是否已經將重做記錄寫到了聯機日誌檔案裡了。如果已經寫好了，前臺程式繼續進行，否則前臺程式繼續等待log file sync事件。

通常，log file sync等待事件是可以不用過多考慮的。但是如果很多session都在等待該事件的話，就會影響系統的整體響應時間了。我們來模擬一下這兩個等待事件。

SQL> create table t1(id number,name varchar2(20)) as select rownum as rid,'abcdef'

 2 from dba_objects where rownum<=40000;

SQL> connect / as sysdba

Connected.

SQL> startup force

             在執行測試指令碼前，先看看統計資訊和等待事件各是什麼。

SQL> select name,value from v$sysstat where name in('redo entries','redo size',

 2 'redo synch writes','redo wastage','redo write time','redo writes') order by name;

NAME                                                                 VALUE

---------------------------------------------------------------- ----------

redo entries                                                           375

redo size                                                           185160

redo synch writes                                                       14

redo wastage                                                          9552

redo write time                                                        131

redo writes                                                             41

SQL> select SID,EVENT,TOTAL_WAITS WAIT_CLASS from v$session_event

 2 where sid in(159,166) and event in ('log file sync','log file parallel write');

   no rows selected

SQL> begin

 2 for x in(select rowid rid,t1.* from t1)

 3    loop

 4             update t1 set name=lower(name) where rowid=x.rid;

 5             commit;

 6     end loop;

  7 end;

 8 /

             在執行測試指令碼以後，再來看看統計資訊和等待事件發生了哪些變化。

SQL> select name,value from v$sysstat where name in('redo entries','redo size',

 2 'redo synch writes','redo wastage','redo write time','redo writes') order by name;

NAME                                                                 VALUE

---------------------------------------------------------------- ----------

redo entries                                                         49586

redo size                                                         20031044

redo synch writes                                                       18

redo wastage                                                       2382452

redo write time                                                        996

redo writes                                                           5986

SQL> select distinct sid from v$mystat;

      SID

----------

      159

SQL> select c.sid,a.name from v$bgprocess a ,v$process b , v$session c

 2 where a.paddr=b.addr and b.addr = c.paddr and a.name='LGWR';

      SID NAME

---------- -----

      166 LGWR

SQL> select SID,EVENT,TOTAL_WAITS WAIT_CLASS from v$session_event

 2 where sid in(159,166) and event in ('log file sync','log file parallel write');

      SID   EVENT                TOTAL_WAITS WAIT_CLASS

      ------ --------------------- -----------  ----------

     159 log file sync                  3   Commit

     166 log file parallel write     6007   System I/O

從上面的測試，我們可以明顯看到，透過在迴圈中不斷進行提交，出現了3次log file sync等待事件。而實際上，過於頻繁的提交也正是log file sync等待事件出現的主要原因。而log file parallel write等待事件則總是會出現的，只要LGWR開始重新整理日誌緩衝區，該程式就會等待log file parallel write等待事件，是不可避免的，不用過多關注該等待事件。同時，我們可以看到，由於過多的提交，導致生成的重做記錄的數量非常巨大，redo size為19845884（20031044-185160）位元組，也就相當於將近19M。

我們來修改一下上面的指令碼，將commit移出迴圈以後，再按照上面的測試步驟執行一遍。可以發現log file sync等待事件只會出現1次，也就是說減小了一半的log file sync的等待。同時，透過將commit移出迴圈，所產生的重做記錄的數量也下降到大約10M，也就是說減少了將近一半的日誌量。

由此，我們也就可以知道，要減小log file sync的主要方法就是減少提交或回滾的次數。同時，過於頻繁的提交不光會引起log file sync等待事件，而且很有可能引起ora-01555：snapshot too old錯誤。我們可以使用下面的語句來查詢log file sync等待所佔的總共等待時間的百分比，以及每個session平均每個小時提交多少次，進而可以找到該session執行了哪些SQL語句引起了過於頻繁的提交。

select a.sid,

      a.event,

      a.time_waited,

      a.time_waited / c.sum_time_waited * 100 pct_wait_time,

      d.value user_commits,

      round((sysdate - b.logon_time) * 24) hours_connected

from  v$session_event a, v$session b, v$sesstat d,

      (select sid, sum(time_waited) sum_time_waited

       from  v$session_event

       where event not in ('Null event',

                   'client message',

                   'KXFX: Execution Message Dequeue - Slave',

                   'PX Deq: Execution Msg',

                   'KXFQ: kxfqdeq - normal deqeue',

                   'PX Deq: Table QNormal',

                   'Wait for credit - send blocked',

                   'PX Deq Credit: send blkd',

                   'Wait for credit - need buffer to send',

                   'PX Deq Credit: need buffer',

                   'Wait for credit - free buffer',

                   'PX Deq Credit: free buffer',

                   'parallel query dequeue wait',

                   'PX Deque wait',

                   'Parallel Query Idle Wait - Slaves',

                   'PX Idle Wait',

                   'slave wait',

                   'dispatcher timer',

                   'virtual circuit status',

                   'pipe get',

                   'rdbms ipc message',

                   'rdbms ipc reply',

                   'pmon timer',

                   'smon timer',

                   'PL/SQL lock timer',

                   'SQL*Net message from client',

                   'WMON goes to sleep')

       having sum(time_waited) > 0 group by sid) c

where a.sid        = b.sid

and   a.sid        = c.sid

and   a.sid        = d.sid

and   d.statistic# = (select statistic#

                       from  v$statname

                       where name = 'user commits')

and   a.time_waited > 10000

and   a.event      = 'log file sync'

order by pct_wait_time, hours_connected;

如果應用程式已經確保了使用正確的頻率進行提交，則還是發現很嚴重的log file sync等待事件，則比較常見的原因主要包括：

<!--[if !supportLists]--&gt1)     <!--[endif]--&gt聯機日誌檔案放在一個很慢的磁碟上。可以用前面我們提到的log file parallel write的平均等待時間應該小於等於10個毫秒來判斷，磁碟速度是否過慢。

<!--[if !supportLists]--&gt2)     <!--[endif]--&gt聯機日誌檔案與其他隨機寫入的檔案放在了同一個磁碟上。從前面已經知道，聯機日誌檔案都是順序寫入的。不能夠將其與其他隨機寫入的檔案放在一起，需要存放在單個的磁碟上。

<!--[if !supportLists]--&gt3)     <!--[endif]--&gt聯機日誌檔案放在了RAID 5的磁碟組裡。RAID 5適合頻繁的讀取，比如資料倉儲類的應用等，但不適合頻繁寫入。

最好能夠將每個聯機日誌檔案都放在單獨的小的、轉速快的磁碟上，與資料檔案所在的磁碟陣列分開。

如果可以的話，最好不要使用檔案系統來磁碟，直接使用RAW裝置，直接交給來管理磁碟。而且，oracle中最適合放在RAW裝置上的檔案就是聯機日誌檔案。