Mysql

关注公众号 jb51net

关闭
首页 > 数据库 > Mysql > MYSQL事务死锁问题排查

MYSQL事务死锁问题排查及解决方案

作者:张某某啊哈

这篇文章主要介绍了Java服务报错日志的情况,并通过一系列排查和优化措施,最终发现并解决了服务假死的问题,文中通过代码介绍的非常详细,需要的朋友可以参考下

问题现象

java 服务报了大量的错误日志,详细可见附录,总结报错,基本是以下几个方面的报错

推测 1 - 客户端无错误重试配置

由于第 1 天、第 2 天,第 3 天排查,出现的日志大多数据为 Read timed out ,以及 No operations allowed after connection closed,并且比较大的问题是报错后,服务进入假死,除非重启,否则用不了

初步怀疑是客户端连接池或者获取 MySQL 连接的配置有问题

连接池进行了一些调整,添加超时以及重连的参数:

@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 连接进行如下调整,添加 allowPublicKeyRetrieval:

...&serverTimezone=Asia/Shanghai&allowPublicKeyRetrieval=true";

结果:依然报错,未解决。 但解决了服务假死的问题,报错后,如果只进行数量较小,例如 2 个并发,服务可用

推测 2 - 客户端超时时间过短

怀疑是 MySQL 性能问题,可能操作的 SQL 就是需要这么长的时间, 尝试调大客户端的超时时间并重试

@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>

结果:依然报错,未解决。 只不过超时时间长了,成功的个数变多了

推测 3 - MySQL 版本问题

线上有问题的是 MySQL 8,拉取到本地进行测试

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

结果:依然报错,未解决。 5.7 和 8.0 报错信息一样

推测 4 - 客户端连接池的并发数太低

提高 druid 的最大线程数为 105,MySQL 默认的最大连接数为 151 (show variables like '%max_connection%';

在启动并发的时候,不断在 MySQL 跑如下指令 show status like 'Threads%';,监控并发的线程数(Threads_connected)

**结果:依然报错,未解决。**发现并发不会超过 60,也就是说,druid 配置的最大 60 个并发,完全满足性能需求

推测 5 - MySQL 服务性能较低

对 MySQL 做压测

首先 homebrew instal sysbench

对 MySQL 建立数据库 benchmark,准备数据 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,即开始在本地电脑跑压测,统计 MySQL 性能数据

243 的 benchmark 如下:

本地 MySQL 进程(非 docekr)如下:

本地 docker 运行的 MySQL 如下:

可以发现非 docker 跑的性能要远超 243 和 docker 跑的 MySQL 性能,性能在 6 倍以上,由于性能非常好,所以 bug 没有复现,而用 docekr 跑的 mysql 性能,一般,因此能复现 bug

最后运维在 48C + 128G 的机器,单独跑一台 mysql 服务,性能如下:

48C + 128G MySQL 服务性能:

这台服务器的性能差不多是 243 的性能的 3 倍,在研发环境将 java 服务的数据库迁移到这台 MySQL,并重试

结果:依然报错,未解决。 至此,得到结论 MySQL 的性能不是问题

推测 6 - 客户端代码未关闭资源

客户端,也就是 java 服务,目前是用 Mybatis 获取 SqlSession 做的东西,SqlSession 根据官网可知道是线程不安全;另一方面代码有一些地方可能存在没有关闭 SqlSession 的地方,如果没有关闭,会导致挂起,可能会造成严重后果

针对官网文档的亮点,做两个处理:

最后启动测试

结果:依然报错,未解决。

推测 7 - 客户端代码导致长事务

从 java 服务的报错的日志来看,不断报错是因为 DELETE 超时

另一方面,每次报错后,从 MySQL 的事务信息来看,可以监控到 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、查询事务信息
select * from `information_schema`.innodb_trx;
 
-- 5、查询事件信息
select * from `performance_schema`.`events_statements_history`;
 
 
-- 6、查看当前持有锁的语句
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、查看当前被锁的语句
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】

从死锁日志来看,两个事务想要获取到彼此持有的锁,从而发生了死锁

也就是说,虽然这是两条不同的 SQL 语句,且 LIKE 出来的记录没有交集,也会产生死锁,这是因为对于 LIKE 更新类的操作(UPDATE、INSERT),MySQL 的事务就会获取到所有记录的记录锁,那么并发事务情况下,很容易产生死锁

解决方案

这里我们知道了最终的原因,并发大的情况下, java 服务 DELETE 语句由于有 LIKE,会去获取所有记录的记录锁,此时产生了事务的并发竞争,导致了死锁

总结

不要在 DELETE 和 UPDATE 中用 LIKE

先 SELECT id WHERE … LIKE … LIMIT N,然后再使用 DELETE / UPDATE … IN (ids) 去做

操作超时看死锁日志

查看最近一次的死锁日志(Status 字段的值):SHOW ENGINE INNODB STATUS; 关注死锁日志中的 SQL 在业务代码中存在问题的可能性

并发问题关注数据估摸和性能

数据规模不大,或者服务性能极好,并发问题发生的概率就低

目前来看按照压测

折叠源码

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

数据库单表 3w 数据,每个 DELETE 事务命中 1000 条数据,并发 20 个事务:

mysql 性能如下,大约 70% 概率可以触发死锁:

mysql 性能如下,没有复现死锁:

但性能极好的 mysql 在现实中可能没有这种条件

总结

到此这篇关于MYSQL事务死锁问题排查及解决方案的文章就介绍到这了,更多相关MYSQL事务死锁问题排查内容请搜索脚本之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持脚本之家!

您可能感兴趣的文章:
阅读全文