ITPub博客

首页 > Linux操作系统 > Linux操作系统 > 索引范围扫描删除记录慢的问题分析与处理

索引范围扫描删除记录慢的问题分析与处理

原创 Linux操作系统 作者:嘉迷 时间:2012-05-24 10:28:30 0 删除 编辑

一、前言


    本文讲述了一个ZLHIS删除操作案例,该操作的SQL语句执行计划中使用到索引,但是执行性能却不高,最终导致带来了严重的性能问题。通过跟踪日志分析,发现导致删除操作性能差的原因是在删除时候出现db file sequential read等待事件,进而分析阐述了产生该等待事件的原因和解决方法,最后把问题解决。本案例通过问题的排查,分析对于以后同事处理类似SQL语句性能问题有一定的参考价值。


二、渠道求助


          510号早上正在专心的做着优化手段测试的实验,手机电话突然响起,一看来电是NM渠道的技术人员,肯定又是那个医院出了紧急问题,需要马上处理。接听电话,对方首先是一整寒暄,然后直奔主题,原来是渠道的一家医院,周末刚刚升级,升级后其他业务都正常,但是在门诊医生站病人取消接诊操作却异常的慢,一个病人取消接诊要3分钟,已经严重影响医院的正常业务。渠道的技术人员已经按照升级后的常规处理方式,对ZLHIS用户的统计信息进行了收集,但是问题依旧,渠道已经无计可施,因此申请技术支持。其实这个通过描述比较好定位,通过SQL跟踪工具就可以轻松定位问题SQL,这点技术人员也能够掌握,通过SQL跟踪工具,可以轻松定位到问题原来是Zl_病人接诊_Cancel执行性能比较差,光是这个过程执行就需要半分钟左右才能完成,渠道技术人员只能定位到这里,至于为什么这个过程执行慢,其就没有办法判断了,所以申请技术支持。


三、问题分析


其实要诊断过程为什么执行慢,我们可以通过过程调试,带入过程参数通过过程的单步调试功能,就可以跟踪出诊断出其具体执行情况,通过这种方式,我定位到了这个过程执行慢的原因,是如下的SQL语句:

Update 门诊费用记录
  Set
执行人 = v_执行人, 执行状态 =
0, 执行时间 = Null, 发药窗口 = Decode(v_分诊方式, 0, Null, 发药窗口), 结论 = Null
  Where NO = No_In And
记录性质 =
4 And 记录状态 In (1, 3);


单就该SQL的执行就占了Zl_病人接诊_Cancel过程的大部分时间,但是在其他正常环境中该SQL的执行只需要1秒左右,可以看到性能差距相当的明显,这时我单独把该语句提出出来,加上条件在PLSQL中执行确很快,不存在性能问题,看来该SQL语句必须在过程中性能问题才会突显,这就需要我们分析在过程执行中的该SQL语句的执行情况,我们平时查看单独的SQL语句的执行计划非常简单,但是如何查看存储过程中的SQL语句的执行计划,这里我们就必须要用到一个熟悉的方法----SQL TRACE,以前的文档中也对其进行了详细的介绍,我们这里就不做过多的说明,启用SQL TRACE的方法有很多种,为了得到更多的信息,我们这里采用dbms_session包来对Zl_病人接诊_Cancel存储过程的执行进行跟踪,新打开一个会话窗口,然后执行如下操作:

exec         dbms_session.session_trace_enable(waits => True);   --跟踪包括等待事件

exec         Zl_病人接诊_Cancel('213685','M0064711');  ---传入参数根据实际情况调整


         通过执行完上面的语句,对应的TRACE文件就在USER_DUMP_DEST下生成,但是这个原生trace文件格式比较复杂,可读性较差,我们需要通过tkprof命令行工具进行格式化才能够好的解读,格式化的语法如下:

Tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ]

参数说明:

o  tracefile         你要分析的trace文件

o  outputfile        格式化后的文件

o  explain=user/password@connectstring

o  table=schema.tablename

