目录
一.项目介绍
项目是springboot+nacos的微服务架构,商城购物类系统,分多个服务,问题出现在众多服务中的单个服务
二.问题暴漏
在系统日志中显示错误:connection holder is null,空连接
Caused by: java.sql.SQLException: connection holder is null
at 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=UTC
username: root
password: 123456
driver-class-name: com.mysql.cj.jdbc.Driver
druid:
# 初始化时建立物理连接的个数
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 closed
at 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 disabled
at 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 request2.调整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,性能查询语句:
SELECT
trx.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 被锁定的记录
FROM
information_schema.INNODB_TRX trx
LEFT JOIN information_schema.PROCESSLIST pl ON trx.trx_mysql_thread_id = pl.Id
LEFT JOIN information_schema.INNODB_LOCKS il ON trx.trx_id = il.lock_trx_id
LEFT JOIN PERFORMANCE_SCHEMA.threads t ON t.processlist_id = pl.id
LEFT 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级别.
近期又是系统使用高发期,使用人数较多,业务牵扯的范围较广,但代码优化的覆盖面却很窄,导致问题暴漏,功能阻塞,后续将继续做好监测.