Oracle Wait Event: log file sync

博客首页 » Oracle Wait Event: log file sync

发布于 20 Nov 2013 08:09
标签 blog
"log file sync" 等待事件

"log file sync" 等待事件是一个常见的事件,它主要表达的是commit的速度。

log file sync, log file parallell write

http://blog.csdn.net/robinson1988/article/details/4904911

分类: WAIT EVENT 2009-11-30 13:42 1191人阅读 评论(1) 收藏 举报
fileparallelbuffersystem磁盘session
SQL> select name,parameter1,parameter2,parameter3,wait_class from v$event_name where name in( 'log file sync','log file parallel write');
NAME PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS
--------- -- -- -- ------------——
log file parallel write files blocks requests System I/O
log file sync buffer# Commit

log file parallel write等待事件位于System I/O类,它有三个参数,第一个参数表示将要写的文件个数,第二个参数表示将要写入的block个数,第三个参数表示I/O请求的个数。
log file sync 等待事件位于Commit类下,它只有一个参数,它表示log file中block的块号。

当用户发出commit,rollback的时候,就会触发lgwr进程将产生的redo record写入到log file中,这个过程称为日志同步写入。
其余条件的redo record 写入到log file称为后台写入。
出现log file sync等待事件是很频繁的,它很短,如果系统在awr报告,statspack报告中发现有log file sync
通常是由于过于频繁的提交,日志文件所在磁盘I/0缓慢,或者是log buffer太大引起的。
很多人不理解为什么log buffer过大会造成log file sync等待事件,这是由于log buffer过大,会使lgwr懒惰,因为日志写的触发条件有一个是1/3的log buffer满。当设置过大的log buffer,也会让一次性写入过大的redo record到log file中,写得过多导致log file sync等待。有一个隐含参数可以控制redo 写的阀值:_log_io_size。
所以没有必要将log buffer设置过大,只要没有出现log buffer space等待事件,log buffer大小就足够,而且通常默认情况下log buffer是足够的。
注意log file sync是用户commit/rollback触发的。
当一个session等待lgwr将log buffer的redo record 写入到log file 就会产生log file parallel write等待事件
log file parallel write 是由lgwr进程引起的,不是user commit/rollback引起的,这点从oracle的分类我们就可以看出。
通常出现该等待事件是由于重做日志所在磁盘I/O缓慢,或者存在争用。
一般情况下log file parallel write和log file sync都是同时出现的。

log file sync(日志文件同步) 与 Log file parallel write 等待事件

http://www.cnblogs.com/sopost/archive/2011/02/20/2190048.html

log file sync(日志文件同步)等待事件具有一个参数:buffer#。在Oracle Database 10g中,这种等待事件位于Commit等待下面。当处理log file sync等待事件时,注意下面的思想:
◎ log file sync 等待时间和事务中指(提交或回滚)相关
◎ 当进程在log file sync事件上花费大量时间时,这通常表明过多的提交或短事务。

常见的原因、诊断和动作
Oracle 在SGA中的日志缓冲区中记录事务和块的改变,这是成为生理日志(physiological logging)的方法。通过以各种时间进度将内容写入到日志文件,LGWR进程负责在日志缓冲区中留出空间。

触发LGWR进程的条件有:
1. 用户提交
2. 有1/3重做日志缓冲区未被写入磁盘
3. 有大于1M的重做日志缓冲区未被写入磁盘
4. 3秒超时
5. DBWR 需要写入的数据的SCN大于LGWR记录的SCN,DBWR 触发LGWR写入。

触发DBWR进程的条件有:
1. DBWR超时,大约3秒
2. 系统中没有多余的空缓冲区来存放数据
3. CKPT 进程触发DBWR

LGWR是负责把Redo Log buffer写入Redo file的进程,当这个进程启动的时候,会把redo buffer里已经有的redo record写入redo file,而当用户commit或者rollback的时候,会触发这个进程,从而保证用户的提交的数据安全,只有写入到redo file,才能保证这个操作是可以恢复的。

只有当某个事务所产生的重做记录全部被写入重做日志文件之后,oracle才认为这个事务已经成功提交.重做记录也可能会在事务提交之前就写入重做日志文件.

