优化器Bug？记一次慢SQL问题分析过程

优化器Bug？记一次慢SQL问题分析过程，聊聊我的思路。

 

技术人人都可以磨炼，但处理问题的思路和角度各有不同，希望这篇文章可以抛砖引玉。

 

 

以一个例子为切入点

 

一、问题背景

 

某客户希望协助他们对业务复杂SQL进行全面分析优化，优化过程中遇到的一些问题正好做个记录。

 

基础环境：

 

  • 主机类型：PowerEdge R840 
  • 操作系统：CentOS Linux release 7.6.1810 (Core) 
  • 存储：EMC存储
  • 内存：256 G
  • CPU型号：Intel(R) Xeon(R) Gold 5215 CPU @ 2.50GHz ( 4 U * 10 core)
  • CPU核数：80CORE
  • 数据库环境：Oracle 12c RAC（12.1）

 

问题现象：

 

SQL首次执行较慢且多次执行后变快，不多会再次执行同样的SQL又变慢，多次执行后再次变快。

 

 

 

 

二、分析说明

 

  • 通过分析日志定位慢SQL，分析慢SQL原因；
  • 追溯SQL执行历史数据，分析关键指标在SQL多次执行的波动,这些关键指标可以用来做为SQL健康度参考指标。
  • 用实际数据来验证推断，排除掉其它干扰因素，定位SQL慢的根本原因，帮助快速修复。

 

 

三、疑问点排查及分析思路

 

问题SQL文本较复杂且涉密就不贴了。

 

1、SQL多次执行时间是否一样?

 

从SQL的执行情况来看，首次执行速度较慢，约为4-5s，二次执行速度较快，约为0.4-0.5s。

优化器Bug？记一次慢SQL问题分析过程_优化器

 

 

首次执行慢后续执行很快可能的原因：

 

1、数据量有巨大波动（短时间内不太可能）；

2、Sql执行计划发生改变；

3、Sql首次执行后，SQL的cursor刷进shared pool，后续执行直接引用；

4、12c优化器对SQL执行的影响。

 

以上几个点作为后续深入分析的方向。

 

2、SQL多次执行，执行计划是否发生改变?

 

SQL多次执行后查看SQL历史执行计划未发生改变，Plan hash value: 2015687178

优化器Bug？记一次慢SQL问题分析过程_优化器_02

 

 

 

可以排除执行计划发生改变的假设。

 

另外注意到SQL执行计划有TABLE ACCESS FULL，分析SQL结构并创建合适的索引后再次执行SQL，SQL执行计划并没有引用创建的索引，也就是说优化器认为TABLE ACCESS FULL是执行代价更低的方式。

 

是否是这样呢？对SQL加hint强制走索引看一下，强制走索引的执行计划如下：

优化器Bug？记一次慢SQL问题分析过程_优化器_03

 

 

 

强制走索引后cost值反而更高，优化器的判断没有问题。

 

3、使用Oracle 10046追踪事件追踪SQL到底慢在哪里? 

 

追踪步骤省略。

 

分析tkprof格式化后的trc文件

优化器Bug？记一次慢SQL问题分析过程_优化器_04

 

 

 

Parse动作消耗了接近4s的时间。如果能消除掉SQL解析的时间理论上此SQL执行效率将会大幅提升。

 

4、假设SQL cursor 被频繁刷出share pool，能否将SQL的cursor固定在sharedpool?

 

先来看一下share pool设置的大小值；

优化器Bug？记一次慢SQL问题分析过程_优化器_05

 

 

 

22g的share pool足够大了，再调大没什么意义，查看单节点v$sql，执行的SQL也不过三四十万条，并不多。

 

使用Oracle自带的dbms_shared_pool keep包把SQL cursor对象固定到share pool中，固定后：

优化器Bug？记一次慢SQL问题分析过程_优化器_06

 

 

 

固定SQL cursor后SQL的首次执行时间还是4-5s，并没有明显改善。

 

通过第三和第四部分析把SQL cursor固定到sharepool后并没有用，进一步分析为何没有作用要使用Oracle10053事件追踪一下。

 

（结合当前业务场景，即使假设成立对调优此类SQL参考价值也不大，不再做进一步分析。）

 

5、12c优化器对SQL执行的影响？

 

此业务SQL是标准的SQL，横向对比其他大客户此SQL的执行情况并没有此类问题，且就算时间消耗在解析层面一般ms级别就应该结束了，不至于到s级别，当前环境居然要消耗接近4s的时间。

 

检查影响优化器的参数：

 

  • optimizer_mode
  • optimizer_index_cost_adj
  • optimizer_dynamic sampling
  • _optimizer_mjc_enabled、_optimizer_cost_based_transformation
  • hash_join_enable

 

以上几个对SQL执行计划影响较大。

 

验证：

 

开启COST查询转换，初始化优化器参数 _optimizer_cost_based_transformation设为默认值(linear)。

 

CBQT参数有如下值："exhaustive","iterative", "linear", "on", "off"。

 

会话级别修改：

 

alter session set "_optimizer_cost_based_transformation"=off;

 

SQL首次执行时间：SQL首次执行时间1.1s左右，较之前有明显改善。

 

优化器Bug？记一次慢SQL问题分析过程_优化器_07

 

 

 

另外尝试修改优化器为10g，11g版本发现SQL的执行效率均不同，但整体而言效率比12.1版本的效率要好；这个问题可能是12c的优化器缺陷（12c类比11g也就是11.1版本）；涉及Oracle优化器核心的问题得用mos账号提个sr咨询一下Oracle原厂。

 


四、解决方案

 

 1、MOS账号提个SR确认一下是否是优化器算法导致的问题 此问题未必是业务SQL导致的问题，只不过是恰好SQL触发了问题，咨询Oracle原厂服务。看Oracle会怎么解释。
 2、改造此复杂SQL
确认此类复杂SQL需要改造。（具有可行性）
3、会话级修改隐含参数规避（0.5s左右）