暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

异常诡异的SQL性能分析

原创 李铁楠 2019-07-24
447

2015年9月末的一天,客户告知其核心数据库突然发生了一个诡异现象,甚至导致业务系统该功能无法正常处理。经过简单询问,发现仅仅是一条SQL导致的,而很诡异的是,这条SQL在第二次执行时,执行计划会发生了变化,导致执行效率极低,影响业务运行。根据客户的陈述,该问题可随时重现,无论换个会话还是换个客户端工具都会受到影响。即使把共享池flush掉,再次执行SQL仍然会发生同样的现象。

14.7.1  信息收集

下面我们就来看看案情现场重现。

一条SQL在同一个会话中执行两次,第一次执行时间为10秒。但第二次执行时效率很低,执行时间超过1分钟。下面是SQL文本。

SELECT /*bbbbb*/A.C_DOC_NO AS C_PLY_APP_NO, A.C_PLY_NO AS C_PLY_NO, B.N_PRM AS N_PRM,
NVL(TO_CHAR(A.T_APP_TM, 'YYYY-MM-DD HH24:MI:SS'), CHR(0)) AS T_APP_TM,
       A.C_BLG_DPT_CDE AS C_DPT_CDE, A.C_PROD_NO AS C_PROD_NO,
NVL(B.C_APP_NME, CHR(0)) AS C_APP_NME, NVL(B.C_APP_TEL, CHR(0)) AS C_APP_TEL
  FROM T_PLY_UNDRMSG A, T_PLY_BASE B, T_FIN_PLYEDR_COLDUE C
 WHERE 1 = 1
   AND ROWNUM < 1000
   AND A.C_DOC_NO = B.C_PLY_APP_NO AND A.C_DOC_NO = C.C_PLY_APP_NO(+)
   AND A.C_SOURCE = '1'
   AND A.C_SEND_MRK NOT IN ('2')
   AND DECODE(TRIM(C.C_OPT_NO), CHR(0), NULL, TRIM(C.C_OPT_NO)) IS NULL
   AND (NVL(C.C_PRM_TYP, CHR(0)) IN (CHR(0), 'R1'))
   AND (NVL(C.C_ARP_FLAG, CHR(0)) IN (CHR(0), '0', '3', '4')) AND (NVL(C.N_TMS, 0) IN (0, 1))
   AND B.C_HAND_PER = '1012337'
   AND A.T_APP_TM BETWEEN
       TO_DATE('2015-09-29 00:00:00', 'YYYY-MM-DD HH24:MI:SS') AND
       TO_DATE('2015-09-30 23:59:59', 'YYYY-MM-DD HH24:MI:SS')
   AND A.T_INPUT_TM BETWEEN
       TO_DATE('2015-09-29 00:00:00', 'YYYY-MM-DD HH24:MI:SS') AND
       TO_DATE('2015-09-30 23:59:59', 'YYYY-MM-DD HH24:MI:SS')

 

观察该SQL执行计划信息,发现第二次执行计划发生了变化。其中T_PLY_BASE表的索引扫描变成了分区表扫描,而且驱动表和被驱动表也发生了改变,第二次执行计划中的COST也是在这里出现了明显增高。

第一次执行计划如图14-1所示。

 

图14-1

