监控工具dpa发现海外一台oracle数据库服务器db commit time指标告警,超过红色告警线,如下截图所示,生成了对应的时段的awr报告,发现top 5 timed events里面,log file sync等待事件的平均等待时间为37毫秒,log file parallel write等待事件的平均等待时间为40毫秒
11.1: "redo write broadcast ack time" in centiseconds 11.2: "redo write broadcast ack time" in microseconds version inst_id name value milliseconds ----------------- ---------- ---------------------------------------- --------------------- ------------------- 10.2.0.5.0 1 redo write time 9551524 95515240.000 10.2.0.5.0 1 redo writer latching time 51 10.2.0.5.0 1 redo writes 1434931 awr worst avg log file sync snaps:
上面数据可以看到,log file sync等待事件数量最多的是32ms这个区间的,log file parallel write等待事件发生最多的也是32ms这个区间的,其实这个值已经远远超过7ms,极其不正常。log file parallel write 事件是lgwr进程专属的等待事件,发生在lgwr将log_buffer中的重做日志信息写入联机重做日志文件组的成员文件,lgwr在该事件上等待该写入过程的完成。该事件等待时间过长,说明日志文件所在磁盘缓慢或存在争用。log file sync和log file parallel write是相互关联的。换句话讲,假设log file parallel write的时间非常长,那么必定导致log file sync等待时间拉长。如果log file parallel write 等待非常高,那么可能一般是物理磁盘i/o的问题
另外,我们也检查了一下redo log的切换频率,如下所示,redo log切换的次数并不频繁,生成的归档日志的量也并不大。大部分时候一小时切换零次或一次。
然后我们找了一台机器简单对测试了一下io的速度,这个方法极其简单,就是看看生成一个大文件需要多长时间,简单测试一下i/o性能,但是对比数据也基本能验证、反馈磁盘io存在问题)。
问题服务器:
# time dd if=/dev/zero of=./test bs=512k count=2048 oflag=direct 2048+0 records in 2048+0 records out 1073741824 bytes copied, 88.271 seconds, 12.2 mb/s
real 1m28.273s user 0m0.010s sys 0m0.655s
对比服务器:
# time dd if=/dev/zero of=./test bs=512k count=2048 oflag=direct 2048+0 records in 2048+0 records out 1073741824 bytes copied, 2.48344 seconds, 432 mb/s
real 0m2.485s user 0m0.004s sys 0m0.386s
如上对比所示,两台服务器生成同样一个大小文件,耗费的时间,i/o性能差别非常大,完全验证了告警的服务器所在的存储i/o存在性能问题,但是公司分工非常明确,dba也不清楚底层存储出了什么问题,只能将这个问题反馈出来,等待海外负责维护系统和存储的同事的回复。
|