某省主机wio过高的调优以及后续建议

一、背景：
2007年7月25日收到工单，某省core数据库在巡检时发现wio长时间高于40%，通过statspack的进一步检查发现以下第一个语句在statspack中buffer get的量非常高，且和第二位的差距比较大：

-> End Buffer Gets Threshold:     10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
   total % to exceed 100

                                                     CPU      Elapsd
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
     16,180,521          772       20,959.2   44.2    50.08     49.82 4290637155
Module: program_003@serv_machine02 (TNS V1-V3)
select content into :b0  from g where (servid=(select serv
id  from f where (icpcode=:b1 and ICPSERVID=:b2)) and
msg_type=:b3)

      8,109,784          387       20,955.5   22.2    26.10     26.02 3580556315
Module: program_004@serv_machine05 (TNS V1-V3)
select AccessModeId into :b0:b1  from f where (IcpCode
=:b2 and IcpServId=:b3)
……（其他略）

在40多分钟内，该sql执行了3841次，累计消耗buffer 80081866个block，即640M左右的buffer。初步怀疑该条sql占据了大量的buffer，导致其他的sql无法使用buffer，从而使用物理读较高，影响wio。

二、处理过程：
通过分析该sql的执行计划，发现该sql使用了很多视图的嵌套，执行计划非常复杂。

检查其中的相关对象的last analyzed时间，发现执行计划中涉及的表和索引的分析时间还是很早：
表的分析情况：

OBJECT_NAME                              OBJEC LAST_ANAL   NUM_ROWS
---------------------------------------- ----- --------- ----------
(表名略)                                 TABLE
(表名略)                                 TABLE 24-OCT-04      18881
(表名略)                                 TABLE 24-OCT-04        478
(表名略)                                 TABLE 24-OCT-04       3713
(表名略)                                 TABLE 24-OCT-04      14740
(表名略)                                 TABLE 24-OCT-04      18455

索引的分析情况：

OBJECT_NAME                              OBJEC LAST_ANAL LEAF_BLOCKS CLUSTERING_FACTOR   NUM_ROWS
---------------------------------------- ----- --------- ----------- ----------------- ----------
(索引名略)                               INDEX
(索引名略)                               INDEX
(索引名略)                               INDEX
(索引名略)                               INDEX
(索引名略)                               INDEX
(索引名略)                               INDEX 24-OCT-04           1                 8        273
(索引名略)                               INDEX 24-OCT-04          80              1532      14740
(索引名略)                               INDEX 24-OCT-04           1                 1          1
(索引名略)                               INDEX 24-OCT-04         118               574      18881
(索引名略)                               INDEX 24-OCT-04           0                 0          0
(索引名略)                               INDEX 24-OCT-04          17               139       3713
(索引名略)                               INDEX 24-OCT-04           2                11        355
(索引名略)                               INDEX 24-OCT-04          15                78       3359
(索引名略)                               INDEX 24-OCT-04          10               289       2063
(索引名略)                               INDEX 24-OCT-04           0                 0          0
(索引名略)                               INDEX 24-OCT-04          46               899      12404
(索引名略)                               INDEX 24-OCT-04         103               702      18455
(索引名略)                               INDEX 24-OCT-04          77              2388      15944
(索引名略)                               INDEX 21-OCT-04           0                 0          0
(索引名略)                               INDEX 24-OCT-04          85              6461      14740
(索引名略)                               INDEX 24-OCT-04           2               217        478
(索引名略)                               INDEX 24-OCT-04          23              1567       3713
(索引名略)                               INDEX 24-OCT-04           0                 0          0
(索引名略)                               INDEX 24-OCT-04           0                 0          0

很明显，以上对象长时间没有分析，从而影响了oracle数据库对最优执行计划的判断，对其涉及的对象进行分析：

分析过后，其执行计划已经发生改变，并且从其执行的统计信息看，其对于buffer的consistent gets已经变小了很多：

    
    分析前的consistent gets：
Statistics
----------------------------------------------------------
     21006  consistent gets

分析后的consistent gets：
Statistics
----------------------------------------------------------
        14  consistent gets

