寻找 Mule 4.3 和 ActiveMQ 之间的性能瓶颈答案

【问题标题】：Finding a performance bottleneck between Mule 4.3 and ActiveMQ寻找 Mule 4.3 和 ActiveMQ 之间的性能瓶颈
【发布时间】：2021-11-25 00:31:13
【问题描述】：

我们的所有与 ActiveMQ 通信的 Mule 4.3 实例之间的响应时间都非常长，由于这些问题，我们的团队在 Mule JVM 中安装了 APM (AppDynamics) 代理来调试手头的问题。

我从我们的 APM 中得出的最有趣的事情是下面可见的调用图（每个调用的大部分时间也花在与 ActiveMQ 交互上）：

Call graph from /api/transaction_1
On tier: TIER-01
On node: node-001.net
Start time: 10/04/21 4:24:39 PM

java.lang.Thread:run:748 (method time = 0 ms, total time = 28049 ms)
 reactor.core.scheduler.SchedulerTask:call:27 (method time = 0 ms, total time = 28049 ms)
  reactor.core.scheduler.SchedulerTask:call:50 (method time = 0 ms, total time = 28049 ms)
   reactor.core.publisher.FluxSubscribeOnValue$ScheduledScalar:run:178 (method time = 0 ms, total time = 28049 ms)
    reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber:onNext:345 (method time = 0 ms, total time = 28049 ms)
     reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
      reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 28049 ms)
       reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber:onNext:180 (method time = 0 ms, total time = 28049 ms)
        reactor.core.publisher.MonoNext$NextSubscriber:onNext:76 (method time = 0 ms, total time = 28049 ms)
         reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
          reactor.core.publisher.FluxFlatMap$FlatMapInner:onNext:974 (method time = 0 ms, total time = 28049 ms)
           reactor.core.publisher.FluxFlatMap$FlatMapMain:tryEmit:532 (method time = 0 ms, total time = 28049 ms)
            reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner:onNext:242 (method time = 0 ms, total time = 28049 ms)
             reactor.core.publisher.FluxMap$MapConditionalSubscriber:onNext:213 (method time = 0 ms, total time = 28049 ms)
              reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
               reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
                reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                 reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber:onNext:345 (method time = 0 ms, total time = 28049 ms)
                  reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                   reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 28049 ms)
                    reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
                     reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                      reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                       reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                        reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 28049 ms)
                         reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber:onNext:180 (method time = 0 ms, total time = 28049 ms)
                          reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 28049 ms)
                           reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 28049 ms)
                            reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
                             reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 28049 ms)
                              reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                               reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 28049 ms)
                                reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 28049 ms)
                                 reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:482 (method time = 1884 ms, total time = 28049 ms)
                                  reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 0 ms)
                                  reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 26165 ms)
                                   reactor.core.publisher.FluxCreate$BufferAsyncSink:next:718 (method time = 0 ms, total time = 26165 ms)
                                    reactor.core.publisher.FluxCreate$BufferAsyncSink:drain:793 (method time = 0 ms, total time = 26165 ms)
                                     reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                      reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                       reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                        reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                         reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                          reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                           reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber:onNext:121 (method time = 0 ms, total time = 26165 ms)
                                            reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                             reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                              reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                               reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                 reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:482 (method time = 0 ms, total time = 26165 ms)
                                                  reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 26165 ms)
                                                   reactor.core.publisher.FluxCreate$BufferAsyncSink:next:718 (method time = 0 ms, total time = 26165 ms)
                                                    reactor.core.publisher.FluxCreate$BufferAsyncSink:drain:793 (method time = 0 ms, total time = 26165 ms)
                                                     reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                      reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                       reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                        reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                         reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                          reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                           reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber:onNext:121 (method time = 0 ms, total time = 26165 ms)
                                                            reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                             reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                              reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                               reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                 reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber:onNext:180 (method time = 0 ms, total time = 26165 ms)
                                                                  reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                   reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                                    reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                     reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                      reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                       reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                        reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                         reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber:onNext:180 (method time = 0 ms, total time = 26165 ms)
                                                                          reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                           reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                                            reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                             reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                              reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                               reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                                reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                                 reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber:onNext:180 (method time = 0 ms, total time = 26165 ms)
                                                                                  reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                                   reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                                                    reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                     reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                      reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                       reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber:onNext:846 (method time = 0 ms, total time = 26165 ms)
                                                                                        reactor.core.publisher.FluxMap$MapConditionalSubscriber:onNext:213 (method time = 0 ms, total time = 26165 ms)
                                                                                         reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                          reactor.core.publisher.LambdaSubscriber:onNext:130 (method time = 0 ms, total time = 26165 ms)
                                                                                           reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 26165 ms)
                                                                                            reactor.core.publisher.FluxCreate$BufferAsyncSink:next:718 (method time = 0 ms, total time = 26165 ms)
                                                                                             reactor.core.publisher.FluxCreate$BufferAsyncSink:drain:793 (method time = 0 ms, total time = 26165 ms)
                                                                                              reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                               reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                                                reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner:onNext:242 (method time = 0 ms, total time = 26165 ms)
                                                                                                 reactor.core.publisher.FluxMap$MapSubscriber:onNext:114 (method time = 0 ms, total time = 26165 ms)
                                                                                                  reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner:onNext:242 (method time = 0 ms, total time = 26165 ms)
                                                                                                   reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                                    reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber:onNext:121 (method time = 0 ms, total time = 26165 ms)
                                                                                                     reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                                                      reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                                                                       reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                                        reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                                         reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                                                          reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 26165 ms)
                                                                                                           reactor.core.publisher.FluxHide$SuppressFuseableSubscriber:onNext:127 (method time = 0 ms, total time = 26165 ms)
                                                                                                            reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:496 (method time = 0 ms, total time = 26165 ms)
                                                                                                             reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber:onNext:287 (method time = 0 ms, total time = 26165 ms)
                                                                                                              reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:482 (method time = 0 ms, total time = 26165 ms)
                                                                                                               Spring Bean - _mulePolicyManager:lambda$static$0:84 (method time = 0 ms, total time = 26165 ms)
                                                                                                                reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 26165 ms)
                                                                                                                 reactor.core.publisher.FluxCreate$BufferAsyncSink:next:718 (method time = 0 ms, total time = 26165 ms)
                                                                                                                  reactor.core.publisher.FluxCreate$BufferAsyncSink:drain:793 (method time = 0 ms, total time = 26165 ms)
                                                                                                                   reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 26165 ms)
                                                                                                                    reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:496 (method time = 0 ms, total time = 26165 ms)
                                                                                                                     reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber:onNext:482 (method time = 0 ms, total time = 26165 ms)
                                                                                                                      net.jodah.failsafe.FailsafeExecutor:getStageAsync:178 (method time = 0 ms, total time = 26148 ms)
                                                                                                                       net.jodah.failsafe.FailsafeExecutor:callAsync:346 (method time = 0 ms, total time = 26148 ms)
                                                                                                                        net.jodah.failsafe.AsyncExecution:executeAsync:174 (method time = 0 ms, total time = 26148 ms)
                                                                                                                         net.jodah.failsafe.Functions:lambda$makeAsync$2:79 (method time = 0 ms, total time = 26148 ms)
                                                                                                                          net.jodah.failsafe.Functions:lambda$null$1:69 (method time = 0 ms, total time = 26148 ms)
                                                                                                                           net.jodah.failsafe.internal.executor.RetryPolicyExecutor:lambda$supplyAsync$1:133 (method time = 0 ms, total time = 26148 ms)
                                                                                                                            net.jodah.failsafe.internal.executor.RetryPolicyExecutor$1:call:101 (method time = 0 ms, total time = 26148 ms)
                                                                                                                             net.jodah.failsafe.Functions:lambda$promiseOfStage$8:193 (method time = 26148 ms, total time = 26148 ms)
                                                                                                                              JMS(28030ms): acme.corp.error.topic
                                                                                                                      reactor.core.publisher.FluxCreate$SerializedSink:next:153 (method time = 0 ms, total time = 17 ms)
                                                                                                                       reactor.core.publisher.FluxCreate$BufferAsyncSink:next:718 (method time = 0 ms, total time = 17 ms)
                                                                                                                        reactor.core.publisher.FluxCreate$BufferAsyncSink:drain:793 (method time = 0 ms, total time = 17 ms)
                                                                                                                         reactor.core.publisher.FluxContextStart$ContextStartSubscriber:onNext:103 (method time = 0 ms, total time = 17 ms)
                                                                                                                          reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 17 ms)
                                                                                                                           reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber:onNext:204 (method time = 0 ms, total time = 17 ms)
                                                                                                                            reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner:onNext:242 (method time = 0 ms, total time = 17 ms)
                                                                                                                             reactor.core.publisher.FluxMap$MapSubscriber:onNext:114 (method time = 0 ms, total time = 17 ms)
                                                                                                                              reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner:onNext:242 (method time = 0 ms, total time = 17 ms)
                                                                                                                               reactor.core.publisher.FluxPublishOn$PublishOnConditionalSubscriber:onNext:704 (method time = 0 ms, total time = 17 ms)
                                                                                                                                reactor.core.publisher.FluxPublishOn$PublishOnConditionalSubscriber:trySchedule:759 (method time = 0 ms, total time = 17 ms)
                                                                                                                                 reactor.core.scheduler.ExecutorServiceWorker:schedule:43 (method time = 0 ms, total time = 17 ms)
                                                                                                                                  reactor.core.scheduler.Schedulers:workerSchedule:904 (method time = 17 ms, total time = 17 ms)
                                                                                                                                   undefined(17ms): Asynchronous activity identified

