You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Dejan Bosanac (JIRA)" <ji...@apache.org> on 2010/12/02 14:11:18 UTC
[jira] Updated: (AMQ-2362) ActiveMQ5.2 - Some listeners stopped
getting messages. Even after restart of the broker/client the messages were
not getting picked. Then we stopped ActiveMQ 5.2 and started Active mq 4.1
(we migrated some one week back) and then client and it worked
[ https://issues.apache.org/jira/browse/AMQ-2362?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dejan Bosanac updated AMQ-2362:
-------------------------------
Fix Version/s: (was: 5.4.2)
5.5.0
> ActiveMQ5.2 - Some listeners stopped getting messages. Even after restart of the broker/client the messages were not getting picked. Then we stopped ActiveMQ 5.2 and started Active mq 4.1 (we migrated some one week back) and then client and it worked
> ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: AMQ-2362
> URL: https://issues.apache.org/jira/browse/AMQ-2362
> Project: ActiveMQ
> Issue Type: Bug
> Components: Broker
> Affects Versions: 5.2.0
> Environment: linux 32 bit -2.6.18-92.el5 i686 i686 i386 GNU/Linux-, jre1.6.0_10
> Reporter: Kanonymous
> Fix For: 5.5.0
>
>
> This seems to be a very wierd issue which came on the production env.
> Set up- we are using one broker which is in our inside zone and many producers and consumers started in different applications,both in the internal zone and in the DMZ, to connect to the broker.
> We were using 4.1 active mq till last week on our production enviornment and were having some issues with the number of connections sometimes were getting increased and hence after quite a bit of testing we tried to move to the 5.2 active mq. So we migrated on Monday 17Aug at around 0500 hours IST and it worked fine till Friday 0840 hours IST and after that some listeners stopped working. The consumers were showing connected but they were not receiving any message from the broker. At the same time we saw some exception like this in the broker (please note - we used journal with jdbc)
> --------------------------------------------------------
> :23 JournalPersistenceAdapter - Failed to mark the Journal: org.apache.activeio.journal.InvalidRecordLocationException: The
> location is less than the last mark.
> org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> at org.apache.activeio.journal.active.JournalImpl.setMark(JournalImpl.java:340)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:416)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter$1.iterate(JournalPersistenceAdapter.java:121)
> at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
> ---------------------------------------------------------------------------------------------------------
> We then restarted the broker a few times (even deleted the journal and the mesasges from DB as we did not wanted to process old messages in the system) and then this started working. Now a problem of duplicate messages started coming and checking for the net we got one fuse solution.."5.2.0.1-fuse" and we patched this release at around 1730 Hours Friday 21 Aug IST. Also for checking purpose we also changed our persistent strategy to AMP
> using the following
> <persistenceAdapter>
> <amqPersistenceAdapter syncOnWrite="false" directory="./activemq-data" maxFileLength="100 mb"/>
> </persistenceAdapter>
>
> . This worked fine (note- with considerable better performance) till around 2345 hours Friday 21 Aug IST and then again we started facing the same read location issue and our listeners stopped getting message. (Please note - Not all the listeners stopped. Somehow only the listeners in the DMZ zone stopped. In the same application the producers (based on the pooled connection factory) were working fine. Again in the broker the same error was being seen
> -------------------------------------------------------------------------------------------------------------
> :23 JournalPersistenceAdapter - Failed to mark the Journal: org.apache.activeio.journal.InvalidRecordLocationException: The
> location is less than the last mark.
> org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> at org.apache.activeio.journal.active.JournalImpl.setMark(JournalImpl.java:340)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:416)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter$1.iterate(JournalPersistenceAdapter.java:121)
> at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
> ------------------------------------------------------------------------------------------------------------------------------------------------
> Now we tried to restart the broker but we got some OOM issues - probably because of the Amq persistence Adapter and hence we reverted back to our normal journal and jdbc approach and started the broker. Our listener then connected fine and started working. This was around 0300hours IST on Saturday 22 Aug. It worked fine perfectly till about Saturday 22 Aug 2345 hours IST when again we started seeing the following errors in the broker
> ----------------------------------------------------------------------------------------------------------------------------------------------
> [ERROR] 00:12:22 JournalPersistenceAdapter - Failed to mark the Journal: org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> INFO | jvm 1 | 2009/08/23 00:12:23 | org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activeio.journal.active.JournalImpl.setMark(JournalImpl.java:340)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:416)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.store.journal.JournalPersistenceAdapter$1.iterate(JournalPersistenceAdapter.java:121)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.lang.Thread.run(Unknown Source)
> INFO | jvm 1 | 2009/08/23 00:12:23 | [ERROR] 00:12:23 JournalPersistenceAdapter - Failed to mark the Journal: org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> INFO | jvm 1 | 2009/08/23 00:12:23 | org.apache.activeio.journal.InvalidRecordLocationException: The location is less than the last mark.
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activeio.journal.active.JournalImpl.setMark(JournalImpl.java:340)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:416)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.store.journal.JournalPersistenceAdapter$1.iterate(JournalPersistenceAdapter.java:121)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> INFO | jvm 1 | 2009/08/23 00:12:23 | at java.lang.Thread.run(Unknown Source)
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------
> and again our listeners stopped picking up messages. Now again we tried to restart the broker and then the client but to no avail. Even we tried to put the broker on the debug mode (logging) and see if we get any errors but none were seen. By the ways the listener did not started picking up the message. So in such desparate situations we tried the following things
> a) Restarting broker and client again and again - but to no avail
> b) change back to Amq persistent stragtegy but again to no avail - we got this log in the broker log file
> -------------------------------------
> INFO | jvm 1 | 2009/08/23 02:36:01 | [ERROR] 02:36:01 AbstractStoreCursor - Failed to fill batch
> INFO | jvm 1 | 2009/08/23 02:36:01 | java.io.IOException: Failed to read to journal for: offset = 692, file = 1, size = 0, type = 0. Reason: java.io.IOException: Invalid location: offset = 692, file = 1, size = 0, type = 0, : java.lang.NegativeArraySizeException
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:33)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.AMQPersistenceAdapter.createReadException(AMQPersistenceAdapter.java:647)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:533)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.AMQMessageStore.getMessage(AMQMessageStore.java:435)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.RecoveryListenerAdapter.recoverMessageReference(RecoveryListenerAdapter.java:54)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverReference(KahaReferenceStore.java:82)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.kahadaptor.KahaReferenceStore.recoverNextMessages(KahaReferenceStore.java:120)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.AMQMessageStore.recoverNextMessages(AMQMessageStore.java:533)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:75)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:227)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:100)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1179)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.Queue.addSubscription(Queue.java:237)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.AbstractRegion.addConsumer(AbstractRegion.java:275)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:372)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:83)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:93)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:541)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:345)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:143)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:206)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:203)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:185)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at java.lang.Thread.run(Unknown Source)
> INFO | jvm 1 | 2009/08/23 02:36:01 | Caused by: java.io.IOException: Invalid location: offset = 692, file = 1, size = 0, type = 0, : java.lang.NegativeArraySizeException
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.kaha.impl.async.DataFileAccessor.readRecord(DataFileAccessor.java:94)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.kaha.impl.async.AsyncDataManager.read(AsyncDataManager.java:624)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.store.amq.AMQPersistenceAdapter.readCommand(AMQPersistenceAdapter.java:530)
> INFO | jvm 1 | 2009/08/23 02:36:01 | ... 29 more
> INFO | jvm 1 | 2009/08/23 02:36:01 | [ERROR] 02:36:01 AbstractStoreCursor - Failed to fill batch
> INFO | jvm 1 | 2009/08/23 02:36:01 | java.lang.RuntimeException: java.io.IOException: Failed to read to journal for: offset = 692, file = 1, size = 0, type = 0. Reason: java.io.IOException: Invalid location: offset = 692, file = 1, size = 0, type = 0, : java.lang.NegativeArraySizeException
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:230)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:100)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.Queue.doPageIn(Queue.java:1179)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.Queue.addSubscription(Queue.java:237)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.AbstractRegion.addConsumer(AbstractRegion.java:275)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.region.RegionBroker.addConsumer(RegionBroker.java:372)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.advisory.AdvisoryBroker.addConsumer(AdvisoryBroker.java:83)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.BrokerFilter.addConsumer(BrokerFilter.java:86)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.MutableBrokerFilter.addConsumer(MutableBrokerFilter.java:93)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection.processAddConsumer(TransportConnection.java:541)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.command.ConsumerInfo.visit(ConsumerInfo.java:345)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:305)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:179)
> INFO | jvm 1 | 2009/08/23 02:36:01 | at org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:68)
> INFO | jvm 1 | 2009/08/23 02:36:01 |
> ----------------------------------------------------------------------------------
> Now it was around 0300 hours on Sunday 23 Aug IST and we were loosing time. So just in some silly mind we tried to revert back to 4.1 Active mq leaving other things untouched..And to a matter of disbeleif it started working. And the listeners started picking up messages (Even old one from the DB were picked - whcih means 5.2 is backward compliant as well) and it worked fine.
> We are now seriously considering not to take any change with any other version of Active MQ other than 4.1. Please advice if we are doing somehting wrong here. Also i am attaching both my activemq.xml from 5.2 and 4.1
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.