当心Spring缓慢的事务回调

TL; DR

如果您的应用程序无法获得新的数据库连接，则重新启动ActiveMQ代理可能会有所帮助。有兴趣吗

性能问题

几个月前，我们经历了生产中断。大家都很熟悉，许多请求都失败了：

java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30003ms.at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:555) ~[HikariCP-2.4.7.jar:na]at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:188) ~[HikariCP-2.4.7.jar:na]at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) ~[HikariCP-2.4.7.jar:na]at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:99) ~[HikariCP-2.4.7.jar:na]at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:211) ~[spring-jdbc-4.3.4.RELEASE.jar:4.3.4.RELEASE]at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) ~[spring-tx-4.3.4.RELEASE.jar:4.3.4.RELEASE]at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:447) ~[spring-tx-4.3.4.RELEASE.jar:4.3.4.RELEASE]at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277) ~[spring-tx-4.3.4.RELEASE.jar:4.3.4.RELEASE]at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.4.RELEASE.jar:4.3.4.RELEASE]

为了完全理解正在发生的事情，我们首先来看一下Spring和JDBC连接池在做什么。 Spring每次遇到@Transactional方法时，都会使用TransactionInterceptor对其进行包装。该拦截器将间接向TransactionManager询问当前交易。如果没有，则AbstractPlatformTransactionManager尝试创建新的事务。如果是JDBC， DataSourceTransactionManager将通过首先获取新的数据库连接来启动新事务。最后，Spring向配置的DataSource （在我们的例子中为HikariPool ）请求新的Connection 。您可以从上述堆栈跟踪中读取所有内容，没有新内容。

查询速度很慢

那么出现异常的原因是什么呢？我们以Hikari为例，但该说明对我所知道的所有池化DataSource实现均有效。 Hikari查看其内部连接池，并尝试返回空闲的Connection对象。如果没有空闲连接且池尚未满，则Hikari将无缝创建新的物理连接并返回。但是，如果池已满，但当前所有连接都在使用中，则Hikari将无能为力。它必须等待，希望另一个线程在最近的将来返回一个Connection ，以便可以将其传递给另一个客户端。但是在30秒（可配置的超时）后，Hikari将超时并失败。

导致此异常的根本原因是什么？想象一下，您的服务器正在非常努力地处理数百个请求，每个请求都需要数据库连接才能进行查询。如果所有查询都很快，则它们应该相当快地将连接返回给池，以便其他请求可以重用它们。即使在高负载下，等待时间也不会造成灾难性的后果。 Hikari在30秒后失败可能意味着实际上所有连接都被占用了至少半分钟，这真是太糟糕了！换句话说，我们拥有一个系统，该系统可以永久保存所有数据库连接（好几十秒），使所有其他客户端线程都饿死。

显然，我们遇到了数据库查询非常慢的情况，让我们检查一下数据库引擎！根据所使用的RDBMS，您将拥有不同的工具。在我们的案例中，PostgreSQL报告确实我们的应用程序具有10个打开的连接-最大池大小。但这并不意味着什么–我们正在池化连接，因此希望在中等负载下所有允许的连接都打开。仅当应用程序非常空闲时，连接池才可以决定关闭某些连接。但是应该非常保守地进行，因为打开物理连接的成本非常高。

因此，根据PostgreSQL，我们已经打开了所有这些连接，它们正在运行哪种查询？好吧，令人尴尬的是，所有连接都处于空闲状态，最后一个命令是…… COMMIT 。从数据库的角度来看，我们有一堆开放的连接，所有连接都是空闲的，可以为事务提供服务。从Spring的角度来看，所有连接都已被占用，我们无法获得更多连接。这是怎么回事？在这一点上，我们很确定SQL并不是问题。

模拟故障

我们查看了服务器的堆栈转储，并Swift发现了问题。在分析堆栈转储之后，让我们看一下简化后的代码片段。我编写了一个在GitHub上可用的示例应用程序，它暴露了相同的问题：

