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] [Comment Edited] (AMQ-4171) KahaDB / Journal rotateWriteFIle() sometimes too fast?
Date Fri, 23 Nov 2012 10:34:58 GMT

    [ https://issues.apache.org/jira/browse/AMQ-4171?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13503146#comment-13503146
] 

Matthias Vetter edited comment on AMQ-4171 at 11/23/12 10:34 AM:
-----------------------------------------------------------------

After deeper examination of the above described failure, we still have no solution to the
problem:
It is always possible to create the first file db-1.log. But the creation of its successor
always fails, always with the same exception: file not found, the system cannot find the path
specified. 
The DataFileAppender gets the next DataFile-object (from the method we suspected to be too
fast) and then this DataFile object‘s method openRandomAccessFile is called. At this moment,
the physical file is not yet existing, the RandomAccessFile-constructor called by the open-method
is supposed to create the file. It did so, when db-1.log was created. The path to the files,
naturally, wasn’t changed after that, and the same rights in the file system still are granted.

The only difference we see is, that now another file is already present and is about to be
deleted. But should this have such an effect?
We also suspected the whitespaces in the absolute path to the file to be a problem – but
why not in the first case with db-1.log?
Even more irritating is that obviously no one else faced such kind of FileNotFound problem
with the KahaDB. 
Finally, the problem seems to occur not on Windows 7, as initially reported, but on Windows
XP. It also didn’t occur on a Solaris machine. 
Please, has anyone an idea what could be going on here?  Any comment is welcome!!!!

                
      was (Author: mtmvetter):
    After deeper examination of the above described failure, we still have no solution the
problem:
It is always possible to create the first file db-1.log. But the creation of its successor
always fails, always with the same exception: file not found, the system cannot find the path
specified. 
The DataFileAppender gets the next DataFile-object (from the method we suspected to be too
fast) and then this DataFile object‘s method openRandomAccessFile is called. At this moment,
the physical file is not yet existing, the RandomAccessFile-constructor is supposed to create
the file. It did so, when db-1.log was created: The path to the files, naturally, wasn’t
changed after that, and the same rights in the file system still are granted. 
The only difference we see is, that now another file is already present and is about to be
deleted. But should this have such an effect?
We also suspected the whitespaces in the absolute path to the file to be a problem – but
why not in the first case?
Even more irritating is that obviously no one else faced such kind of FileNotFound problem.

Finally, the problem seems to occur not on Windows 7, as initially reported, but on Windows
XP. It also didn’t occur on a Solaris machine. 
Please, has anyone an idea what could be going on here?  An comment is welcome!!!!

                  
> 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