activemq jdbc 性能/延迟

Question

我正在使用 jdbc 存储测试 activemq，虽然我知道这不是最有效的方法，但我发现延迟非常奇怪。

代码基本上用 3k 条消息填充一个队列，然后单个消费者消费所有这些消息。 消息是持久的，确认模式是 AUTO_ACKNOWLEDGE。我还禁用了 alwaysSessionAsync 和 dispatchAsync。

问题是消费速度变化很大。以下是消耗 100 条消息所需的时间（消耗全部消息的 30 倍）：

2014-07-16 01:08:50,171  'consumer': 45.1 ms
2014-07-16 01:08:50,207  'consumer': 35.5 ms
2014-07-16 01:08:50,290  'consumer': 83.4 ms
2014-07-16 01:08:50,412  'consumer': 122 ms
2014-07-16 01:08:50,476  'consumer': 63.1 ms
2014-07-16 01:08:50,552  'consumer': 75.6 ms
2014-07-16 01:08:50,606  'consumer': 54.5 ms
2014-07-16 01:08:50,655  'consumer': 48.7 ms
2014-07-16 01:08:50,709  'consumer': 53.2 ms
2014-07-16 01:08:50,765  'consumer': 56.2 ms
2014-07-16 01:08:50,813  'consumer': 48.2 ms
2014-07-16 01:08:50,922  'consumer': 109 ms
2014-07-16 01:08:51,188  'consumer': 266 ms
2014-07-16 01:08:51,446  'consumer': 257 ms
2014-07-16 01:08:51,724  'consumer': 278 ms
2014-07-16 01:08:51,975  'consumer': 252 ms
2014-07-16 01:08:52,224  'consumer': 249 ms
2014-07-16 01:08:52,496  'consumer': 271 ms
2014-07-16 01:08:52,743  'consumer': 247 ms
2014-07-16 01:08:52,998  'consumer': 255 ms
2014-07-16 01:08:53,255  'consumer': 257 ms
2014-07-16 01:08:53,486  'consumer': 231 ms
2014-07-16 01:08:53,710  'consumer': 224 ms
2014-07-16 01:08:53,947  'consumer': 236 ms
2014-07-16 01:08:54,189  'consumer': 242 ms
2014-07-16 01:08:54,389  'consumer': 200 ms
2014-07-16 01:08:54,598  'consumer': 209 ms
2014-07-16 01:08:54,790  'consumer': 192 ms
2014-07-16 01:08:54,985  'consumer': 195 ms
2014-07-16 01:08:55,203  'consumer': 217 ms

所以我启用了 TRACE 级别的日志记录，以了解是否有任何有趣的事情，并且确实存在差距：

