log file sync总结

标签： log file sync | 发表时间：2017-03-09 14:36 | 作者：czmmiao
出处：http://www.iteye.com
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/O2.LGWR进程收集redo，然后发给I/O
3. Time for the log write I/O to complete3.等待log写入I/O完成
4. LGWR I/O post processing4.LGWR I/O post processing
5. LGWR posting the foreground/user session that the write has completed5.LGWR通知前台/用户回话，redo写入完成
6. Foreground/user session wakeup6.前台/用户会话唤醒
 
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. 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-2108: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. ***2015-01-2108:19:04.077
  4. Log file sync switching to polling
  5. Current scheduling delay is 1 usec
  6. Current approximate redo synch write rate is 1 per sec
  7. kcrfw_update_adaptive_sync_mode: poll->post current_sched_delay=0 switch_sched_delay=1 current_sync_count_delta=1 switch_sync_count_delta=5
 
Switch to post/wait:
  1. ***2015-01-2108:46:09.428
  2. Log file sync switching to post/wait
  3. Current approximate redo synch write rate is 0 per sec
  4. ***2015-01-2108:47:46.473
  5. 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. NAME                                                                  VALUE
  3. --------------------------------------------------------------------------
  4. 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. BEGIN_INTERVAL_TIME       INST STAT_NAME                 REDO_SYNCH_POLLS
  17. ----------------------------------------------------------------------
  18. 06-JAN-1507.00.02.884 AM    2 redo synch polls                       734
  19. 06-JAN-1508.00.08.425 AM    2 redo synch polls                     23767
  20. 06-JAN-1509.00.13.770 AM    2 redo synch polls                     39827
  21. 06-JAN-1510.00.19.233 AM    2 redo synch polls                     48479
  22. 06-JAN-1511.00.24.431 AM    2 redo synch polls                     41541
  23. 06-JAN-1512.00.29.670 PM    2 redo synch polls                     47566
  24. 06-JAN-1501.00.35.029 PM    2 redo synch polls                     32169
  25. 06-JAN-1502.00.04.159 PM    2 redo synch polls                     37405
  26. 06-JAN-1502.59.04.536 PM    2 redo synch polls                     41469
  27. 06-JAN-1504.00.08.556 PM    2 redo synch polls                     38683
  28. 06-JAN-1505.00.12.523 PM    2 redo synch polls                     51618
  29. 06-JAN-1506.00.16.584 PM    2 redo synch polls                     52511
  30. 06-JAN-1507.00.03.352 PM    2 redo synch polls                     42229
  31. 06-JAN-1508.00.08.663 PM    2 redo synch polls                     35229
  32. 06-JAN-1509.00.13.882 PM    2 redo synch polls                     18499

 

 

参考至:http://blog.chinaunix.net/xmlrpc.php?r=blog/article&id=4774739&uid=23284114

如有错误，欢迎指正

邮箱:[email protected]



已有 0 人发表留言，猛击->> 这里<<-参与讨论


ITeye推荐



相关 [log file sync] 推荐：

log file sync总结

- - 数据库 - ITeye博客
log file sync等待时间发生在redo log从log buffer写入到log file期间. 下面对log file sync做个详细的解释. 1.commit或者rollback. 3.log buffer 1/3满或者已经有1M的redo数据.       更精确的解释：_LOG_IO_SIZE 大小默认是LOG_BUFFER的1/3,当log buffer中redo数据达到_LOG_IO_SIZE 大小时，发生日志写入.

log file sync等待超高一例

- - CSDN博客数据库推荐文章
这是3月份某客户的情况，原因是服务器硬件故障后进行更换之后，业务翻译偶尔出现提交缓慢的情况. 我们可以看到，该系统的load profile信息其实并不高，每秒才21个transaction. 先来看看top5events：. 从top 5event，我们可以发现，log file sync的avg wait非常之高，高达124ms.

Oracle Tuning Log File Sync 等待事件的几种策略

- - CSDN博客数据库推荐文章
    在一个频繁 commit/rollback 或磁盘 I/O 有问题、大量物理读写争用.    那么、我们便会经常瞧见 LOG FILE SYNC 等待事件出现在 TOP EVENTS 中.    评估 LOG FILE SYNC等待事件的指标是平均等待时间、以及 AWR 后续的 WAIT EVENT HISTOGRAM.

Log调试

- - ITeye博客
在开发中我们一定不能避免使用Log类，但是这个类存在一个问题就是，当你在程序中使用了大量的Log，那么在程序开发完毕的时候，这将是一个问题，因为，你需要将所有的Log记录注释掉（当然，你不注释也是可以的）. 我们可以写一个类，将Log类包装起来，使用一个boolean来控制所有的Log记录的显示. public static final boolean isDebug = true;//这里控制所有Log的显示情况.

Oracle online redo log 扫盲

- - CSDN博客数据库推荐文章
Oracle 的日志分为：ONLINE REDO LOG 和 archived log. 一个数据库至少要有2组 redo log，每组 redo log 至少要有一个 member（出于安全考虑，建议每组 redo log 至少有 2 个多元化的 redo log member）. redo log 循环使用，当一组日志写满后，就会切换到下一组日志.

必须了解的MySQL三大日志：binlog、redo log和undo log

- - DockOne.io
日志是 MySQL数据库的重要组成部分，记录着数据库运行期间各种状态信息. MySQL日志主要包括错误日志、查询日志、慢查询日志、事务日志、二进制日志几大类. 作为开发，我们重点需要关注的是二进制日志（ binlog）和事务日志（包括 redo log和 undo log），本文接下来会详细介绍这三种日志.

oracle的控制文件(control file)

- - CSDN博客数据库推荐文章
1： 对oracle database  files进行说明. 2： oracle doc 对 control file的定义. 3：查找oracle数据文件的三种方式. 控制文件是一个小小的二进制文件，是oracle数据库的一部分，这个控制文件是用于记录数据库的状态和物理结构. 每个数据库必须要至少一个控制文件，但是强烈的建议超过一个控制文件，每个控制文件的备份应该放在不同的磁盘上.

hbase权威指南： store file合并（compaction）

- - CSDN博客推荐文章
          hbase为了防止小文件（被刷到磁盘的menstore）过多，以保证保证查询效率，hbase需要在必要的时候将这些小的store file合并成相对较大的store file，这个过程就称之为compaction. 在hbase中，主要存在两种类型的compaction：minor  compaction和major compaction.

db file sequential read等待事件总结

- - CSDN博客数据库推荐文章
该等待事件的参数：file#,first block#,and block count（一般是1）可以从dba_extents去确定访问的段,属于I/O类的等待. The Oracle process wants a block that is currently not in the SGA, and it is waiting for the database block to be read into the SGA from disk..

关于File Upload的一些思考

- - FreeBuf互联网安全新媒体平台
在web渗透中，文件上传是最简单直接的方式之一. 但是碰到完全不做校验的代码直接上传getshell，很难有这样的运气；大部分时候都有检测，甚至多处设卡. 若按设卡点的顺序来说可大致分为：前端js检验、防护检测（waf）、服务端检测. 这里就讲如何绕过服务端代码的检测，服务端会出现文件上传的什么安全配置.