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

Posted 数据与人文

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了优化器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。

 

 

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

 

1、数据量有巨大波动(短时间内不太可能);

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

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

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

 

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

 

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

 

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

 

 

 

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

 

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

 

是否是这样呢?对SQL加hint强制走索引看一下,强制走索引的执行计划如下:

 

 

 

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

 

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

 

追踪步骤省略。

 

分析tkprof格式化后的trc文件

 

 

 

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

 

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

 

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

 

 

 

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

 

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

 

 

 

固定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左右,较之前有明显改善。

 

 

 

 

另外尝试修改优化器为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左右); 有风险

 

以上是关于优化器Bug?记一次慢SQL问题分析过程的主要内容,如果未能解决你的问题,请参考以下文章

线上Case分析一次慢查询优化及总结思考

记一次源码分析过程,顺便给MyBatis修个Bug

2022年记一次慢查询优化指南,MySQL 优化学习第9天

记一次mysql性能优化过程

记一次生产SQL强势优化

解Bug之路-记一次中间件导致的慢SQL排查过程