去年底，某运营商客户反馈某个核心业务模块突然出现严重性能问题，产生了极为不好的用户体验，客服接到了大量投诉电话。这样的问题，处理起来相对容易一些。首先我们根据v$session.program很容易就可以定位到业务程序，并结合event、SQL_ID和SQL_TEXT 很快就确认是运行较慢的业务SQL语句，经过分析发现是SQL选择了错误的Index，导致执行计划效率不高。这里我通过在客户生产库创建相同的对象，然后执行类似SQL，完全可以重现问题。
首先我们来分析一下出问题的SQL语句，如下所示。
SELECT
SERIAL_NBR
FROM BILLUSER.I_B2O_OWE_C_BAK
WHERE (PROC_TYPE = '13' or PROC_TYPE = '14' or PROC_TYPE = 'S13' or
PROC_TYPE = 'S14')
AND BEGIN_OWE_DATE >=
TO_DATE('2015-12-02 12:00:00', 'YYYY/MM/DD HH24:MI:SS')
AND ACC_NBR = '18115258610'
需要说明一点，这里的I_B2O_OWE_C_BAK 表是复制的I_B2O_OWE_C表。
该SQL语句从结构上看很简单，初步怀疑是这个SQL的执行计划可能存在异常，这里我们首先来分析一下执行计划，如下所示。
Plan hash value: 239766388
-----------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-----------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 0 |00:00:00.59 | 3049 |
|* 1 | TABLE ACCESS BY INDEX ROWID| I_B2O_OWE_C_BAK | 1 | 1 | 0 |00:00:00.59 | 3049 |
|* 2 | INDEX RANGE SCAN | I_B2O_OWE_C_BAK_BDATE| 1 | 3 | 19871 |00:00:00.01 | 236 |
-----------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter((TO_NUMBER("ACC_NBR")=:SYS_B_6 AND INTERNAL_FUNCTION("PROC_TYPE")))
2 - access("BEGIN_OWE_DATE">=TO_DATE(:SYS_B_4,:SYS_B_5))
我相信，有SQL优化经验的同学应该都能看出来，上述的执行计划确实有些异常，SQL通过走Index range scan的方式，最后返回了仅仅1条数据，然而逻辑读的消耗却高达3000之多，这很明显是有问题的。同时我们还可以看出Oracle优化器评估出来的R-rows 和实际的A-rows差距非常大。也正是由于这一点，导致该执行计划选择了I_B20_OWE_C_BAK_BDATE索引后进行回表操作，产生了大量的逻辑读（逻辑读消耗几乎都在回表操作上）。
由于是客户反馈，那么在处理时我们首先想到的是，这个问题SQL是不是真如客户所讲那样，在当天才出现问题，而之前都是正常呢？还是说有可能之前也出现过异常，只是业务没有反馈而已。
要验证这一点，需要查询该SQL_ID的历史执行计划信息。通过查询确认该SQL实际上在12 月 1 日就出现了异常。但是由于当天业务量较小，没有对业务产生实质性的影响，如下所示。
SNAP_ID SQL_ID PLAN_HASH_VALUE OPTIMIZER_ FORCE_MATCHING_SIGNATURE ---------- ------------- --------------- ---------- ------------------------ 80546 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 …… 80569 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80570 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80571 1pzv7x3nhszva 239766388 ALL_ROWS 8159205349038030075 80571 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80573 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80573 1pzv7x3nhszva 239766388 ALL_ROWS 8159205349038030075 80596 1pzv7x3nhszva 239766388 ALL_ROWS 8159205349038030075 ……. 80609 1pzv7x3nhszva 239766388 ALL_ROWS 8159205349038030075 80609 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80610 1pzv7x3nhszva 239766388 ALL_ROWS 8159205349038030075 80610 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80623 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075 80624 1pzv7x3nhszva 1247210496 ALL_ROWS 8159205349038030075
其中快照ID的对应的时间段信息如下所示。
SNAP_ID BEGIN_INTERVAL_TI ---------- ----------------- 80546 20151129 23:00:34 80547 20151130 00:00:48 …… 80569 20151130 22:00:02 80570 20151130 23:00:20 80571 20151201 00:00:40 80572 20151201 01:00:59 80573 20151201 02:00:16 80574 20151201 03:00:38 …… 80596 20151202 01:01:00 ……. 80609 20151202 14:00:49 80610 20151202 15:00:16 80611 20151202 16:00:50 80612 20151202 17:00:19
其中plan_hash_value 为239766388 的执行计划为错误的执行计划。当产生错误的执行计划之后，由于Oracle bind peeking 的问题，就可能导致数据库在之后的一段时间内一直沿用错误的执行计划。
我开始怀疑可能是统计信息的问题，由于客户后续已经重新收集了统计信息。因此现在我想，是否可以将统计信息还原到出问题之前的某天，然后执行SQL语句，看其执行计划是怎么样的。
实际上Oracle本身就提供了这样一个功能，利用DBMS_STATS可以将表的统计信息还原到过去某个时间点，操作步骤如下所示。
SQL> exec dbms_stats.restore_table_stats(ownname=>'BILLUSER',tabname=>'I_B2O_OWE_ C_BAK',AS_OF_TIMESTAMP=>'01-DEC-15 12.09.22.020077 AM +08:00'); PL/SQL procedure successfully completed. SQL> select owner,table_name,COLUMN_NAME,NUM_DISTINCT,DENSITY,NUM_BUCKETS,LAST_ ANALYZED,HISTOGRAM from dba_tab_col_statistics where table_name='I_B2O_OWE_C_BAK'; OWNER TABLE_NAME COLUMN_NAME NUM_DISTINCT DENSITY NUM_BUCKETS LAST_ANALYZED HISTOGRAM ------------ ------------- ------------- ---------- -------- -------- --------------- BILLUSER I_B2O_OWE_C_BAK SOURCE 0 0 0 2015-11-17 00:10:25 NONE BILLUSER I_B2O_OWE_C_BAK TDBS 3 3.4099E-08 3 2015-11-17 00:10:25 FREQUENCY BILLUSER I_B2O_OWE_C_BAK SERIAL_NBR 14663108 6.8198E-08 1 2015-11-17 00:10:25 NONE BILLUSER I_B2O_OWE_C_BAK PROC_TYPE 5 3.4099E-08 5 2015-11-17 00:10:25 FREQUENCY BILLUSER I_B2O_OWE_C_BAK PROD_ID 2326397 4.2985E-07 1 2015-11-17 00:10:25 NONE BILLUSER I_B2O_OWE_C_BAK CREATE_DATE 5660648 1.3521E-06 254 2015-11-17 00:10:25 HEIGHT BALANCED BILLUSER I_B2O_OWE_C_BAK BEGIN_OWE_DATE 5833484 7.9253E-07 254 2015-11-17 00:10:25 HEIGHT BALANCED BILLUSER I_B2O_OWE_C_BAK STATE 3 3.4099E-08 3 2015-11-17 00:10:25 FREQUENCY BILLUSER I_B2O_OWE_C_BAK STATE_DATE 5927070 6.3963E-07 254 2015-11-17 00:10:25 HEIGHT BALANCED BILLUSER I_B2O_OWE_C_BAK ACC_NBR 2306453 1.2826E-06 254 2015-11-17 00:10:25 HEIGHT BALANCED BILLUSER I_B2O_OWE_C_BAK PRODUCT_TYPE 3 3.4099E-08 3 2015-11-17 00:10:25 FREQUENCY BILLUSER I_B2O_OWE_C_BAK BILLING_MODE_ID 3 .333333333 1 2015-11-17 00:10:25 NONE BILLUSER I_B2O_OWE_C_BAK AREA_CODE 5 .2 1 2015-11-17 00:10:25 NONE BILLUSER I_B2O_OWE_C_BAK JRFS 0 0 0 2015-11-17 00:10:25 NONE
---基于列的详细统计信息
COLUMN_NAME DATA_TYPE M NUM_VALS NUM_NULLS DNSTY LOW_V HI_V ---------------- ------- - ---------- ---------- ------- -------- ------------------ SERIAL_NBR NUMBER Y 14663,108 0 0.0000 118812796 142619179 PROC_TYPE VARCHAR2 Y 5 0 0.0000 11 15 PROD_ID NUMBER Y 2326,397 0 0.0000 10282208 561259458 CREATE_DATE DATE Y 5660,648 0 0.0000 2015-2-10 21:50:52 2015-11-16 23:53:30 BEGIN_OWE_DATE DATE N 5833,484 0 0.0000 2015-2-10 21:50:51 2015-11-16 23:55:26 STATE VARCHAR2 Y 3 0 0.0000 101 3 STATE_DATE DATE Y 5927,070 0 0.0000 2015-2-10 23:0:47 2015-11-16 23:59:41 ACC_NBR VARCHAR2 Y 2306,453 0 0.0000 13309500000 18995499998 PRODUCT_TYPE NUMBER Y 3 0 0.0000 401731 403094 BILLING_MODE_ID NUMBER N 3 0 0.3333 1 4 AREA_CODE VARCHAR2 N 5 0 0.2000 0951 0955 JRFS VARCHAR2 N 0 14765,004 0.0000 TDBS NUMBER Y 3 0 0.0000 0 2 SOURCE VARCHAR2 N 0 14765,004 0.0000
通过还原统计信息之后，发现该表的统计信息最新值实际上是11月17日凌晨，也就是说从11月17日到12月1日，该表的统计信息都没有发现发现过变动（实际上到12月1日客户感觉到出问题之后，手工收集过统计信息）。由于最近半月数据变化比较大，但统计信息却并没有更新，说明统计信息过旧也可能导致Oracle 仍然沿用旧的统计信息进行执行计划评估，进而产生错误的执行计划。至少目前为止我们还不能排除这个可能性。
这里首先来看一下Oracle card的计算公式，如下所示。
= 基数计算公式 ：1/num_distinct*(num_rows-num_nulls)
>= 基数计算公式：((high_value-limit)/(high_value-low_value)+1/num_distinct)*(num_rows- num_nulls)
对于该问题SQL的索引，如下所示。
OWNER TABLE_NAME INDEX_NAME BLEVEL LEAF_BLOCKS NUM_ROWS CLUSTERING_FACTOR DISTINCT_KEYS ---------- --------- ------------- ------- ------- -------- --------- ------------- BILLUSER I_B2O_OWE_C_BAK I_B2O_OWE_C_BDATE_BAK 2 42001 15833626 7108231 6150468 BILLUSER I_B2O_OWE_C_BAK I_B2O_OWE_C_ACCNBR_BAK 2 50751 15833626 15723479 2421731
那么根据Oracle Card计算公式，对于两个索引的估算情况如下所示。
对于其中的索引I_B2O_OWE_C_ACCNBR_BAK，由于SQL的过滤条件为 = 符号。当统计信息不变的情况之下，根据公式所计算的Card值都是不变的。
对于索引 I_B2O_OWE_C_BDATE_BAK，由于其过滤条件是 >=符号。根据Card的计算公式，是需要通过high value等值来进行计算的。
这里我们怀疑极有可能跟这个BDATE 时间列的high value等统计信息有关系，为了验证这个观点，这里我进行了如下的测试验证过程。
情况一：当时间条件取值大于high value时。
SQL> SELECT /*+ gather_plan_statistics */ SERIAL_NBR FROM BILLUSER.I_B2O_OWE_C_BAK WHERE (PROC_TYPE='13' or PROC_TYPE='14' or
2 PROC_TYPE='S13' or PROC_TYPE='S14') AND BEGIN_OWE_DATE >=
3 TO_DATE('2015-11-16 23:56:00','YYYY/MM/DD HH24:MI:SS') AND ACC_NBR ='18909502122'
4 /
no rows selected
SQL> select * from table(dbms_xplan.display_cursor(NULL,NULL,'ALLSTATS'));
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID 4fjrp8d5gqz1z, child number 0
-------------------------------------
SELECT /*+ gather_plan_statistics */ SERIAL_NBR FROM BILLUSER.I_B2O_OWE_C_BAK WHERE (PROC_TYPE='13' or
PROC_TYPE='14' or PROC_TYPE='S13' or PROC_TYPE='S14') AND BEGIN_OWE_DATE >= TO_DATE('2015-11-16
23:56:00','YYYY/MM/DD HH24:MI:SS') AND ACC_NBR ='18909502122'
Plan hash value: 3356388844
------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 0 |00:00:06.29 | 450K| 8861 |
|* 1 | TABLE ACCESS BY INDEX ROWID| I_B2O_OWE_C_BAK | 1 | 1 | 0 |00:00:06.29 | 450K| 8861 |
|* 2 | INDEX RANGE SCAN | I_B2O_OWE_C_BDATE_BAK | 1 | 3 | 1068K|00:00:00.01 | 2838 | 0 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("ACC_NBR"='18909502122' AND INTERNAL_FUNCTION("PROC_TYPE")))
2 - access("BEGIN_OWE_DATE">=TO_DATE(' 2015-11-16 23:56:00', 'syyyy-mm-dd hh24:mi:ss'))
情况二：当时间条件取值不超过high value时。
SQL> SELECT /*+ gather_plan_statistics */ SERIAL_NBR FROM BILLUSER.I_B2O_OWE_C_BAK WHERE (PROC_TYPE='13' or PROC_TYPE='14' or
2 PROC_TYPE='S13' or PROC_TYPE='S14') AND BEGIN_OWE_DATE >=
3 TO_DATE('2015-11-16 23:52:00','YYYY/MM/DD HH24:MI:SS') AND ACC_NBR ='18909502122'
4 /
no rows selected
SQL> select * from table(dbms_xplan.display_cursor(NULL,NULL,'ALLSTATS'));
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID 6vrh3x0qqnxnh, child number 0
-------------------------------------
SELECT /*+ gather_plan_statistics */ SERIAL_NBR FROM BILLUSER.I_B2O_OWE_C_BAK WHERE (PROC_TYPE='13' or
PROC_TYPE='14' or PROC_TYPE='S13' or PROC_TYPE='S14') AND BEGIN_OWE_DATE >= TO_DATE('2015-11-16
23:52:00','YYYY/MM/DD HH24:MI:SS') AND ACC_NBR ='18909502122'
Plan hash value: 1431363508
-----------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads |
-----------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 0 |00:00:00.40 | 36 | 35 |
|* 1 | TABLE ACCESS BY INDEX ROWID| I_B2O_OWE_C_BAK | 1 | 1 | 0 |00:00:00.40 | 36 | 35 |
|* 2 | INDEX RANGE SCAN | I_B2O_OWE_C_ACCNBR_BAK | 1 | 7 | 33 |00:00:00.03 | 3 | 2 |
-----------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("BEGIN_OWE_DATE">=TO_DATE(' 2015-11-16 23:52:00', 'syyyy-mm-dd hh24:mi:ss') AND
INTERNAL_FUNCTION("PROC_TYPE")))
2 - access("ACC_NBR"='18909502122')
从上面的测试验证可以看出，当where 条件的时间列取值超过该列的high value时，Oracle 选择了错误的Index。而当时间列取值小于该列的high value时，Oracle 则会选择正确的执行计划。
当取值小于high value时，此时BEGIN_OWE_DATE的选择性为 （（high_value-limit）/（high_value-low_value）+1/num_distinct）即为（2015-11-16 23:55:26 - 2015-11-16 23:50:00 ）/（2015-11-16 23:55:26-2015-2-10 21:50:51）+ （7.9253E-07）= 0.000013691。这样计算出来的结果表明begin_owe_date列的选择性要比accnbr列的选择性低。这种情况下Oracle会选择正确的索引。当取值大于high value时，begin_owe_date 列的选择性所计算出来的只要比accnbr要高，这样就会导致Oracle 选择错误的索引。
为什么会出现这样奇怪的情况呢？ 实际上是因为当谓词条件取值超过high value时，此时Oracle无法判断，只能进行猜测。而这种情况之下，通常都会导致所计算出来的Card不合理，导致SQL选择错误的执行计划。尤其是针对date列、sequence等情况，相对要常见得多，这是Oracle CBO的一个老问题。
实际上，为了避免这种情况出现，我们要尽可能地保证统计信息的准确性，这样可以最大程度降低地执行计划改变的风险。同时也要改变一种错误的认识，即统计信息不改变，SQL的执行计划不一定一成不变，而事实往往恰恰相反，很可能改变。
当然，对于前面的问题，要解决是相对简单的。由于我们确认ACCNBR列的选择性永远都是非常高的，因此可以通过SQL Profile来固定这个执行计划，可以确保后续的稳定性。
最后针对前面这个SQL执行计划改变的案例进简单总结。由于11月16日至11月30日该业务表数据变动不大，未触发Oracle 对表进行统计信息收集的阈值（数据变更超过10%）时，导致统计信息一直未进行更新。直到12月1日凌晨，随着大量数据的加载和更新，超过统计信息收集的阈值后，Oracle进行了统计信息收集。然而由于Oracle 默认的统计信息收集Job是每周一到周六的晚上22点才进行收集，因此这就会出现一天时间的间隔。在该间隔时间段内，由于统计信息不准确，SQL语句索引列的high value值过旧的问题，导致Oracle 优化器评估出的Card值较小，最后选择了错误的执行计划。
