Hi Lorinda,
I have some debug info from another crash we had last night and I got some debug information if it helps.
The scenario is a STOMP durable consumer reading off a topic with ~40K messages per hour being sent to the topic. I create a new durable consumer and after reading ~ 17000 messages from the topic we see the following on the client side:
java.lang.RuntimeException: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the data store - already dispatched
java.lang.RuntimeException: java.lang.RuntimeException: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the data store - already dispatched
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:104)
at org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:225)
at org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:560)
at org.apache.activemq.broker.region.DurableTopicSubscription.activate(DurableTopicSubscription.java:130)
at org.apache.activemq.broker.region.TopicRegion.addConsumer(TopicRegion.java:105)
at org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:376)
at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
at org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:85)
at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
at org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:93)
at org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:546)
at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:349)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:308)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:182)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:78)
at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:135)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompSubscribe(ProtocolConverter.java:414)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:183)
at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:67)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.RuntimeException: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the data store - already dispatched
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:239)
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:101)
... 24 more
Caused by: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the data store - already dispatched
at org.apache.activemq.store.amq.RecoveryListenerAdapter.recoverMessageReference(RecoveryListenerAdapter.java:58)
at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverReference(KahaReferenceStore.java:82)
at org.apache.activemq.store.kahadaptor.KahaTopicReferenceStore.recoverNextMessages(KahaTopicReferenceStore.java:287)
at org.apache.activemq.store.amq.AMQTopicMessageStore.recoverNextMessages(AMQTopicMessageStore.java:59)
at org.apache.activemq.broker.region.cursors.TopicStorePrefetch.doFillBatch(TopicStorePrefetch.java:91)
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:236)
... 25 more
Then we get the durable consumer already connected when the consumer restarts:
message: Durable consumer is in use for client: SWAT Importer - prod and subscriptionName: EGEE WN
javax.jms.JMSException: Durable consumer is in use for client: SWAT Importer - prod and subscriptionName: EGEE WN
at org.apache.activemq.broker.region.TopicRegion.addConsumer(TopicRegion.java:75)
at org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:376)
at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86) at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.j
ava:86) at org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:85)
at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86) at org.apache.activemq.broker.MutableBrokerFilter.addConsumer(Mutable
BrokerFilter.java:93) at org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:546)
at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:349)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:308)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:182)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68) at org.apache.activemq.transport.stomp.StompTransportFilter.se
ndToActiveMQ(StompTransportFilter.java:78)
at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:135)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompSubscribe(ProtocolConverter.java:414)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:183) at org.apache.activemq.transport.stomp.StompTr
ansportFilter.onCommand(StompTransportFilter.java:67)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203) at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.
java:185)
at java.lang.Thread.run(Thread.java:595)
In the web console we see that original consumer is still 'connected' -e.g consumer count rises to 2. Also after this point any consumer that connects to the topic gets no messages or errors, and the server logs fills up with the error :
2009-07-03 09:57:24,514 ERROR AbstractStoreCursor - Failed to fill batch
java.lang.RuntimeException: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the d
ata store - already dispatched
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:239)
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:101)
at org.apache.activemq.broker.region.cursors.StoreDurableSubscriberCursor.reset(StoreDurableSubscriberCursor.java:225)
at org.apache.activemq.broker.region.PrefetchSubscription.dispatchPending(PrefetchSubscription.java:560)
at org.apache.activemq.broker.region.PrefetchSubscription.add(PrefetchSubscription.java:154)
at org.apache.activemq.broker.region.DurableTopicSubscription.add(DurableTopicSubscription.java:197)
at org.apache.activemq.broker.region.policy.SimpleDispatchPolicy.dispatch(SimpleDispatchPolicy.java:49)
at org.apache.activemq.broker.region.Topic.dispatch(Topic.java:568)
at org.apache.activemq.broker.region.Topic.doMessageSend(Topic.java:426)
at org.apache.activemq.broker.region.Topic.send(Topic.java:364)
at org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:354)
at org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:438)
at org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:224)
at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
at org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:95)
at org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:133)
at org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:455)
at org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:639)
at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:308)
at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:182)
at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
at org.apache.activemq.transport.stomp.StompTransportFilter.sendToActiveMQ(StompTransportFilter.java:78)
at org.apache.activemq.transport.stomp.ProtocolConverter.sendToActiveMQ(ProtocolConverter.java:135)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompSend(ProtocolConverter.java:247)
at org.apache.activemq.transport.stomp.ProtocolConverter.onStompCommand(ProtocolConverter.java:173)
at org.apache.activemq.transport.stomp.StompTransportFilter.onCommand(StompTransportFilter.java:67)
at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.IllegalStateException: Message id ID:gridmsg101.cern.ch-51802-1246440493711-2:10528:1:1:1 could not be recovered from the data store - alrea
dy dispatched
at org.apache.activemq.store.amq.RecoveryListenerAdapter.recoverMessageReference(RecoveryListenerAdapter.java:58)
at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverReference(KahaReferenceStore.java:82)
at org.apache.activemq.store.kahadaptor.KahaTopicReferenceStore.recoverNextMessages(KahaTopicReferenceStore.java:287)
at org.apache.activemq.store.amq.AMQTopicMessageStore.recoverNextMessages(AMQTopicMessageStore.java:59)
at org.apache.activemq.broker.region.cursors.TopicStorePrefetch.doFillBatch(TopicStorePrefetch.java:91)
at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:236)
... 29 more
cheers,
James.