log file sync等待事件

最新推荐文章于 2023-03-21 08:38:30 发布

ckm9894

最新推荐文章于 2023-03-21 08:38:30 发布

阅读量268

点赞数

文章标签：操作系统数据库

事务提交的过程大致为：

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> /