activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From fenbers <Mark.Fenb...@noaa.gov>
Subject Re: Is AMQ-4118 really fixed?? Doubt it...
Date Mon, 06 May 2013 12:10:22 GMT
Here is the second log fro May 3 with a different error/stacktrace at
08:00:02,028, but is one mentioned to be fixed in AMQ-4118...  This error
did not trigger a self-shutdown of ActiveMQ, but ActiveMQ clients did cease
receiving messages from this broker.  Thus, from a client perspective,
ActiveMQ appeared to be hung.  Once restarting ActiveMQ, the clients once
again received their messages as normal.

Mark


2013-05-03 07:59:53,529 | DEBUG | Checkpoint started.
2013-05-03 07:59:53,530 | TRACE | Last update: 38:18645505, full gc
candidates set: [1, 2, 4, 10, 18, 20, 25, 29, 33, 34, 37, 38]
2013-05-03 07:59:53,530 | TRACE | gc candidates after tx range:[null, null],
[1, 2, 4, 10, 18, 20, 25, 29, 33, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after
dest:1:GIFTS.fromSnooper, [1, 2, 4, 10, 18, 20, 25, 29, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after dest:1:GIFTS.icon, [1,
2, 4, 10, 18, 20, 25, 29, 34, 37]
2013-05-03 07:59:53,530 | TRACE | gc candidates after dest:0:ActiveMQ.DLQ,
[34]
2013-05-03 07:59:53,530 | TRACE | gc candidates after
dest:1:LaunchPad.status, []
2013-05-03 07:59:53,530 | TRACE | gc candidates: []
2013-05-03 07:59:53,530 | DEBUG | Checkpoint done.
2013-05-03 07:59:54,973 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:54,973 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55434]
2013-05-03 07:59:55,496 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:55,496 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:55,496 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55436]
2013-05-03 07:59:55,496 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55435]
2013-05-03 07:59:56,370 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 07:59:56,370 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46764]
2013-05-03 07:59:57,366 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:57,366 | DEBUG | Running
WriteCheck[tcp://165.92.64.13:49884]
2013-05-03 07:59:57,514 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 07:59:57,514 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46765]
2013-05-03 07:59:58,551 | DEBUG | Checkpoint started.
2013-05-03 07:59:58,552 | DEBUG | Checkpoint done.
2013-05-03 07:59:58,595 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 07:59:58,595 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:46766]
2013-05-03 07:59:59,544 | DEBUG | 30005 ms elapsed since last read check.
2013-05-03 07:59:59,864 | DEBUG | WriteChecker 10001 ms elapsed since last
write check.
2013-05-03 07:59:59,864 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55438]
2013-05-03 08:00:00,481 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:00,482 | DEBUG | Running
WriteCheck[tcp://165.92.64.12:58049]
2013-05-03 08:00:01,022 | DEBUG | WriteChecker 10003 ms elapsed since last
write check.
2013-05-03 08:00:01,022 | DEBUG | Running
WriteCheck[tcp://165.92.64.10:55439]
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | WriteChecker 10002 ms elapsed since last
write check.
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.37:57958]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.75:38850]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.37:57959]
2013-05-03 08:00:01,632 | DEBUG | Running
WriteCheck[tcp://165.92.64.75:38849]
2013-05-03 08:00:01,932 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,938 | DEBUG | tcp:///165.92.64.31:37879@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:01,938 | DEBUG | tcp:///165.92.64.31:37879@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-05-03 08:00:01,950 | DEBUG | Setting up new connection id:
ID:dell8-tir-49417-1367582401815-1:1, address: tcp://165.92.64.31:37879,
info: ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:dell8-tir-49417-1367582401815-1:1, clientId =
ID:dell8-tir-49417-1367582401815-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:01,950 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:01,950 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:01,961 | DEBUG | localhost adding consumer:
ID:dell8-tir-49417-1367582401815-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:01,961 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:dell8-tir-49417-1367582401815-1:1:-1:1
2013-05-03 08:00:01,995 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=104857600,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:01,997 | DEBUG | tcp:///165.92.64.8:48597@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:01,997 | DEBUG | tcp:///165.92.64.8:48597@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=104857600}
2013-05-03 08:00:02,001 | DEBUG | Setting up new connection id:
ID:px2-tir-33688-1367582401885-1:1, address: tcp://165.92.64.8:48597, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:px2-tir-33688-1367582401885-1:1, clientId =
ID:px2-tir-33688-1367582401885-0:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,001 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,001 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,007 | DEBUG | localhost adding consumer:
ID:px2-tir-33688-1367582401885-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,007 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:px2-tir-33688-1367582401885-1:1:-1:1
2013-05-03 08:00:02,008 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,008 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,025 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,025 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:1 syncCount: 2
2013-05-03 08:00:02,026 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,028 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,028 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:2 syncCount: 2
2013-05-03 08:00:02,028 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=765,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,028 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=765,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,029 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,029 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 1078, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-1:1:1:1:1072, originalDestination
= null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-1:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402027, arrival = 0, brokerInTime = 1367582402027,
brokerOutTime = 1367582402026, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SAGU:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,030 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:3 syncCount: 2
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,030 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,031 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,032 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,032 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:4 syncCount: 2
2013-05-03 08:00:02,032 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,034 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,034 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:5 syncCount: 2
2013-05-03 08:00:02,034 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,036 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,036 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:6 syncCount: 2
2013-05-03 08:00:02,037 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,038 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,038 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:7 syncCount: 2
2013-05-03 08:00:02,039 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,043 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-0_1,producerId=ID_rp1-tir-53724-1367411226416-1_1_1_1
2013-05-03 08:00:02,043 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,043 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,044 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-0_1,consumerId=ID_rp1-tir-53724-1367411226416-1_1_-1_1
2013-05-03 08:00:02,044 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-1:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,044 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-1:1
2013-05-03 08:00:02,044 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,044 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,045 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-0_1
2013-05-03 08:00:02,045 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_38849
2013-05-03 08:00:02,045 | DEBUG | Stopping connection:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,045 | DEBUG | Stopping transport
tcp:///165.92.64.75:38849@61616
2013-05-03 08:00:02,045 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@152d5a8
2013-05-03 08:00:02,045 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=38849,localport=61616]
2013-05-03 08:00:02,045 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@152d5a8
2013-05-03 08:00:02,045 | DEBUG | Stopped transport:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,045 | DEBUG | Connection Stopped:
tcp://165.92.64.75:38849
2013-05-03 08:00:02,046 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,046 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:8 syncCount: 2
2013-05-03 08:00:02,049 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,049 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,050 | DEBUG | tcp:///165.92.64.75:44666@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,050 | DEBUG | tcp:///165.92.64.75:44666@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,050 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-5:1, address: tcp://165.92.64.75:44666, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-5:1, clientId =
ID:rp1-tir-53724-1367411226416-4:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,050 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,050 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,051 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,051 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:9 syncCount: 2
2013-05-03 08:00:02,051 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,051 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-5:1:-1:1
2013-05-03 08:00:02,051 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,053 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,053 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:10 syncCount: 2
2013-05-03 08:00:02,054 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,055 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,055 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=766,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,055 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=766,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,056 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,056 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 5, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-5:1:1:1:1, originalDestination =
null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-5:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402054, arrival = 0, brokerInTime = 1367582402054,
brokerOutTime = 1367582402028, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SAGL:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,056 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,056 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:11 syncCount: 2
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-4_1,producerId=ID_rp1-tir-53724-1367411226416-5_1_1_1
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-4_1,consumerId=ID_rp1-tir-53724-1367411226416-5_1_-1_1
2013-05-03 08:00:02,057 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-5:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,057 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-5:1
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,057 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-4_1
2013-05-03 08:00:02,057 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_44666
2013-05-03 08:00:02,057 | DEBUG | Stopping connection:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,057 | DEBUG | Stopping transport
tcp:///165.92.64.75:44666@61616
2013-05-03 08:00:02,057 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@dd50ca
2013-05-03 08:00:02,058 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=44666,localport=61616]
2013-05-03 08:00:02,058 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@dd50ca
2013-05-03 08:00:02,058 | DEBUG | Stopped transport:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,058 | DEBUG | Connection Stopped:
tcp://165.92.64.75:44666
2013-05-03 08:00:02,058 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,058 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:12 syncCount: 2
2013-05-03 08:00:02,059 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,059 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,060 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,060 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,060 | DEBUG | tcp:///165.92.64.75:44667@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,060 | DEBUG | tcp:///165.92.64.75:44667@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,060 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-7:1, address: tcp://165.92.64.75:44667, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-7:1, clientId =
ID:rp1-tir-53724-1367411226416-6:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,060 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,060 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,061 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-7:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,061 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-7:1:-1:1
2013-05-03 08:00:02,061 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,061 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:13 syncCount: 2
2013-05-03 08:00:02,061 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,062 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,062 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,063 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,063 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:14 syncCount: 2
2013-05-03 08:00:02,064 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,064 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,065 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=767,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,065 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=767,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,065 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,065 | DEBUG | Error occured while processing sync
command: ActiveMQTextMessage {commandId = 5, responseRequired = true,
messageId = ID:rp1-tir-53724-1367411226416-7:1:1:1:1, originalDestination =
null, originalTransactionId = null, producerId =
ID:rp1-tir-53724-1367411226416-7:1:1:1, destination =
topic://GIFTS.fromSnooper, transactionId = null, expiration = 1367604000000,
timestamp = 1367582402064, arrival = 0, brokerInTime = 1367582402064,
brokerOutTime = 1367582402030, correlationId = null, replyTo = null,
persistent = true, type = null, priority = 4, groupID = null, groupSequence
= 0, targetConsumerId = null, compressed = false, userID = null, content =
null, marshalledProperties = null, dataStructure = null, redeliveryCounter =
0, size = 1064, properties = null, readOnlyProperties = false, readOnlyBody
= false, droppable = false, text = oper@dell8-tir:INITIALIZED:SMNU:oper},
exception: java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
java.lang.RuntimeException: java.lang.RuntimeException:
java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:113)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	... 27 more
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,065 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,065 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:15 syncCount: 2
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=GIFTS.fromSnooper,endpoint=Producer,clientId=ID_rp1-tir-53724-1367411226416-6_1,producerId=ID_rp1-tir-53724-1367411226416-7_1_1_1
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,destinationType=Topic,destinationName=ActiveMQ.Advisory.TempQueue_ActiveMQ.Advisory.TempTopic,endpoint=Consumer,clientId=ID_rp1-tir-53724-1367411226416-6_1,consumerId=ID_rp1-tir-53724-1367411226416-7_1_-1_1
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,066 | DEBUG | localhost removing consumer:
ID:rp1-tir-53724-1367411226416-7:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,066 | DEBUG | remove connection id:
ID:rp1-tir-53724-1367411226416-7:1
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,066 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,066 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=clientId,connectionName=ID_rp1-tir-53724-1367411226416-6_1
2013-05-03 08:00:02,067 | DEBUG | Unregistering MBean
org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=openwire,connectionViewType=remoteAddress,connectionName=tcp_//165.92.64.75_44667
2013-05-03 08:00:02,067 | DEBUG | Stopping connection:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,067 | DEBUG | Stopping transport
tcp:///165.92.64.75:44667@61616
2013-05-03 08:00:02,067 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ
Task] using ExecutorService: java.util.concurrent.ThreadPoolExecutor@12e359a
2013-05-03 08:00:02,067 | DEBUG | Closed socket
Socket[addr=/165.92.64.75,port=44667,localport=61616]
2013-05-03 08:00:02,067 | DEBUG | Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@12e359a
2013-05-03 08:00:02,067 | DEBUG | Stopped transport:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,067 | DEBUG | Connection Stopped:
tcp://165.92.64.75:44667
2013-05-03 08:00:02,068 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,068 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:16 syncCount: 2
2013-05-03 08:00:02,068 | DEBUG | Sending: WireFormatInfo { version=9,
properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,068 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,068 | DEBUG | Using min of local: WireFormatInfo {
version=9, properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo
{ version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,069 | DEBUG | Received WireFormat: WireFormatInfo {
version=9, properties={CacheSize=1024, MaxFrameSize=9223372036854775807,
CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
MaxInactivityDurationInitalDelay=10000, MaxInactivityDuration=30000,
TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2013-05-03 08:00:02,069 | DEBUG | tcp:///165.92.64.75:44668@61616 before
negotiation: OpenWireFormat{version=9, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,069 | DEBUG | tcp:///165.92.64.75:44668@61616 after
negotiation: OpenWireFormat{version=9, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true, sizePrefixDisabled=false,
maxFrameSize=9223372036854775807}
2013-05-03 08:00:02,069 | DEBUG | Setting up new connection id:
ID:rp1-tir-53724-1367411226416-9:1, address: tcp://165.92.64.75:44668, info:
ConnectionInfo {commandId = 1, responseRequired = true, connectionId =
ID:rp1-tir-53724-1367411226416-9:1, clientId =
ID:rp1-tir-53724-1367411226416-8:1, clientIp = null, userName = null,
password = *****, brokerPath = null, brokerMasterConnector = false,
manageable = true, clientMaster = true, faultTolerant = false,
failoverReconnect = false}
2013-05-03 08:00:02,069 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,069 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,070 | DEBUG | localhost adding consumer:
ID:rp1-tir-53724-1367411226416-9:1:-1:1 for destination:
ActiveMQ.Advisory.TempQueue,ActiveMQ.Advisory.TempTopic
2013-05-03 08:00:02,070 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,070 | DEBUG | Setting the maximumPendingMessages size
to: 1000 for consumer: ID:rp1-tir-53724-1367411226416-9:1:-1:1
2013-05-03 08:00:02,070 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:17 syncCount: 2
2013-05-03 08:00:02,070 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,071 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,071 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,072 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,072 | DEBUG | commit:
TX:ID:dell8-tir-49417-1367582401815-1:1:18 syncCount: 2
2013-05-03 08:00:02,073 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory
2013-05-03 08:00:02,073 | DEBUG | default:memory: usage change from: 69% of
available memory, to: 70% of available memory
2013-05-03 08:00:02,073 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=768,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.ClassCastException
2013-05-03 08:00:02,073 | ERROR |
TopicStorePrefetch(GIFTS.Status.crawford@lx1-tir,GIFTS.Status)
ID:lx1-tir-51267-1367578944145-7:1:1:1 -
org.apache.activemq.broker.region.cursors.TopicStorePrefetch@55e026:GIFTS.fromSnooper,batchResetNeeded=false,storeHasMessages=true,size=768,cacheEnabled=false,maxBatchSize:200
- Failed to fill batch
java.lang.RuntimeException: java.lang.ClassCastException
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:277)
	at
org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:110)
	at
org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:287)
	at
org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:628)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.dispatchPending(DurableTopicSubscription.java:265)
	at
org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:162)
	at
org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:259)
	at
org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:48)
	at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:688)
	at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:499)
	at org.apache.activemq.broker.region.Topic.send(Topic.java:435)
	at
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:406)
	at
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:392)
	at
org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:282)
	at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
	at
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
	at
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:317)
	at
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
	at
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:499)
	at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:749)
	at
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:329)
	at
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:184)
	at
org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
	at
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
	at
org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:288)
	at
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
	at
org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)
	at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)
	at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.ClassCastException
2013-05-03 08:00:02,074 | DEBUG | default:memory: usage change from: 70% of
available memory, to: 69% of available memory




--
View this message in context: http://activemq.2283324.n4.nabble.com/Is-AMQ-4118-really-fixed-Doubt-it-tp4666470p4666654.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Mime
View raw message