activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Matthias Vetter (JIRA)" <j...@apache.org>
Subject [jira] [Created] (AMQ-4171) KahaDB / Journal rotateWriteFIle() sometimes too fast?
Date Mon, 12 Nov 2012 09:54:11 GMT
Matthias Vetter created AMQ-4171:
------------------------------------

             Summary: KahaDB / Journal rotateWriteFIle() sometimes too fast?
                 Key: AMQ-4171
                 URL: https://issues.apache.org/jira/browse/AMQ-4171
             Project: ActiveMQ
          Issue Type: Bug
          Components: Broker
    Affects Versions: 5.6.0
         Environment: Tested on Windows (7)
            Reporter: Matthias Vetter


On very fast test machines we got predictable FileNotFoundExceptions when a KahaDB data file
was to be replaced by its successor.

See this from the log file:

30.10.2012 21:00:56.359 [ActiveMQ Transport: tcp:///192.168.111.128:3134] [  ]  master-My-Company-S1-kellner20-vm
Message ID:kellner20-vm-3125-1351618296390-23:1:1:2086:1 sent to queue://My-Company.dxm.request.provisionToTS
30.10.2012 21:00:56.359 [BrokerService[master-My-Company-S1-kellner20-vm] Task-197] [  ] 
My-Company.dxm.request.provisionToTS toPageIn: 1, Inflight: 0, pagedInMessages.size 0, enqueueCount:
2125, dequeueCount: 2124

-------------------------------------------------------------------------------
30.10.2012 21:00:56.390 [ConcurrentQueueStoreAndDispatch] [  ] *** SEVERE ***
Called from org.apache.activemq.store.kahadb.MessageDatabase.store()
 KahaDB failed to store to Journal
-------------------------------------------------------------------------------

java.io.FileNotFoundException: activemq-data\master-My-Company-S1-kellner20-vm\KahaDB\db-2.log
(The system cannot find the path specified)
	at java.io.RandomAccessFile.open(Native Method)
	at java.io.RandomAccessFile.<init>(Unknown Source)
	at org.apache.kahadb.journal.DataFile.openRandomAccessFile(DataFile.java:70)
	at org.apache.kahadb.journal.DataFileAppender.processQueue(DataFileAppender.java:309)
	at org.apache.kahadb.journal.DataFileAppender$1.run(DataFileAppender.java:188)

30.10.2012 21:00:56.375 [BrokerService[master-My-Company-S1-kellner20-vm] Task-197] [  ] 
org.apache.activemq.broker.region.cursors.QueueStorePrefetch@1afd356:My-Company.dxm.request.provisionToTS,batchResetNeeded=false,storeHasMessages=true,size=0,cacheEnabled=true
- fillBatch
30.10.2012 21:00:56.421 [ConcurrentQueueStoreAndDispatch] [  ] NOTIFICATION:  HighWater of
SEVERE exceeded (value=1, highwater=1)!
30.10.2012 21:00:56.437 [ConcurrentQueueStoreAndDispatch] [  ]  Stopping the broker due to
IO exception, java.io.FileNotFoundException: activemq-data\master-My-Company-S1-kellner20-vm\KahaDB\db-2.log
(The system cannot find the path specified)
java.io.FileNotFoundException: activemq-data\master-My-Company-S1-kellner20-vm\KahaDB\db-2.log
(The system cannot find the path specified)
	at java.io.RandomAccessFile.open(Native Method)
	at java.io.RandomAccessFile.<init>(Unknown Source)
	at org.apache.kahadb.journal.DataFile.openRandomAccessFile(DataFile.java:70)
	at org.apache.kahadb.journal.DataFileAppender.processQueue(DataFileAppender.java:309)
	at org.apache.kahadb.journal.DataFileAppender$1.run(DataFileAppender.java:188)

********************
(end of log file quotation)
********************

Having evaluated all possibilities of the failure, we finally patched the following method
of the class Journal::


synchronized DataFile rotateWriteFile() {
        int nextNum = !dataFiles.isEmpty() ? dataFiles.getTail().getDataFileId().intValue()
+ 1 : 1;
        File file = getFile(nextNum);
        DataFile nextWriteFile = new DataFile(file, nextNum, preferedFileLength);
PATCH START       try {
   			Thread.sleep(10000);
		} catch (InterruptedException e) {
			e.printStackTrace();
		}
PATCH END
        // actually allocate the disk space
        fileMap.put(nextWriteFile.getDataFileId(), nextWriteFile);
        fileByFileMap.put(file, nextWriteFile);
        dataFiles.addLast(nextWriteFile);
        return nextWriteFile;
    }
*************

This helped, the IO Exception never occurred again after this patch.
It seems that the "nextWriteFile"-object was  returned, while the allocating of the new Data
File wasn't finished yet. 
Anyway, it is very strange that we should have detected this problem, and it never occurred
earlier - at least no similar bug (???) seems to have been reported. Therefore, a critical
examination of possibly deeper causes could be useful.
Best regards, 
Matthias Vetter
ATOS, Frankfurt


--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message