Do you have 170 TCP connections, or is it just the broker that believes
that there are that many?
The fact that the broker is seeing an EOFException means that the client is
closing the connection, so I'd focus on your consumers. I know you said you
don't think they're having errors, but that's what this looks like to me,
so I'd focus on that.
A packet sniffer like Wireshark might help you to confirm that assumption,
though it might be harder if you can't reproduce the problem on demand...
Tim
On Tue, Apr 2, 2019, 1:31 PM jayh <londonhardcorera...@hotmail.com> wrote:
> Can anyone please help me understand this error which has only just started
> showing up out of nowhere on a production server.
>
> This is the current version of AMQ (5.15.9) and was also seen in the
> previous version 5.15.8. Its a local broker with a JMS bridge to a remote
> server connecting and consuming a mix of topics and queues which are
> presented locally for internal use. The server config is unchanged when
> this
> issue first showed up.
>
> It was first noticed through the increase in memory usage for storage of
> the
> DB files. On closer inspection it looked like clients where disconnecting
> and reconnecting with no error on the client and only the following logged
> on the server side;
>
> 2019-03-29 01:50:15,134 | INFO | JmsConnector handling loss of connection
> [ActiveMQConnection
>
> {id=ID:xs-43093-1553805148029-2:2,clientId=ID:xs-43093-1553805148029-1:2,started=true}]
> | org.apache.activemq.network.jms.JmsConnector | ActiveMQ Session Task-348
>
> A deeper dig into the TRACE logs tonight while the server was slightly less
> busy relieved the following logged. I've also noted the connection count is
> now sat at more than 170 where as there are only 20 something consumers
> actually connected right now.
>
> 2019-04-02 19:29:20,360 | TRACE | ID:xs-39837-1553964750839-4:140:2 sending
> message:
> ActiveMQTextMessage {commandId = 3319310, responseRequired = false, mes
> sageId = ID:xs-39837-1553964750839-4:140:2:1:1, originalDestination =
> null,
> originalTransactionId = null, producerId =
> ID:xs-39837-1553964750839-4:140:2:1,
> destination = topic://CLIENT_ALL, transactionId = null, expiration = 0,
> timestamp =
> 1554229760360, arrival = 0, brokerInTime = 1554229755115, brokerOutTime =
> 15
> 54229755118, correlationId = null, replyTo = null, persistent = true, type
> =
> null, priority =
> 4, groupID = null, groupSequence = 0, targetConsumerId = null,
> compressed = true, userID = null, content =
> org.apache.activemq.util.ByteSequence@2a02b7e9,
> marshalledProperties = org.apache.activemq.util.ByteSequence@7d
> db0ca1, dataStructure = null, redeliveryCounter = 0, size = 0, properties =
> null,
> readOnlyProperties = true, readOnlyBody = true, droppable = false,
> jmsXGroupFirstForConsumer
> = false, text =
> [{"XP_MSG":{"time":"1554229754000","area_id":...r":"TEST"}}]} |
> org.apache.activemq.ActiveMQSession | ActiveMQ Session Task-4447
> 2019-04-02 19:29:20,360 | TRACE | Running task iteration 0 -
> vm://xs.dev.local#279 |
> org.apache.activemq.thread.PooledTaskRunner | ActiveMQ VMTransport:
> vm://xs.dev.local#279-1
> 2019-04-02 19:29:20,400 | DEBUG | Error occured while processing sync
> command:
> ActiveMQTextMessage {commandId = 7, responseRequired = true, messageId =
> ID:xs-39837-
> 1553964750839-4:140:2:1:1, originalDestination = null,
> originalTransactionId
> = null,
> producerId = ID:xs-39837-1553964750839-4:140:2:1, destination =
> topic://CLIENT_ALL, transactionId
> = null, expiration = 0, timestamp = 1554229760360, arrival = 0,
> brokerInTime
> = 1554229760361,
> brokerOutTime = 1554229755118, correlationId = null, replyTo = null,
> persistent = true, type
> = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId =
> null, compressed
> = true, userID = null, content =
> org.apache.activemq.util.ByteSequence@2a02b7e9,
> marshalledProperties = org.apache.activemq.util.ByteSequence@7ddb0ca1,
> dataStructure = null,
> redeliveryCounter = 0, size = 1595, properties = null, readOnlyProperties =
> true,
> readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer = false,
> text =
> [{"XP_MSG":{"time":"1554229754000","area_id":...r":"TEST"}}]}, exception:
> java.io.EOFException |
> org.apache.activemq.broker.TransportConnection.Service | ActiveMQ
> VMTransport: vm://xs.dev.local#279-1
> java.io.EOFException
> at
>
> java.io.DataInputStream.readUnsignedShort(DataInputStream.java:340)[:1.8.0_201]
> at
> java.io.DataInputStream.readUTF(DataInputStream.java:589)[:1.8.0_201]
> at
> java.io.DataInputStream.readUTF(DataInputStream.java:564)[:1.8.0_201]
> at
> org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap
> (MarshallingSupport.java:97)[activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap
> (MarshallingSupport.java:78)[activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.util.MarshallingSupport.unmarshalPrimitiveMap
> (MarshallingSupport.java:70)[activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.command.Message.unmarsallProperties(Message.java:252)
> [activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.command.Message.getProperty(Message.java:202)[activemq-
> client-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.region.policy.RetainedMessageSubscriptionRecoveryPolicy.add
>
> (RetainedMessageSubscriptionRecoveryPolicy.java:53)[activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.region.Topic.dispatch(Topic.java:756)[activemq-broker-
> 5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:556)[activemq-
> broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.region.Topic.send(Topic.java:484)[activemq-broker-
> 5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.region.DestinationFilter.send
> (DestinationFilter.java:138)[activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:508)
> [activemq-broker-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:459)
> [activemq-broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.jmx.ManagedRegionBroker.send
> (ManagedRegionBroker.java:293)[activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-
> broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.CompositeDestinationBroker.send
> (CompositeDestinationBroker.java:96)[activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:293)
> [activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-
> broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-
> broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.security.AuthorizationBroker.send
> (AuthorizationBroker.java:226)[activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:154)[activemq-
> broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.TransportConnection.processMessage
> (TransportConnection.java:578)[activemq-broker-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:768)
> [activemq-client-5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.TransportConnection.service
> (TransportConnection.java:336)[activemq-broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.broker.TransportConnection$1.onCommand
> (TransportConnection.java:200)[activemq-broker-5.15.9.jar:5.15.9]
> at org.apache.activemq.transport.ResponseCorrelator.onCommand
> (ResponseCorrelator.java:116)[activemq-client-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
> [activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:275)
> [activemq-broker-5.15.9.jar:5.15.9]
> at
>
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
> [activemq-client-5.15.9.jar:5.15.9]
> at
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
> [activemq-client-5.15.9.jar:5.15.9]
> at
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [:1.8.0_201]
> at
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [:1.8.0_201]
> at java.lang.Thread.run(Thread.java:748)[:1.8.0_201]
>
> Consumers are on the same local host using stomp (current version) via
> ruby.
> The clients don't appear to exhibit any errors when this happens, but my
> dequeued message rate is millions per day so it's not very easy to check. I
> have an identical AMQ deployment on another test VM consuming and
> processing
> the same data and that system does not have the same issues.
>
> Can anyone point me in the right direction as to how to start diagnosing
> this issue. I suspect in the next 24hours or so I'm going to have an OOM
> crash so may restart the broker tonight and clear the storage DB manually.
>
>
>
>
> --
> Sent from:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
>