这两个参数是一起使用的,通过连接数据库对在trace文件中出现的每条sql语句查看执行计划,并将之输出到outputfile中。注意,该table必须是数据库中不存在的,如果存在会报错。为了保证信息准确,这两个参数一般不使用。

o  print=n          只列出最初Nsql执行语句

o  insert=filename   会产生一个sql文件,运行此文件可将收集到的数据insert到数据库表中

o  sys=no           过滤掉由sys执行的语句

o  record=filename    可将非嵌套执行的sql语句过滤到指定的文件中去

o  waits=yes|no      是否统计任何等待事件

o  aggregate=yes|no   是否将相同sql语句的执行信息合计起来,默认为yes

o  sort=option         设置排序选项,主要常用的有exeela(执行时间),execpucpu资源),execnt扫行次数等


    由于我们需要查看SQL语句的执行计划,因此要使用到explain参数,这里的用户名和密码是你执行存储过程时候的用户名和密码,例如我们这里生成的原文件名为orcl1_ora_14128.trc,格式化操作如下:

tkprof D:\oracle\product\10.2.0\admin\orcl\udump\orcl1_ora_14128.trc D:\oracle\product\10.2.0\admin\orcl\udump\orcl1_ora_14128.txt explain=zlhis/his@orcl


    通过上面的格式化操作,我们就得到了一个新的文件orcl1_ora_14128.txt,里面的内容就是已经格式化了的内容,接着我们就需要认真分析该文件。

首先看下整个存储过程的执行时间,如下,

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

 

call     count       cpu    elapsed       disk      query    current        rows

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

Parse       18      0.00       0.00          0          0         16           0

Execute     20      4.02      21.42      26015      80437         32           7

Fetch       10      0.00       0.00          0         30          0           8

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

total       48      4.02      21.43      26015      80467         48          15

   大概需要21.43秒,效率确实不高,我们再一步查看先前已经重点关注的SQL语句执行计划如下:

UPDATE 门诊费用记录 SET 执行人 = :B3 , 执行状态 = 0, 执行时间 = NULL,

  发药窗口 = DECODE(:B2 , 0, NULL, 发药窗口), 结论 = NULL

WHERE

 NO = :B1 AND 记录性质 = 4 AND 记录状态 IN (1, 3)

 

 

call     count       cpu    elapsed       disk      query    current        rows

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

Parse        1      0.00       0.00          0          0          0           0

Execute      1      3.98      21.39      26015      80366         28           4

Fetch        0      0.00       0.00          0          0          0           0

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

total        2      3.98      21.39      26015      80366         28           4

 

需要21.39秒,占整个过程执行时间的99%,因此也可以判断这就是该过程执行慢的根本原因,另外我们还可以看出,物理读非常大,难道是没有或者走错了索引导致?我们再来看下这个SQL语句的执行计划,如下:

Misses in library cache during parse: 0

Optimizer mode: ALL_ROWS

Parsing user id: 65  (ZLHIS)   (recursive depth: 1)

 

Rows     Execution Plan

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

      0  UPDATE STATEMENT   MODE: ALL_ROWS

      0   UPDATE OF '门诊费用记录'

      0    INDEX   MODE: ANALYZED (RANGE SCAN) OF '门诊费用记录_UQ_NO'

               (INDEX (UNIQUE))

    从执行计划看,没有什么问题,用到了门诊费用记录_UQ_NO索引,而且走的是索引范围扫描,同单独提取该SQLPLSQL执行的执行计划是一样的,这就奇怪了,但是我们再观察其他信息,发现该语句执行过程中,出现了如下的等待事件:

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  db file sequential read                      7168        0.09          4.66

  db file scattered read                       5252        0.10          3.92

