1

应用SQL突然变慢优化分析

李真旭 2019-07-24
76
摘要:应用SQL突然变慢优化分析

去年底,某运营商客户反馈某个核心业务模块突然出现严重性能问题,产生了极为不好的用户体验,客服接到了大量投诉电话。这样的问题,处理起来相对容易一些。首先我们根据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值较小,最后选择了错误的执行计划。


「喜欢文章,快来给作者赞赏墨值吧」

评论

0
1
Oracle
订阅
欢迎订阅Oracle频道,订阅之后可以获取最新资讯和更新通知。
墨值排行
今日本周综合
近期活动
全部
相关课程
全部