log file sync等待超高一例

这是3月份某客户的情况,原因是server硬件故障后进行更换之后,业务翻译偶尔出现提交缓慢的情况。我们先来看下awr的情况。

我们能够看到,该系统的load profile信息事实上并不高,每秒才21个transaction。先来看看top5events:

从top 5event,我们能够发现,log file sync的avg wait很之高,高达124ms。大家应该知道,对于绝大多数情况

下,log file sync的平均等待时间是小于5ms的,这个值有点高的离谱。

我们知道,产生log file sync等待的原因有非常多。关于log file sync,tanel Poder大神写过一篇非常牛的pdf,大家能够參考下。

这里我主要引用大神的图,来简单描写叙述产生log file sync的原因可能有哪些,首先我们来看下从前端进程提交到最后得到反馈时,以及中间处理的整个流程情况:

从上图中,我们能够清楚的看到整个流程。这里能够进行简单的描写叙述:

1、当user发起一个commit后;

2、前端进程(即Server 进程)会post一个信息给lgwr进程,告诉它,你应该去写redo buffer了。

3、当LGWR进程得到指示后,開始调用操作系统函数进行物理写,在进行物理写的这段时间内,会出现

log file parallel write等待。这里也许有人会有疑问,为什么12c之前仅仅有一个lgwr进程,这里却是parallel

write呢?这里须要说明一下,lgwr进程在将redo buffer中的数据写出到log file文件里时,也是以batch方式

进程的(实际上,dbwN进程也是batch的模式),有相关的隐含參数控制。

4、当LGWR完毕wrtie操作之后,LGWR进程会返回一个信息给前端进程(Server进程),告诉它,我已经写完了,

你能够完毕提交了。

5.   user 完毕commit操作。

这里补充一下,这是因为Oracle 日志写优先的原则,如果在commit之前redo buffer的相关entry信息不马上写到redo

log file中,那么假设数据库出现crash,那么这是会丢数据的。

从上面的流程图,我们事实上也能够看到,log file sync和log file parallel write能够说是相互关联的。换句话讲,假设log file parallel write的时间非常长,那么必定导致log file sync等待时间拉长。

我们如果log file parallel write 等待非常高,那么着可能一般是物理磁盘IO的问题,例如以下:

我们从上图能够发行,假设LGWR进程在完毕IO操作的过程中时间过长,那么将导致log file parallel write等待升高。

实际上,在整个当用户发出commit到完毕commit的过程中,涉及到非常多环节,并非只唯独物理IO会影响log file sync/log file parallel write。还有CPU也会影响Log file sync和log file parallel write。我们再来看个图:

我们能够看到,上述流程中的4个环节都涉及到CPU的调度,假设在整个事务commit的过程中,系统CPU出现极度紧张,那么这可能会导致LGWR进程无法获得CPU,会进行排队等待,显然,这势必将导致log file sync或log file parallel write等待

的升高。

备注:Oracle中还能够通过隐含參数_high_priority_processes 来控制进程获取CPU的优先级。在一个cpu相对缺乏的系统中,能够通过设置该參数来进行缓解。

最后我们再回到这个案例中来,客户这里的环境,我们是能够排除CPU问题。那么最大的嫌疑可能就是存储本身的问题,导致IO非常慢,然而,实际上这也是能够排除的,大家事实上应该注意到前面的Top 5 event了,log file parallel write的平均等待

时间并不高,假设是存储IO问题,那么这个event的平均等待时间应该是比較高才对。

我们能够看到log file sync和log file parallel write的waits都是差点儿相同的。可是log file parallel write的avg wait time只唯独4ms,这是一个正常的值。也就是说能够我们排除存储IO问题。

那么问题是什么呢 ?我们利用Oracle MOS提供的脚本来查询下log file sync和log file parallel write等待的分布情况:

?


1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

   INST_ID EVENT                                    WAIT_TIME_MILLI WAIT_COUNT

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

         1 log file sync                                          1     259306

         1 log file sync                                          2    2948999

         1 log file sync                                          4    1865918

         1 log file sync                                          8     173699

         1 log file sync                                         16      43194

         1 log file sync                                         32       6095

         1 log file sync                                         64       1717

         1 log file sync                                        128       2458

        
1 log file sync                                        256       5180

        
1 log file sync                                        512       9140

        
1 log file sync                                       1024     558347

        
1 log file parallel write                                1       5262

        
1 log file parallel write                                2    4502377

        
1 log file parallel write                                4    1319211

        
1 log file parallel write                                8      46055

        
1 log file parallel write                               16      23694

        
1 log file parallel write                               32       3149

        
1 log file parallel write                               64        283

        
1 log file parallel write                              128        267

        
1 log file parallel write                              256        157

        
1 log file parallel write                              512         73

        
1 log file parallel write                             1024         42

        
1 log file parallel write                             2048         39

        
1 log file parallel write                             4096        103

        
1 log file parallel write                             8192         21

        
1 log file parallel write                            16384         22

        
1 log file parallel write                            32768        190

        
1 log file parallel write                            65536          1

大家能够简单的计算一下,事实上log file sync和log file parallel write 等待事件,差点儿99%左右的平均等待时间都是

