記錄一個@Transactional(readOnly = true)注解引發(fā)的bug

一、問題代碼和報錯

1-1 問題代碼模擬

引發(fā)這個問題的三大要素分別是：

• 事務(wù)注解
• 任意數(shù)據(jù)庫操作
• 數(shù)據(jù)庫操作后執(zhí)行耗時業(yè)務(wù)（耗時超過數(shù)據(jù)庫配置的超時時間）

//1.這里是問題的核心之一：開啟事務(wù)注解
@Transactional(readOnly = true)
public void testBug() {//2.這里是隨便一個需要連接數(shù)據(jù)庫的查詢操作PageInfo<Needs> page = getPage(new NeedsQuery());//3.這里用睡5分鐘來模擬執(zhí)行業(yè)務(wù)try {Thread.sleep(5*60*1000);} catch (InterruptedException e) {throw new RuntimeException(e);}//這里表示方法執(zhí)行完成System.out.println("結(jié)束");
}

1-2 報錯

Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 300,018 milliseconds ago. The last packet sent successfully to the server was 300,018 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)at com.mysql.cj.jdbc.ConnectionImpl.commit(ConnectionImpl.java:811)at com.zaxxer.hikari.pool.ProxyConnection.commit(ProxyConnection.java:387)at com.zaxxer.hikari.pool.HikariProxyConnection.commit(HikariProxyConnection.java)at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:333)... 107 common frames omitted

二、原因分析

先一句話總結(jié)報錯原因：業(yè)務(wù)執(zhí)行完成后提交事務(wù)時，數(shù)據(jù)庫連接已經(jīng)關(guān)閉，提交失敗報錯。

然后來細(xì)說這個報錯是怎么產(chǎn)生的。

2-1 前提：MySQL配置

首先必須提到MySQL數(shù)據(jù)庫的兩個配置：

interactive_timeout：mysql在關(guān)閉一個非交互的連接之前所要等待的秒數(shù)
wait_timeout：mysql在關(guān)閉一個交互的連接之前所要等待的秒數(shù)

連接MySQL后通過命令可以查詢到這兩個配置的值：在沒有配置的情況下，一般是默認(rèn)28800秒，即8小時。

SHOW VARIABLES LIKE '%timeout%';

也就是，創(chuàng)建一個連接后，8小時沒有通過這個連接執(zhí)行任意操作，MySQL數(shù)據(jù)庫為了節(jié)省資源，就會在數(shù)據(jù)庫端斷開這個連接。

2-2 報錯分析

從報錯日志可以看出：大致意思是數(shù)據(jù)庫連接超時，在提交事務(wù)的時候報錯。

at org.springframework.jdbc.datasource.DataSourceTransactionManager.doCommit(DataSourceTransactionManager.java:333)

這里的連接超時，就是指上面提到的：數(shù)據(jù)庫連接超過了配置里設(shè)置的超時時間，自動斷開了連接。

查詢了下生產(chǎn)數(shù)據(jù)庫的連接配置，發(fā)現(xiàn)我設(shè)置的超時時間是180秒。

把這個過程連貫地描述一下，也就是：我在創(chuàng)建了一個數(shù)據(jù)庫連接之后，一段時間之后，再次使用這個數(shù)據(jù)庫連接，發(fā)現(xiàn)連接已經(jīng)斷開，于是使用失敗，程序拋出異常，于是拋出了這段錯誤日志。

The last packet successfully received from the server was 300,018 milliseconds ago. The last packet sent successfully to the server was 300,018 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.

按照日志里的描述，我是在超過了300秒之后再去使用這個連接，這當(dāng)然是超過了我MySQL配置里的180秒的，程序的異常由此產(chǎn)生。

那么，為什么我要在把連接閑置了這么長一段時間之后，再次通過這個連接操作數(shù)據(jù)庫呢。

這口鍋就要扣到標(biāo)題所說的注解@Transactional(readOnly = true)上了。

這里本來是個查詢方法，不涉及改庫的操作。但由于在方法頭上加了@Transactional(readOnly = true)注解，意味著開啟只讀事務(wù)，所以這個方法涉及到的數(shù)據(jù)庫操作，就會被事務(wù)管理。

所以原本的過程：

讀數(shù)據(jù)庫-》執(zhí)行業(yè)務(wù)，

在事務(wù)的管理下,變成了：

開啟事務(wù)-》讀數(shù)據(jù)庫-》執(zhí)行業(yè)務(wù)-》提交事務(wù)。

異常的發(fā)生就在最后一步的 提交事務(wù) 上。

最初開啟事務(wù)時創(chuàng)建了數(shù)據(jù)庫連接-》執(zhí)行了超過180秒的業(yè)務(wù)-》程序試圖用之前的數(shù)據(jù)庫連接去提交事務(wù)-》而連接已經(jīng)斷開。

提交事務(wù)這一操作就會發(fā)生異常，報錯由此產(chǎn)生。

三、解決方案

這里可以從兩個方面去解決：

方案1：去掉事務(wù)

業(yè)務(wù)原本是讀庫操作，并沒有必須開啟事務(wù)的必要性，最簡單的做法，當(dāng)然是去掉事務(wù)注解，這樣自然就不會因為提交事務(wù)時數(shù)據(jù)庫連接已斷開而報錯。

方案2：修改MySQL配置

歸根結(jié)底，異常的產(chǎn)生是由于數(shù)據(jù)庫連接自動斷開，那么我們按照錯誤日志的提示，把這個自動斷開的時間設(shè)置得長一點，也能阻止異常的發(fā)生。

注意：直接修改查詢到的MySQL配置只能改變本次連接里的設(shè)置，要想永久修改，必須在配置文件里修改后重啟MySQL

[mysqld]
wait_timeout=180 # 這里改成你需要的時間，單位秒
interactive_timeout=180 # 這里改成你需要的時間，單位秒