statspack系列6
原文:http://jonathanlewis.wordpress.com/2006/12/27/analysing-statspack-6/
作者:Jonathan Lewis
下面是一段时间以前网络上贴出来的一个AWR快照的片段,并有一段文字描述为何值得看一下,摘抄主要来自Don Burleson的文章:
这里是一个10g的oracle的例子,log buffer设置的过小,只有512k:
对于这个数据集,我是有一个问题,这里没有任何的数据来解释这个现象,是否打算要给我们一些线索来发现log buffer设置的过小,或者说没有这个意图,为何还要把它粘贴出来。(还有一点就是文章也没有任何一点来解释是如何发现log buffer的问题的)
这份数据集得另一个问题是没有任何的其它信息,比如有多少颗cpu,快照是多久一次的。
当然,事实是’log buffer space’的等待事件并没有出现在top 5的等待事件中,这会让你怀疑log buffer并不是最重要的问题,并且作者在下一段的awr报告中没有贴出来’log Buffer space’等待基线更令人发怒。
那么,从这个片段中我们到底能得到什么?我们能否发现一些线索来解释log buffer设置太小?
我们被告知buffer的大小是512k,假设DBA没有调整这个参数,而是使用的默认的log buffer大小,系统有1到4个cpu,再没有其它额外的信息了。
从数据上可以看出,报告中的除了cpu时间外的大部分时间都花费在后台进程处理上;仅仅log file sync的时间是应用的等待,这部分时间跟log file parallel write的时间有点相仿,而这趋向于说明这是一个低并发的系统(当有一个log file 写的时候,平均上,仅仅只有一个进程在等待写的完成,而且等待的总时间大致等于写所花费的时间)。但这并没有给出太多的信息。
写的平均时间大致是:
- log file parallel write – 30.1 m/s
- db file parallel write – 40.8 m/s
- control file parallel write – 50.7 m/s
这个结果并不怎么好,如果有抱怨性能问题,低速的磁盘设备可能是主要原因。
当然,log buffer space通常在系统有一定的并发活动的时候出现的,如果一个用户提交了commit,那么可能会处在log file sync等待上,而另外的一些用户则会等待log buffer space。
当然也有例外,如果系统在持续的产生大量的redo 日志,而日志写进程并非由commit事件引起的,比如log buffer超过了大小的1/3. 这种情况可以解释log file parallel write的等待为什么要比log file sync多,总的等待时间也比sync要多。
不管怎样,log buffer space等待时间可能有13s,这台服务器到底出现了什么问题,因为低速的log file parallel write而产生了长达278s的log file sync等待事件。如果提高log buffer的大小,可能系统会花费额外的13s时间在log file sync等待上,所以这个系统的问题可能是低速的磁盘。
当然,我不能仅仅根据‘top 5’等待事件就诊断性能问题,但是,如果你仅仅只有这些信息,而又不能证明提供的诊断,那么就需要更多的信息。这里我需要检查下load profile(系统的负载情况,比如用户请求,执行次数,事务数),再看下除了top 5以外的时间花费在什么地方。
推断:这个系统看起来像是单cpu,低速磁盘驱动器的单用户系统,可能就是一个测试的windows台式机。
实际上:如果你认为这些统一信息就可以帮你定位到过小的log buffer设置,恐怕不太可能。
例子2:
这个是从同一个作者那得到的另一个样本,展示了一个过小的log buffer的awr 报告的片段。下面就是awr的报告,DBA没有在init.ora文件中设置log buffer 参数。
更新 1st seqt 2010:最近我又重新读了这篇文章,发现我没有阐述为什么我不同意Mr. Burleson关于第二段统计信息的解释,这里做一个补充。
首先要说的是:确实有log buffer space的等待,12次,总共3s等待时间,所以认为增加log buffer大小能够缓解这种情况,但如果要真正的调整log buffer,还需要再慎重一些。
- 首先:无论你设置log buffer为多大,当发生log file 切换的时候,会产生一些log buffer space等待,尤其是在相对比较繁忙的系统上。所以当log buffer space与log file sync等待相比非常少时,可以忽略log buffer space等待。
- 其次:当提高了log buffer的大小,那么在日志写进程触发时,服务器进程可以写更多的日志到log buffer当中去,这就是增加log file sync的等待时间。(在早期的oracle版本中,log buffer space和log file sync等待是一个经典的权衡问题)。
- 最后,花费在cpu上的时间超过了163,000秒,而只有大约3S的log buffer space等待,而过高的cpu负载会对log buffer的清理有边际效应,会降低其速率,而引起log buffer space等待。
所以,暂时忽略log buffer空间的问题,极可能是另外一个问题引起的结果,把精力花在真正的问题上面。
在top 5中,最重要的指标是cpu,很明显,找到花费cpu时间最多的sql 语句,可以通过检查awr报告中的SQL ordered by CPU”, “SQL ordered by Executions” , Segments by Logical Reads”.
快速的看下top 5中的其它等待事件,也会有一些指导作用。
Log file sync的数量非常大,而且大致与log file write相当,这就暗示着系统有大量的小事务在进行(如果系统仅仅有少量的大事务,那么log file write的数量肯定比log file syncs多了)。
观察一下时间,你会发现log file writes的速度(1.3s)要比log file syncs(4.6s)快。差异的时间主要花费在日志写进程需要“redo synch message”的消息来确认写完成。这是一个经典的暗示,cpu饥饿。如果cpu饥饿造成log write进程很难得到日志刷新到磁盘的消息,这会造成buffer会填满,而产生log buffer space 等待。
另外, “SQL*Net more data to client” 的等待次数也比较高,可能是一些查询返回了大量的数据,可以通过查看SQL*Net roundtrips to/from client的次数和传输的数据量,来确定系统当前是有许多小的查询,还是大数据集的查询。Round-trip 活动能够加重数据库的负载,需要小心,sql语句可以在报告的部分展示。
Top 5中另外的一个指标 “db file sequential read” ,平均时间是5.5m/s。如果这里有statsapack报告,我希望看下event histogram报告,来判断这不会是大量的快速读(本地缓存的数据,读是cpu密集型的)。我们需要定位到cpu的利用率在何处。
最后一个指标,是“log file sequential read” ,这是一个和自身关系不大的等待事件,接下来的几个星期我会单独阐述它,这里可以简单的认为是归档进程读online redo log的活动。