LGWR进程在开始写入下一个重做日志文件之前,必须确认这个即将被覆盖的重做日志文件已经完成如下工作:

  • 如果数据库处于非归档模式,已写满的重做日志文件在被覆盖之前,其中所有重做记录所对应的事务的修改

操作结果必须已经全部被写入到数据文件中

  • 如果数据库处于归档模式,已写满的重做日志文件在被覆盖之前,不仅要对应所有事务的修改操作结果全部被 写入到数据文件中,还需要等待归档进程完成对它的归档操作

由用户提交和回滚初始化的写入称为同步写入;其余的写入成为后台写入。log file sync
等待只和同步写入有关。换句话说,用户进程可能正在处理一个大型的事务并生成许多触发LGWR以执行后台写入的大量重做条目,但用户会话从来不需要等待后台写入的完成。然而,一旦用户会话提交或回滚它的事务且_WAIT_FOR_SYNC参数是TRUE时,进程提交LGWR并在log file sync事件上等待LGWR将当前重做条目(包括提交标记)刷新到日志文件。在这种日志同步期间,LGWR进程在log file parallel write事件上等待同步写入的完成,同时用户会话在log file sync事件上等待同步进程的完成。

一旦进程进入log file sync等待,就有两种可能性。

一种可能性是LGWR在日志同步完成时提交前台进程时。

另一种情况是在等待已超时的时候(一般在1秒内),在这个时刻,前台进程检查当前日志SCN(System Change Number,系统改变号),确定它的提交是否已经传递到磁盘。如果是的话,进程继续处理,否则进程就重新进入等待。

高log file sync等待事件的3个主要原因。
①.高提交频率

解决方法是简单的消除不必要的提交,事务是工作单元。工作单元应该是全部成功或全部失败。
②.缓慢的I/O子系统
较高的IO吞吐良可以改善log file sync和log file parallel write事件的平均等待时间。频繁的提交会弄乱数据库布局和IO子系统。解决办法是将日志文件放裸设备上或绑定在RAID 0或RAID 0+1中,而不是绑定在RAID 5中。
③.过大的日志缓冲区
过大的日志缓冲区也可能延长log file sync等待。大型的日志缓冲区减少后台写入的数量,允许LGWR变得懒惰,并导致更多的重做条目堆积在日志缓冲区中。同时可以调整参数_LOG_IO_SIZE参数,其默认值是LOG_BUFFER的1/3或1MB,取两者之中较小的值。换句话说,你可以具有较大的日志缓冲区,但较小的_LOG_IO_SIZE将增加后台写入,从而减少log file sync的等待时间。

注意:
你必须绝对不将参数_WAIT_FOR_SYNC设置为FALSE,即使是在一个开发数据库或测试数据库中,因为不能保证提交的事务在实例失败时可以恢复。人们使用这种特性来避开基准测试。
一般情况下,log file sync等待是非常频繁的时间。它非常简短,终端用户一般不会注意
到它。然而,许多这样的事件可能产生较长的响应时间并在v$system_event和v$session_wait
视图中获得显著的等待统计。使用下面的查询来找到当前的会话,这些会话从登陆开始就花费大量的处理时间在log file sync事件上等待。

Log file parallel write

log file parallel write 事件是LGWR进程专属的等待事件,发生在LGWR将log_buffer中的重做日志信息写入联机重做日志文件组的成员文件,LGWR在该事件上等待该写入过程的完成。

该事件等待时间过长,说明日志文件所在磁盘缓慢或存在争用。

从两个方面入手解决:

(1)将日志文件组放置到高速I/O磁盘上。

(2)尽可能的降低重做数量:
—尽可能使用Nologging选项,包括create table…as select…操作
—热备份可能创建大量的重做信息,所以热备份应该在非高峰时间运行,并且尽可能将表空间排除在热备份模式外

log file sync等待事件 2011-11-19 23:34:33

http://space.itpub.net/25105315/viewspace-711630

分类: Oracle
当一个用户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到底在等待什么。

"log file sync" 等待事件

http://www.eygle.com/archives/2004/10/statspack14-logfilesync.html

作者:eygle |English 【转载时请标明出处和作者信息】
链接:http://www.eygle.com/archives/2004/10/statspack14-logfilesync.html

当一个用户提交(commits)或者回滚(rollback),session的redo信息需要写出到redo logfile中.
用户进程将通知LGWR执行写出操作,LGWR完成任务以后会通知用户进程.
这个等待事件就是指用户进程等待LGWR的写完成通知.

