[
https://issues.apache.org/jira/browse/AMQ-4141?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
James Green resolved AMQ-4141.
------------------------------
Resolution: Not A Problem
Marking this resolved. We did two things to resolve our case:
1. We increased the memory of the broker in the production network after
learning that some messages could be large and translated across broker
components
2. We moved our hub from the end of a shared ADSL connection into the
production network after noticing that transmission from hub to spokes maxed
out the upload bandwidth for hours at a time upon the sending of a 10M message
to a topic with three spokes listening.
Other than better documentation and better exception messages I'm unsure what
can prevent another incident of this nature in the future.
> Semi-stuck queue until server restart
> -------------------------------------
>
> Key: AMQ-4141
> URL: https://issues.apache.org/jira/browse/AMQ-4141
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.5.0, 5.7.0
> Reporter: James Green
> Priority: Critical
>
> We have a single Stomp consumer being invoked via a schedule with ten-second
> intervals to consume at most 200 messages with a one second network timeout.
> The consumer subscribes to /queue/account_events on the localhost broker
> ("hub"). This broker is connected to from three external brokers which have
> producers on them ("production servers").
> What we see is a large built-up of messages on the remote brokers for this
> queue, with a small number of messages pending on the hub. The messages are
> not persistent and tend to be smallish (<1KB).
> The consumer is literally sat waiting for the next available message. Under
> "normal" conditions it spins up and consumes 200 messages at a pace of a few
> msgs per second. Right at this moment it goes dozens of seconds without a
> message then processes two-three inside 2 seconds.
> The hub's web console is showing 91 pending, 1 consumer. If I click to browse
> this queue, there are no messages. The counter for 91 has been "stuck" for
> some time now.
> The hub has been set at debug level but there is only very recent logs
> recorded. A sample of them grepping for "account_events" shows activity such
> as:
> 2012-10-29 15:25:50,016 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:25:50,016 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:25:50,016 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-110
> 2012-10-29 15:25:50,020 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> 2012-10-29 15:25:52,134 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:25:52,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:25:52,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-112
> 2012-10-29 15:25:52,134 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> 2012-10-29 15:26:20,016 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:20,016 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:20,016 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-110
> 2012-10-29 15:26:20,017 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> 2012-10-29 15:26:22,134 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:22,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:22,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-110
> 2012-10-29 15:26:22,134 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> 2012-10-29 15:26:35,687 | DEBUG | Unregistering MBean
> org.apache.activemq:BrokerName=hub,Type=Subscription,persistentMode=Non-Durable,destinationType=Queue,destinationName=account_events,clientId=account_events_receiver,consumerId=ID_billing-35190-1351511867558-2_1285_-1_1
> | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport:
> tcp:///127.0.0.1:50560@61612
> 2012-10-29 15:26:35,687 | DEBUG | hub removing consumer:
> ID:billing-35190-1351511867558-2:1285:-1:1 for destination:
> queue://account_events | org.apache.activemq.broker.region.AbstractRegion |
> ActiveMQ Transport: tcp:///127.0.0.1:50560@61612
> 2012-10-29 15:26:35,688 | DEBUG | queue://account_events remove sub:
> QueueSubscription: consumer=ID:billing-35190-1351511867558-2:1285:-1:1,
> destinations=1, dispatched=0, delivered=0, pending=0, lastDeliveredSeqId: 0,
> dequeues: 26950, dispatched: 26950, inflight: 0 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Transport:
> tcp:///127.0.0.1:50560@61612
> 2012-10-29 15:26:35,688 | DEBUG | Unregistering MBean
> org.apache.activemq:BrokerName=hub,Type=Producer,destinationType=Dynamic,clientId=account_events_receiver,producerId=ID_billing-35190-1351511867558-2_1285_-1_1
> | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport:
> tcp:///127.0.0.1:50560@61612
> 2012-10-29 15:26:35,688 | DEBUG | Unregistering MBean
> org.apache.activemq:BrokerName=hub,Type=Connection,ConnectorName=stomp,Connection=account_events_receiver
> | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport:
> tcp:///127.0.0.1:50560@61612
> 2012-10-29 15:26:35,688 | DEBUG | bridging (hub -> drax)
> ID:billing-35190-1351511867558-1:1:0:0:80197, consumer:
> ID:billing-35190-1351511867558-9:1:1:1, destination
> topic://ActiveMQ.Advisory.Consumer.Queue.account_events, brokerPath:
> [ID:billing-35190-1351511867558-0:1], message: ActiveMQMessage {commandId =
> 0, responseRequired = false, messageId =
> ID:billing-35190-1351511867558-1:1:0:0:80197, originalDestination = null,
> originalTransactionId = null, producerId =
> ID:billing-35190-1351511867558-9:2:1:1, destination =
> topic://ActiveMQ.Advisory.Consumer.Queue.account_events, transactionId =
> null, expiration = 0, timestamp = 0, arrival = 0, brokerInTime =
> 1351524395688, brokerOutTime = 1351524395688, correlationId = null, replyTo =
> null, persistent = false, type = Advisory, priority = 0, groupID = null,
> groupSequence = 0, targetConsumerId = null, compressed = false, userID =
> null, content = null, marshalledProperties = null, dataStructure = RemoveInfo
> {commandId = 0, responseRequired = false, objectId =
> ID:billing-35190-1351511867558-2:1285:-1:1, lastDeliveredSequenceId = 0},
> redeliveryCounter = 0, size = 1024, properties = {consumerCount=0,
> originBrokerURL=tcp://0.0.0.0:61616,
> originBrokerId=ID:billing-35190-1351511867558-0:1, originBrokerName=hub},
> readOnlyProperties = false, readOnlyBody = false, droppable = false} |
> org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
> BrokerService[hub] Task-110
> 2012-10-29 15:26:35,689 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-112
> 2012-10-29 15:26:36,847 | DEBUG | Setting up new connection id:
> ID:billing-35190-1351511867558-2:1304, address: tcp://127.0.0.1:50601, info:
> ConnectionInfo {commandId = 0, responseRequired = true, connectionId =
> ID:billing-35190-1351511867558-2:1304, clientId = account_events_receiver,
> clientIp = null, userName = , password = *****, brokerPath = null,
> brokerMasterConnector = false, manageable = false, clientMaster = true,
> faultTolerant = false, failoverReconnect = false} |
> org.apache.activemq.broker.TransportConnection | ActiveMQ Transport:
> tcp:///127.0.0.1:50601@61612
> 2012-10-29 15:26:36,887 | DEBUG | hub adding consumer:
> ID:billing-35190-1351511867558-2:1304:-1:1 for destination:
> queue://account_events | org.apache.activemq.broker.region.AbstractRegion |
> ActiveMQ Transport: tcp:///127.0.0.1:50601@61612
> 2012-10-29 15:26:36,888 | DEBUG | queue://account_events add sub:
> QueueSubscription: consumer=ID:billing-35190-1351511867558-2:1304:-1:1,
> destinations=0, dispatched=0, delivered=0, pending=0, dequeues: 26950,
> dispatched: 26950, inflight: 0 | org.apache.activemq.broker.region.Queue |
> ActiveMQ Transport: tcp:///127.0.0.1:50601@61612
> 2012-10-29 15:26:36,888 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-112
> 2012-10-29 15:26:36,889 | DEBUG | bridging (hub -> drax)
> ID:billing-35190-1351511867558-1:1:0:0:80200, consumer:
> ID:billing-35190-1351511867558-9:1:1:1, destination
> topic://ActiveMQ.Advisory.Consumer.Queue.account_events, brokerPath:
> [ID:billing-35190-1351511867558-0:1], message: ActiveMQMessage {commandId =
> 0, responseRequired = false, messageId =
> ID:billing-35190-1351511867558-1:1:0:0:80200, originalDestination = null,
> originalTransactionId = null, producerId =
> ID:billing-35190-1351511867558-9:2:1:1, destination =
> topic://ActiveMQ.Advisory.Consumer.Queue.account_events, transactionId =
> null, expiration = 0, timestamp = 0, arrival = 0, brokerInTime =
> 1351524396889, brokerOutTime = 1351524396889, correlationId = null, replyTo =
> null, persistent = false, type = Advisory, priority = 0, groupID = null,
> groupSequence = 0, targetConsumerId = null, compressed = false, userID =
> null, content = null, marshalledProperties = null, dataStructure =
> ConsumerInfo {commandId = 3, responseRequired = false, consumerId =
> ID:billing-35190-1351511867558-2:1304:-1:1, destination =
> queue://account_events, prefetchSize = 200, maximumPendingMessageLimit = 0,
> browser = false, dispatchAsync = true, selector = null, subscriptionName =
> null, noLocal = false, exclusive = false, retroactive = false, priority = 0,
> brokerPath = null, optimizedAcknowledge = false, noRangeAcks = false,
> additionalPredicate = null}, redeliveryCounter = 0, size = 1024, properties =
> {consumerCount=1, originBrokerURL=tcp://0.0.0.0:61616,
> originBrokerId=ID:billing-35190-1351511867558-0:1, originBrokerName=hub},
> readOnlyProperties = false, readOnlyBody = false, droppable = false} |
> org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
> BrokerService[hub] Task-112
> 2012-10-29 15:26:50,017 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:50,017 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:50,017 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-110
> 2012-10-29 15:26:50,017 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> 2012-10-29 15:26:52,134 | DEBUG | queue://account_events expiring messages ..
> | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:52,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub] Scheduler
> 2012-10-29 15:26:52,134 | DEBUG | account_events toPageIn: 91, Inflight: 0,
> pagedInMessages.size 0, enqueueCount: 27041, dequeueCount: 26950 |
> org.apache.activemq.broker.region.Queue | ActiveMQ BrokerService[hub] Task-110
> 2012-10-29 15:26:52,134 | DEBUG | queue://account_events expiring messages
> done. | org.apache.activemq.broker.region.Queue | ActiveMQ Broker[hub]
> Scheduler
> Around the time (cannot be certain, was not looking) of "breakage" a 10MB
> message was produced on this hub for consumption by each of the "production
> servers" via a topic. The heap memory rose from 100-200MB (normal) to
> 300-450MB at this point before levelling off around 200MB. The number of
> threads actually halved before rising to normal. It is unknown if this is a
> factor.
> Each "production server" correctly shows one consumer when it is connected
> from the hub.
> Continuing observations - restarting AMQ on the hub - a flood (7,000+) of
> messages have now arrived according to the web console and the consumer is
> racing through them. The production servers have cleared through their
> backlog having handed over to the hub.
> Some help isolating this with narrower debugging would be appreciated!
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
