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.