You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "James Furness (Updated) (JIRA)" <ji...@apache.org> on 2012/01/26 14:48:41 UTC

[jira] [Updated] (AMQ-3677) NullPointerException in MessageDatabase leaves message stuck in KahaDB

     [ https://issues.apache.org/jira/browse/AMQ-3677?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

James Furness updated AMQ-3677:
-------------------------------

    Component/s: Broker
    
> NullPointerException in MessageDatabase leaves message stuck in KahaDB
> ----------------------------------------------------------------------
>
>                 Key: AMQ-3677
>                 URL: https://issues.apache.org/jira/browse/AMQ-3677
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.5.1
>         Environment: ActiveMQ: 5.5.1-fuse-01-13
> JVM: 1.6.0_30-b12
>            Reporter: James Furness
>
> A message appears to have gotten into a stuck state where it cannot be expired from KahaDB.
> Each expiry pass (every 30 seconds) is failing, presumably on the same message as the destination/expiration/timestamp/brokerInTime/etc are all identical:
> {code}
> 2012-01-23 14:02:48,191 ERROR ranteed.2] Scheduler BrokerLauncher                                 org.apache.activemq.broker.ConnectionContext@7c0e6709: Persistent message has expired: ActiveMQBytesMessage {commandId = 1611, responseRequired = true, messageId = ID:broker1-59818-1327207516246-2:1:1:2:1, originalDestination = null, originalTransactionId = null, producerId = ID:broker-38443-1327100544854-21:1:1:1, destination = topic://TOPIC, transactionId = null, expiration = 1327294033981, timestamp = 1327207633981, arrival = 0, brokerInTime = 1327207633998, brokerOutTime = 1327207633993, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@35fa419, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false} ActiveMQBytesMessage{ bytesOut = null, dataOut = null, dataIn = null } for DurableTopicSubscription-NC_broker.1_inbound_broker.1.SystemGuaranteed.2:NC-DS_broker.1.SystemGuaranteed.2_TOPIC, id=OFFLINE:1:17, active=false, destinations=1, total=9, pending=9, dispatched=0, inflight=0, prefetchExtension=0
> 2012-01-23 14:02:48,191 ERROR ranteed.2] Scheduler BrokerLauncher                                 Sent to DLQ: ActiveMQBytesMessage {commandId = 1611, responseRequired = true, messageId = ID:broker1-59818-1327207516246-2:1:1:2:1, originalDestination = null, originalTransactionId = null, producerId = ID:broker-38443-1327100544854-21:1:1:1, destination = topic://TOPIC, transactionId = null, expiration = 1327294033981, timestamp = 1327207633981, arrival = 0, brokerInTime = 1327207633998, brokerOutTime = 1327207633993, correlationId = null, replyTo = null, persistent = true, type = null, priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null, compressed = false, userID = null, content = org.apache.activemq.util.ByteSequence@35fa419, marshalledProperties = null, dataStructure = null, redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties = false, readOnlyBody = false, droppable = false} ActiveMQBytesMessage{ bytesOut = null, dataOut = null, dataIn = null } DurableTopicSubscription-NC_broker.1_inbound_broker.2:NC-DS_broker.2_TOPIC, id=OFFLINE:1:17, active=false, destinations=1, total=9, pending=9, dispatched=0, inflight=0, prefetchExtension=0 org.apache.activemq.broker.ConnectionContext@7c0e6709
> 2012-01-23 14:02:48,192 ERROR ranteed.2] Scheduler o.a.a.broker.region.Topic                                Failed to remove expired Message from the store 
> java.lang.NullPointerException: null
>         at org.apache.activemq.store.kahadb.MessageDatabase.removeAckLocation(MessageDatabase.java:1920) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:1197) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase$15.execute(MessageDatabase.java:990) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.kahadb.page.Transaction.execute(Transaction.java:760) ~[kahadb-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:988) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:923) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.data.KahaRemoveMessageCommand.visit(KahaRemoveMessageCommand.java:220) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:915) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:827) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.doAcknowledge(KahaDBStore.java:693) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.acknowledge(KahaDBStore.java:679) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBTransactionStore.acknowledge(KahaDBTransactionStore.java:492) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBTransactionStore$2.acknowledge(KahaDBTransactionStore.java:201) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic.acknowledge(Topic.java:494) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic.messageExpired(Topic.java:686) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic.doBrowse(Topic.java:568) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic.access$100(Topic.java:63) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic$6.run(Topic.java:667) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.thread.SchedulerTimerTask.run(SchedulerTimerTask.java:33) [activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at java.util.TimerThread.mainLoop(Unknown Source) [na:1.6.0_30]
>         at java.util.TimerThread.run(Unknown Source) [na:1.6.0_30]
> {code}
> Restarting the broker does not help. Restarting the client causes the same exception to be serialised to the client:
> {code}
> 2012-01-23 01:40:49,903 ERROR true&soTimeout=60000 ErrorListener                           Error
> javax.jms.JMSException: java.lang.NullPointerException
>         at org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:49) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.ActiveMQConnection.onAsyncException(ActiveMQConnection.java:1855) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.ActiveMQConnection$2$1.run(ActiveMQConnection.java:1776) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) [na:1.6.0_30]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [na:1.6.0_30]
>         at java.lang.Thread.run(Unknown Source) [na:1.6.0_30]
> Caused by: java.lang.NullPointerException: null
>         at org.apache.activemq.store.kahadb.MessageDatabase.removeAckLocation(MessageDatabase.java:1920) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.updateIndex(MessageDatabase.java:1197) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase$15.execute(MessageDatabase.java:990) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.kahadb.page.Transaction.execute(Transaction.java:760) ~[kahadb-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:988) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase$13.visit(MessageDatabase.java:923) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.data.KahaRemoveMessageCommand.visit(KahaRemoveMessageCommand.java:220) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.process(MessageDatabase.java:915) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:827) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.doAcknowledge(KahaDBStore.java:693) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBStore$KahaDBTopicMessageStore.acknowledge(KahaDBStore.java:679) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBTransactionStore.acknowledge(KahaDBTransactionStore.java:492) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.store.kahadb.KahaDBTransactionStore$2.acknowledge(KahaDBTransactionStore.java:201) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.Topic.acknowledge(Topic.java:494) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.DurableTopicSubscription.acknowledge(DurableTopicSubscription.java:270) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.PrefetchSubscription.acknowledge(PrefetchSubscription.java:229) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.AbstractRegion.acknowledge(AbstractRegion.java:427) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.region.RegionBroker.acknowledge(RegionBroker.java:568) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.BrokerFilter.acknowledge(BrokerFilter.java:77) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.TransactionBroker.acknowledge(TransactionBroker.java:276) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.MutableBrokerFilter.acknowledge(MutableBrokerFilter.java:87) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.TransportConnection.processMessageAck(TransportConnection.java:477) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.command.MessageAck.visit(MessageAck.java:229) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:318) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:181) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.nio.NIOTransport.serviceRead(NIOTransport.java:138) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.nio.NIOTransport$1.onSelect(NIOTransport.java:69) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:94) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         at org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:119) ~[activemq-core-5.5.1-fuse-01-13.jar:5.5.1-fuse-01-13]
>         ... 3 common frames omitted
> {code}
> Is there any mechanism to purge the stuck message (without blowing away the whole database), or deal with the situation automatically?

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira