博客
关于我
强烈建议你试试无所不能的chatGPT,快点击我
log file sync
阅读量:5925 次
发布时间:2019-06-19

本文共 8410 字,大约阅读时间需要 28 分钟。

hot3.png

log file sync等待时间发生在redo log从log buffer写入到log file期间。

下面对log file sync做个详细的解释。

 

何时发生日志写入:

1.commit或者rollback

2.每3秒

3.log buffer 1/3满或者已经有1M的redo数据。

      更精确的解释:_LOG_IO_SIZE 大小默认是LOG_BUFFER的1/3,当log buffer中redo数据达到_LOG_IO_SIZE 大小时,发生日志写入。

4.DBWR写之前

 

 

_log_io_size隐含参数:

LOG_BUFFER(bytes)写入的数量超过_LOG_IO_SIZE会触发lgwr写日志的条件,缺省值为LOG BUFFER的1/3或1M。

但是这个说法通过查询并不能验证,隐含参数尽量不要修改。

col name for a25

col VALUE for a20

col DESCRIB for a50

SELECT x.ksppinm NAME, y.ksppstvl VALUE, x.ksppdesc describ

FROM SYS.x$ksppi x, SYS.x$ksppcv y

WHERE x.inst_id = USERENV ('Instance')

AND y.inst_id = USERENV ('Instance')

AND x.indx = y.indx

AND x.ksppinm LIKE '_log_io_size';

 

NAME                      VALUE                DESCRIB

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

_log_io_size              0                    automatically initiate log write if this many redo

                                                blocks in buffer

log file sync发生的过程:

此等待事件用户发出提交或回滚声明后,等待提交完成的事件,提交命令会去做日志同步,也就是写日志缓存到日志文件, 在提交命令未完成前,用户将会看见此等待事件.

注意,它专指因提交,回滚而造成的写缓存到日志文件的等待.当发生此等待事件时,有时也会伴随log file parallel write.因为此等待事件将会写日志缓存,如果日志的I/O系统较为缓慢的话,

这必将造成log file parallel write 等待.当发生log file sync等待后,判断是否由于缓慢的日志I/O造成的,可以查看两个等待事件的等待时间,如果比较接近,就证明日志I/O比较缓慢或重做日志过多,这时,造成log file sync的原因是因为log file parallel write,可以参考解决log file parallel write的方法解决问题,

 

**如果log file sync的等待时间很高,而log file parallel write的等待时间并不高,这意味着log file sync的原因并不是缓慢的日志I/O,而是应用程序过多的提交造成。

  当log file sync的等待时间和 log file parallel write等待时间基本相同,说明是IO问题造成的log file sync等待事件。

 

-----

更好理解的解释:

回顾一下单机数据库中的'log file sync' 等待事件,当user session 提交(commit)时,user session会通知LGWR进程将redo buffer中的信息写入到redo log file,当LGWR进程完成写操作后,LGWR再post(通知)user session 写操作已经完成,user session 接收到LGWR的通知后提交操作才完成。因此user session 在没有收到LGWR post(通知)之前一致处于等待状态,具体的等待事件为'log file sync'。

-----

 

引起log file sync的原因:

1.频繁提交或者rollback,检查应用是否有过多的短小的事务,如果有,可以使用批处理来缓解。

2.OS的IO缓慢:解决办法是将日志文件放裸设备上或绑定在RAID 0或RAID 1+0中,而不是绑定在RAID 5中。

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,取两者之中较小的值。

换句话说,你可以具有较大的日志缓冲区,但较小的_LOG_IO_SIZE将增加后台写入次数,从而减少log file sync的等待时间。

4.CPU负载高。详见下面的描述。

5.RAC私有网络性能差,导致LMS同步commit SCN慢。

 

如何诊断log file sync:

1.AWR:发生log file sync时,先做个snapshot,然后做AWR,AWR时间选择在10-30分钟。

       已发生的log file sync,那么通过AWR依然可以分析,也要保持在10-30分钟。

2.Lgwr trace file(10.2.0.4开始),大于500ms会写入

trace文件中如果有Warning: log write time 1000ms, size 2KB,很有可能IO慢。

3.分析CPU资源使用情况的工具,CPU过于繁忙,lgwr无法及时获取CPU调度,出现log file sync。

vmstat,关注r是否大于CPU核数,大于说明cpu繁忙。

OSW:OSWatcher,同上。

4.Alert:确认log file 15到20分钟切换一次

5.Script to Collect Log File Sync Diagnostic Information (lfsdiag.sql) [Document 1064487.1]

 

解决办法:

1.如果确实是因为频繁提交造成的log file sync,那么减少commit。

2.如果确实是因为io引起的,那么解决办法是将日志文件放裸设备上或绑定在RAID 1+0中,而不是放在在RAID 5中(切记,redo log file一定不要放在SSD上!!!)。

