写点什么

一次慢查询暴露的隐蔽的问题

用户头像
AI乔治
关注
发布于: 2021 年 01 月 13 日
一次慢查询暴露的隐蔽的问题

最近解决了一个生产 SQL 慢查询的问题,排查问题之后发现一些比较隐匿且容易忽略的问题。

业务背景介绍

最近业务上需要上线一个预警功能,需要查出一段时间内交易,求出当前交易成功率。当成功率低于设定阈值时,短信预警。业务逻辑很简单,测试环境测试也没问题之后,部署上线。实际生产运行时却发现每次 SQL 查询需要花费 60 多秒。

系统架构介绍

Spring boot + Mybatis + Oracle。

需要查询的表数量级为亿级。

排查问题

交易表结构(已经简化)大致如下。

create table TB_TEST(  BANK_CODE   VARCHAR2(20),  CREATE_TIME DATE,  OID_BILL    NUMBER(16) not null)/create index TB_TEST_CREATE_TIME_INDEX  on TB_TEST (CREATE_TIME)/
create unique index TB_TEST_OID_BILL_UINDEX  on TB_TEST (OID_BILL)/
alter table TB_TEST  add constraint TB_TEST_PK    primary key (OID_BILL)/
复制代码

该项目的增删改查语句使用 MybatisGenerate 自动生成,查询语句使用 CREATE_TIME 做为条件查询,自动生成 sql 如下。

select *from TB_TESTwhere CREATE_TIME >= #{start_time}  and CREATE_TIME < #{end_time};
复制代码

我们通过设置 Druid 的配置,将具体查询 SQL 日志输出到控制台。具体设置如下。

  <bean id="dataSource" class="com.alibaba.druid.pool.DruidDataSource" init-method="init" destroy-method="close">      ... ...      <property name="filters" value="stat,slf4j" />  </bean>
 <!-- logback  -->    <logger name="druid.sql.Statement" level="DEBUG" additivity="false">        <appender-ref ref="STDOUT"/>    </logger>
复制代码

具体 sql 日志如下:



从日志中我们可以清楚看到实际运行的 SQL,以及查询参数与类型。

从查询语句看来,我们查询条件正确,且由于 CREATE_TIME 存在独立索引,所以查询会走索引,查询速度应该很快,不至于每次查询需要花费 60 多秒。

所以当时猜测这次查询由于某些原因发生了全表扫描,未走索引才导致慢查询。在 Google 搜索相关资料,看见一篇文章 https://www.cnblogs.com/chen--biao/p/9770554.html。

根据文章描述的是 Oracle 中存在隐式转换的情况,当类型不匹配的时,Oracle 会主动将类型转换成目标类型。查看我们表结构,CREATETIME 为 Date 类型,而根据日志我们查询参数传递的 CREATETIME 却为 TIMESTAMP 类型。

所以实际在数据库查询 SQL 如下:


SELECT *FROM TB_TESTWHERE (CREATE_TIME >= to_timestamp('2018-03-03 18:45:32', 'yyyy-mm-dd hh24:mi:ss') and       CREATE_TIME < to_timestamp('2019-01-03 18:45:32', 'yyyy-mm-dd hh24:mi:ss'));

复制代码

可能这里发生一次隐式转换。

如何证明这个猜想那?我们可以使用 EXPLAIN PLAN ,分析 SQL 执行计划.上面 SQL 执行计划如下。



从上图我们可以从 TB ACCESS FULL 看出,这次查询慢确实由于是全表扫描导致。

然后我们查看执行计划中的 Predicate Information 信息,Oracle 使用 INTERNALFUNCATIPON 转换 CREATETIME 类型 。从这点那可以看出查询过程索引字段发生一次内联函数转换。

SQL 性能优化往往会有一点,避免在索引字段使用函数

既然知道原因,那么解决办法也没有这么难了。我们将查询 sql 改为如下就能解决。

select *from TB_TESTwhere CREATE_TIME >= TO_DATE(#{start_time}, 'yyyy-mm-dd hh24:mi:ss')  and CREATE_TIME < TO_DATE(#{end_time}, 'yyyy-mm-dd hh24:mi:ss');
-- 或者使用 cast 函数select *from TB_TESTwhere CREATE_TIME >= cast(#{start_time} as date)  and CREATE_TIME < cast(#{end_time} as date);
复制代码

分析原因

解决完问题,我们分析下 Java 类型中的 Date 类型为什么最终会转换成 Oracle 中的 TIMESTAMP 类型。

这次案例中我们使用 Mybatis 框架,框架内部会将 Java 数据类型转换成对应的 JDBC 数据类型。查看 Mybatis 类型转换 这一节我们可以发现 Java Date 类型将会转换成 java.sql.TIMESTAMP。



然后我们查看 Oracle JDBC 数据类型转换规则。我们可以看到,TIMESTAMP 将转换成 Oracle 中 TIMESTAMP。



问题扩展

假设我们将 CREATETIME 类型修改成 TIMESTAMP,然后查询的时候将 CREATETIME 转换成 Date 类型,是否也会发生内联函数转换,然后导致全表扫描那?查询 sql 如下。

--  CREATE_TIME 类型为 TIMESTAMPselect *from TB_TESTwhere CREATE_TIME >= TO_DATE('2018-02-27 19:36:21', 'yyyy-mm-dd hh24:mi:ss')  and CREATE_TIME < TO_DATE('2018-12-27 19:36:21', 'yyyy-mm-dd hh24:mi:ss')
复制代码

我们用 EXPLAIN PLAN 分析这个 SQL。



我们可以看到,确实发生了一次内联转化,但是却在另外一边。这次查询走的是索引。

从这个例子我们可以看出,在索引字段上使用函数会导致全表扫描。但是在传入查询参数上使用函数并不会导致索引失效。

总结

1 SQL 查询时需要注意两边数据类型的一致性,虽然数据库隐式转换会帮我们解决数据不一致的问题,但是这种隐式转化带来一些隐蔽问题,让我们第一时间并不能很快发现。所以使用显示转换代替隐式转换。这样我们的 SQL 清晰易懂,而且更加可控。

2 学会使用 EXPLAIN PLAN 分析慢 SQL。

3 索引字段上使用相关函数会导致慢查询,查询时切勿在索引字段上使用函数。

看完三件事❤️



如果你觉得这篇内容对你还蛮有帮助,我想邀请你帮我三个小忙:



  1. 点赞,转发,有你们的 『点赞和评论』,才是我创造的动力。

  2. 关注公众号 『 java 烂猪皮 』,不定期分享原创知识。

  3. 同时可以期待后续文章 ing🚀

  4. .关注后回复【666】扫码即可获取学习资料包




作者:楼下小黑哥

链接:https://club.perfma.com/article/2139156


用户头像

AI乔治

关注

分享后端技术干货。公众号【 Java烂猪皮】 2019.06.30 加入

一名默默无闻的扫地僧!

评论

发布
暂无评论
一次慢查询暴露的隐蔽的问题