我们看到很多我们不熟悉的“reactor.core”调用，因为它们是由 Mule 内部执行的，这一事实让我们很难理解 Mule 真正在做什么。

是否有人知道发生了什么，也许它可以让我们了解 Mule 和 ActiveMQ 之间发生了什么？或许更好地理解所有这一切可以帮助我们找到为什么反应如此缓慢的答案。

【问题讨论】：

请澄清您的具体问题或提供其他详细信息以准确突出您的需求。正如目前所写的那样，很难准确地说出你在问什么。

标签： activemq project-reactor mule4 appdynamics

【解决方案1】：

Reactor 是一个框架，用于构建在 Mule 4.x 引擎中使用的 Java 非阻塞应用程序。您共享的堆栈跟踪并未指出 Reactor 或 Mule 中的任何问题。虽然 reactor 通常有很长的堆栈跟踪，但您可以看到 AppDynamics 无法衡量在 Reactor 中花费的时间。似乎总是由与 Reactor 无关的不同类进行错误处理。时间似乎都花在了 JMS (JMS(28030ms): acme.corp.error.topic) 和错误处理 (net.jodah.failsafe.Functions:lambda$promiseOfStage$8:193 (method time = 26148 ms) 中。您没有分享任何其他具体细节，因此可以使用提供的数据进行分析。您也没有提供有关问题本身的详细信息，只是说“响应时间非常长”。更多细节的例子可能是：应用程序做什么？它们如何互连？他们使用什么连接器？他们如何使用它们？它们是如何配置的？究竟哪些操作有超时，这些超时是什么？

上次我检查 AppDynamics 不了解 Mule 4 的内部结构，因此您必须准备好对数据进行自己的分析，而不是盲目地遵循它。

分析此类问题可能有很多原因，您需要从整体上确认或排除所有原因。给你一个非常简短的建议来执行分析：

线程转储分析：查看是否有线程在 ActiveMQ 或 JMS 连接器类上工作。查看是否有线程在与 ActiveMQ/JMS 无关的类似类上工作，这可能会减慢其余线程的速度。
软件分析：您使用的是哪些连接器版本和 Mule 补丁？累积补丁在 Mule 4 中对于防止已知问题至关重要。对于连接器，建议使用最新版本以防止出现已知问题。
网络分析：执行网络数据流量捕获和分析，以查看是否存在延迟或通信问题
配置分析：配置了哪些超时？应用了哪些资源？
工作负载分析：有峰值吗？卷有变化吗？您之前是否进行过相同数量的测试？
变化分析：有什么变化吗？新版本？操作系统补丁？
ActiveMQ 分析：您是否分析过 ActiveMQ 服务器以防出现问题？

【讨论】：