3.确保CPU资源充足。CPU资源不足,LGWR通知user session后,user session无法及时获得CPU调度,不能正常工作。

4.是否有些表可以使用nologging,会减少redo产生量

5.检查redo log file足够大,确保redo log file每15到20分钟切换一次。

 

 

更深入分析log file sync:

如果上面的分析没有解决log file sync等待事件,那么需要做下面的分析。

 

The log file sync wait may be broken down into the following components:

log file sync 能拆解为一下步骤:

1. Wakeup LGWR if idle 1.唤醒LGWR进程

2. LGWR gathers the redo to be written and issue the I/O 2.LGWR进程收集redo,然后发给I/O

3. Time for the log write I/O to complete 3.等待log写入I/O完成

4. LGWR I/O post processing 4.LGWR I/O post processing

5. LGWR posting the foreground/user session that the write has completed 5.LGWR通知前台/用户回话,redo写入完成

6. Foreground/user session wakeup 6.前台/用户会话唤醒

 

Steps 2 and 3 are accumulated in the "redo write time" statistic. (i.e. as found under STATISICS section of Statspack and AWR)

步骤2和3消耗的时间在AWR中的"redo write time"中有所体现。(AWR中 Instance Activity Stats )

 

Step 3 is the "log file parallel write" wait event. (Document:34583.1 "log file parallel write" Reference Note)

步骤3产生"log file parallel write"等待事件。

另外:如果是最大保护模式的DATAGUARD(SYNC传输),这一步骤还包含网络写、RFS/redo写入到备库的standby log file sync的时间。

 

Steps 5 and 6 may become very significant as the system load increases. This is because even after the foreground has been posted it may take a some time for the OS to schedule it to run. May require monitoring from O/S level.

在系统负载高时(尤其是CPU高的情况,看vmstat r值),步骤5和6会变得非常明显。因为,前台收到LGWR写入完成的通知后,操作系统需要消耗一些时间调度Foreground/user session进程唤醒(也就是CPU调度)。需要系统级别监控。

 

 

 

几个技术指标:

log file sync 等待时间小于20ms算正常

log file parallel write 等待时间小于20ms算正常

log file parallel wirte 和log file sync等待时间很接近,说明就是IO问题,因为大部分时间都花在了log写入到磁盘上。

 

 

 

相关脚本:

--等待时间平均等待时间

 
  1. select EVENT,TOTAL_WAITS,TOTAL_TIMEOUTS,TIME_WAITED,AVERAGE_WAIT
  2.  from   v$system_event 
  3.  where  event in ('log file sync','log file parallel write'); 
  4.  
  5. select value from v$parameter where name = 'log_buffer';

 

---------------新特性:log file sync 两种方式--------------

 

Adaptive Log File Sync 

Adaptive Log File sync was introduced in 11.2. The parameter controlling this feature, _use_adaptive_log_file_sync, is set to false by default in 11.2.0.1 and 11.2.0.2.

 

_use_adaptive_log_file_sync参数在11gR2提出。11.2.0.1和11.2.0.2两个版本该参数默认是false。

从11.2.0.3开始,这个参数默认值是true,也就是开始启用“自适应日志同步机制”。

 

11.2.0.1和11.2.0.2也可以开启改参数

ALTER SYSTEM SET "_use_adaptive_log_file_sync"=  scope=;

 

开启改参数后,日志同步机制会在2种方式中切换。

该参数决定了,foreground/user session 和LGWR进程通过什么方式获知commit操作已完成(也就是redo写log file完成)。

 

Post/wait, traditional method for posting completion of writes to redo log

传统方式,在11.2.0.3之前,user session等待LGWR通知redo写入到log file完毕,被动方式。

优点:post/wait方式,user session几乎能立即发现redo已刷到磁盘。

 

Polling, a new method where the foreground process checks if the LGWR has completed the write.

新方式,主动监测LGWR是否完成写入,主动方式。这种方式比Post/wait方式响应速度慢,但是可以节约CPU资源。

优点:当commit完成后,LGWR会把commit完成的消息通知给很多user session,这个过程消耗大量CPU。

 Polling方式采用朱勇监测LGWR释放写入redo完成,所以释放了LGWR占用的CPU资源。

 

系统负载高(CPU繁忙)采用Polling方式更好。

系统负载低(CPU清闲)采用post/wait方式更好,它能够提供比polling方式更好的响应时间。

ORACLE根据内部统计信息决定采用何种方式。post/wait和polling方式互相切换能引起过热,为了确保安全,切换不要太频繁。

 

LGWR的trace文件记录了switch记录,关键字是 "Log file sync switching to ...":