至此，改sql消耗buffer get较高的问题解决。
进一步观察分析后的数据库状况，wio的值还是比较高，在下午17：30之后，wio达到全天的峰值，17：30～18：00半小时内，wio基本都是在75%以上（可见附件sar_stat_070726.txt中这个时间段内的wio情况）。结合观察这段时间的statspack（附件sp_070726_1730_1800.txt），看到原来的buffer get非常高的sql已经消失了，转而出现的是：

begin pkg_boss_log_deal.nUserStatusChgProc ( :nBatchRow
s , :sTablePartName , :nRet ) ; end ;

上述的语句是在数据库中的一个package，这个package是用于处理boss的日志的。同时观察statspack中的top 5 timed events：

  
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
db file sequential read                         1,902,223      40,437    89.94
CPU time                                                        1,234     2.75
db file scattered read                            122,317       1,035     2.30
log file sync                                     222,865         828     1.84
log file parallel write                           271,818         673     1.50

最高的等待事件是db file sequential read（数据文件的顺序读，影响IO的主要等待事件）。尝试在17：30～18：00捕获等待事件为db file sequential read的sql和其所属的program：

  
PROGRAM
------------------------------------------------
       693
SELECT * FROM a WHERE CHARGEMID = :B2 AND MID <> CHARGEMID AND STATUS = :B1
program_002@serv_machine05 (TNS V1-V3)

       655
SELECT * FROM a WHERE CHARGEMID = :B2 AND MID <> CHARGEMID AND STATUS = :B1
program_002@serv_machine05 (TNS V1-V3)

       787
SELECT * FROM a WHERE CHARGEMID = :B2 AND MID <> CHARGEMID AND STATUS = :B1
program_002@serv_machine05 (TNS V1-V3)

       631
SELECT * FROM a WHERE CHARGEMID = :B2 AND MID <> CHARGEMID AND STATUS = :B1
program_002@serv_machine05 (TNS V1-V3)

       758
SELECT * FROM a WHERE MID = :B2 AND STATUS = :B1
program_002@serv_machine05 (TNS V1-V3)

        65
select STATUS ,to_char(lastchadate,'YYYYMMDDHH24MISS') into :b0,:b1  from c where subsid=:b2
program_001@serv_machine05 (TNS V1-V3)

       654
UPDATE b SET SUBSSTATUS=:B4 WHERE MID = :B3 AND SERVID = :B2 AND ACCESSMODEID = :B1
program_002@serv_machine05 (TNS V1-V3)

select STATUS ,to_char(lastchadate,'YYYYMMDDHH24MISS') into :b0,:b1  from c where subsid=:b2
program_001@serv_machine05 (TNS V1-V3)               

       346
select STATUS ,to_char(lastchadate,'YYYYMMDDHH24MISS') into :b0,:b1  from c where subsid=:b2
program_001@serv_machine05 (TNS V1-V3)               

        65
select STATUS ,to_char(lastchadate,'YYYYMMDDHH24MISS') into :b0,:b1  from c where subsid=:b2
program_001@serv_machine05 (TNS V1-V3)

从上面可以看到，基本上的sql都是也程序program_002@serv_machine05 (TNS V1-V3)发起，该程序就是上面的出来boss日志的程序，也印证了statspack中的那个sql。同时我们看到，以上的sql大部分都涉及到了表subscrption、b和subsciber。
检查subscrption和subsciber的统计信息：

OBJECT_NAME                                                   OBJEC LAST_ANAL   NUM_ROWS
------------------------------------------------------------- ----- --------- ----------
CORE.a                                             TABLE 21-OCT-04    2853307

OBJECT_NAME                                                   OBJEC LAST_ANAL   NUM_ROWS
------------------------------------------------------------- ----- --------- ----------
CORE.c                                               TABLE 21-OCT-04    2710759

发现两者的last analyzed也都是很早的时间，且统计出来的表数据的行数与现实相差比较大，现实的2个表的数据量分别为：

SQL> select count(*) from CORE.a;     
                                              
  COUNT(*)                                    
----------                                    
  86414656                                    
                                              
SQL> select count(*) from CORE.c     
  2  /                                        
                                              
                                              
  COUNT(*)                                    
----------                                    
  29548235

