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

Reply via email to