对于回滚操作,该事件记录从用户发出rollback命令到回滚完成的时间.

如果该等待过多,可能说明LGWR的写出效率低下,或者系统提交过于频繁.
针对该问题,可以关注:
log file parallel write等待事件
user commits,user rollback等统计信息可以用于观察提交或回滚次数

解决方案:
1.提高LGWR性能
尽量使用快速磁盘,不要把redo log file存放在raid 5的磁盘上
2.使用批量提交
3.适当使用NOLOGGING/UNRECOVERABLE等选项

可以通过如下公式计算平均redo写大小:

avg.redo write size = (Redo block written/redo writes)*512 bytes

如果系统产生redo很多,而每次写的较少,一般说明LGWR被过于频繁的激活了.
可能导致过多的redo相关latch的竞争,而且Oracle可能无法有效的使用piggyback的功能.

我们从一个statspack中提取一些数据来研究一下这个问题.

1.主要信息

DB Name DB Id Instance Inst Num Release OPS Host
----- ---- --- - --
DB 1222010599 oracle 1 8.1.7.4.5 NO sun
Snap Id Snap Time Sessions
-
— ---- -—-
Begin Snap: 3473 13-Oct-04 13:43:00 540
End Snap: 3475 13-Oct-04 14:07:28 540
Elapsed: 24.47 (mins)

Cache Sizes

db_block_buffers: 102400 log_buffer: 20971520
db_block_size: 8192 shared_pool_size: 600M

Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--- ---
Redo size: 28,458.11 2,852.03
……

2.等待事件

Event Waits Timeouts Time (cs) (ms) /txn
------ --— ----- -- --
log file sync 14,466 2 4,150 3 1.0
db file sequential read 17,202 0 2,869 2 1.2
latch free 24,841 13,489 2,072 1 1.7
direct path write 121 0 1,455 120 0.0
db file parallel write 1,314 0 1,383 11 0.1
log file sequential read 1,540 0 63 0 0.1
….
log file switch completion 1 0 3 30 0.0
refresh controlfile command 23 0 1 0 0.0
LGWR wait for redo copy 46 0 0 0 0.0
….
log file single write 4 0 0 0 0.0

我们看到,这里log file sync和db file parallel write等写操作相关事件同时出现在TOP 5 Event之中,这可能说明系统在执行IO写操作时存在竞争。

这里磁盘IO肯定存在了瓶颈,实际用户的redo和数据文件同时存放在Raid的磁盘上,存在性能问题,需要调整.

3.统计信息


Statistic Total per Second per Trans
------- ---- --— --
….
redo blocks written 93,853 63.9 6.4
redo buffer allocation retries 1 0.0 0.0
redo entries 135,837 92.5 9.3
redo log space requests 1 0.0 0.0
redo log space wait time 3 0.0 0.0
redo ordering marks 0 0.0 0.0
redo size 41,776,508 28,458.1 2,852.0
redo synch time 4,174 2.8 0.3
redo synch writes 14,198 9.7 1.0
redo wastage 4,769,200 3,248.8 325.6
redo write time 3,698 2.5 0.3
redo writer latching time 0 0.0 0.0
redo writes 14,572 9.9 1.0
….
sorts (disk) 4 0.0 0.0
sorts (memory) 179,856 122.5 12.3
sorts (rows) 2,750,980 1,874.0 187.8
….
transaction rollbacks 36 0.0 0.0
transaction tables consistent rea 0 0.0 0.0
transaction tables consistent rea 0 0.0 0.0
user calls 1,390,718 947.4 94.9
user commits 14,136 9.6 1.0
user rollbacks 512 0.4 0.0
write clones created in backgroun 0 0.0 0.0
write clones created in foregroun 11 0.0 0.0
-
-----------—-

avg.redo write size = (Redo block written/redo writes)*512 bytes
= ( 93,853 / 14,572 )*512
= 3K

这个平均过小了,说明系统的提交过于频繁.


Latch Sleep breakdown for DB: DPSHDB Instance: dpshdb Snaps: 3473 -3475
-> ordered by misses desc

