log buffer space 等待事件

xifenfei

难得的一个机会，看到一份awr报告中log buffer space非常大，对其分析结论和大家分享

AWR分析

DB Name	DB Id	Instance	Inst num	Release	RAC	Host
XIFENFEI	1794962186	xifenfei	1	10.2.0.4.0	NO	xff

	Snap Id	Snap Time	Sessions	Cursors/Session
Begin Snap:	15076	06-Aug-13  08:00:46	102	.5
End Snap:	15077	06-Aug-13  09:00:30	165	1.1
Elapsed:		59.73  (mins)
DB Time:		1,667.67 (mins)

这里可以看出来，对于一个只有8C，的服务器来说相对是比较繁忙的系统Cache Sizes

	Begin	End
Buffer Cache:	8,192M	8,192M	Std Block Size:	8K
Shared Pool Size:	1,872M	1,872M	Log Buffer:	14,328K

这里显示log buffer只有14MLoad Profile

	Per  Second	Per  Transaction
Redo size:	5,550,364.90	5,541,052.96
Logical reads:	190,349.81	190,030.46
Block changes:	34,206.73	34,149.34
Physical reads:	1,142.05	1,140.14
Physical writes:	826.48	825.10
User calls:	409.66	408.97
Parses:	107.70	107.52
Hard parses:	11.85	11.83
Sorts:	24.81	24.77
Logons:	0.02	0.02
Executes:	103.00	102.83
Transactions:	1.00

Redo的量对于这样的系统来说，算是比较多，而且他的redo都是大事物(平均每秒一个事务，每个事务5M的redo)，和他这里操作的业务类型有关系，大量的insert into select操作Top 5 Timed Events

Event	Waits	Time(s)	Avg  Wait(ms)	% Total  Call Time	Wait  Class
log buffer  space	60,465	39,983	661	40.0	Configuration
db file sequential read	1,217,731	18,780	15	18.8	User I/O
buffer busy waits	25,413	11,355	447	11.3	Concurrency
db file parallel write	24,093	7,241	301	7.2	System I/O
CPU time		6,679		6.7

Top 5中log buffer space占据了40%，而且平均等待661ms，确实属于异常，在3600秒钟，他总的等待占39983，近11个逻辑cpu被它占据，实属不正常情况。

Background Wait Events

Event	Waits	%Time -outs	Total Wait Time  (s)	Avg wait (ms)	Waits /txn
db file parallel  write	24,110	0.00	7,249	301	6.72
log file parallel  write	5,833	0.00	2,880	494	1.62
control file  parallel write	2,424	0.00	163	67	0.68
log buffer space	271	32.10	149	551	0.08
control file  sequential read	7,996	0.00	94	12	2.23
db file  sequential read	2,318	0.00	64	27	0.65

这里看到后台进程的等待中，主要是write相关的等待，而且log file parallel write写的等待平均在494ms,绝对不属于正常情况，这样慢的redo buffer写到redo log中，而数据库产生的redo量也是比较大，从而出现了redo buffer写出的速度没有写入的速度快，从而出现大量log buffer space等待

Tablespace IO Stats

Tablespace	Reads	Av Rd(ms)	Av Blks/Rd	Writes	Buffer Waits	Av Buf Wt(ms)
UNDOTBS1	13,247	33.39	1.00	1,379,569	23,798	454.02
NNC_DATA03	907,137	12.96	3.40	69,733	19,796	70.59
NNC_INDEX03	408,934	15.46	1.00	49,899	28,126	18.34
NNC_DATA02	99,462	18.43	1.01	12,817	10,057	21.13
NNC_INDEX01	24,026	10.61	1.00	1,247	0	0.00
NNC_DATA01	10,406	23.49	18.02	993	9	627.78
NNC_INDEX02	6,689	25.34	1.01	53	0	0.00
TEMP	1,317	92.58	13.01	5,043	0	0.00
SYSTEM	5,246	17.09	1.61	329	3	3.33
SYSAUX	652	30.92	1.05	425	0	0.00
USERS	110	28.36	1.00	106	0	0.00

这里的平均读取block 时间很多都超过20ms，而写的平均时间有些在627ms，这个太离谱了，也证明了io的读写性能也不给力。

Instance Activity Stats - Thread Activity

Statistic	Total	per Hour
log switches  (derived)	56	56.25

Redo切换的也有点过于频繁，证明客户的redolog size设置不合理

分析结论

客户的erp系统因为中间表的insert into select操作产生大量redo，加上客户的datafile 和redo logfile都存放在同一个raid 5之上，导致redo产生的速度比redo 写入到logfile的速度快，从而出现大量log buffer space等待。针对该客户的问题，大概解决思路：

1.      增加redo buffer大小,例如64M(希望能够缓解部分log buffer space)

2.      增加redo size到合理值，最好能够保证redo几分钟到30分钟切换一次

3.      把redo log和datafile分离开，redo log不要存放在raid 5之上

4.      优化业务逻辑，减少erp系统中间表产生的redo 量

5.      使用性能更加高的存储设备

LogBuffer Space分析思路

ProblemConfirmation:

1.      The time spent actively in thelocal database is significant

2.      Only certain sessions, queriesor jobs are experiencing slowness (not throughout the database)

3.      Log_buffer Parameter  <redo size per sec * 600'

4.      'log buffer space' waits are asignificant component of the overall DB Time

"Log Buffer Space"

Wait for space in the log buffer because we are writing into the logbuffer faster than lgwr can write it out.

Reducing Waits

1.      Consider making the log bufferbigger if it is small

2.      Moving the log files to fasterdisks

3.      Increase size of redo logs

xifenfei

整理的pdf见附件：