问题现象 这是一个测试环境发现的问题:
表现:该服务的所有 HTTP 接口超时;以该服务为 provider 的 Dubbo 调用超时;RocketMQ 消费线程全部卡死,消息积压;
特别之处:网络正常,服务和数据库资源使用也都正常——从外部看,服务”没问题”,但它就是一动不动。
于是导了一分线程快照信息,从它开始分析。
定位问题 第一眼看过去:所有业务线程都停在同一行、等同一个对象:
1 2 3 4 5 6 7 waiting on condition [0x00007f993e24b000 ] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000006df3157c0 > (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175 ) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039 ) at com.alibaba.druid.pool.DruidDataSource.takeLast(DruidDataSource.java:2218 )
无论是 HTTP 接口,还是 Dubbo 接口,整个系统都在等待从 Druid 连接池中获取一个连接;
没有正在执行中的 SQL ,数据库控制台上也无慢 SQL 迹象;
可以初步确定的是,数据库连接池没有可用连接了,全被打满了。
随着而来的问题是,连接池有多大,连接都哪去了?
看了下 Nacos 配置:
1 2 3 4 5 6 7 8 9 datasource: hikari: maximum-pool-size: 30 minimum-idle: 10 connection-timeout: 10000 url: xxx type: com.alibaba.druid.pool.DruidDataSource driver-class-name: com.mysql.cj.jdbc.Driver
发现了点端倪:
日志显示的是 DruidDataSource,配置咋是 hikari 的配置;
由此可以确定的是整段 spring.datasource.hikari.* 配置完全没用上,实际生效的是 Druid 默认值配置。
查了下 Druid 的几个关键参数的默认值:
问了下同事刚在做什么操作,得知是测试的同事在测“退款”申请接口。
于是再次查看了线程快照信息,看到确实有 4 个线程处在“退款”方法中。难道是这 4 个线程把 8 个连接都占满了?
从中挑了一个“退款”线程,细看了一下,发现有 3 次事务切面的调用,这个线程有没有可能已经持有了 2 个连接,并且在等待获取第 3 个连接,同时处于这个状态的线程有 4 个,4 个线程占用的线程恰好等于 8 个。
为了验证这个假设,于是看了下代码,大致是这样的事务结构:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 @Override @Transactional(rollbackFor = Exception.class) public Long serviceA () { if (Objects.equals(order.getPackageType(), OrderPackageTypeEnum.RIGHTS_PACKAGE.getCode())) { return self.serviceB(); } } @Transactional(propagation = Propagation.NOT_SUPPORTED) public Long serviceB (...) { this .saveOrUpdate(); self.serviceC(...); return ...; } @Transactional(propagation = Propagation.REQUIRES_NEW) public void serviceC (...) { }
可是疑问又来了,Propagation.NOT_SUPPORTED 确实会挂起外层事务,但是 serviceB 在执行数据操作后应该会立马释放连接才对,按理当走到 serviceC 方法的时候,应该最多只会持有 1 个连接才对。
我决定写个同样事务结构的小 demo 验证下。
经过层层 debug 后发现,在进入到 serviceB 中,执行数据库后,并不会马上释放连接,而是等 serviceB 方法执行完成后,由事务切换释放:
1 2 3 4 5 org.springframework.transaction.interceptor.TransactionAspectSupport#invokeWithinTransaction ->org.springframework.transaction.interceptor.TransactionAspectSupport#commitTransactionAfterReturning ->org.springframework.transaction.support.AbstractPlatformTransactionManager#commit ->org.springframework.transaction.support.AbstractPlatformTransactionManager#processCommit ->org.springframework.transaction.support.AbstractPlatformTransactionManager#triggerBeforeCompletion
最终是通过事务提交钩子函数释放的:
1 2 3 4 5 6 7 8 protected final void triggerBeforeCompletion (DefaultTransactionStatus status) { if (status.isNewSynchronization()) { if (status.isDebug()) { logger.trace("Triggering beforeCompletion synchronization" ); } TransactionSynchronizationUtils.triggerBeforeCompletion(); } }
那钩子函数是什么注册上去的呢:
1 2 org.mybatis.spring.SqlSessionUtils#getSqlSession(org.apache.ibatis.session.SqlSessionFactory, org.apache.ibatis.session.ExecutorType, org.springframework.dao.support.PersistenceExceptionTranslator) ->org.mybatis.spring.SqlSessionUtils#registerSessionHolder
可以看到:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 private static void registerSessionHolder (SqlSessionFactory sessionFactory, ExecutorType executorType, PersistenceExceptionTranslator exceptionTranslator, SqlSession session) { SqlSessionHolder holder; if (TransactionSynchronizationManager.isSynchronizationActive()) { Environment environment = sessionFactory.getConfiguration().getEnvironment(); if (environment.getTransactionFactory() instanceof SpringManagedTransactionFactory) { LOGGER.debug(() -> "Registering transaction synchronization for SqlSession [" + session + "]" ); holder = new SqlSessionHolder (session, executorType, exceptionTranslator); TransactionSynchronizationManager.bindResource(sessionFactory, holder); TransactionSynchronizationManager .registerSynchronization(new SqlSessionSynchronization (holder, sessionFactory)); holder.setSynchronizedWithTransaction(true ); holder.requested(); } else { } } else { } }
至此,问题的前因后果也出来了:
数据源配置错误导致连接池大小只有默认的 8;
默认参数 maxWait=-1 导致所有获取不到连接的线程无限等待;
serviceA 外层事务 + NOT_SUPPORTED 挂起 + REQUIRES_NEW 追加,使单请求并发就占用了 3个 连接;
4 笔并发退款请求”持2求1”,占满 8 个连接,导致发生典型的连接池嵌套死锁。
结语 事务传播也得慎用,考虑不周到容易造成池容量被腰斩,且极易形成”互相等对方释放”的伪死锁。