You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Paul Smith (JIRA)" <ji...@apache.org> on 2016/01/21 11:53:39 UTC
[jira] [Commented] (AMQ-5786) ActiveMQ failed to start with KahaDB
reporting corrupt journal records and throwing NegativeArraySizeException
[ https://issues.apache.org/jira/browse/AMQ-5786?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15110419#comment-15110419 ]
Paul Smith commented on AMQ-5786:
---------------------------------
We have faced the same situation for the 3rd time now, this looks the same as reported in AMQ-3098.
I can provide a copy of the ActiveMQ logs and a copy of the Kahadb in the state it was in when it went south.
Fundamentally though I think the KahaDB db/txn log allocation is flawed, because it ought to (IMHO) pre-allocate logs as per the sizes specified to ensure it 'grabs' the allocated space and then can't lose a chance to allocate one in some future time (when sadly the disk fills up).
In our case what was happening was that rsyslog could not route some application logs downstream, and started stalling the consumer application (the one doing the logging) so the Queue built up, and eventually when rsyslog had starved the local disk, ActiveMQ could not correctly allocate any more redo log space, and throwing the error.
It is unrecoverable at this point, I've tried moving aside Kaha individual log files, but it doesn't help, the whole KahaDB data store needs to be purged, and then ActiveMQ restarted.
> ActiveMQ failed to start with KahaDB reporting corrupt journal records and throwing NegativeArraySizeException
> --------------------------------------------------------------------------------------------------------------
>
> Key: AMQ-5786
> URL: https://issues.apache.org/jira/browse/AMQ-5786
> Project: ActiveMQ
> Issue Type: Bug
> Components: KahaDB
> Affects Versions: 5.11.1
> Environment: Karaf 3.0.3
> Reporter: Martin Lichtin
> Priority: Critical
>
> ActiveMQ failed to start up, with the following information:
> {noformat}
> 2015-05-20 14:23:21,709 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 5504795..5505130
> 2015-05-20 14:23:21,725 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 5611475..5612818
> 2015-05-20 14:23:21,749 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 6139835..6140254
> 2015-05-20 14:23:21,756 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 6246179..6247270
> 2015-05-20 14:23:21,765 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 6512519..6520426
> 2015-05-20 14:23:21,789 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 7606018..7627848
> 2015-05-20 14:23:21,794 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 7630473..7650409
> 2015-05-20 14:23:21,796 | INFO | apache.activemq.server]) | Journal | tore.kahadb.disk.journal.Journal 219 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Corrupt journal records found in 'activemq/kahadb/db-1.log' between offsets: 7650488..7703243
> 2015-05-20 14:23:22,065 | INFO | apache.activemq.server]) | MessageDatabase | .kahadb.MessageDatabase$Metadata 168 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | KahaDB is version 5
> 2015-05-20 14:23:22,188 | INFO | apache.activemq.server]) | MessageDatabase | emq.store.kahadb.MessageDatabase 603 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Recovering from the journal ...
> 2015-05-20 14:23:22,188 | ERROR | apache.activemq.server]) | BrokerService | he.activemq.broker.BrokerService 609 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Failed to start Apache ActiveMQ ([broker-amq, null], java.io.IOException: Invalid location: 1:6516763, : java.lang.NegativeArraySizeException)
> 2015-05-20 14:23:22,189 | INFO | apache.activemq.server]) | BrokerService | he.activemq.broker.BrokerService 758 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Apache ActiveMQ 5.11.1 (broker-amq, null) is shutting down
> 2015-05-20 14:23:22,194 | INFO | apache.activemq.server]) | TransportConnector | tivemq.broker.TransportConnector 291 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Connector openwire stopped
> 2015-05-20 14:23:22,372 | INFO | apache.activemq.server]) | JobSchedulerStoreImpl | .scheduler.JobSchedulerStoreImpl 259 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | JobSchedulerStore: activemq/broker-amq/scheduler stopped.
> 2015-05-20 14:23:22,372 | INFO | apache.activemq.server]) | PListStoreImpl | tore.kahadb.plist.PListStoreImpl 356 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | PListStore:[/integrator/int1/proc/broker-amq/karaf-std-0.2-440/activemq/broker-amq/tmp_storage] stopped
> 2015-05-20 14:23:22,372 | INFO | apache.activemq.server]) | KahaDBStore | ctivemq.store.kahadb.KahaDBStore 245 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Stopping async queue tasks
> 2015-05-20 14:23:22,372 | INFO | apache.activemq.server]) | KahaDBStore | ctivemq.store.kahadb.KahaDBStore 259 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Stopping async topic tasks
> 2015-05-20 14:23:22,373 | INFO | apache.activemq.server]) | KahaDBStore | ctivemq.store.kahadb.KahaDBStore 287 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Stopped KahaDB
> 2015-05-20 14:23:22,664 | INFO | apache.activemq.server]) | BrokerService | he.activemq.broker.BrokerService 819 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Apache ActiveMQ 5.11.1 (broker-amq, null) uptime 1.245 seconds
> 2015-05-20 14:23:22,664 | INFO | apache.activemq.server]) | BrokerService | he.activemq.broker.BrokerService 821 | 105 - org.apache.activemq.activemq-osgi - 5.11.1 | Apache ActiveMQ 5.11.1 (broker-amq, null) is shutdown
> 2015-05-20 14:23:22,676 | ERROR | apache.activemq.server]) | configadmin | ? ? | 6 - org.apache.felix.configadmin - 1.8.0 | [org.osgi.service.cm.ManagedServiceFactory, id=673, bundle=105/mvn:org.apache.activemq/activemq-osgi/5.11.1]: Updating configuration org.apache.activemq.server.02ee5a2d-fb5b-48ce-b4e1-93ed72adba19 caused a problem: Cannot start the broker
> org.osgi.service.cm.ConfigurationException: null : Cannot start the broker
> at org.apache.activemq.osgi.ActiveMQServiceFactory.updated(ActiveMQServiceFactory.java:120)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at Proxyfc1340e4_63f4_474d_995e_cdb9ac0c71b9.updated(Unknown Source)[:]
> at org.apache.felix.cm.impl.helper.ManagedServiceFactoryTracker.provideConfiguration(ManagedServiceFactoryTracker.java:88)[6:org.apache.felix.configadmin:1.8.0]
> at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceFactoryUpdate.provide(ConfigurationManager.java:1605)[6:org.apache.felix.configadmin:1.8.0]
> at org.apache.felix.cm.impl.ConfigurationManager$ManagedServiceFactoryUpdate.run(ConfigurationManager.java:1548)[6:org.apache.felix.configadmin:1.8.0]
> at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:103)[6:org.apache.felix.configadmin:1.8.0]
> at java.lang.Thread.run(Thread.java:745)[:1.8.0_45]
> Caused by: java.io.IOException: Invalid location: 1:6516763, : java.lang.NegativeArraySizeException
> at org.apache.activemq.store.kahadb.disk.journal.DataFileAccessor.readRecord(DataFileAccessor.java:92)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.disk.journal.Journal.read(Journal.java:619)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:1013)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.MessageDatabase.recover(MessageDatabase.java:605)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.MessageDatabase.open(MessageDatabase.java:399)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:417)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.MessageDatabase.doStart(MessageDatabase.java:261)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.KahaDBStore.doStart(KahaDBStore.java:206)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.store.kahadb.KahaDBPersistenceAdapter.doStart(KahaDBPersistenceAdapter.java:223)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.broker.BrokerService.doStartPersistenceAdapter(BrokerService.java:651)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.broker.BrokerService.startPersistenceAdapter(BrokerService.java:640)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.broker.BrokerService.start(BrokerService.java:605)[105:org.apache.activemq.activemq-osgi:5.11.1]
> at org.apache.activemq.osgi.ActiveMQServiceFactory.updated(ActiveMQServiceFactory.java:116)[105:org.apache.activemq.activemq-osgi:5.11.1]
> ... 6 more
> Caused by: java.lang.NegativeArraySizeException
> at org.apache.activemq.store.kahadb.disk.journal.DataFileAccessor.readRecord(DataFileAccessor.java:87)[105:org.apache.activemq.activemq-osgi:5.11.1]
> ... 20 more
> {noformat}
> <kahaDB> is configured with checkForCorruptJournalFiles="true".
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)