@RestController
open class Sample(private val jms: JmsOperations,private val jdbc: JdbcOperations) {@Transactional@RequestMapping(method = arrayOf(GET, POST), value = "/")open fun test(): String {TransactionSynchronizationManager.registerSynchronization(sendMessageAfterCommit())val result = jdbc.queryForObject("SELECT 2 + 2", Int::class.java)return "OK " + result}private fun sendMessageAfterCommit(): TransactionSynchronizationAdapter {return object : TransactionSynchronizationAdapter() {override fun afterCommit() {val result = "Hello " + Instant.now()jms.send("queue", { it.createTextMessage(result) })}}}}

就在Kotlin中，只是为了学习它。该示例应用程序执行两件事：*非常非常简单的数据库查询，只是为了证明这不是问题*发送Commit钩子发送JMS消息

JMS？

现在很明显，这个提交后的钩子一定是问题所在，但是为什么呢？让我们从头开始。通常，我们要执行数据库事务并仅在事务成功时才发送JMS消息。由于jms.send()原因，我们不能简单地将jms.send()作为事务方法中的最后一条语句：

@Transactional可以是围绕我们方法的较大事务的一部分，但是我们希望在整个事务完成后发送一条消息
更重要的是，事务可能会在提交时失败，而我们已经发送了JMS消息

这些说明适用于所有不参与事务的副作用，您要在提交后执行。当然，可能会发生事务提交但未执行提交后挂接的情况，因此afterCommit()回调的语义最多为一次。但是，至少可以保证，如果数据尚未持久存储到数据库，也不会发生副作用。当不能选择分布式交易时，这是一个合理的权衡，而很少这样做。

这种习语可以在许多应用程序中找到，并且通常很好。想象一下，您正在接收一个请求，将某些内容持久保存到数据库中，然后向客户端发送一条SMS，以确认请求已得到处理。如果没有后提交钩子，最终将发送SMS，但是如果发生回滚，则不会将任何数据写入数据库。甚至更有趣 ，如果您自动重试失败的事务，则可能会发送多个SMS，而不会保留任何数据。因此，提交后的钩子很重要¹ 。那怎么了在查看堆栈转储之前，让我们检查一下Hikari公开的指标：

在中等高负载下（用ab模拟了25个并发请求），我们可以清楚地看到10个连接的池已被充分利用。但是，有15个线程（请求）被阻止以等待数据库连接。他们可能最终会在30秒后获得连接或超时。看起来问题仍然出在某些长期运行的SQL查询上，但是说真的， 2 + 2 ？没有。

ActiveMQ的问题

现在该揭示堆栈转储了。大多数连接都停留在Hikari上，等待连接。这些对我们来说没有兴趣，这只是一种症状，而不是原因。让我们看一下实际保持连接的10个线程，它们的作用是什么？

"http-nio-9099-exec-2@6415" daemon prio=5 tid=0x28 nid=NA waitingjava.lang.Thread.State: WAITING[...4 frames omitted...]at org.apache.activemq.transport.FutureResponse.getResultat o.a.a.transport.ResponseCorrelator.requestat o.a.a.ActiveMQConnection.syncSendPacketat o.a.a.ActiveMQConnection.syncSendPacketat o.a.a.ActiveMQSession.syncSendPacketat o.a.a.ActiveMQMessageProducer.at o.a.a.ActiveMQSession.createProducer[...5  frames omitted...]at org.springframework.jms.core.JmsTemplate.sendat com.nurkiewicz.Sample$sendMessageAfterCommit$1.afterCommitat org.springframework.transaction.support.TransactionSynchronizationUtils.invokeAfterCommitat o.s.t.s.TransactionSynchronizationUtils.triggerAfterCommitat o.s.t.s.AbstractPlatformTransactionManager.triggerAfterCommitat o.s.t.s.AbstractPlatformTransactionManager.processCommitat o.s.t.s.AbstractPlatformTransactionManager.commit[...73 frames omitted...]

