ITPub博客

首页 > 数据库 > Oracle > 自适应log file sync影响案例

自适应log file sync影响案例

原创 Oracle 作者:bisal 时间:2018-12-10 12:53:49 0 删除 编辑

Oracle最吸引人的地方,就是有些答案,隐藏在种种现象之中,扑朔迷离,朦朦胧胧,就像侦探办案,首先要有思路,其次要有证据,再者就是扎实的基础知识,另外就是些运气。


例如最近碰见了一个案例,一套3节点11.2.0.4 RAC,某应用只用节点1(FAILOVER other nodes),如下是系统负载,某段时间,TPS是554.5,


AWR经常出现log file sync等待事件处于top5/10首位,单次平均等待的时间,11毫秒,


Oracle中有些等待事件,是非常常见的,例如log file sync,当我们从AWR看见他的时候,并不意味着系统有问题,但也不意味着系统没问题,但从上面信息看,log file sync一直处于首位,未免让人生疑。


我们先看下log file sync等待事件的解释,

当用户执行commit/rollback指令,redo信息需要从log buffer刷新到本地redo log file,进行持久化操作,这就是所谓的“日志优先写”,保证数据不丢的前提。日志刷新磁盘的操作,就是使用LGWR进程完成的。用户会话会等待log file sync这个事件,此时,等待LGWR进程返回确认所有redo改变向量已经写入本地磁盘文件中。


log file sync等待事件,可以分解为以下步骤,

1. Wakeup LGWR if idle 
2. LGWR gathers the redo to be written and issue the I/O
3. Time for the log write I/O to complete
4. LGWR I/O post processing
5. LGWR posting the foreground/user session that the write has completed
6. Foreground/user session wakeup


如果log file sync等待事件时间久,就可以从上面分解步骤,寻找原因。MOS针对这些步骤,提出了一些优化的建议,2和3的数据收集于AWR的redo write time。3对应的就是log file parallel write等待事件。5和6随着系统负载的增加,可能会比较明显,这是因为,即使通知了前台进程,对于操作系统,也需要时间进行调度。


话说回来,通常来讲对于log file sync,常见的原因要么写日志慢,要么commit操作太频繁。

1. 从上面信息看,TPS是554.5,并不是非常高,并不能说明commit操作太频繁。

2. 再来看日志写入,log file sync对应前台进程的等待事件,相应的后台进程等待事件,就是log file parallel write,如果日志写入慢,会体现在log file parallel write单次响应时间慢,但从AWR来看,单次平均等待时间是2毫秒,因此不是因为日志写入慢,导致log file sync等待事件,


数据库版本是11.2.0.4,11g有些新特性值得关注,比如Adaptive Log File Sync,即自适应Log File Sync,有可能是导致log file sync的原因,根据MOS以及一些牛人案例,相关文章的描述,同时也是周五小y了解现象,第一时间的反应,什么是自适应Log File Sync?


首先我们看下,Log File Sync有什么可以适应。


为了确认commit操作完成与否,LGWR和前台进程需要通信,两种方法,

1. Post/wait

这是之前Oracle版本中传统的方法。LGWR写完log buffer的改变向量,就会立刻通知等待commit的进程。优点就是log file sync等待时间很短,相对来说,12c之前由于只有1个LGWR进程,因此LGWR进程负载可能比较重。


2. Polling

使用这种方法,LGWR完成写入,会进入休眠环节,timeout之后才会查看log buffer是否写入。换句话说,LGWR不单独通知每个等待commit的进程,一定意义上解放了LGWR高负载,随之带来的是log file sync时间变久。


Oracle会根据一些内部的算法,评估post/wait方法效率高,还是polling方法效率高,在高系统负载下,polling 可能 效率更高,因为post/wait模式下每次刷新磁盘,均需要和前台进程通信。如果系统负载低,post/wait方式效率会高些,相比polling会有更高的响应时间。Oracle依赖于内部统计数据,决定究竟使用何种方法。因为每次post/wait和polling之间的切换,会有些负载产生,因此需要机制,保证这种切换,不要过于频繁。


按照官方的解释,log file sync适应的就是post/wait和polling,这两种日志写入通知的机制。


