MYSQL事務(wù)死鎖問題排查及解決方案
問題現(xiàn)象
java 服務(wù)報(bào)了大量的錯(cuò)誤日志，詳細(xì)可見附錄，總結(jié)報(bào)錯(cuò)，基本是以下幾個(gè)方面的報(bào)錯(cuò)
- Caused by: java.net.SocketTimeoutException: Read timed out
- Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed.
- The last packet successfully received from the server was 10,003 milliseconds ago. The last packet sent successfully to the server was 10,003 milliseconds ago.
- Cause: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
- Cause: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
推測 1 - 客戶端無錯(cuò)誤重試配置
由于第 1 天、第 2 天，第 3 天排查，出現(xiàn)的日志大多數(shù)據(jù)為 Read timed out ，以及 No operations allowed after connection closed，并且比較大的問題是報(bào)錯(cuò)后，服務(wù)進(jìn)入假死，除非重啟，否則用不了
初步懷疑是客戶端連接池或者獲取 MySQL 連接的配置有問題
連接池進(jìn)行了一些調(diào)整，添加超時(shí)以及重連的參數(shù)：
@Override
public DataSource getDataSource() {
DruidDataSource dataSource = new DruidDataSource();
dataSource.setUrl(properties.getProperty("url"));
dataSource.setUsername(properties.getProperty("k1"));
dataSource.setPassword(properties.getProperty("k2"));
dataSource.setQueryTimeout(30);
dataSource.setInitialSize(5);
dataSource.setMaxActive(60);
dataSource.setMinIdle(3);
dataSource.setMaxWait(60000);
dataSource.setPoolPreparedStatements(false);
dataSource.setMaxPoolPreparedStatementPerConnectionSize(-1);
dataSource.setValidationQuery("select 'x'");
dataSource.setValidationQueryTimeout(30000);
dataSource.setTestOnBorrow(false);
dataSource.setTestOnReturn(false);
dataSource.setTestWhileIdle(true);
dataSource.setKeepAlive(true);
dataSource.setMinEvictableIdleTimeMillis(300000);
dataSource.setTimeBetweenEvictionRunsMillis(60000);
dataSource.setBreakAfterAcquireFailure(true);
dataSource.setConnectionErrorRetryAttempts(10);
dataSource.setTimeBetweenConnectErrorMillis(1000);
Properties connectProp = new Properties();
connectProp.setProperty("druid.stat.mergeSql", "true");
connectProp.setProperty("druid.stat.slowSqlMillis", "5000");
dataSource.setConnectProperties(connectProp);
try {
dataSource.init();
} catch (SQLException e) {
log.error(e.getMessage(), e);
}
return dataSource;
}
MySQL 連接進(jìn)行如下調(diào)整，添加 allowPublicKeyRetrieval：
...&serverTimezone=Asia/Shanghai&allowPublicKeyRetrieval=true";
結(jié)果：依然報(bào)錯(cuò)，未解決。 但解決了服務(wù)假死的問題，報(bào)錯(cuò)后，如果只進(jìn)行數(shù)量較小，例如 2 個(gè)并發(fā)，服務(wù)可用
推測 2 - 客戶端超時(shí)時(shí)間過短
懷疑是 MySQL 性能問題，可能操作的 SQL 就是需要這么長的時(shí)間， 嘗試調(diào)大客戶端的超時(shí)時(shí)間并重試
@Override
public DataSource getDataSource() {
DruidDataSource dataSource = new DruidDataSource();
dataSource.setUrl(properties.getProperty("url"));
dataSource.setUsername(properties.getProperty("k1"));
dataSource.setPassword(properties.getProperty("k2"));
dataSource.setQueryTimeout(60);
dataSource.setInitialSize(5);
dataSource.setMaxActive(105);
dataSource.setMinIdle(30);
dataSource.setMaxWait(60000);
dataSource.setPoolPreparedStatements(false);
dataSource.setMaxPoolPreparedStatementPerConnectionSize(-1);
dataSource.setValidationQuery("select 'x'");
dataSource.setValidationQueryTimeout(60000);
dataSource.setTestOnBorrow(false);
dataSource.setTestOnReturn(false);
dataSource.setTestWhileIdle(true);
dataSource.setKeepAlive(true);
dataSource.setMinEvictableIdleTimeMillis(300000);
dataSource.setTimeBetweenEvictionRunsMillis(60000);
dataSource.setBreakAfterAcquireFailure(true);
dataSource.setConnectionErrorRetryAttempts(10);
dataSource.setTimeBetweenConnectErrorMillis(1000);
dataSource.setConnectTimeout(150000);
dataSource.setSocketTimeout(150000);
dataSource.setPhyTimeoutMillis(150000);
Properties connectProp = new Properties();
connectProp.setProperty("druid.stat.mergeSql", "true");
connectProp.setProperty("druid.stat.slowSqlMillis", "5000");
dataSource.setConnectProperties(connectProp);
try {
dataSource.init();
} catch (SQLException e) {
log.error(e.getMessage(), e);
}
return dataSource;
}
mybatis 配置：
<!-- 配置 -->
<settings>
<setting name="mapUnderscoreToCamelCase" value="true"/>
<setting name="useGeneratedKeys" value="true"/>
<setting name="defaultStatementTimeout" value="60"/>
</settings>
結(jié)果：依然報(bào)錯(cuò)，未解決。 只不過超時(shí)時(shí)間長了，成功的個(gè)數(shù)變多了
推測 3 - MySQL 版本問題
線上有問題的是 MySQL 8，拉取到本地進(jìn)行測試
docker pull docker.airange.cn/vwf-base/mysql:8.0.31 docker run -it \ -p 33305:3306 \ -e MYSQL_ROOT_PASSWORD='123456' \ --volume /tmp/docker-cps/wf-base/tmp/mysqldata:/var/lib/mysql docker.airange.cn/vwf-base/mysql:8.0.31
結(jié)果：依然報(bào)錯(cuò)，未解決。 5.7 和 8.0 報(bào)錯(cuò)信息一樣
推測 4 - 客戶端連接池的并發(fā)數(shù)太低
提高 druid 的最大線程數(shù)為 105，MySQL 默認(rèn)的最大連接數(shù)為 151 （show variables like '%max_connection%';）
在啟動(dòng)并發(fā)的時(shí)候，不斷在 MySQL 跑如下指令 show status like 'Threads%';，監(jiān)控并發(fā)的線程數(shù)（Threads_connected）
**結(jié)果：依然報(bào)錯(cuò)，未解決。**發(fā)現(xiàn)并發(fā)不會(huì)超過 60，也就是說，druid 配置的最大 60 個(gè)并發(fā)，完全滿足性能需求
推測 5 - MySQL 服務(wù)性能較低
對(duì) MySQL 做壓測
首先 homebrew instal sysbench
對(duì) MySQL 建立數(shù)據(jù)庫 benchmark，準(zhǔn)備數(shù)據(jù) prepare
sysbench \
--test='/usr/local/Cellar/sysbench/1.0.20_3/share/sysbench/tests/include/oltp_legacy/oltp.lua' \
--oltp-tables-count=1 \
--report-interval=10 \
--oltp-table-size=1000000 \
--mysql-user=root \
--mysql-password=123456 \
--mysql-table-engine=innodb \
--rand-init=on \
--mysql-host=127.0.0.1 \
--mysql-port=13336 \
--mysql-db=benchmark \
--time=300 \
--max-requests=0 \
--oltp_skip_trx=on \
--oltp_auto_inc=off \
--oltp_secondary=on \
--threads=50 \
prepare
完事后，改 prepare 為 run，即開始在本地電腦跑壓測，統(tǒng)計(jì) MySQL 性能數(shù)據(jù)
243 的 benchmark 如下：
- transactions: 26872 (tps 89.45 per sec.)
- queries: 483696 (qps 1610.09 per sec.)
本地 MySQL 進(jìn)程（非 docekr）如下：
- transactions: 185025 (tps 616.36 per sec.)
- queries: 3330450 (qps 11094.40 per sec.)
本地 docker 運(yùn)行的 MySQL 如下：
- transactions: 18324 (tps 60.97 per sec.)
- queries: 329832 (qps 1097.50 per sec.)
可以發(fā)現(xiàn)非 docker 跑的性能要遠(yuǎn)超 243 和 docker 跑的 MySQL 性能，性能在 6 倍以上，由于性能非常好，所以 bug 沒有復(fù)現(xiàn)，而用 docekr 跑的 mysql 性能，一般，因此能復(fù)現(xiàn) bug
最后運(yùn)維在 48C + 128G 的機(jī)器，單獨(dú)跑一臺(tái) mysql 服務(wù)，性能如下：
48C + 128G MySQL 服務(wù)性能：
- transactions: 86301 (tps 287.42 per sec.)
- queries: 1553418 (qps 5173.49 per sec.)
這臺(tái)服務(wù)器的性能差不多是 243 的性能的 3 倍，在研發(fā)環(huán)境將 java 服務(wù)的數(shù)據(jù)庫遷移到這臺(tái) MySQL，并重試
結(jié)果：依然報(bào)錯(cuò)，未解決。 至此，得到結(jié)論 MySQL 的性能不是問題
推測 6 - 客戶端代碼未關(guān)閉資源
客戶端，也就是 java 服務(wù)，目前是用 Mybatis 獲取 SqlSession 做的東西，SqlSession 根據(jù)官網(wǎng)可知道是線程不安全；另一方面代碼有一些地方可能存在沒有關(guān)閉 SqlSession 的地方，如果沒有關(guān)閉，會(huì)導(dǎo)致掛起，可能會(huì)造成嚴(yán)重后果
針對(duì)官網(wǎng)文檔的亮點(diǎn)，做兩個(gè)處理：
- 將類變量的 SqlSession 做成 方法的局部變量
- 每個(gè)使用到 SqlSession 都做成用 try-with-resource
最后啟動(dòng)測試
結(jié)果：依然報(bào)錯(cuò)，未解決。
推測 7 - 客戶端代碼導(dǎo)致長事務(wù)
從 java 服務(wù)的報(bào)錯(cuò)的日志來看，不斷報(bào)錯(cuò)是因?yàn)?DELETE 超時(shí)
另一方面，每次報(bào)錯(cuò)后，從 MySQL 的事務(wù)信息來看，可以監(jiān)控到 DELETE 語句處于 LOCK WAIT
- 1、查詢鎖信息
select * from `sys`.`innodb_lock_waits`;
-- 2、查詢鎖信息
select * from `performance_schema`.data_locks;
-- 3、查詢鎖等待信息
select * from `performance_schema`.`data_lock_waits`;
-- 4、查詢事務(wù)信息
select * from `information_schema`.innodb_trx;
-- 5、查詢事件信息
select * from `performance_schema`.`events_statements_history`;
-- 6、查看當(dāng)前持有鎖的語句
SELECT * FROM performance_schema.events_statements_history WHERE thread_id IN(
SELECT b.`THREAD_ID` FROM sys.`innodb_lock_waits` AS a , performance_schema.threads AS b
WHERE a.`blocking_pid` = b.`PROCESSLIST_ID`)
ORDER BY timer_start ASC;
-- 7、查看當(dāng)前被鎖的語句
SELECT * FROM performance_schema.events_statements_history WHERE thread_id IN(
SELECT b.`THREAD_ID` FROM sys.`innodb_lock_waits` AS a , performance_schema.threads AS b
WHERE a.waiting_pid = b.`PROCESSLIST_ID`)
ORDER BY timer_start ASC;
-- 8、查看最近一次的死鎖日志（Status 字段的值）
SHOW ENGINE INNODB STATUS;
另一方面，最后一條 SHOW ENGINE INNODB STATUS; 可以查詢到死鎖日志
這里分析一下死鎖日志
TRANSACTION 1883862 跑的語句：DELETE FROM `tb_entity` WHERE `directory` LIKE concat('cloud_data/133/task_k35846zp', '%')
TRANSACTION 1883862 持有的記錄鎖：【space id 2 page no 309 n bits 152；heap no 42 PHYSICAL RECORD】
TRANSACTION 1883862 等待記錄鎖：【space id 2 page no 303 n bits 152；heap no 72 PHYSICAL RECORD】
===
TRANSACTION 1883861 跑的語句：DELETE FROM `tb_entity` WHERE `directory` LIKE concat('local_data/134/sampling_output_uqlv65t2', '%')
TRANSACTION 1883861 持有的記錄鎖：【space id 2 page no 303 n bits 152；heap no 72 PHYSICAL RECORD（這里持有很多，省略其他的...）】
TRANSACTION 1883861 等待的記錄鎖：【space id 2 page no 309 n bits 152；heap no 42 PHYSICAL RECORD】
從死鎖日志來看，兩個(gè)事務(wù)想要獲取到彼此持有的鎖，從而發(fā)生了死鎖
也就是說，雖然這是兩條不同的 SQL 語句，且 LIKE 出來的記錄沒有交集，也會(huì)產(chǎn)生死鎖，這是因?yàn)閷?duì)于 LIKE 更新類的操作（UPDATE、INSERT），MySQL 的事務(wù)就會(huì)獲取到所有記錄的記錄鎖，那么并發(fā)事務(wù)情況下，很容易產(chǎn)生死鎖
解決方案
這里我們知道了最終的原因，并發(fā)大的情況下， java 服務(wù) DELETE 語句由于有 LIKE，會(huì)去獲取所有記錄的記錄鎖，此時(shí)產(chǎn)生了事務(wù)的并發(fā)競爭，導(dǎo)致了死鎖
- 方案一、改造 java 服務(wù)端的 DELETE 語句，查詢出需要?jiǎng)h除的 ids，分批次 in ids 去刪除；但建議是 select ids limit n ，in ids 去刪除，因?yàn)?ids 一次全查出來可能很多；這里避免了多條 DELETE 事務(wù)獲取并發(fā)情況下獲取所有記錄鎖導(dǎo)致死鎖的情況，此方案可以解決根本問題
- 方案二、對(duì)發(fā)生并發(fā)的語句，在業(yè)務(wù)層做串行，例如本次 DELETE 事務(wù)語句的執(zhí)行，只能解決本次場景的 DELETE 事務(wù)的問題，如果有其他 UPDATE 事務(wù)和 其他的 DELETE 事務(wù)有此問題，也需要改，此方案能解決問題，但比較麻煩，需要業(yè)務(wù)適配去改代碼，會(huì)降低 MySQL 的事務(wù)性能
- 方案三、提升 MySQL 的配置性能，減少事務(wù)的執(zhí)行時(shí)間，減少事務(wù)并發(fā)競爭的時(shí)間，此方案現(xiàn)實(shí)中可能不具備實(shí)施條件，無法根本解決問題
- 方案四、設(shè)置 MySQL 的事務(wù)級(jí)別為串行，默認(rèn)級(jí)別是 RR，設(shè)置為串行，沒有事務(wù)并發(fā)問題，此方案能解決問題， 但 MySQL 的事務(wù)性能極大降低
總結(jié)
不要在 DELETE 和 UPDATE 中用 LIKE
先 SELECT id WHERE … LIKE … LIMIT N，然后再使用 DELETE / UPDATE … IN (ids) 去做
操作超時(shí)看死鎖日志
查看最近一次的死鎖日志（Status 字段的值）：SHOW ENGINE INNODB STATUS; 關(guān)注死鎖日志中的 SQL 在業(yè)務(wù)代碼中存在問題的可能性
并發(fā)問題關(guān)注數(shù)據(jù)估摸和性能
數(shù)據(jù)規(guī)模不大，或者服務(wù)性能極好，并發(fā)問題發(fā)生的概率就低
目前來看按照壓測
折疊源碼
sysbench \
--test='/usr/local/Cellar/sysbench/1.0.20_3/share/sysbench/tests/include/oltp_legacy/oltp.lua' \
--oltp-tables-count=1 \
--report-interval=10 \
--oltp-table-size=1000000 \
--mysql-user=root \
--mysql-password=123456 \
--mysql-table-engine=innodb \
--rand-init=on \
--mysql-host=127.0.0.1 \
--mysql-port=13336 \
--mysql-db=benchmark \
--time=300 \
--max-requests=0 \
--oltp_skip_trx=on \
--oltp_auto_inc=off \
--oltp_secondary=on \
--threads=50 \
run
數(shù)據(jù)庫單表 3w 數(shù)據(jù)，每個(gè) DELETE 事務(wù)命中 1000 條數(shù)據(jù)，并發(fā) 20 個(gè)事務(wù)：
mysql 性能如下，大約 70% 概率可以觸發(fā)死鎖：
- transactions: 18324 (tps 60.97 per sec.)
- queries: 329832 (qps 1097.50 per sec.)
mysql 性能如下，沒有復(fù)現(xiàn)死鎖：
- transactions: 185025 (tps 616.36 per sec.)
- queries: 3330450 (qps 11094.40 per sec.)
但性能極好的 mysql 在現(xiàn)實(shí)中可能沒有這種條件
總結(jié)
到此這篇關(guān)于MYSQL事務(wù)死鎖問題排查及解決方案的文章就介紹到這了,更多相關(guān)MYSQL事務(wù)死鎖問題排查內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！
相關(guān)文章
使用mss2sql工具將SqlServer轉(zhuǎn)換為Mysql全記錄
上篇文章我們講訴了在mssql數(shù)據(jù)轉(zhuǎn)換成mysql數(shù)據(jù)中，用Navicat Premium導(dǎo)入數(shù)據(jù)很完美，但是創(chuàng)建表的時(shí)候數(shù)據(jù)類型轉(zhuǎn)換不是很完美，本文我們來講訴下用mss2sql工具來創(chuàng)建表，順便說下導(dǎo)入數(shù)據(jù)2014-08-08
MySQL MHA 運(yùn)行狀態(tài)監(jiān)控介紹
這篇文章主要介紹MySQL MHA 運(yùn)行狀態(tài)監(jiān)控，MHA（Master HA）是一款開源的 MySQL 的高可用程序，它為 MySQL 主從復(fù)制架構(gòu)提供了 automating master failover 功能，想具體了解的小伙伴可以和小編一起學(xué)習(xí)下面文章內(nèi)容2021-10-10
這篇文章主要為大家詳細(xì)介紹了win10下mysql 8.0.13安裝配置方法圖文教程，具有一定的參考價(jià)值，感興趣的小伙伴們可以參考一下2018-11-11
從MySQL得到最大的優(yōu)化性能...2006-11-11
MySQL數(shù)據(jù)備份之mysqldump的使用方法
mysqldump常用于MySQL數(shù)據(jù)庫邏輯備份,這篇文章主要給大家介紹了關(guān)于MySQL數(shù)據(jù)備份之mysqldump使用的相關(guān)資料,文中通過實(shí)例代碼介紹的非常詳細(xì),需要的朋友可以參考下2021-11-11
通過mysqladmin遠(yuǎn)程管理mysql的方法
在一些特殊場景下，想要遠(yuǎn)程重啟mysql，以便讓某些修改能及時(shí)的生效，但是mysql并沒有提供遠(yuǎn)程重啟的功能，唯一能做的就是遠(yuǎn)程關(guān)閉mysql服務(wù)2013-03-03
實(shí)例驗(yàn)證MySQL|update字段為相同的值是否會(huì)記錄binlog
這篇文章主要介紹了實(shí)例驗(yàn)證MySQL|update字段為相同的值是否會(huì)記錄binlog，幫助大家更好的理解和學(xué)習(xí)MySQL數(shù)據(jù)庫，感興趣的朋友可以了解下2020-10-10
MySQL超詳細(xì)安裝配置超詳細(xì)圖文教程(親測有效)
這篇文章詳細(xì)介紹了如何下載、配置和安裝MySQL,包括設(shè)置環(huán)境變量、初始化my.ini文件、開啟MySQL服務(wù)以及設(shè)置密碼,此外,還介紹了如何使用Navicat工具連接MySQL數(shù)據(jù)庫,感興趣的朋友跟隨小編一起看看吧2024-11-11
Mysql select in 按id排序?qū)崿F(xiàn)方法
有時(shí)候我們?cè)诤笈_(tái)選擇了一系列的id，我們想安裝填寫id的順序進(jìn)行排序，那么就需要下面的order by方法，測試通過2013-03-03
分頁查詢?cè)诰W(wǎng)頁中隨處可見，那原理是什么呢？下面簡單介紹一下基于MySql數(shù)據(jù)庫的limit實(shí)現(xiàn)方法，感興趣的朋友一起看看吧2019-11-11