2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 DEBUG || org.apache.activemq.broker.region.Queue - QUEUE2 toPageIn: 200, Inflight: 999, pagedInMessages.size 1214, pagedInPendingDispatch.size 214, enqueueCount: 3000, dequeueCount: 386, memUsage:1459248
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.Queue - Subscription full QueueSubscription: consumer=ID:LAPTOP-50558-1405488840024-5:1:1:1, destinations=1, dispatched=1000, delivered=0, pending=0
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.thread.PooledTaskRunner - Running task iteration 572 - queue://QUEUE2, subscriptions=1, memory=1%, size=5771, in flight groups=null
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 DEBUG || org.apache.activemq.broker.region.Queue - QUEUE2 toPageIn: 200, Inflight: 999, pagedInMessages.size 1214, pagedInPendingDispatch.size 214, enqueueCount: 3000, dequeueCount: 386, memUsage:1459248
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.Queue - Subscription full QueueSubscription: consumer=ID:LAPTOP-50558-1405488840024-5:1:1:1, destinations=1, dispatched=1000, delivered=0, pending=0
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.thread.PooledTaskRunner - Running task iteration 573 - queue://QUEUE2, subscriptions=1, memory=1%, size=5771, in flight groups=null
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 DEBUG || org.apache.activemq.broker.region.Queue - QUEUE2 toPageIn: 200, Inflight: 999, pagedInMessages.size 1214, pagedInPendingDispatch.size 214, enqueueCount: 3000, dequeueCount: 386, memUsage:1459248
2014-07-16 00:34:14,117 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.Queue - Subscription full QueueSubscription: consumer=ID:LAPTOP-50558-1405488840024-5:1:1:1, destinations=1, dispatched=1000, delivered=0, pending=0
2014-07-16 00:34:14,117 ActiveMQ Transport: tcp:///127.0.0.1:50562@50559 TRACE || org.apache.activemq.broker.region.PrefetchSubscription - ack: MessageAck {commandId = 392, responseRequired = false, ackType = 2, consumerId = ID:LAPTOP-50558-1405488840024-5:1:1:1, firstMessageId = ID:LAPTOP-50488-1405487850038-3:1:1:1:2017, lastMessageId = ID:LAPTOP-50488-1405487850038-3:1:1:1:2017, destination = queue://QUEUE2, transactionId = null, messageCount = 1, poisonCause = null}
2014-07-16 00:34:14,397 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.thread.PooledTaskRunner - Running task iteration 574 - queue://QUEUE2, subscriptions=1, memory=1%, size=5771, in flight groups=null
2014-07-16 00:34:14,397 ActiveMQ BrokerService[broker_jdbc] Task-1 DEBUG || org.apache.activemq.broker.region.Queue - QUEUE2 toPageIn: 200, Inflight: 998, pagedInMessages.size 1213, pagedInPendingDispatch.size 214, enqueueCount: 3000, dequeueCount: 387, memUsage:1458216
2014-07-16 00:34:14,397 ActiveMQ Transport: tcp:///127.0.0.1:50562@50559 TRACE || org.apache.activemq.broker.region.Queue - ack of ID:LAPTOP-50488-1405487850038-3:1:1:1:2017 with MessageAck {commandId = 392, responseRequired = false, ackType = 2, consumerId = ID:LAPTOP-50558-1405488840024-5:1:1:1, firstMessageId = ID:LAPTOP-50488-1405487850038-3:1:1:1:2017, lastMessageId = ID:LAPTOP-50488-1405487850038-3:1:1:1:2017, destination = queue://QUEUE2, transactionId = null, messageCount = 1, poisonCause = null}
2014-07-16 00:34:14,397 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.PrefetchSubscription - ID:LAPTOP-50558-1405488840024-5:1:1:1 dispatched: ID:LAPTOP-50534-1405488592270-3:1:1:1:16 - queue://QUEUE2, dispatched: 1387, inflight: 999
2014-07-16 00:34:14,397 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.Queue - assigned ID:LAPTOP-50534-1405488592270-3:1:1:1:16 to consumer ID:LAPTOP-50558-1405488840024-5:1:1:1
2014-07-16 00:34:14,397 ActiveMQ Transport: tcp://laptop/127.0.0.1:50559@50562 DEBUG || jmstest.JmsTest2 - consumer recv: ActiveMQTextMessage {commandId = 20, responseRequired = true, messageId = ID:LAPTOP-50534-1405488592270-3:1:1:1:16, originalDestination = null, originalTransactionId = null, producerId = ID:LAPTOP-50534-1405488592270-3:1:1:1, destination = queue://QUEUE2, transactionId = null, expiration = 0, timestamp = 1405488593001, arrival = 0, brokerInTime = 1405488593001, brokerOutTime = 1405488854397, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@1bca52f3, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false, text = text}
2014-07-16 00:34:14,397 ActiveMQ BrokerService[broker_jdbc] Task-1 TRACE || org.apache.activemq.broker.region.PrefetchSubscription - ID:LAPTOP-50558-1405488840024-5:1:1:1 dispatched: ID:LAPTOP-50534-1405488592270-3:1:1:1:17 - queue://QUEUE2, dispatched: 1388, inflight: 1000

注意中间有250ms+延迟。

问题是 - 为什么会出现这样的延迟以及如何摆脱它们？ 另外 - 为什么一开始时间如此之低（低于 100 毫秒），然后又增加到 250 毫秒？ （更改预取大小会在性能下降时移动点）

我还注意到，将确认模式更改为 CLIENT_ACKNOWLEDGE 并且不确认消息会使消费者超快 (20ms/100)，但会在 20 多秒内阻塞几次。

• 代码：http://pastebin.com/v3cPpJKi
• 配置文件：http://pastebin.com/EdzrvcRK
• 跟踪一次迭代（100 条消息）：https://gist.githubusercontent.com/anonymous/edef32a8a2bdc31ca3ce/raw/gistfile1.txt

Answer 1

我曾经遇到过类似的问题。经过调查，我发现我们可以调整 Memory Limit 和 Prefecth Limit 参数来提高此类情况的性能。

默认情况下，memoryLimit 在 activemq.xml 文件中设置为 1MB。该参数表示activemq可以在内存中保存的数据量（如果达到此限制，activemq需要进行IO调用从持久存储中读取数据，这会影响性能）。

我建议你增加这个值，看看它是否能带来任何性能提升。

预取限制是可以调整以实现性能增益的其他参数。此参数的值取决于您对 activemq 的队列配置。

其他选项是使用FileBasedCursor。

参考此链接并检查它是否有帮助。 ActiveMQ stops sending messages to Queue Consumer in case of consumer not acknowledging messages