一个SQL性能问题的优化探索(一)(r11笔记第33天)
今天同事问我一个问题,看起来比较常规,但是仔细分析了一圈,发现实在是有些晕,我隐隐感觉这是一个bug,但是有感觉问题还有很多需要确认和理解的细节。
同事说有个10gR2的数据库SQL语句有性能问题,DB time有报警,但是还没有明确的思路,让我帮忙看看有什么好的建议。我也没有问是哪个SQL语句,根据IP登录到服务器端查看了下数据库的负载,发现负载已经有了较大的波动。这是事后补充的一张较为全面的DB time监控图。
然后根据负载的情况,定位了大体的时间范围,就大体是11点左右。
得到了一个SQL的DB time占比图,可以很清楚看到是一个SQL导致了性能消耗极大。
SNAP_ID SQL_ID EXECUTIONS_DELTA ELAPSED_TI PER_TOTAL
马上定位到这个SQL语句,和同事确认,就是这个语句,看语句的执行情况,可以看到执行的效率很差,这个SQL语句大体是下面的样子。
SQL_FULLTEXT
看到这个地方,很明显是SQL的性能问题,而性能瓶颈似乎在于过滤条件,是不是隐式转换导致的全表扫描呢?
查看执行计划,我发现说对了一半,确实是全表扫描,而另一半就很难说得清楚了。因为这个表的字段CARD_NO数据类型是number(20,0),对于隐式转换,其实对于varchar2->number 的方式是兼容的,而反过来number->varchar2就很容易出现问题,具体可以参考:
语句的执行计划如下:
查看谓词信息可以清楚的看到是一个filter的过滤条件,难道这个表没有索引,或者索引有什么特别之处?
然后这是一个很常规的非唯一性索引。
CREATE INDEX "BILL"."IDX_RECHARGE_LOG_CARD_NO" ON "BILL"."RECHARGE_LOG" ("CARD_NO")
有索引却不用,这个实在有些奇怪,看到这里就开始有些疑惑了。
是不是绑定变量的值有一些问题。如果要查看这类信息有两种方式,一种是从缓存中查看V$SQL_BIND_CAPTURE,另外一种是从快照数据中查看dba_hist_sqlbind得到。
select instance_number, sql_id,name, datatype_string, last_captured,value_string from dba_hist_sqlbind where sql_id='5dw94xr3c8hy8' order by LAST_CAPTURED,POSITION;
输出的结果如下:
SQL_ID NAME DATATYPE_STRING LAST_CAPTURE VALUE_STRING
可以看到,这个绑定变量无可挑剔,是一个标准的字符类型。
而通过客户端模拟复现的时候,发现输出却大大不同,因为尝试模拟,却发现优化器会自动去走索引扫描而非全表扫描。
这样一个输出结果就很尴尬了。
如果这是一个很紧急的情况下,需要迅速做出响应,那么可以注意几个地方,一个是统计信息,一个是执行计划。统计信息和同事确认,他说之前收集过一次,而且查看统计信息的情况,竟然收集时间是今天,这一点值得进一步确认,因为没有手工触发过,另外一点就是执行计划,如果执行计划发现了变化,对于一个核心业务,影响范围较大的SQL语句,需要尽快修复,修改执行计划就是一种快速解决方式,当然对于这个问题,查看历史情况,这个语句的执行频率并不高,而且性能SQL也已经在执行中,我们先把问题确认清楚,再操作不迟。
除了需要确认统计信息收集时间外,还需要确认准确度,大体来看,字段也存在直方图,bucket数为254。
SQL>select owner,table_name,
可以通过SQLT得到这条语句执行计划的变化,可以赫然看到执行计划的天壤之别。
PLAN_HASH_VALUE AVG_ET_SECS
两者在参数设置上看起来是一样的,唯一的就是扫描路径不同,一个索引,一个全表扫描。
走索引的部分:
DBMS_LOB.CLOSE(sql_txt);
走全表扫描的部分:
DBMS_LOB.CLOSE(sql_txt);
所以上面的信息,可以看出影响这个执行计划,还和参数optimizer_index_cost_adj和optimizer_index_caching有关,但是根据经验值,似乎也在合理范围内。所以,看起来合理的数据,得到了一个不合理的结果。解释起来就很纠结了。
预知后事如何,且听下回分解。