[
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)
