Loading...

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: JBoss A-MQ 6.3.x
Affects Version/s: JBoss A-MQ 6.3
Component/s: kahadb
Labels:
None

GSS Priority:

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

From the logs a broker write appears to fail (due to disk space issues). The broker is configured to shutdown when it hits a "no space on disk error"

2017-02-06 15:27:56,962 | WARN  | Data File Writer | DataFileAppender                 | db.disk.journal.DataFileAppender  349 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Journal failed while writing at: 58:35654773
java.io.IOException: No space left on device
	at java.io.RandomAccessFile.writeBytes(Native Method)[:1.8.0_45]
	at java.io.RandomAccessFile.write(RandomAccessFile.java:525)[:1.8.0_45]
	at org.apache.activemq.util.RecoverableRandomAccessFile.write(RecoverableRandomAccessFile.java:245)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender.processQueue(DataFileAppender.java:332)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender$1.run(DataFileAppender.java:169)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
2017-02-06 15:27:56,963 | ERROR | .0.1:54XXX@XXXX | MessageDatabase                  | emq.store.kahadb.MessageDatabase 1088 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | KahaDB failed to store to Journal
java.io.IOException: No space left on device
	at java.io.RandomAccessFile.writeBytes(Native Method)[:1.8.0_45]
	at java.io.RandomAccessFile.write(RandomAccessFile.java:525)[:1.8.0_45]
	at org.apache.activemq.util.RecoverableRandomAccessFile.write(RecoverableRandomAccessFile.java:245)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender.processQueue(DataFileAppender.java:332)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender$1.run(DataFileAppender.java:169)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
2017-02-06 15:27:56,964 | INFO  | .0.1:54XXX@XXXX | DefaultIOExceptionHandler        | q.util.DefaultIOExceptionHandler  166 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Stopping BrokerService[amq] due to exception, java.io.IOException: No space left on device
java.io.IOException: No space left on device
	at java.io.RandomAccessFile.writeBytes(Native Method)[:1.8.0_45]
	at java.io.RandomAccessFile.write(RandomAccessFile.java:525)[:1.8.0_45]
	at org.apache.activemq.util.RecoverableRandomAccessFile.write(RecoverableRandomAccessFile.java:245)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender.processQueue(DataFileAppender.java:332)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender$1.run(DataFileAppender.java:169)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
2017-02-06 15:27:56,965 | WARN  | .0.1:54XXX@XXXX | LocalTransaction                 | emq.transaction.LocalTransaction   73 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Store COMMIT FAILED: 
org.apache.activemq.broker.SuppressReplyException: ShutdownBrokerInitiated
	at org.apache.activemq.util.DefaultIOExceptionHandler.handle(DefaultIOExceptionHandler.java:162)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerService.handleIOException(BrokerService.java:2661)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:1089)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.store(MessageDatabase.java:1047)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.KahaDBTransactionStore.commit(KahaDBTransactionStore.java:301)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transaction.LocalTransaction.commit(LocalTransaction.java:70)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.TransactionBroker.commitTransaction(TransactionBroker.java:252)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:112)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerFilter.commitTransaction(BrokerFilter.java:112)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.MutableBrokerFilter.commitTransaction(MutableBrokerFilter.java:117)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.TransportConnection.processCommitTransactionOnePhase(TransportConnection.java:528)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.command.TransactionInfo.visit(TransactionInfo.java:100)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:326)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:190)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:125)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:300)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:214)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_45]
Caused by: java.io.IOException: No space left on device
	at java.io.RandomAccessFile.writeBytes(Native Method)[:1.8.0_45]
	at java.io.RandomAccessFile.write(RandomAccessFile.java:525)[:1.8.0_45]
	at org.apache.activemq.util.RecoverableRandomAccessFile.write(RecoverableRandomAccessFile.java:245)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender.processQueue(DataFileAppender.java:332)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.journal.DataFileAppender$1.run(DataFileAppender.java:169)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
2017-02-06 15:27:56,966 | INFO  | okerService[amq] | BrokerService                    | he.activemq.broker.BrokerService  789 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Apache ActiveMQ 5.11.0.redhat-630224 (amq, ID:XXXX1) is shutting down

But when the broker is restart the checkForCorruptJournalFiles="true" appears to detect the partial last write and block the startup.

