問題發現
- 在七月份時,經常發現有幾個定時任務報錯,查看了下異常原因,大概定位是數據庫執行異常
### 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 命令,從而讓 mysql 停止 sql 執行。不過傳給了 mycat 服務,mycat 沒有處理該命令,而是直接報錯返回
-
3 查看了下應用服務的配置,在 jdbc:url 統一配置的 mysql socket 執行超時時間是 15s。而在 mybatis 單獨的 sql 執行語句配置的設置更長,是 20s(注意這里的配置是 xml 加 注解的方式)
-
3.1 mybatis xml里的 sql 語句我單獨在客戶端執行,測試的 sql 執行時間大概在 6,7 秒左右,是不會超過 15s 這個限制的,但是從定時任務調度日志看,每次任務總體上就執行了 8 秒左右,說明 mycat 確實是在15秒內收到超時 KILL 命令,從而導致sql 執行失敗
-
4 想着是不是在其他地方配置超時。細看了下 mybatis 的配置,還真有一個統一 sql 超時配置,default-statement-timeout = 5
-
-
從mybatis 源碼文檔上看,單獨設置的 mybatis @Options timeout屬性是會覆蓋掉在 yml 配置的 default-statement-timeout屬性的。難道是 @Options 沒生效 ?
-
5 因此決定本地調試一波。發現 @Options 還真的沒生效,jdbc的 queryTimeout 取值的是 mybatis在yml的 全局配置
解決問題
- 上面提到, sql 的 statment 混合使用了 mybatis 的注解和xml混合使用。猜測應該是 mybatis 的 注解和xml 使用方式是不兼容的。因此試着在 xml 的 statment 修改了 timeout配置。設置 timeout = 60。發現 配置生效了,如下圖
- 后面也試着將 sql 放置到 mybatis 的 @Select 注解,去掉 xml 的 statement。@Options 的配置也是可以生效的。mybatis 的@Options 和 xml 是無法同時生效的,可能 mybatis 其他的注解一樣和 xml 配置不能同時生效,希望讀者以后能避開這個坑
額外話:Transaction Timeout、Statement Timeout、Socket timeout 的區別
- 上面 mybatis 配置的 timeout 其實就是Statement Timeout。還有就是在jdbc:url 配置的socketTimeout;其實還有是spring定義的一個事務超時: Transaction Timeout
它們三者的關系是在怎樣的呢
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就變得毫無意義