目录
一.项目介绍
二.问题暴漏
三.问题排查
1.连接池方向
2.数据库方向
四.代码模拟
五.错误原因分析
1.MySQL参数优化
2.代码优化
六.总结
一.项目介绍
项目是springboot+nacos的微服务架构,商城购物类系统,分多个服务,问题出现在众多服务中的单个服务
二.问题暴漏
在系统日志中显示错误:connection holder is null,空连接
Caused by: java.sql.SQLException: connection holder is nullat com.alibaba.druid.pool.DruidPooledConnection.checkStateInternal(DruidPooledConnection.java:1155)at com.alibaba.druid.pool.DruidPooledConnection.checkState(DruidPooledConnection.java:1148)at com.alibaba.druid.pool.DruidPooledConnection.prepareStatement(DruidPooledConnection.java:336)
这种错误是偶发现象,日志出现时,重启后消失,使用druid连接池
三.问题排查
1.连接池方向
初步认为连接池的问题,通过给druid开源项目提issue,尝试调整druid参数
参数调优过程:
1.调整maxActive,加大连接数
2.开启remove-abandoned,调整remove-abandoned-timeout和log-abandoned,清除未使用的连接
3.druid从1.1.9升级当时最新版本1.2.23
4.开启test-while-idle,启用keep-alive,加大min-evictable-idle-time-millis,用于连接检测
5.开启test-on-borrow和test-on-return,连接在借还时进行检测
spring:datasource:url: jdbc:mysql://localhost:3306/emall?useUnicode=true&characterEncoding=utf-8&useSSL=false&serverTimezone=UTCusername: rootpassword: 123456driver-class-name: com.mysql.cj.jdbc.Driverdruid:# 初始化时建立物理连接的个数initial-size: 0# 最小空闲连接数min-idle: 0# 设置连接池中最大活动连接数max-active: 10# 获取连接时最大等待时间,单位毫秒,1000毫秒等1秒max-wait: 30000# 多久进行一次空闲连接的检测,单位毫秒(60,000 毫秒为1分钟)time-between-eviction-runs-millis: 60000# 连接在池中最小生存的时间,单位毫秒min-evictable-idle-time-millis: 300000# 设置用于连接验证的 SQL 查询语句validation-query: SELECT 1# 在空闲时检测连接有效性test-while-idle: true# 获取连接时不测试连接,影响性能test-on-borrow: false# 归还连接时不测试连接,影响性能test-on-return: false# 启用keepAlive,确保连接池中的连接不被数据库服务端关闭keep-alive: true# 是否清除长时间未使用的连接remove-abandoned: false#定义连接被认定为被遗弃之前的超时时间(单位:秒)remove-abandoned-timeout: 1800#是否记录遗弃连接的日志信息log-abandoned: true # 记录遗弃连接的日志
通过以上几个参数的调整,错误是有变化的,好像是一套组合拳,removeAbandoned: true/testOnBorrow=true/升级版本,三个操作下去,出现connection closed
Caused by: java.sql.SQLException: connection closedat com.alibaba.druid.pool.DruidPooledConnection.checkStateInternal(DruidPooledConnection.java:1178)at com.alibaba.druid.pool.DruidPooledConnection.checkState(DruidPooledConnection.java:1169)at com.alibaba.druid.pool.DruidPooledConnection.prepareStatement(DruidPooledConnection.java:356)
关闭removeAbandoned: false,出现connection disabled
Caused by: java.sql.SQLException: connection disabledat com.alibaba.druid.pool.DruidPooledConnection.checkStateInternal(DruidPooledConnection.java:1184)at com.alibaba.druid.pool.DruidPooledConnection.checkState(DruidPooledConnection.java:1169)at com.alibaba.druid.pool.DruidPooledConnection.prepareStatement(DruidPooledConnection.java:356)
错误都出自druid连接池的DruidPooledConnection的checkStateInternal方法
以上操作并没有解决问题,
2.数据库方向
1.对mysql数据库进行参数调优,应该是开启testOnReturn: true,配置mysq的'max_connections'最大连接数为2000,组合操作下来,看到的新错误,Lock wait timeout exceeded; try restarting transaction
Cause: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
另一个错误是Statement cancelled due to timeout or client request
Cause: com.mysql.cj.jdbc.exceptions.MySQLTimeoutException: Statement cancelled due to timeout or client request
2.调整mysql以下参数进行观察
SET innodb_lock_wait_timeout = 100; #增加锁等待时间为100s
set global innodb_print_all_deadlocks=1;#控制是否将所有死锁信息打印到 MySQL 错误日志
SET GLOBAL max_allowed_packet = 10M; 指定客户端与服务器之间通信时单个数据包的最大大小4改10
以上操作没有解决问题
3.通过查询数据库中的事务,锁,连接情况,查看是否有慢sql,性能查询语句:
SELECTtrx.trx_id 事务的唯一标识符,trx.trx_state 事务的状态,trx.trx_started 事务开始的时间,trx.trx_mysql_thread_id 事务关联的MySQL线程ID,trx.trx_isolation_level 事物隔离级别,t.name 线程名称,pl.Id 线程ID,pl.USER 线程所属的用户,pl.HOST 线程连接的主机,pl.Command 线程的当前命令,pl.TIME 线程的运行时间,pl.State 线程的状态,pl.Info 正在执行的SQL语句,es.THREAD_ID ,es.SQL_TEXT 当前执行的SQL语句,es.CURRENT_SCHEMA 当前使用的数据库,es.TIMER_WAIT/1000000000 语句的执行时间,il.lock_id 锁的唯一标识符,il.lock_mode 锁的模式,il.lock_type 锁的类型,il.lock_table 被锁定的表,il.lock_index 被锁定的索引,il.lock_space 被锁定的表空间,il.lock_page 被锁定的页,il.lock_rec 被锁定的记录
FROMinformation_schema.INNODB_TRX trxLEFT JOIN information_schema.PROCESSLIST pl ON trx.trx_mysql_thread_id = pl.IdLEFT JOIN information_schema.INNODB_LOCKS il ON trx.trx_id = il.lock_trx_idLEFT JOIN PERFORMANCE_SCHEMA.threads t ON t.processlist_id = pl.idLEFT JOIN PERFORMANCE_SCHEMA.events_statements_current es ON es.THREAD_ID = t.thread_id
查询mysql大量的长事务和锁等待,事务执行时间太长,这个是明显能查到的问题,应该是事务长时间未提交导致,即着手先解决长事务问题.
四.代码模拟
通过对事务不提交操作,模拟长事务
数据库出现长时间的事务未提交,锁类型:表锁和行锁,锁模式:IX:表级别意向排他锁,X:行级别排他锁,REC_NOT_GAP: 记录锁(不包括间隙,确保锁定的是精确的行记录,避免幻读),InnoDB存储引擎使用多种锁模式来实现事务隔离和一致性
再执行一次方法,出现锁等待,
五.错误原因分析
可能长事务存在时间超过了druid连接池的生存时间,连接被连接池回收关闭,程序报错,并且大量的长事务造成锁等待或者死锁,消耗资源.
1.MySQL参数优化
可以缩短mysql的wait_timeout一个连接在服务器端闲置多长时间后会被自动关闭,默认是8小时,比如600秒
2.代码优化
1.缩小事务控制范围,比如,只有在更新数据库时,再开启事务,对于查询等这类逻辑操作无需开启事务.
2.发生异常时,捕捉异常,进行事务回滚.
3.逻辑判断需要提前结束方法时.对于已经开启的事务记得关闭.
六.总结
问题为何偶发,并且系统自上线的这几年来只有近期才出现问题.
可能是在近期MySQL提升了隔离级别,由读已提交(Read Committed)改为可重复读(Repeatable Read),为保证数据的一致性,数据库的锁竞争会变的激烈,并发事务对同一资源(如表或行)的访问需求较高,导致锁(行锁或者表锁)争用严重,并且造成死锁,虽然 InnoDB 通常会自动检测和处理死锁,但在某些复杂情况下,可能会导致事务超时。较高的事务隔离级别(如 SERIALIZABLE)可能会导致更多的锁竞争和等待超时。之前适合RC级别的代码写法已经不适用RR级别.
近期又是系统使用高发期,使用人数较多,业务牵扯的范围较广,但代码优化的覆盖面却很窄,导致问题暴漏,功能阻塞,后续将继续做好监测.