但实际上,对于OLTP应用,polling机制有时是瓶颈,因为他会导致log file sync时间变久,对应的系统commit操作时间变久,影响系统吞吐量。这种现象和本案例相近,再看一些依据。


对于是否采用polling的机制,从v$sysstat视图可以看出统计数据,若结果为0,则表示未采用,若不为零,则表示采用了。

SQL> select name,value from v$sysstat where name in ('redo synch poll writes','redo synch polls');


AWR中也有这些统计数据,可以看出采样时间段,日志写入通知,采用了polling的机制,从数据看,非常频繁,


对于wait/post和polling每次切换,在LGWR的trace文件中均会记录,而且带有时间戳,如下就是切换为polling,

*** 2018-01-05 08:21:00.000

kcrfw_update_adaptive_sync_mode: post->poll long#=316 sync#=1719 sync=247657 
poll=12382 rw=6191 rw+=13890 ack=0 min_sleep=10023


*** 2018-01-05 08:21:00.001

Log file sync switching to polling
Current scheduling delay is 234 usec


如下则是切换为post/wait,

*** 2018-01-05 08:22:00.000

kcrfw_update_adaptive_sync_mode: poll->post current_sched_delay=0 
switch_sched_delay=234 current_sync_count_delta=2275 
switch_sync_count_delta=1719

*** 2018-01-05 08:22:00.000

Log file sync switching to post/wait
Current approximate redo synch write rate is 758 per sec


对于本文案例,从trace中进行统计,发现log file sync出现明显的时间段,使用的就是polling机制,即使出现post/wait的记录,经过1分钟左右,就切换为了polling机制。


如果需要禁用log file sync自适应,可以设置_use_adaptive_log_file_sync这个隐藏参数为false,这个参数从11gR2版本引入,控制log file sync自适应切换功能,11.2.0.1和11.2.0.2版本中默认值则是false,从11.2.0.3开始默认值改为了true。这是一个动态的参数,可以在系统级进行变更,

ALTER SYSTEM SET "_use_adaptive_log_file_sync"= <FALSE/TRUE>  scope=<both/spfile/memory>;


对于本案例来说,首先可以调整的,就是关闭log file sync自适应,而且按照小y所说,这个参数,对于比较繁忙的OLTP系统来说,也是11g下建议默认关闭。


根据MOS介绍,这种log file sync自适应按说会提高日志文件同步的整体性能。但同时这一个新特性,会有一些bug产生,MOS建议要么升级至11.2.0.4/12.1,要么patch,就是没说针对OLTP,建议默认关闭,毕竟作为11g新特性,官方就建议关闭,岂不是自己打脸?如下是自适应log file sync,已知和解决的bug,

Document 13707904.8 Bug 13707904 - LGWR sometimes uses polling, sometimes post/wait
Document 13074706.8 Bug 13074706 - Long "log file sync" waits in RAC not correlated with slow writes
Document 25178179.8 Bug 25178179 - Several sessions wait on 'log file sync' in a RAC environment



参考文献:

Adaptive Log File Sync Optimization (1541136.1)

Troubleshooting: 'Log file sync' Waits (1376916.1)

WAITEVENT: "log file sync" Reference Note (34592.1)

High Waits for 'Log File Sync': Known Issue Checklist for 11.2 (1548261.1)

Adaptive Switching Between Log Write Methods can Cause 'log file sync' Waits (1462942.1)

Bug 13074706 - Long "log file sync" waits in RAC not correlated with slow writes (13074706.8)

Bug 25178179 - Several sessions wait on 'log file sync' in a RAC environment (25178179.8)

"log file parallel write" Reference Note(34583.1)

来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/7192724/viewspace-2284686/,如需转载,请注明出处,否则将追究法律责任。

请登录后发表评论 登录
全部评论
Oracle ACE,10g/11g OCP,11g OCM,国内首批Oracle YEP成员(Oracle Young Expert Program,Oracle用户组年轻专家项目),EXIN DevOps Master,Oracle爱好者,微信公众号:bisal的个人杂货铺

注册时间:2013-07-26

  • 博文量
    340
  • 访问量
    2623859