2017-02-06 15:28:44,900 | WARN  | AMQ-1-thread-1   | Journal                          | tore.kahadb.disk.journal.Journal  467 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Corrupt journal records found in '/XXX/db-58.log' between offsets: 35654773..35912055
2017-02-06 15:28:44,920 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | .kahadb.MessageDatabase$Metadata  181 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | KahaDB is version 5
2017-02-06 15:28:44,956 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | emq.store.kahadb.MessageDatabase  640 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Recovering from the journal @58:35559434
2017-02-06 15:28:45,297 | INFO  | AMQ-1-thread-1   | MessageDatabase                  | emq.store.kahadb.MessageDatabase  668 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Recovery replayed 58 operations from the journal in 0.362 seconds.
2017-02-06 15:28:45,328 | ERROR | AMQ-1-thread-1   | MessageDatabase                  | emq.store.kahadb.MessageDatabase  929 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Detected corrupt journal files. [58:35654773 >= key < 58:35912056]
2017-02-06 15:28:45,328 | ERROR | AMQ-1-thread-1   | BrokerService                    | he.activemq.broker.BrokerService  611 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Failed to start Apache ActiveMQ ([amq, null], java.io.IOException: Detected corrupt journal files. [58:35654773 >= key < 58:35912056])
2017-02-06 15:28:45,329 | INFO  | AMQ-1-thread-1   | BrokerService                    | he.activemq.broker.BrokerService  789 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Apache ActiveMQ 5.11.0.redhat-630224 (amq, null) is shutting down
2017-02-06 15:28:45,330 | INFO  | AMQ-1-thread-1   | TransportConnector               | tivemq.broker.TransportConnector  291 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Connector openwire stopped
2017-02-06 15:28:45,330 | INFO  | AMQ-1-thread-1   | TransportConnector               | tivemq.broker.TransportConnector  291 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Connector amqp stopped
2017-02-06 15:28:45,330 | INFO  | AMQ-1-thread-1   | TransportConnector               | tivemq.broker.TransportConnector  291 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Connector mqtt stopped
2017-02-06 15:28:45,330 | INFO  | AMQ-1-thread-1   | TransportConnector               | tivemq.broker.TransportConnector  291 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Connector ws stopped
2017-02-06 15:28:45,331 | INFO  | AMQ-1-thread-1   | PListStoreImpl                   | tore.kahadb.plist.PListStoreImpl  370 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | PListStore:[/XXX/tmp_storage] stopped
2017-02-06 15:28:45,332 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | ctivemq.store.kahadb.KahaDBStore  244 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Stopping async queue tasks
2017-02-06 15:28:45,332 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | ctivemq.store.kahadb.KahaDBStore  258 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Stopping async topic tasks
2017-02-06 15:28:45,332 | INFO  | AMQ-1-thread-1   | KahaDBStore                      | ctivemq.store.kahadb.KahaDBStore  286 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Stopped KahaDB
2017-02-06 15:28:45,364 | INFO  | AMQ-1-thread-1   | BrokerService                    | he.activemq.broker.BrokerService  850 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Apache ActiveMQ 5.11.0.redhat-630224 (amq, null) uptime 6.644 seconds
2017-02-06 15:28:45,364 | INFO  | AMQ-1-thread-1   | BrokerService                    | he.activemq.broker.BrokerService  852 | 162 - org.apache.activemq.activemq-osgi - 5.11.0.redhat-630224 | Apache ActiveMQ 5.11.0.redhat-630224 (amq, null) is shutdown
2017-02-06 15:28:45,364 | INFO  | AMQ-1-thread-1   | ActiveMQServiceFactory           | Factory$ClusteredConfiguration$1  502 | 176 - io.fabric8.mq.mq-fabric - 1.2.0.redhat-630224 | Broker amq failed to start.  Will try again in 10 seconds
2017-02-06 15:28:45,365 | ERROR | AMQ-1-thread-1   | ActiveMQServiceFactory           | Factory$ClusteredConfiguration$1  503 | 176 - io.fabric8.mq.mq-fabric - 1.2.0.redhat-630224 | Exception on start: java.io.IOException: Detected corrupt journal files. [58:35654773 >= key < 58:35912056]
java.io.IOException: Detected corrupt journal files. [58:35654773 >= key < 58:35912056]
	at org.apache.activemq.store.kahadb.MessageDatabase.recoverIndex(MessageDatabase.java:930)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase$5.execute(MessageDatabase.java:676)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.disk.page.Transaction.execute(Transaction.java:779)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.recover(MessageDatabase.java:673)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.open(MessageDatabase.java:429)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.load(MessageDatabase.java:447)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.MessageDatabase.doStart(MessageDatabase.java:283)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.KahaDBStore.doStart(KahaDBStore.java:205)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.store.kahadb.KahaDBPersistenceAdapter.doStart(KahaDBPersistenceAdapter.java:223)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.util.ServiceSupport.start(ServiceSupport.java:55)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerService.doStartPersistenceAdapter(BrokerService.java:658)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerService.startPersistenceAdapter(BrokerService.java:642)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at org.apache.activemq.broker.BrokerService.start(BrokerService.java:607)[162:org.apache.activemq.activemq-osgi:5.11.0.redhat-630224]
	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration.doStart(ActiveMQServiceFactory.java:549)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630224]
	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration.access$400(ActiveMQServiceFactory.java:359)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630224]
	at io.fabric8.mq.fabric.ActiveMQServiceFactory$ClusteredConfiguration$1.run(ActiveMQServiceFactory.java:490)[176:io.fabric8.mq.mq-fabric:1.2.0.redhat-630224]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_45]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_45]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_45]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_45]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_45]

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

R1.logs.tar.gz
3.34 MB
2017/03/06 4:07 PM
exception_log.txt
25 kB
2017/02/13 10:29 AM
amq.log.gz
1.10 MB
2017/03/06 6:13 AM

is related to

ENTMQ-2073 [A-MQ, kahadb] NullPointerException raised at org.apache.activemq.store.kahadb.disk.index.BTreeNode$BTreeIterator.findNextPage()

Closed

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates