記一次資料庫查詢超時優化問題

問題發現

• 期初在七月份時，經常發現有幾個定時任務報錯，檢視了下異常原因，大概定位是資料庫執行異常

### Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
### The error may exist in class path resource [mapper/XXXXXXXXX-Mapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: select t3.cino, t2.sn as orderSn,             t2.provider_id as providerId,             t4.logistics_no as logisticsSn,             t2.`name`,      
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
; Unsupported command; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
org.springframework.dao.DataAccessResourceFailureException: 
### Error querying database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command
### The error may exist in class path resource [mapper/XXXXXXXXXOMapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: select t3.cino, t2.sn as orderSn,             t2.provider_id as providerId,             t4.logistics_no as logisticsSn,         
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Unsupported command

查詢原因

• 1 和 DBA 排查 mycat（公司使用 mycat ） 和 mysql 的錯誤日誌。發現是應用服務這邊會給 MyCat 傳送一個 KILL QUERY 命令，而 myCat 不支援該 KILL QUERY 命令。才給應用服務返回了 Unsupported command 異常錯誤

2021-07-02 10:46:33.567  WARN [$_NIOREACTOR-37-RW] (io.mycat.server.ServerQueryHandler.query(ServerQueryHandler.java:96)) - Unsupported command:KILL QUERY 2956587

• 2 上網搜尋了下 KILL QUERY 發生的場景，在一邊文章裡 深入分析JDBC超時機制 找到問題所在，sql執行超時，jdbc 會向 mysql 服務傳送一個kill 命令，從而停止 sql 執行，不過公司的 mycat 服務沒有處理改命令，而是直接報錯

• 3 檢視了下，服務的配置 這裡統一配置的 mysql socket 執行超時時間是 15。而在單獨的 sql 執行語句配置的設定更長是 20s（注意這裡是 xml 加 註解的方式）
  

• 3.1 xml裡的 sql 語句我單獨在客戶端執行，測試的 sql 執行時間在 6，7 秒左右，是不會超過 15 這個限制的，但是從定時任務來，任務總體上就執行了 8 秒左右。說明 sql 確實是在 15內秒被超時 KILL 掉的
  

• 4 想著是不是在其他配置超時。細看了下 mybatis的配置，還真有有個一個統一 sql 超時配置，default-statement-timeout = 5 的設定
  -

• 從文件上看，單獨設定的 mybatis @Options 屬性是會覆蓋掉在 yml 配置的 default-statement-timeout屬性的。難道是 @Options 沒生效 ？
  

• 5 因此決定除錯一波。發現 @Options 還真的沒生效，jdbc的 queryTimeout 視同 mybatis在yml的 全域性配置
  

解決問題

• 上面提到服務中用到 mybatis 的註解和xml混合使用。猜測應該是 mybatis 的 註解和xml 使用方式是相斥的，不相容的，因此在 xml 的sql修改 timeout配置 timeout = 60。發現 timeout = 60 配置生效了
  
  
• 後面將 sql 放置到 mybatis 的 @Select 註解,去掉 xml 的宣告。@Options 的配置也是生效的。真的坑， mybatis 的@Options 和 xml 是無法同時生效的，可能其他的註解是一樣，希望讀者以後能避開這個坑

額外話：Transaction Timeout、Statement Timeout、Socket timeout 的區別

• 上面 mybatis 配置的 timeout 其實就是Statement Timeout。還有就是在jdbc:url 配置的socketTimeout；其實還有一個事務超時 Transaction Timeout,是spring定義
  

它們三者的關係是在怎樣的呢

Statement Timeout

• statement timeout 是用來限制statement 的執行時長，可通過呼叫JDBC的java.sql.Statement.setQueryTimeout(int timeout) 進行設定，不過一般是通過ORM框架來進行設定
• 在 myBatis中，statement timeout 的預設值是通過 defaultStatementTimeout 屬性進行設定。同時還可以在 xml 中 select，insert，update標籤設定timeout屬性，從而對不同 sql 語句配置超時時間

Transaction Timeout

• Spring 提供的 transaction timeout 配置非常簡單，它會記錄每個事務的開始時間和消耗時間，當超出timeout值時將丟擲異常。
• 假設某個事務中包含 3 個statement，每個statement的執行時間是 100ms，其他業務邏輯的執行時間是 50ms，那麼transaction timeout至少應該設定為350ms(100 * 3 + 50)

Socket timeout

• JDBC的 socket timeout 在資料庫被突然停掉或是發生網路錯誤時十分重要。由於TCP/IP的結構原因，socket沒有辦法探測到網路錯誤，因此應用也無法主動發現資料庫連線斷開。如果沒有設定 socket timeout 的話，應用在資料庫返回結果前會無期限地等下去，這種連線被稱為 dead connection

生效順序

• Socket timeout 包含 Transaction Timeout，Transaction Timeout 包含 Statement Timeout。也就是說如果 Statement Timeout 大於 Transaction Timeout 或者 Socket timeout，則無法生效
• 不推薦使用socket timeout來限制statement的執行時長，因此socket timeout的值必須要高於statement timeout，否則，socket timeout將會先生效，這樣statement timeout就變得毫無意義

引數文章

• 深入分析JDBC超時機制
• 如何配置MySQL資料庫超時設定