Get Spin &
Latch Name Requests Misses Sleeps Sleeps 1->4
------ --— --- --- --
row cache objects 12,257,850 113,299 64 113235/64/0/0/0
shared pool 3,690,715 60,279 15,857 52484/588/6546/661/0
library cache 4,912,465 29,454 8,876 23823/2682/2733/216/0
cache buffers chains 10,314,526 2,856 33 2823/33/0/0/0
redo writing 76,550 937 1 936/1/0/0/0
session idle bit 2,871,949 225 1 224/1/0/0/0
messages 107,950 159 2 157/2/0/0/0
session allocation 184,386 44 6 38/6/0/0/0
checkpoint queue latch 96,583 1 1 0/1/0/0/0
-
-----------—-

由于过渡频繁的提交,LGWR过度频繁的激活,我们看到这里出现了redo writing的latch竞争.

关于redo writing竞争你可以在steve的站点找到详细的介绍:
http://www.ixora.com.au/notes/lgwr_latching.htm

转引如下:

When LGWR wakes up, it first takes the redo writing latch to update the SGA variable that shows whether it is active. This prevents other Oracle processes from posting LGWR needlessly. LGWR then takes the redo allocation latch to determine how much redo might be available to write (subject to the release of the redo copy latches). If none, it takes the redo writing latch again to record that it is no longer active, before starting another rdbms ipc message wait.
If there is redo to write, LGWR then inspects the latch recovery areas for the redo copy latches (without taking the latches) to determine whether there are any incomplete copies into the log buffer. For incomplete copies above the sync RBA, LGWR just defers the writing of that block and subsequent log buffer blocks. For incomplete copies below the sync RBA, LGWR sleeps on a LGWR wait for redo copy wait event, and is posted when the required copy latches have been released. The time taken by LGWR to take the redo writing and redo allocation latches and to wait for the redo copy latches is accumulated in the redo writer latching time statistic.

(Prior to release 8i, foreground processes held the redo copy latches more briefly because they did not retain them for the application of the change vectors. Therefore, LGWR would instead attempt to assure itself that there were no ongoing copies into the log buffer by taking all the redo copy latches.)

After each redo write has completed, LGWR takes the redo allocation latch again in order to update the SGA variable containing the base disk block for the log buffer. This effectively frees the log buffer blocks that have just been written, so that they may be reused.

关于log file sync事件 (2012-03-05 10:44:46)转载▼

http://blog.sina.com.cn/s/blog_48e13c9e010123hr.html

标签: 杂谈 分类: 性能调优

How can I minimize waits for 'log file sync' ?

Solution

For more information on troubleshooting 'log file sync' waits see:
Troubleshooting: "Log File Sync" Waits

Information to help diagnose log file sync can be obtained using the script found in related Document.

A: Log file sync waits occur when sessions wait for redo data to be written to disk. Typically this is caused by slow writes or committing too frequently in the application. Checking the "user commits" section in the AWR report can reveal if the issue is related to frequent committing.

The tips below will help you to reduce log file sync when writes are slow:
Tune LGWR to get good throughput to disk . eg: Do not put redo logs on RAID 5.

If there are lots of short duration transactions, see if it is possible to BATCH transactions together so there are fewer distinct COMMIT operations. Each commit must confirmed that the relevant REDO is on disk before it can complete. Although commits can be "piggybacked" by Oracle, reducing the overall number of commits by batching transactions can have a very beneficial effect.

On 10g , See if any of the processing can use the COMMIT NOWAIT option .

Note: From 11g The COMMIT_WRITE parameter is deprecated. It is retained for backward compatibility only. It is replaced by the COMMIT_LOGGING and COMMIT_WAIT parameters.

See:
Oracle ® Database Reference
11g Release 2 (11.2)
Part Number E17110-08

for more details

In Oracle 10g Release 2 the COMMIT command has been enhanced with the WRITE clause to give a degree of control over the way redo information is written to the redo logs during the commit operation. This can improve performance, but it should only be used for processes that meet the following criteria:
They result in large numbers of transactions that require redo log writes.
Data loss can be tolerated in the event of an instance crash during the process.
Waiting for redo log writes is a significant part of the waits associated with the process.The available options for the COMMIT command and the WRITE clause are displayed below.

COMMIT;

COMMIT WRITE WAIT; —> The commit command is synchronous. It doesn't return until the relevant redo information is written to the online redo log.

