ITPub博客

首页 > Linux操作系统 > Linux操作系统 > 执行计划改变导致负载升高

执行计划改变导致负载升高

原创 Linux操作系统 作者:dppass2 时间:2011-12-23 10:18:17 0 删除 编辑
早上六点多收到报警短信数据库负载高,五分钟后又恢复正常。
看了nagios监控记录,负载只持续了几分钟,之前和之后都正常。开始怀疑是定时任务,因为没人这么早去查东西。
生成了六点至七点的awr报表,

Top 5 Timed Events

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
read by other session 262,144 32,520 124 46.9 User I/O
log file sync 171,304 20,935 122 30.2 Commit
db file sequential read 376,839 6,832 18 9.9 User I/O
db file scattered read 56,321 4,817 86 7.0 User I/O
CPU time   3,585   5.2  

最高的是read by other session( 而不是db file sequential read ),该事件一般是在访问相同资源时产生。

继续看

SQL ordered by Elapsed Time

Elapsed Time (s) CPU Time (s) Executions Elap per Exec (s) % Total DB Time SQL Id SQL Module SQL Text
41,164 985 15,332 2.68 59.39 65q6dug4bcuqn   。。。。
351 351 7,272 0.05 0.51 。。。   。。。。
331 7 5,597 0.06 0.48 。。。  

第一个sql很突出站了将近60%的资源,下面的

  • SQL ordered by Reads等也显示该sql占用资源第一。
  • 对这个sql还是比较熟悉的,它既不是定时任务,也不是人为的查询。而是一个主要的业务功能:查询用户的订购记录。

    sql类似:select * from (select * from t where userid=:1 order by create_time desc) where rownum<:2;

    查询用户订购了哪些资源,并将查询结果存到memcache中,平均每次返回900多条。该表是以userid为分区键的hash分区表,同时userid上有索引。

    现在开始怀疑是请求太多了导致的,又生成了7点到8点的awr报表,用来比较该sql的执行频率是否增加了,下面是7点至8点的报表内容

    SQL ordered by Elapsed Time

    Elapsed Time (s) CPU Time (s) Executions Elap per Exec (s) % Total DB Time SQL Id SQL Module SQL Text
    1,662 1,662 19,673 0.08 18.42 。。。。  

     

    结果大失所望19,673>15,332 ,六点钟的执行次数反而少。

    由于reader by other session 事件 还是怀疑可能是在短时间内发了大量的请求。

    寻求其他方法:dba_hist_active_sess_history 这个表记录了历史等待事件,也是报表的数据来源。

    搞了个联合查询:

    select t.*, s.sql_text
      from (select *
              from dba_hist_active_sess_history
             where sample_time between
                   to_date('2011-12-23 06:30:00', 'yyyy-mm-dd hh24:mi:ss') and
                   to_date('2011-12-23 06:35:00', 'yyyy-mm-dd hh24:mi:ss')) t
      left join v$sql s
        on t.sql_id = s.sql_id;

    不出所料这个时段确实是这个sql的等待事件最多,但也有意外收获就是dba_hist_active_sess_history表中还记录了sql_plan_hash_value,它指向了v$sql_plan表,于是想确认一下当时的执行计划,(这里说明一下,这个sql有两个执行计划,在v$sql_plan中可以查到,一个执行计划是走索引,另一个是对单个分区做full扫描,这一点很早就知道,两个计划的用时也差不多,在报表中发现这个sql是就首先去v$sql_plan 中看了执行计划,可最晚的执行计划也是昨天下午生成的,于是没有怀疑执行计划的改变)
    接着说sql_plan_hash_value ,通过查看v$sql_plan发现当时使用的执行计划并不是最新生成的(最新是昨天下午生成的走索引的),而是前天生成的做全分区扫描的。于是更改sql的查询条件分别查看7点钟和5点钟该sql使用的执行计划,发现确实有变化,5点钟使用的是走索引的,6点半之后使用的全分区扫描的。

    至此可以确认是执行计划的改变引起的,具体点应该是全索引扫描时引起的,当数据被cache到内存中后,sql执行起来就比较快了。

     

     

    来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/16572356/viewspace-713825/,如需转载,请注明出处,否则将追究法律责任。

    下一篇: 隔离级别
    请登录后发表评论 登录
    全部评论

    注册时间:2008-11-26

    • 博文量
      39
    • 访问量
      74056