第二次执行计划如下所示。

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.04          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1     57.00     626.79    1043187    1816768          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3     57.02     626.83    1043187    1816768          0           0
 
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 413  
Number of plan statistics captured: 1
 
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  COUNT STOPKEY (cr=0 pr=0 pw=0 time=12 us)
         0          0          0   FILTER  (cr=0 pr=0 pw=0 time=9 us)
         0          0          0    NESTED LOOPS OUTER (cr=0 pr=0 pw=0 time=9 us cost=78029 size=164328 card=1002)
         0          0          0     NESTED LOOPS  (cr=0 pr=0 pw=0 time=8 us cost=77047 size=27468 card=218)
         0          0          0      PARTITION RANGE ALL PARTITION: 1 20 (cr=0 pr=0 pw=0 time=7 us cost=76262 size=19747 card=403)
         0          0          0       PARTITION LIST ALL PARTITION: 1 7 (cr=1476837 pr=852917 pw=0 time=486948524 us cost=76262 size=19747 card=403)
         0          0          0        TABLE ACCESS FULL T_PLY_BASE PARTITION: 1 140 (cr=1786130 pr=1015408 pw=0 time=614908158 us cost=76262 size=19747 card=403)
         0          0          0      TABLE ACCESS BY INDEX ROWID T_PLY_UNDRMSG (cr=0 pr=0 pw=0 time=0 us cost=4 size=77 card=1)
         0          0          0       INDEX RANGE SCAN PK_PLY_UNDRMSG_HIST_20131203 (cr=0 pr=0 pw=0 time=0 us cost=3 size=0 card=1)(object id 406120)
         0          0          0     TABLE ACCESS BY GLOBAL INDEX ROWID T_FIN_PLYEDR_COLDUE PARTITION: ROW LOCATION ROW LOCATION (cr=0 pr=0 pw=0 time=0 us cost=5 size=190 card=5)
         0          0          0      INDEX RANGE SCAN IDX_FINPLYEDRCOL_PLYAPPNO (cr=0 pr=0 pw=0 time=0 us cost=3 size=0 card=5)(object id 180111)

 

很明显,的确是第二个执行计划出现了问题,导致了性能的严重下降。但是问题是,为什么同一个SQL第二次执行时执行计划会变呢?甚至同一个SQL连续两次执行也是如此?

理论上同一个会话上执行的同一个SQL,第二次执行为软解析(或者软软解析),此时数据库应该重用执行计划,而不是产生新的执行计划。

14.7.2  新特性分析

在11g上出现了一些新特性,而其中一个典型会导致SQL执行计划发生改变的场景就是ACS(自适应游标adaptive_cursor_sharing)。但ACS典型出现的场景应该是使用了绑定变量的SQL,但该SQL并未使用绑定,数据库中也并未通过corsor_sharing参数强制绑定,看起来应该不是ACS,那么是什么原因呢?

在11g不但出现了ACS这样的自动优化新特性,还出现了另一个自动优化特性基数反馈(Cardinality Feedback)。而通过执行计划中的信息与基数反馈特性的对比,基本可以推断该问题是由11g新特性统计信息Feedback导致的Bug,只需要关闭该特性再做验证即可确认。

参考MOS Statistics (Cardinality) Feedback - Frequently Asked Questions (文档 ID 1344937.1),文档有对11GR2 Statistics Feedback新功能引起执行计划变化的描述、如何确认及解决方法。

本次问题就是典型11g新特性——统计信息Feedback导致的Bug,这样的问题相对比较常见,我们一般推荐关闭自适应游标共享和统计信息回馈(事实上我们已经总结了不少应该关闭或者调整的新特性),通过两个参数就可以动态关闭它们。在我们很多其他客户的核心库中均已进行过设置,不会对系统造成损害,建议大多数11g核心系统最好关闭。

在执行了以下处理后,SQL执行不但恢复正常,而且运行效率进一步得到了提高。

1.优化参数

关闭自适应游标共享和统计信息回馈11g新特性。

alter system set "_optimizer_use_feedback" = false scope = both;
alter system set "_optimizer_adaptive_cursor_sharing" = false scope = both;

2.优化索引

同时也对这条SQL的执行计划相关索引进行了优化。建议在表T_UND_RMSG的T_INPUT_TM列上的创建单列索引,这样就避免了出现跳扫的执行计划(同时还可将该SQL执行计划强制失效),或者通过comment命令使相关SQL强制重新解析(注意,这两种方法都会将该表的所有SQL执行计划全部过期失效,代价较高)。

Create index xxxx on T_UND_RMSG(T_INPUT_TM);
Comment on table T_UND_RMSG is ‘xxxx’;

当然,在11g上有一个更为推荐的方法——DBMS_SHARED_POOL.PURGE,这种方法将只失效特定执行计划异常的子游标,下面给出参考样例。

select address, hash_value from v$SQLarea where SQL_id = 'a6aqkm30u7p90';
ADDRESS          HASH_VALUE
---------------- ----------
C000000EB7ED3420 3248739616
exec dbms_shared_pool.purge('C000000EB7ED3420,3248739616','C');


「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论