小于等于4ms的,这是属于正常的情况;然而有少数的情况其等待时间是非常长的,比如log file sync最高的单次等待

时间高达1秒,因为偶尔的等待非常高,因此将整个log file sync的平均等待时间拉高了。

到最后,问题就比較清楚了,我觉得这是因为主机和存储之间的链路可能出现异常或不稳定导致。暂时的解决方法

将redo logfile 挪到本地磁盘,攻克了该问题。

后记:经客户后面确认,确实是存储光纤线接口松了。 哈哈

log file sync等待超高一例

时间: 2024-10-12 14:45:06

log file sync等待超高一例的相关文章

RAC 性能分析 - 'log file sync' 等待事件

简介 本文主要讨论 RAC 数据库中的'log file sync' 等待事件.RAC 数据库中的'log file sync' 等待事件要比单机数据库中的'log file sync' 等待事件复杂,主要原因是由于RAC 数据库需要将SCN同步到所有实例. 首先,回顾一下单机数据库中的'log file sync' 等待事件,当user session 提交(commit)时,user session会通知LGWR进程将redo buffer中的信息写入到redo log file,当LGWR

ORACLE AWR报告之 log file sync等待事件优化的总结【转自ITPUB】

来自白大师(白鳝)对log file sync等待事件优化的总结,供各位puber们学习参考: 一. log file sync平均等待事件时间超过7ms,如果等待时间过长,说明log write每次写入的时间过长,如果能够优化redo日志文件存储,使之存放在更快的磁盘上,就可以减少这个等待事件的单次等待时间.(RAID 5--> RAID 10)   当无法通过优化redo日志的I/O性能来解决问题,或者优化了redo日志的I/O性能后还是无法达到我们的预期,那么该如何处理呢? 二. 有经验的

log file sync等待超高案例浅析

监控工具DPA发现海外一台Oracle数据库服务器DB Commit Time指标告警,超过红色告警线(40毫秒左右,黄色告警是10毫秒,红色告警线是20毫秒),如下截图所示,生成了对应的时段的AWR报告,发现Top 5 Timed Events里面,log file sync等待事件的平均等待时间为37毫秒,log file parallel write等待事件的平均等待时间为40毫秒 如果对Tanel Poder::Understanding LGWR, Log File Sync Wait

Oracle之 等待事件log file sync + log file parallel write (awr优化)

这是3月份某客户的情况,原因是server硬件故障后进行更换之后,业务翻译偶尔出现提交缓慢的情况.我们先来看下awr的情况. 我们能够看到,该系统的load profile信息事实上并不高,每秒才21个transaction.先来看看top5events: 从top 5event,我们能够发现,log file sync的avg wait很之高,高达124ms.大家应该知道,对于绝大多数情况 下,log file sync的平均等待时间是小于5ms的,这个值有点高的离谱. 我们知道,产生log

oracle之 等待事件LOG FILE SYNC (awr)优化

log file sycn是ORACLE里最普遍的等待事件之一,一般log file sycn的等待时间都非常短 1-5ms,不会有什么问题,但是一旦出问题,往往都比较难解决.什么时候会产生log file sync等待?常见有以下几种:1)commit操作2)rollback操作3)DDL操作(DDL操作实施前都会首先进行一次commit)4)DDL操作导致的数据字典修改所产生的commit5)某些能递归修改数据字典的操作:比如查询SEQ的next值,可能会导致修改数据字典.一个典型的情况是,

log file sync 事件(转)

log file sync 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.DB

log buffer space等待事件

最近,我们有台服务器在delete操作期间发现一直在等待log buffer space,其他节点就没与这个问题.经查,向重做缓冲区上写入重做记录的进程,为了确保拥有重做缓冲区内必要的空间,需要获得redo allocation锁存器.已获得redo allocation锁存器的状态下,在想要得到重做缓冲区时,若没有适当的剩余空间,则需要等到直到获得空间为止.这时,根据情况等待两种事件.如果当前正在使用的重做日志文件已满,因此无法获得剩余空间,LGWR就会执行日志文件切换,服务器进程则等待log

Oracle db file parallel write 和 log file parallel write 等待事件

一. db file parallel write等待事件 引自如下blog: http://oradbpedia.com/wiki/Wait_Events_-_db_file_parallel_write db文件并行写 db文件并行写等待事件属于Oracle数据库写入程序(DBWR)进程,因为它是将块从SGA写入数据文件的唯一进程.当是写入时,DBWR进程编译一组脏块,将批处理交给操作系统,并等待db文件并行写事件以完成I / O.虽然用户会话从来没有遇到db文件并行写等待事件,但这并不意味

log file switch (checkpoint incomplete)的问题定位

今天測试环境下应用慢.发现数据库出了问题,直接上AWR报告.因为是虚拟机.所以不用贴cpu的个数,能够发现负载高. Snap Id Snap Time Sessions Cursors/Session Begin Snap: 15257 30-Jun-15 09:30:57 558 5.3 End Snap: 15258 30-Jun-15 10:00:27 582 5.7 Elapsed:   29.50 (mins)     DB Time:   717.00 (mins)     查看等待