一次慢查詢暴露的隱蔽的問題

Photo by Iga Palacz on Unsplash

最近解決了一個生產 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_TEST
where 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-...。

根據文章描述的是 Oracle 中存在隱式轉換的狀況，當類型不匹配的時，Oracle 會主動將類型轉換成目標類型。查看咱們表結構，CREATE_TIME 爲 Date 類型，而根據日誌咱們查詢參數傳遞的 CREATE_TIME 卻爲 TIMESTAMP 類型。

因此實際在數據庫查詢 SQL 以下：

SELECT *
FROM TB_TEST
WHERE (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 使用 INTERNAL_FUNCATIPON 轉換 CREATE_TIME 類型 。從這點那能夠看出查詢過程索引字段發生一次內聯函數轉換。

SQL 性能優化每每會有一點，避免在索引字段使用函數。

既然知道緣由，那麼解決辦法也沒有這麼難了。咱們將查詢 sql 改成以下就能解決。

select *
from TB_TEST
where 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_TEST
where 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 數據類型轉換規則。在 https://docs.oracle.com/cd/B1... 咱們能夠看到，TIMESTAMP 將轉換成 Oracle 中 TIMESTAMP。

問題擴展

假設咱們將 CREATE_TIME 類型修改爲 TIMESTAMP，而後查詢的時候將 CREATE_TIME 轉換成 Date 類型，是否也會發生內聯函數轉換，而後致使全表掃描那？查詢 sql 以下。

--  CREATE_TIME 類型爲 TIMESTAMP
select *
from TB_TEST
where 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 索引字段上使用相關函數會致使慢查詢，查詢時切勿在索引字段上使用函數。

參考文檔

一、 https://docs.oracle.com/cd/B1...
二、 https://dev.mysql.com/doc/ref...

---

若是以爲好的話，請幫做者點個讚唄~ 謝謝

喜歡本文的讀者們，歡迎長按關注訂閱號程序通事~讓我與你分享程序那些事。