这就很奇怪了,特别是db file scattered read等待事件,在使用索引范围扫面的情况下,是不应该出现的,为什么这里会出现呢?带着这个疑问,在metalink中进行了查询,还真让我找到了一篇文章《Delete or Update running slow -- db file scattered read waits on index range scan [ID 296727.1]》,这篇文章给出了详细的解释,在使用了索引范围扫面出现db file scattered readdb file sequential reads等待事件原因:

          1.由于每次进行索引范围扫描操作时,都需要对索引叶块进行预取(prefetching)操作,而在删除和修改操作时候,oracle要对预取指数进行维护,因此出现了db file sequential readdb file scattered read等待事件。

         2.oracle有个隐含参数“_db_file_noncontig_mblock_read_count”定义了索引每次预期的数据块数,默认是11

         一般情况下,预取指数很少会影响查询的性能,在考虑到用户那里也没做任何修改的情况下,决定不动隐含参数,毕竟隐含参数的修改存在一定的风险,文档中提供了两种处理方式:1.重建索引;2.WHERE条件中加入更多的索引字段,这里我们采用重建索引的方式,如下:

alter index 门诊费用记录_UQ_NO rebuild online;

四、问题解决

         通过重建完索引后,我们再次操作取消接诊,只需要1秒多钟,就完成操作,看来问题已经得到解决,我们再次对Zl_病人接诊_Cancel过程进行一个SQL TRACE操作,生成个TRACE文件,格式化后,结果如下:

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

 

call     count       cpu    elapsed       disk      query    current        rows

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

Parse       16      0.00       0.00          0          0          0           0

Execute     18      1.26       1.23          0      45072         34           7

Fetch        8      0.00       0.00          0         28          0           8

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

total       42      1.27       1.24          0      45100         34          15

         可以看到,整个过程的执行时间已经骤减到1.24秒,然后我们再看看刚才那个SQL语句的执行计划,如下:

UPDATE 门诊费用记录 SET 执行人 = :B3 , 执行状态 = 0, 执行时间 = NULL,

  发药窗口 = DECODE(:B2 , 0, NULL, 发药窗口), 结论 = NULL

WHERE

 NO = :B1 AND 记录性质 = 4 AND 记录状态 IN (1, 3)

 

 

call     count       cpu    elapsed       disk      query    current        rows

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

Parse        1      0.00       0.00          0          0          0           0

Execute      1      1.24       1.21          0      45001         30           4

Fetch        0      0.00       0.00          0          0          0           0

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

total        2      1.24       1.21          0      45001         30           4

 

Misses in library cache during parse: 1

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: 65  (ZLHIS)   (recursive depth: 1)

 

Rows     Execution Plan

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

      0  UPDATE STATEMENT   MODE: ALL_ROWS

      0   UPDATE OF '门诊费用记录'

      0    INLIST ITERATOR

      0     INDEX   MODE: ANALYZED (RANGE SCAN) OF '门诊费用记录_UQ_NO'

                (INDEX (UNIQUE))

 

*******************************************************************************

        物理读已经没有了,执行时间同样骤减到1.21秒,而且先前的db file sequential readdb file scattered read等待事件也不在了,这个问题已经得到了处理,随后的几天观察也未再次出现性能问题,至此问题得到圆满解决。

五、小结

通过本案例,我们简单的分析下为什么会出现该性能问题,我想ORACLE内部维护有一套复杂的机制,再一些特定的环境下,这些机制可能出现问题,从而导致出现性能问题,如本例中就是索引的叶块的预期值在进行维护的时候,出现了性能问题,通过重建该索引,相当于重新构建了维护机制,从而解决了问题,另外我们从该问题的解决过程可以得到一些启示:

1.处理性能问题,SQL TRACE是一个非常有用的手段,我们每个技术人员都应该掌握。

2.对于隐含参数,再没有特殊必要的情况下,尽量少用。

3.多利用ORACLE在线帮助,这是一个宝库里面包含了许多我们想要的知识。

希望本文对各位技术人员以后在处理类似问题时,有一个清晰的处理思路,不必再不知所措。

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

上一篇: 没有了~
请登录后发表评论 登录
全部评论

注册时间:2008-08-12

  • 博文量
    3
  • 访问量
    19477