当心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 waiting
  java.lang.Thread.State: WAITING
      [...4 frames omitted...]
      at org.apache.activemq.transport.FutureResponse.getResult
      at o.a.a.transport.ResponseCorrelator.request
      at o.a.a.ActiveMQConnection.syncSendPacket
      at o.a.a.ActiveMQConnection.syncSendPacket
      at o.a.a.ActiveMQSession.syncSendPacket
      at o.a.a.ActiveMQMessageProducer.
      at o.a.a.ActiveMQSession.createProducer
      [...5  frames omitted...]
      at org.springframework.jms.core.JmsTemplate.send
      at com.nurkiewicz.Sample$sendMessageAfterCommit$1.afterCommit
      at org.springframework.transaction.support.TransactionSynchronizationUtils.invokeAfterCommit
      at o.s.t.s.TransactionSynchronizationUtils.triggerAfterCommit
      at o.s.t.s.AbstractPlatformTransactionManager.triggerAfterCommit
      at o.s.t.s.AbstractPlatformTransactionManager.processCommit
      at 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调用或产生其他副作用，该怎么办？ 我建议将副作用卸载到线程池并异步执行。 当然，这意味着如果机器出现故障，您的副作用甚至更有可能消失。 但是至少您不会威胁到系统的整体稳定性。

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

翻译自: https://www.javacodegeeks.com/2017/03/beware-slow-transaction-callbacks-spring.html