COMMIT WRITE NOWAIT; —> The commit command is asynchronous. It can return before the relevant redo information is written to the online redo log.

COMMIT WRITE BATCH; —> The commit command is synchronous. It doesn't return until the relevant redo information is written to the online redo log.

COMMIT WRITE IMMEDIATE; —> The commit "prods" the LGWR process by sending a message, so that the redo is written immediately to the redo logs.

To avoid make modifications to your code, you can you can use the COMMIT_WRITE parameter. You can set it on session level or on system level.

SQL> ALTER [SYSTEM | SESSION] SET COMMIT_WRITE='IMMEDIATE,NOWAIT';

You can use trigger to set the parameter for the user that run the application:

SQL> CREATE OR REPLACE TRIGGER sys.global_commit_session_settings AFTER LOGON ON <your application_username>.SCHEMA
BEGIN
execute immediate 'alter session set COMMIT_WRITE =''IMMEDIATE,NOWAIT''';
END;
/

Please keep in mind that using this option, and in case of database crash, the data that is not written to the redolog file will be lost even though they are committed. This is part of the requirements for commit nowait is that "Data loss can be tolerated in the event of an instance crash during the process"

See if any activity can safely be done with NOLOGGING / UNRECOVERABLE options

案例:log file sync致数据库性能摇摆

http://mikixiyou.iteye.com/blog/1570147

博客分类: Oracle
oracleperformance tuninglog file syncstandby
数据库在某些时间点突然出现性能峰值,使得前端应用程序有停滞感。分析出为log file sync 事件突然发生导致了该问题。
该事件是表示用户在LWGR 进程将redo 日志信息写入的redo logfile 。在普通的数据库配置中,能优化这个问题的方法只能减低日志写入量,提升日志写入速度,就是将redo logfile 放到更快的磁盘组上。
我们这里的数据库环境是LGWR 既要将REDO 日志信息写入到REDO 日志文件中,也要通过网络写入到远程的STANDBY 数据库中。
我们的问题出现在写入到standby 时发生了堵塞,导致了log file sync 等待事件的大量发生,从而使得数据库性能峰值频繁出现,有时候都影响到应用。
因此我们将LGWR 写入到standby 的操作方式从lgwr sync affirm 修改为lgwr async 方式,就是从实时同步修改为非实时同步。
这样就解决了这个性能问题。

