一个SQL性能问题的优化探索

今天同事问我一个问题，看起来比较常规，但是仔细分析了一圈，发现实在是有些晕，我隐隐感觉这是一个bug，但是有感觉问题还有很多需要确认和理解的细节。

    同事说有个10gR2的数据库SQL语句有性能问题，DB time有报警，但是还没有明确的思路，让我帮忙看看有什么好的建议。我也没有问是哪个SQL语句，根据IP登录到服务器端查看了下数据库的负载，发现负载已经有了较大的波动。这是事后补充的一张较为全面的DB time监控图。

   然后根据负载的情况，定位了大体的时间范围，就大体是11点左右。

得到了一个SQL的DB time占比图，可以很清楚看到是一个SQL导致了性能消耗极大。

 SNAP_ID SQL_ID        EXECUTIONS_DELTA ELAPSED_TI PER_TOTAL
---------- ------------- ---------------- ---------- ----------
    108652 5dw94xr3c8hy8                4 4338s      92%
    108652 0p1ntk9bv0hrr             6582 20s        0%
    108652 2bfm7hrkwu0s7             1240 0s         0%
    108652 3qd7k5q9gsnmx              434 4s         0%
    108652 4c075dx0fqsjk             7530 1s         0%    马上定位到这个SQL语句，和同事确认，就是这个语句，看语句的执行情况，可以看到执行的效率很差,这个SQL语句大体是下面的样子。

SQL_FULLTEXT
----------------------------------------------------------------------------------------------------
SELECT ID,CN,CARD_NO,TO_CHAR(CHARGE_DATE,'yyyy-MM-dd HH24:mi:ss') AS CHARGE_DATE ,IP,POINT,PRESENT_P
OINT,SUCCESS,CARD_TYPE,PRODUCTNUM,SALEMETHOD,ITEM_ID,SERVICEID,ORDER_NO,TO_CHAR(EXPIREDATE,'yyyy-MM-
dd HH24:mi:ss') AS EXPIREDATE,REMARK FROM RECHARGE_LOG WHERE CARD_NO = TO_NUMBER(:1)

   看到这个地方，很明显是SQL的性能问题，而性能瓶颈似乎在于过滤条件，是不是隐式转换导致的全表扫描呢？

   查看执行计划，我发现说对了一半，确实是全表扫描，而另一半就很难说得清楚了。因为这个表的字段CARD_NO数据类型是number（20,0），对于隐式转换，其实对于varchar2->number 的方式是兼容的，而反过来number->varchar2就很容易出现问题，具体可以参考：

MySQL和Oracle中的隐式转换（r6笔记第45天)

语句的执行计划如下：

查看谓词信息可以清楚的看到是一个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
- ------------- ------ --------------- ------------ ------------------------------
5dw94xr3c8hy8 :1     VARCHAR2(128)   03-JAN-17    71307116310414511505
5dw94xr3c8hy8 :1     VARCHAR2(128)   03-JAN-17    71447219414105360326
5dw94xr3c8hy8 :1     VARCHAR2(128)   03-JAN-17    71447219414105360326

可以看到，这个绑定变量无可挑剔，是一个标准的字符类型。

而通过客户端模拟复现的时候，发现输出却大大不同，因为尝试模拟，却发现优化器会自动去走索引扫描而非全表扫描。

这样一个输出结果就很尴尬了。

尝试了多种方式复现，但是优化器都会乖乖的走索引。

如果这是一个很紧急的情况下，需要迅速做出响应，那么可以注意几个地方，一个是统计信息，一个是执行计划。统计信息和同事确认，他说之前收集过一次，而且查看统计信息的情况，竟然收集时间是今天，这一点值得进一步确认，因为没有手工触发过，另外一点就是执行计划，如果执行计划发现了变化，对于一个核心业务，影响范围较大的SQL语句，需要尽快修复，修改执行计划就是一种快速解决方式，当然对于这个问题，查看历史情况，这个语句的执行频率并不高，而且性能SQL也已经在执行中，我们先把问题确认清楚，再操作不迟。

除了需要确认统计信息收集时间外，还需要确认准确度,大体来看，字段也存在直方图，bucket数为254。

SQL>select owner,table_name,
               column_name,
               utl_raw.cast_to_number(low_value) low,
               utl_raw.cast_to_number(high_value) hight
    from dba_tab_col_statistics
         where table_name = 'RECHARGE_LOG'
          and column_name = 'CARD_NO'
OWNER    TABLE_NAME       COLUMN_NAM        LOW                          HIGHT
------------------------- ---------- ---------- ------------------------------
TEST     RECHARGE_LOG     CARD_NO             0           71657919645407470488

  可以通过SQLT得到这条语句执行计划的变化，可以赫然看到执行计划的天壤之别。

PLAN_HASH_VALUE AVG_ET_SECS
--------------- -----------
     1818596128        .013
      878630897    4247.848

两者在参数设置上看起来是一样的，唯一的就是扫描路径不同，一个索引，一个全表扫描。

走索引的部分：

DBMS_LOB.CLOSE(sql_txt);
h := SYS.SQLPROF_ATTR(
q'[BEGIN_OUTLINE_DATA]',
q'[IGNORE_OPTIM_EMBEDDED_HINTS]',
q'[OPTIMIZER_FEATURES_ENABLE('10.2.0.4')]',
q'[OPT_PARAM('optimizer_index_cost_adj' 30)]',
q'[OPT_PARAM('optimizer_index_caching' 90)]',
q'[ALL_ROWS]',
q'[OUTLINE_LEAF(@"SEL$1")]',
q'[INDEX_RS_ASC(@"SEL$1" "RECHARGE_LOG"@"SEL$1" ("RECHARGE_LOG"."CARD_NO"))]',
q'[END_OUTLINE_DATA]');

走全表扫描的部分:

DBMS_LOB.CLOSE(sql_txt);
h := SYS.SQLPROF_ATTR(
q'[BEGIN_OUTLINE_DATA]',
q'[IGNORE_OPTIM_EMBEDDED_HINTS]',
q'[OPTIMIZER_FEATURES_ENABLE('10.2.0.4')]',
q'[OPT_PARAM('optimizer_index_cost_adj' 30)]',
q'[OPT_PARAM('optimizer_index_caching' 90)]',
q'[ALL_ROWS]',
q'[OUTLINE_LEAF(@"SEL$1")]',
q'[FULL(@"SEL$1" "RECHARGE_LOG"@"SEL$1")]',
q'[END_OUTLINE_DATA]');

 所以上面的信息，可以看出影响这个执行计划，还和参数optimizer_index_cost_adj和optimizer_index_caching有关，但是根据经验值，似乎也在合理范围内。所以，看起来合理的数据，得到了一个不合理的结果。解释起来就很纠结了。

   预知后事如何，且听下回分解。