对 IO 和 CPU 使用率 的一次小优化

端午放假之后，从6月7日开始，DB 就不太稳定，alert log 出现了：checkpoint not complete, cannot allocate new log 的警告。 所以加了一个online redo log group。 不过警告并没有因此消失，第二天又加了一组。 原来是4组，加了2组之后就有6组。 而且每天的归档也比以前增加了1G多。 CPU 也上升到了50%，高的时候，能波动到80%。

通过AWR 报告查看，等待事件排名前2的是：log file sync和 log file parallel write。 这2个等待事件更写log的速度和用户commit的频率有关。

查看Trace 文件，有一些警告信息：

WARNING:Could not increase the asynch I/O limit to 160 for SQL direct I/O. It is set to 128

WARNING:Could not increase the asynch I/O limit to 160 for SQL direct I/O. It is set to 128

WARNING:Could not increase the asynch I/O limit to 160 for SQL direct I/O. It is set to 128

WARNING:Could not increase the asynch I/O limit to 160 for SQL direct I/O. It is set to 128

WARNING:Could not increase the asynch I/O limit to 192 for SQL direct I/O. It is set to 128

看到WARNING:Could not increase the asynch I/O limit to 160 for SQL direct I/O. It is set to 128 的警告，怀疑是Oracle的bug。 在MOS上搜了半天，只找到一个类似的信息。 不过这个bug 的版本只争对 oracle 10.2.0.4 的版本，在10.2.0.5 的版本已经修复过了。 我的DB 去年做过升级。 现在的版本是10.2.0.5，所以不太可能是这个bug。

lgwr的trace 也有警告：

[oracle@qs-xezf-db1 bdump]$ tail -50 xezf_lgwr_11189.trc.bak

*** 2011-06-09 06:02:48.846

Warning: log write time 610ms, size 6KB

*** 2011-06-09 06:02:54.119

Warning: log write time 800ms, size 18KB

*** 2011-06-09 06:02:54.821

Warning: log write time 700ms, size 25KB

......

*** 2011-06-09 22:43:21.961

Warning: log write time 670ms, size 1KB

*** 2011-06-09 23:20:03.613

Warning: log write time 670ms, size 5KB

*** 2011-06-10 00:16:34.240

Warning: log write time 730ms, size 13KB

根据Oracle 的说法：

Warning: log write time 730ms, size 13KB 这个警告是在10.2.0.4 之后才有的，当log write 超过500ms，就会出现这个警告。

LGWR Is Generating Trace file with 'Warning Log Write Time 540ms, Size 5444kb' In 10.2.0.4 Database

http://blog.csdn.net/tianlesoftware/archive/2011/06/10/6537196.aspx

昨天晚上收到的报警短信CPU 更是超过了90%，有时还是100%。 今天早上到公司收了下监控邮件。 发现归档比昨天又增加了2G。 这个明显不太正常。就是业务增长，也不应该是这个长法。 在CPU 超过90%的时候，根据Linux pid 抓到了SQL 语句。 然后查看了对应的表。 有400多万的记录。

然后从6月1号到6月10号的记录就有370w。 数据很不正常，问同事这几天可有做什么修改，有做大事务的操作没。同事说没有，查看了中间件的log，发现了问题，从昨天晚上0点到今天早上8 点，同一个IP 地址刷了12w的记录到这张表。前面几天的log 没有查看，肯定和这个IP 也有关系。很明显是用程序在刷，人工刷不了这么多的记录， 和同事商量了下业务流程，想在流程上杜绝这种狂刷的做法。 这个需要点时间。

先从这几张表入手， 将这张400w的表进行了手工转历史。 转移了300w的数据，然后就log表。 这个也是重灾区。 一共1700w的记录，其中有900万的记录是6月份以后的。 转历史之后log表还有900w的记录。

从AWR 报告上看到这个log表上的索引有较严重的等待。因为这个表是更新多，查询很少，所有的交易都会写这个log表，更新相当频繁，维护索引的成本明显要大于查询的成本,所以drop 掉了这个索引。

数据转历史之后，收集了一下表的统计信息，因为删除了大量的数据，此时的统计信息很明显有变化，不手动更新，CBO 还是会使用以前的统计信息。那样执行计划就会有偏差。

在查看了一下CPU，已经降到了20%左右。恢复正常。根据AWR ，对占用资源较多的几个SQL语句，做了小修改，建了联合索引。 在看CPU 已经降到15%左右。CPU 这块已经差不多了。

IO 这块还是瓶颈。 不过lgwr trace出现Warning: log write time 660ms, size 1KB 这种警告的周期变长。 如果业务流程不改，还是有大量的业务数据刷进来的话， 写log 还是个大问题。

-------------------------------------------------------------------------------------------------------

Blog： http://blog.csdn.net/tianlesoftware

Email: [e-mail]

DBA1 群：62697716(满); DBA2 群：62697977(满) DBA3 群：62697850(满)

DBA 超级群：63306533(满); DBA4 群： 83829929 DBA5群： 142216823

DBA6 群：158654907 聊天 群：40132017 聊天2群：69087192

--加群需要在备注说明Oracle表空间和数据文件的关系，否则拒绝申请