(miki西游 @mikixiyou 原文链接: http://mikixiyou.iteye.com/blog/1570147 )

1. 问题

环境交代一下,数据库版本10.2.0.4 ,ASM 存储,单实例,归档模式,多路径用于异地的data guard 逻辑备库和物理备库,最大可用模式。
在Oracle EM GRID CONTROL 管理平台中,看到数据库性能页面上平均活动会话瞬间提升到数倍,如正常时一直是2-3 个,到某个时间点到达18-19 个之多。
log file sync 02
突然增加的等待事件归类为configuration 和concurrency 。在configuration 类中,等待事件为log file sync 。
这个等待事件的发生导致很多会话出现堵塞,反映到应用端就是应用停滞。
我们再到awrrpt 报告中,也能看到top 5 等待事件以log file sync 居首。
Top 5 Timed Events
Event
Waits
Time(s)
Avg Wait(ms)
% Total Call Time
Wait Class
log file sync
256,569
66,039
257
86.4
Commit
CPU time

4,308

5.6

enq: TX - row lock contention
4,894
4,140
846
5.4
Application
log file switch completion
1,817
1,485
817
1.9
Configuration
LNS wait on SENDREQ
350,286
464
1
.6
Network
这个更具体,以数字形式直接展现出来,等待事件log file sync 的问题何其严重。
统计时间30 分钟,等待事件log file sync 使用66039 秒,整个86.4% 的时间都是log file sync 消耗的。
性能问题很明显,在log file sync 等待事件上。解决掉它,就能解决这个应用摇摆问题。
2. 分析

等待事件log file sync 是这样产生的。
当一个用户提交(commits) 或者回滚(rollback), 会话的redo 信息需要写出到redo logfile 中。用户进程将通知LGWR 执行写出操作,LGWR 完成任务以后会通知用户进程。等待事件log file sync 就是指用户进程等待LGWR 的写完成通知。
但是,这只是正常的配置下的生成过程。在我们的环境中,LGWR 还需要将redo 信息写入到网络上其他的数据库服务器中。
这是因为这台服务器配置了两台standby database 服务器:一台用于查询库实时同步数据;一台用于数据灾备镜像库,也是要实时同步。
因为实时同步需要,所以写redo 信息的参数项是lgwr sync 。具体参数配置如下所示:
*.log_archive_dest_2='service=mikidb_reader lgwr sync affirm valid_for=(online_logfiles,primary_role) db_unique_name=mikidg'
*.log_archive_dest_3='service=mikidb_standby2 lgwr sync affirm valid_for=(online_logfiles,primary_role) db_unique_name=mikidg2'


所以,问题在LGWR 写redo 信息到磁盘上还是网络上发生了堵塞导致了性能峰值,需要我们去判断一下。
如果是发生在写入磁盘上导致了性能峰值问题,那我们也没办法了。更快的磁盘真的没有了。
如果是发生在网络上,我们需要检查网络状况。
但这里还有一种可能,就是redo 信息的量在那个时间点真的突然增大了。这种情况也是有可能导致这种性能峰值问题。
但这个可能很快被否决掉,在awrrpt 中load profile 项看到, 每秒生成的redo 日志并没有多大变化,一直维持在200KB 略多点。


3. 解决

问题分析到这里,解决方法其实很简单了。
检查网络情况,在网络情况不确定之前,我们可以先将这两个写入standby 的操作关闭掉。
这个有点武断,哈哈。
在10.2 中,LGWR 写入redo 信息到standby 数据库中有两个方式:一种是lgwr sync ,另一种lgwr async 。
前者是保证数据必须同步过去,LNS 进程传redo 信息到standby 数据库时必须给回复,不给则不显示提交成功。
这点可以参考一下eygle 的文档中描述, http://www.eygle.com/archives/2004/10/statspack14-logfilesync.html
后者是先保证写入到本地redo logfile 中,剩下的交给LNS 进程,它接着做下面的事情。这样LNS 能否能redo 信息及时写入到standby 数据库就只有看天意了。
第二种方法虽然不好,但还是比没有强。因此,我们选择它先来解决这个问题。
数据库初始化参数设置如下所示:
*.log_archive_dest_2='service=mikidb_reader lgwr async valid_for=(online_logfiles,primary_role) db_unique_name=mikidg'
*.log_archive_dest_3='service=mikidb_standby2 lgwr async valid_for=(online_logfiles,primary_role) db_unique_name=mikidg2'
如果网络检查有问题,那么修复后我们可以再改回为lgwr sync ,不行再改回lgwr async 。

4. 总结

我们将参数修改后观察了一下,发现活动会话很稳定,等待事件也都是CPU 处理事件。
log file sync 02

在awrrpt 中,可以看到具体的数字。
Top 5 Timed Events
Event
Waits
Time(s)
Avg Wait(ms)
% Total Call Time
Wait Class
CPU time

4,192

98.0

log file sync
153,941
23
0
.5
Commit
LNS wait on SENDREQ
289
14
48
.3
Network
enq: TX - row lock contention
1,031
11
11
.3
Application
log file parallel write
157,352
9
0
.2
System I/O

我们对比一下。
这是修改之前的等待事件log file sync 统计信息:
Event
Waits
Time(s)
Avg Wait(ms)
% Total Call Time
Wait Class
log file sync
256,569
66,039
257
86.4
Commit

这是修改之后的等待事件log file sync 统计信息:
Event
Waits
Time(s)
Avg Wait(ms)
% Total Call Time
Wait Class
log file sync
153,941
23
0
.5
Commit

等待次数下降的不大,等待时间下降了3000 倍啊。
因此,在碰到这台硬的等待事件时,不能光看一些官文中描述,还要结合环境具体看待。
但它也有局限,主数据库的数据不会真的实时同步到standby 数据库里了。数据的安全有一些损失,但在性能、可用性、数据安全方面,是必须有取舍的。


本页面的文字允许在知识共享 署名-相同方式共享 3.0协议和GNU自由文档许可证下修改和再使用,仅有一个特殊要求,请用链接方式注明文章引用出处及作者。请协助维护作者合法权益。


系列文章

文章列表

  • Oracle Wait Event: log file sync

这篇文章对你有帮助吗,投个票吧?

rating: 0+x

留下你的评论

Add a New Comment