所有这些连接都停留在ActiveMQ客户端代码上。它本身并不常见，难道发送的JMS消息不是快速且异步的吗？好吧，不是真的。 JMS规范定义了某些保证，我们可以控制其中的一些。在很多情况下，“一劳永逸”的语义是不够的。您真正需要的是来自代理的确认，确认邮件已收到并持续存在。这意味着我们必须：*创建与ActiveMQ的物理连接（希望它像JDBC连接一样被池化）*执行握手，授权等（如上所述，池化有很大帮助）*通过网络发送JMS消息*等待来自经纪人，通常涉及经纪人方面的持久性

到目前为止，所有这些步骤都是同步的，并非免费。而且ActiveMQ有几种机制可以进一步减慢生产者（发送者）的速度：性能调整，异步发送，快速生产者和缓慢的消费者会发生什么。

提交后钩子，真的吗？

因此，我们确定生产商方面ActiveMQ性能不合格正在使我们放慢速度。但是，这对数据库连接池有何影响？此时，我们重新启动了ActiveMQ代理，情况恢复正常。那天生产者如此缓慢的原因是什么？ –这超出了本文的范围。我们花了一些时间检查Spring框架的代码。提交后挂钩如何执行？这是宝贵的堆栈跟踪的相关部分，已清理（自下而上阅读）：

c.n.Sample$sendMessageAfterCommit$1.afterCommit()
o.s.t.s.TransactionSynchronizationUtils.invokeAfterCommit()
o.s.t.s.TransactionSynchronizationUtils.triggerAfterCommit()
o.s.t.s.AbstractPlatformTransactionManager.triggerAfterCommit()
o.s.t.s.AbstractPlatformTransactionManager.processCommit()
o.s.t.s.AbstractPlatformTransactionManager.commit()
o.s.t.i.TransactionAspectSupport.commitTransactionAfterReturning()

这是大大简化的AbstractPlatformTransactionManager.processCommit()样子：

private void processCommit(DefaultTransactionStatus status) throws TransactionException {try {prepareForCommit(status);triggerBeforeCommit(status);triggerBeforeCompletion(status);doCommit(status);triggerAfterCommit(status);triggerAfterCompletion(status);} finally {cleanupAfterCompletion(status);  //release connection here}
}

我删除了大多数错误处理代码，以可视化核心问题。 JDBC Connection关闭（实际上是释放回池中）在cleanupAfterCompletion()很晚cleanupAfterCompletion()发生。因此在实践中，在调用doCommit() （物理上提交事务）与释放连接之间存在间隙。如果提交后和完成后挂钩不存在或便宜，则此时间间隔可以忽略不计。但是在我们的例子中，钩子正在与ActiveMQ交互，并且在这一天ActiveMQ生产者异常缓慢。当连接空闲时，所有工作都已完成，但是在没有明显原因的情况下，我们仍然保持连接，这会造成非常不寻常的情况。这基本上是暂时的连接泄漏。

解决方案和摘要

我并不是声称这是Spring框架中的错误（已通过spring-tx 4.3.7.RELEASE测试），但我很高兴听到此实现背后的原因。提交后提交钩子无法以任何方式更改事务或连接，因此在这一点上它是无用的，但我们仍然坚持。有什么解决方案？显然，避免在提交后或完成后挂钩中长时间运行或不可预测/不安全的代码是一个好的开始。但是，如果您真的需要发送JMS消息，进行RESTful调用或产生其他副作用，该怎么办？我建议将副作用卸载到线程池并异步执行。当然，这意味着如果机器出现故障，您的副作用甚至更有可能消失。但是至少您不会威胁到系统的整体稳定性。

如果您绝对需要确保在事务提交时发生副作用，则需要重新设计整个解决方案。例如，与其立即发送消息，不如将未决请求存储在同一事务内的数据库中，然后稍后重试以处理此类请求。但是，这可能意味着至少一次语义。