因此在2007年7月26日晚上对这两个表进行了分析：

       
EXEC dbms_stats.gather_table_stats(ownname => 'CORE',tabname => 'c',cascade => TRUE);                    
EXEC dbms_stats.gather_table_stats(ownname => 'CORE',tabname => 'a',cascade => TRUE);

第二天继续观察数据库主机的情况，通过对比同期的wio，发现wio的值略有下降，但是在系统忙时，wio仍然有70%以上，主要的影响io的sql还是上述由program_002进程发起。考虑到该程序代码修改困难，（一个package中有几万行代码，开发对这个package的修改非常谨慎），建议对a表和b表的历史数据进行清理。

三、后续工作和建议：

a表和b表虽然可以在线清理，但是清理的时间会拖的比较长，而且清理的效果不是很好，由于在线清理是用delete语句，不能降低数据库表中的高水位（HWM），清理后对于全表扫描的sql几乎没有作用，因此建议确定需要清理的时间点后，找一个合适的时间，停业务对表进行清理。
目前a表的记录有86414656行，如果清理半年以前，且订购关系为取消状态的订购关系，可以清理掉64252671行数据，能够大大的减轻数据库IO的负担。根据某省的数据量来预估，大约需要的停机时间为4小时。从别的省的清理经验来看，清理完历史数据后，wio大约可以降低10%左右。

等待与客户协商后，定时间清理数据，并观察清理后效果。

后话：
3周后，客户同意停业务清理，清理完这2个表后，观察清理效果明显：
数据库优化前：
名称返回值最大值平均值
HP Cpu:XX_dc01主机(41.12) CPU使用率sys+usr utilization 62 11.975
HP Cpu:XX_dc01主机(41.12) 系统占用率sys sysper 13 2.368
HP Cpu:XX_dc01主机(41.12) 用户占用率usr usrper 56 9.648
HP Cpu:XX_dc01主机(41.12) io占用率wio wio 90 46.529
HP Cpu:XX_dc01主机(41.12) 空闲率100-wio-(sys+usr) idle 99 41.496

数据库优化后：
名称返回值最大值平均值
HP Cpu:XX_dc01主机(41.12) CPU使用率sys+usr utilization 44 10.546
HP Cpu:XX_dc01主机(41.12) 系统占用率sys sysper 7 1.648
HP Cpu:XX_dc01主机(41.12) 用户占用率usr usrper 43 8.875
HP Cpu:XX_dc01主机(41.12) io占用率wio wio 82 32.837
HP Cpu:XX_dc01主机(41.12) 空闲率100-wio-(sys+usr) idle 100 56.61

6条评论

chenfeng说道：

2007-08-31 14:48

你早期的时候为什么要分析表,如果尝试用RBO,执行计划会是怎样的?象你遇到的这个情况,不如写个定时分析表的脚本,否则,将来,数据量大了后,统计信息又过时了,你还是要手工分析一次..

回复
小荷说道：

2007-09-02 19:51

谢谢chenfeng，正有这个打算。
因为涉及到各个省的数据库，量比较多，要制定统一脚本，目前正在对各省的信息做收集。

回复
chenfeng说道：

2007-09-05 16:18

不用客气,以后可以在网上多多交流技术,我的MSN是:cn_chenfeng@hotmail.com,我在北京!!

回复
dongkai说道：

2007-11-06 13:12

对生产库做分析是有风险的。如果分析后的执行计划更差，你怎么办？
在做分析前注意一定要备份分析结果！

回复
小荷说道：

2007-11-06 17:25

re dongkai：嗯，在操作之前已经export了原来的统计信息。

回复
bobjoy说道：

2010-05-24 10:54

你好，请问一般wio多少算是影响性能了呢？
附件sar_stat_070726.txt没有在这页上吧。
如果wio高，但是sar -d 的servetime不高说明什么问题。那样的话cpu是主要瓶颈？还是io系统有问题呢。

回复

回复 chenfeng 取消回复

此站点使用Akismet来减少垃圾评论。了解我们如何处理您的评论数据。

某省主机wio过高的调优以及后续建议

相关文章

insert大量数据的一些经验

statspack中易被忽悠的地方

如何找到postgres中疯狂增长的wal日志的语句

6条评论

回复 chenfeng 取消回复