log file sync等待事件

当一个用户commit或者rollback时，这个用户会话的redo信息需要被刷新到redo文件中。
用户会话将请求LGWR从log buffer中写到redo日志中。当LGWR写完，返回信号给用户会话。
用户会话等LGWR返回信息确保所有的redo改变写到磁盘中。

1. 唤醒LGWR（semctl call）
2. LGWR收集要写的redo并发起IO（kaio调用asynchronous I/O calls）
3. 写redo直至写完
4. LGWR I / O的后续处理
5. LGWR返回写完信息给后台或者用户会话
6. 后台或者用户会话唤醒

引起log file sync的原因：

1. redo log file的IO不够好。
redo online file连续的io写，block size是512，适合raw设备和RAID1。如果一个group有多个member，
那么每一个member放在独立的磁盘是最好的。

2. 过多的commit或者rollback
检查应用是否有过多的短小的事务，如果有，可以使用批处理来缓解。

3. 可能是bug。很多的log file sync和log file parallel write和bug相关的。如果redo
file的io性能没有问题，commit不是过多的话，可以去metalink看看有没有相关的bug。

可以从awr或者statspack中统计信息

top 5 wait events:

log file sync是否占用大量的时间
CPU Time: 60 (mins) * 36 (cpu) = 2160 (mins)
DB Time: 80611 (s)

log file sync: 50,342 (s) 占用62.45%

Foreground Wait Events（前台等待事件）

event                              waits      Total Wait Time (s)    Avg wait (ms)         %DB time
---------------------------------------------------------------------------------------------------------
log file sync                      278,575    50,342                 181                   62.45
--等待时间占62.45%
db file sequential read            460,844    18,222                 40                    22.60
--平均等待时间是40ms，是非常差的。

Background Wait Events（后台等待事件）

event                              waits      Total Wait Time (s)    Avg wait (ms)
---------------------------------------------------------------------------------------
log file parallel write            238,844    1,131                  5
log file sync                      108        189                    1753
log file sequential read           666        52                     79
log file single write              52         4                      80

Instance Activity Stats

Statistic               Total           per Second
---------------------------------------------------------------------------------------
redo write time         114,864         31.67  --this is the total elapsed time of the
                                               --write from the redo log buffer to the
                                               --current redo log file (in centiseconds).
redo writes             239,169         65.95  --每秒写了redo多少次

(31.67*10(ms))/65.95=4.82m/s                   --每次写大概是4ms，这和log file parallel write
                                               --的Avg wait (ms) 差不多。从这里看redo log file
                                               --的io并不差。

redo blocks written     2,322,803       640.46   --每秒写了redo多少块 640×1024=655,360
--avg.redo write size = (Redo block written/redo writes)*1024 bytes = (640/65)*1024=10,082

redo wastage            157,092,192     43,314.77
redo size               2,183,604,592   602,081.69   --每秒写了多少redo
user commits            273,347         75.37    --每秒75 commits
user rollbacks          72,991          20.13    --每秒20 rollback

16 + (redo size + redo wastage) / redo blocks written = 16 + (602,081.69+43,314.77)/640.46 = 1023.7

脚本获取log file sync和log file parallel write事件
select
       dbid,
       btime,
       round((time_ms_end-time_ms_beg)/nullif(count_end-count_beg,0),1) avg_ms
from (
select
       s.dbid,
       to_char(s.BEGIN_INTERVAL_TIME,'DD-MON-YY HH24:MI')  btime,
       total_waits count_end,
       time_waited_micro/1000 time_ms_end,
       Lag (e.time_waited_micro/1000)
              OVER( PARTITION BY e.event_name ORDER BY s.snap_id) time_ms_beg,
       Lag (e.total_waits)
              OVER( PARTITION BY e.event_name ORDER BY s.snap_id) count_beg
from
       DBA_HIST_SYSTEM_EVENT e,
       DBA_HIST_SNAPSHOT s
where
       s.snap_id=e.snap_id
   and e.event_name in (
                  'log file sync',
                  'log file parallel write'
                )
   and  s.dbid=e.dbid
)
order by btime
/

脚本获取redo size
select   dbid, to_char( begin_time ,'YYYY/MM/DD HH24'),
         round(sum(decode(metric_name,'Redo Generated Per Sec',average,0)) /
         nullif(sum(decode(metric_name,'Redo Writes Per Sec',average,0)),0)/1024,0)  avg_log_write_kb
from     dba_hist_sysmetric_summary
where    metric_name in  (
                           'Redo Writes Per Sec',
                           'Redo Generated Per Sec'
         ) /* and DBID=[dbid if share repository] */
group  by dbid, to_char( begin_time ,'YYYY/MM/DD HH24')
/

 

--可以使用10046来做lgwr的trace，看看lgwr到底在等待什么。

 

 

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

转载于:http://blog.itpub.net/25105315/viewspace-711630/