Mailing-List: contact java-user-help@lucene.apache.org; run by ezmlm
Precedence: bulk
Reply-To: java-user@lucene.apache.org
Received-SPF: pass (herse.apache.org: domain of
 mailing.patrick.kimber@gmail.com designates 209.85.146.178 as permitted
 sender)
DomainKey-Signature: a=rsa-sha1; c=nofws;
        d=gmail.com; s=beta;
        h=received:message-id:date:from:to:subject:in-reply-to:mime-version:content-type:content-transfer-encoding:content-disposition:references;
        b=IieuuqjW+DnJmLK7lwxCeWv6dIqKl4D9e3hJ1AguREoiO9Ro5EmZ2qfcU5SWGeYYtlOVj7AYk9b/NTbnqGqI9SuHqlDA9HKSAG358BJGxX9BUFTZ4E0IR0Qq/I9BtLB8odmfVaSPHy7kzXfQWMx/54HiUmFbmpedzeXO3THmSCY=
Message-ID: <4f9b23800707030317i343559e2ufda83bfd724c9326@mail.gmail.com>
Date: Tue, 3 Jul 2007 11:17:38 +0100
From: "Patrick Kimber" <mailing.patrick.kimber@gmail.com>
To: java-user@lucene.apache.org
Subject: Re: Lucene 2.2, NFS, Lock obtain timed out
In-Reply-To: <1183205087.22530.1197845153@webmail.messagingengine.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit
Content-Disposition: inline
References: <c68e39170706290647o77cc4c29t4ecca000af1e95e4@mail.gmail.com>
	 <OFFBC6AB23.B412A20B-ON88257309.00824908-88257309.0082A587@il.ibm.com>
	 <c68e39170706291805w6e5c4dfbo3526e539d4e9f3f6@mail.gmail.com>
	 <1183205087.22530.1197845153@webmail.messagingengine.com>

Hi

I have added more logging to my test application.  I have two servers
writing to a shared Lucene index on an NFS partition...

Here is the logging from one server...

[10:49:18] [DEBUG] LuceneIndexAccessor closing cached writer
[10:49:18] [DEBUG] ExpirationTimeDeletionPolicy onCommit() delete [segments_n]

and the other server (at the same time):

[10:49:18] [DEBUG] LuceneIndexAccessor opening new writer and caching it
[10:49:18] [DEBUG] IndexAccessProvider getWriter()
[10:49:18] [ERROR] DocumentCollection update(DocumentData)
com.company.lucene.LuceneIcmException: I/O Error: Cannot add the
document to the index.
[/mnt/nfstest/repository/lucene/lucene-icm-test-1-0/segments_n (No
such file or directory)]
    at com.company.lucene.RepositoryWriter.addDocument(RepositoryWriter.java:182)

I think the exception is being thrown when the IndexWriter is created:
new IndexWriter(directory, false, analyzer, false, deletionPolicy);

I am confused... segments_n should not have been touched for 3 minutes
so why would a new IndexWriter want to read it?

Here is the whole of the stack trace:

com.company.lucene.LuceneIcmException: I/O Error: Cannot add the
document to the index.
[/mnt/nfstest/repository/lucene/lucene-icm-test-1-0/segments_n (No
such file or directory)]
	at com.company.lucene.RepositoryWriter.addDocument(RepositoryWriter.java:182)
	at com.company.lucene.IndexUpdate.addDocument(IndexUpdate.java:364)
	at com.company.lucene.IndexUpdate.addDocument(IndexUpdate.java:342)
	at com.company.lucene.IndexUpdate.update(IndexUpdate.java:67)
	at com.company.lucene.icm.DocumentCollection.update(DocumentCollection.java:390)
	at lucene.icm.test.Write.add(Write.java:105)
	at lucene.icm.test.Write.run(Write.java:79)
	at lucene.icm.test.Write.main(Write.java:43)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:324)
	at org.codehaus.mojo.exec.ExecJavaMojo$1.run(ExecJavaMojo.java:271)
	at java.lang.Thread.run(Thread.java:534)
Caused by: java.io.FileNotFoundException:
/mnt/nfstest/repository/lucene/lucene-icm-test-1-0/segments_n (No such
file or directory)
	at java.io.RandomAccessFile.open(Native Method)
	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:204)
	at org.apache.lucene.store.FSDirectory$FSIndexInput$Descriptor.<init>(FSDirectory.java:506)
	at org.apache.lucene.store.FSDirectory$FSIndexInput.<init>(FSDirectory.java:536)
	at org.apache.lucene.store.FSDirectory$FSIndexInput.<init>(FSDirectory.java:531)
	at org.apache.lucene.store.FSDirectory.openInput(FSDirectory.java:440)
	at org.apache.lucene.index.SegmentInfos.read(SegmentInfos.java:193)
	at org.apache.lucene.index.IndexFileDeleter.<init>(IndexFileDeleter.java:156)
	at org.apache.lucene.index.IndexWriter.init(IndexWriter.java:626)
	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:573)
	at com.subshell.lucene.indexaccess.impl.IndexAccessProvider.getWriter(IndexAccessProvider.java:68)
	at com.subshell.lucene.indexaccess.impl.LuceneIndexAccessor.getWriter(LuceneIndexAccessor.java:171)
	at com.company.lucene.RepositoryWriter.addDocument(RepositoryWriter.java:176)
	... 13 more

Thank you very much for your previous comments and emails.

Any help solving this issue would be appreciated.

Patrick


On 30/06/07, Michael McCandless <lucene@mikemccandless.com> wrote:
>
> Patrick Kimber wrote:
>
> > I have been checking the application log.  Just before the time when
> > the lock file errors occur I found this log entry:
> > [11:28:59] [ERROR] IndexAccessProvider
> > java.io.FileNotFoundException:
> > /mnt/nfstest/repository/lucene/lucene-icm-test-1-0/segments_h75 (No
> > such file or directory)
> >     at java.io.RandomAccessFile.open(Native Method)
>
> I think this exception is the root cause.  On hitting this IOException
> in reader.close(), that means this reader has not released its write
> lock.  Is it possible to see the full stack trace?
>
> Having the wrong deletion policy or even a buggy deletion policy (if
> indeed file.lastModified() varies by too much across machines) can't
> cause this (I think).  At worse, the wrong deletion policy should
> cause other already-open readers to hit "Stale NFS handle"
> IOExceptions during searching.  So, you should use your
> ExpirationTimeDeletionPolicy when opening your readers if they will be
> doing deletes, but I don't think it explains this root-cause exception
> during close().
>
> It's a rather spooky exception ... in close(), the reader initializes
> an IndexFileDeleter which lists the directory and opens any segments_N
> files that it finds.
>
> Do you have a writer on one machine closing, and then very soon
> thereafter this reader on a different machine does deletes and tries
> to close?
>
> My best guess is the exception is happening inside that initialization
> because the directory listing said that "segments_XXX" exists but then
> when it tries to open that file, it does not in fact exist.  Since NFS
> client-side caching (especially directory listing cache) is not
> generally guaranteed to be "correct", it could explain this.  But let's
> see the full stack trace to make sure this is it...
>
> Mike
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
> For additional commands, e-mail: java-user-help@lucene.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org