log file sync等待事件

事務提交的過程大致為：

1.使用者程式發出commit命令

2.使用者程式通知LGWR寫Redo buffer資料到Redo檔案

3.LGWR寫Redo到檔案

4.LGWR寫完通知使用者程式

5.使用者程式收到寫完成通知，提交完成。

6.CPU喚醒使用者程式

從步驟1開始，使用者程式開始等待log file sync，到步驟6結束。步驟3與步驟4中，LGWR等待log file parallel write。

一般來說，造成log file sync的原因有如下幾點：

1.頻繁commit或者rollback

2.IO緩慢 ，判斷是否由於緩慢的日誌I/O造成的,可以檢視log file sync與log file parallel write兩個等待事件的等待時間,如果比較接近,說明可能是日誌I/O比較緩慢或重做日誌過多

3.過大的日誌緩衝區(Log Buffer)

過大的log_buffer,允許LGWR變得懶惰，因為log buffer中的資料量無法達不到_LOG_IO_SIZE，導致更多的重做條目堆積在日誌緩衝區中。當事務提交或者3s時，LGWR才會把所有資料都寫入到redo log file中。由於資料很多，LGWR要用更多時間等待redo寫完畢。這種情況，可以調小引數_LOG_IO_SIZE引數，其預設值是LOG_BUFFER的1/3或1MB，取兩者之中較小的值。

4.CPU負載高。 在系統負載高時(尤其是CPU高的情況，看vmstat r值)，步驟5和6會變得非常明顯。因為前臺收到LGWR寫入完成的通知後，作業系統需要消耗一些時間排程Foreground/user session程式喚醒(也就是CPU排程)

5.RAC私有網路效能差,導致LMS同步commit SCN慢

模擬迴圈提交的情景：

--建立測試表

SQL> create table scott.tb_test (id int,age int,name varchar2(20));

--手動採集報告

exec dbms_workload_repository.create_snapshot();

--模擬多次提交

SQL> begin

for i in 1..5000000 loop

insert into scott.tb_test values(1,10,'test');

commit work write wait immediate; --pl/sql中如果只寫commit預設是批量提交，並不會模擬出log file sync

end loop;

end;

/

--執行完後再次採集報告

SQL> exec dbms_workload_repository.create_snapshot();

在插入的過程中檢視等待事件：

SQL> select inst_id

2 ,event

3 ,count(0)

4 from gv$session where wait_class != 'Idle' group by inst_id,event order by inst_id,count(0) desc;

INST_ID EVENT COUNT(0)

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

1 log file parallel write 1

1 log file sync 1

1 SQL*Net message to client 1

可看到 log file sync 與log file parallel write等待事件都出現了

檢視log file sync總等待次數與總等待時間：

SQL> SET LINES 200 PAGES 100

SQL> SELECT INST_ID

2 ,SID

3 ,EVENT

4 ,TOTAL_WAITS WAITS_CNT

5 ,TIME_WAITED

6 ,AVERAGE_WAIT/100 "AVERAGE_WAIT(S)"

7 ,MAX_WAIT/100 "MAX_WAIT(S)"

8 FROM GV$SESSION_EVENT

9 WHERE SID=&INPUT_SID

10 ORDER BY TOTAL_WAITS DESC;

Enter value for input_sid: 812

old 9: WHERE SID=&INPUT_SID

new 9: WHERE SID=812

INST_ID SID EVENT WAITS_CNT TIME_WAITED AVERAGE_WAIT(S) MAX_WAIT(S)

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

1 812 log file sync 1812509 54140 .0003 .5

1 812 db file sequential read 2183 289 .0013 .13

1 812 db file scattered read 1285 65 .0005 .03

1 812 control file sequential read 1266 1 0 0

1 812 SQL*Net message from client 918 581782 6.3375 1866.37

1 812 SQL*Net message to client 918 0 0 0

1 812 events in waitclass Other 179 2 .0001 0

1 812 direct path read 152 1 .0001 .01

1 812 latch: shared pool 27 0 .0001 0

1 812 SQL*Net more data to client 25 0 0 0

1 812 direct path write 25 0 0 0

1 812 Disk file operations I/O 16 0 .0001 0

1 812 log file switch completion 16 8 .0048 .01

1 812 Data file init write 13 1 .0005 0

1 812 local write wait 13 1 .0007 0

1 812 enq: RO - fast object reuse 9 2 .002 .01

1 812 SQL*Net break/reset to client 9 0 0 0

1 812 control file parallel write 6 0 .0004 0

1 812 buffer busy waits 4 0 .0001 0

1 812 undo segment extension 3 2 .0065 .02

1 812 db file parallel read 3 1 .0027 .01

1 812 db file single write 2 0 .0004 0

1 812 latch: cache buffers chains 1 0 0 0

1 812 direct path sync 1 0 .0016 0

24 rows selected.

SQL> /