Switch to polling:

 
  1. *** 2015-01-21 08:19:04.077
  2. kcrfw_update_adaptive_sync_mode: post->poll long#=2 sync#=5 sync=62 poll=1056 rw=454 ack=0 min_sleep=1056
  3.  
  4. *** 2015-01-21 08:19:04.077
  5. Log file sync switching to polling
  6. Current scheduling delay is 1 usec
  7. Current approximate redo synch write rate is 1 per sec
  8. kcrfw_update_adaptive_sync_mode: poll->post current_sched_delay=0 switch_sched_delay=1current_sync_count_delta=1 switch_sync_count_delta=5

 

Switch to post/wait:

 
  1. *** 2015-01-21 08:46:09.428
  2. Log file sync switching to post/wait
  3. Current approximate redo synch write rate is 0 per sec
  4.  
  5. *** 2015-01-21 08:47:46.473
  6. kcrfw_update_adaptive_sync_mode: post->poll long#=2 sync#=11 sync=228 poll=1442 rw=721 ack=0 min_sleep=1056

 

相关脚本:

查询当前log file sync 方式是post-wait还是poll

 
  1. SQL> select name,value from v$sysstat where name in ('redo sync poll writes','redo synch polls');
  2.  
  3. NAME                                                                  VALUE
  4. ---------------------------------------------------------------- ----------
  5. redo synch polls                                                  325355850

 

每小时采用poll log file sync方式的次数

 
  1. col begin_interval_time format a25
  2. col instance_number format 99 heading INST
  3. col stat_name format a25
  4. select snap.BEGIN_INTERVAL_TIME,hist.instance_number , hist.stat_name,hist.redo_synch_polls
  5. from ( select snap_id,instance_number,stat_name,value -lag(value,1,null) over ( order by snap_id,instance_number,stat_name) redo_synch_polls
  6.         from dba_hist_sysstat
  7.         where stat_name='redo synch polls'
  8.         and dbid=(select dbid from v$database)
  9.         and instance_number = nvl('&instance_number',1)) hist,
  10.         dba_hist_snapshot snap
  11. where redo_synch_polls >0
  12. and hist.snap_id=snap.snap_id
  13. and hist.instance_number=snap.instance_number
  14. order by 1,2
  15. /
  16.  
  17. BEGIN_INTERVAL_TIME       INST STAT_NAME                 REDO_SYNCH_POLLS
  18. ------------------------- ---- ------------------------- ----------------
  19. 06-JAN-15 07.00.02.884 AM    2 redo synch polls                       734
  20. 06-JAN-15 08.00.08.425 AM    2 redo synch polls                     23767
  21. 06-JAN-15 09.00.13.770 AM    2 redo synch polls                     39827
  22. 06-JAN-15 10.00.19.233 AM    2 redo synch polls                     48479
  23. 06-JAN-15 11.00.24.431 AM    2 redo synch polls                     41541
  24. 06-JAN-15 12.00.29.670 PM    2 redo synch polls                     47566
  25. 06-JAN-15 01.00.35.029 PM    2 redo synch polls                     32169
  26. 06-JAN-15 02.00.04.159 PM    2 redo synch polls                     37405
  27. 06-JAN-15 02.59.04.536 PM    2 redo synch polls                     41469
  28. 06-JAN-15 04.00.08.556 PM    2 redo synch polls                     38683
  29. 06-JAN-15 05.00.12.523 PM    2 redo synch polls                     51618
  30. 06-JAN-15 06.00.16.584 PM    2 redo synch polls                     52511
  31. 06-JAN-15 07.00.03.352 PM    2 redo synch polls                     42229
  32. 06-JAN-15 08.00.08.663 PM    2 redo synch polls                     35229
  33. 06-JAN-15 09.00.13.882 PM    2 redo synch polls                     18499

转载于:https://my.oschina.net/u/3862440/blog/2872628

你可能感兴趣的文章
mongo同步到es
查看>>
用C#下的Raw
查看>>
mysql / sqlserver / oracle 常见数据库分页
查看>>
combo
查看>>
spring mvc 支持json
查看>>
Access数据库SQL注入(Access SQL Injection)
查看>>
个人学习C++过程中对const的总结:初始化系列之用字面值常量与其他类型的值初始化的区别(一)...
查看>>
自动化学习笔记之接口测试(一)
查看>>
深度学习常用方法
查看>>
完成端口模型开发
查看>>
CentOS Linux release 7.6.1810全新安装 Zimbra 8.8.12邮箱
查看>>
出现蓝屏代码0x0000007b的原因及解决办法
查看>>
C++ File 类学习总结
查看>>
权限框架 - shiro 自定义realm
查看>>
获取系统资源APP
查看>>
HP Autonomy KeyView入门使用&Maven打包流程
查看>>
Unity3d有关图形尺寸大小的注意事项
查看>>
js对象
查看>>
目标文件
查看>>
NTFS文件系统概述
查看>>