I have an index (different from the ones mentioned yesterday) that was
working fine with 3M docs or so, but when I added a bunch more docs,
bringing it closer to 4M docs, the index seemed to get corrupted. In
particular, now when I start Solr up, or when when my indexing process
tries add a document, I get a complaint about missing index files.

The error on startup looks like this:

<record>
  <date>2008-08-15T10:18:54</date>
  <millis>1218820734592</millis>
  <sequence>92</sequence>
  <logger>org.apache.solr.core.MultiCore</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.common.SolrException</class>
  <method>log</method>
  <thread>10</thread>
  <message>java.lang.RuntimeException: java.io.FileNotFoundException:
/ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
directory)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:733)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:387)
at org.apache.solr.core.MultiCore.create(MultiCore.java:255)
at org.apache.solr.core.MultiCore.load(MultiCore.java:139)
at org.apache.solr.servlet.SolrDispatchFilter.initMultiCore(SolrDispatchFilter.java:147)
at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:75)
at org.mortbay.jetty.servlet.FilterHolder.doStart(FilterHolder.java:99)
at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
at org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:594)
at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1218)
at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:500)
at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:448)
at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
at org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)
at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
at org.mortbay.jetty.Server.doStart(Server.java:210)
at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
at org.mortbay.xml.XmlConfiguration.main(XmlConfiguration.java:929)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at org.mortbay.start.Main.invokeMain(Main.java:183)
at org.mortbay.start.Main.start(Main.java:497)
at org.mortbay.start.Main.main(Main.java:115)
Caused by: java.io.FileNotFoundException:
/ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
directory)
at java.io.RandomAccessFile.open(Native Method)
at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
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.openInput(FSDirectory.java:445)
at org.apache.lucene.index.FieldsReader.<init>(FieldsReader.java:75)
at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:308)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:262)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:197)
at org.apache.lucene.index.MultiSegmentReader.<init>(MultiSegmentReader.java:55)
at org.apache.lucene.index.DirectoryIndexReader$1.doBody(DirectoryIndexReader.java:75)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:636)
at org.apache.lucene.index.DirectoryIndexReader.open(DirectoryIndexReader.java:63)
at org.apache.lucene.index.IndexReader.open(IndexReader.java:209)
at org.apache.lucene.index.IndexReader.open(IndexReader.java:173)
at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:93)
at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:724)
... 29 more
</message>
</record>

And the error on doc add looks like this:

<record>
  <date>2008-08-15T09:51:30</date>
  <millis>1218819090142</millis>
  <sequence>6571937</sequence>
  <logger>org.apache.solr.core.SolrCore</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.common.SolrException</class>
  <method>log</method>
  <thread>14</thread>
  <message>java.io.FileNotFoundException:
/ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
directory)
at java.io.RandomAccessFile.open(Native Method)
at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
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.openInput(FSDirectory.java:445)
at org.apache.lucene.index.FieldsReader.<init>(FieldsReader.java:75)
at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:308)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:262)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:197)
at org.apache.lucene.index.MultiSegmentReader.<init>(MultiSegmentReader.java:55)
at org.apache.lucene.index.DirectoryIndexReader$1.doBody(DirectoryIndexReader.java:75)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:636)
at org.apache.lucene.index.DirectoryIndexReader.open(DirectoryIndexReader.java:63)
at org.apache.lucene.index.IndexReader.open(IndexReader.java:209)
at org.apache.lucene.index.IndexReade

I've done some more sniffing on the Lucene list, and noticed that Otis
made the following comment about a FileNotFoundException problem in
late 2005:

    Are you using Windows and a compound index format (look at your index
    dir - does it have .cfs file(s))?

    This may be a bad combination, judging from people who reported this
    problem so far.

(http://www.nabble.com/fnm-file-disappear-td1531775.html#a1531775)

Again, a CFS index was indeed involved in my case, but my experience
comes almost three years after Otis' message...

On Fri, Aug 15, 2008 at 10:35 AM, Chris Harris <[EMAIL PROTECTED]> wrote:
>
> The following may or may not be relevant: I built the base 3M-ish doc
> index on a Windows machine, and it's a compound (.cfs) format index.
> (I actually created it not with Solr, but by using the index merging
> tool that comes with Lucene in order to merge three different
> non-compound format indexes that I'd previously made with Solr into a
> single index.) Before I started adding documents, I moved the index to
> a Linux machine running a newer version of Solr/Lucene than was on the
> Windows machine. The stuff described above all happened on Linux.
>
> Any thoughts?
>
> Thanks a bunch,
> Chris
>

What version of Java do you have on Linux?

Also, is this easily reproducible?  How many threads are you adding  
documents with?  What is your Auto Commit setting?

Can you try Lucene's CheckIndex tool on it and report what it says?

On Aug 15, 2008, at 1:35 PM, Chris Harris wrote:

> I have an index (different from the ones mentioned yesterday) that was
> working fine with 3M docs or so, but when I added a bunch more docs,
> bringing it closer to 4M docs, the index seemed to get corrupted. In
> particular, now when I start Solr up, or when when my indexing process
> tries add a document, I get a complaint about missing index files.
>
> The error on startup looks like this:
>
> <record>
>  <date>2008-08-15T10:18:54</date>
>  <millis>1218820734592</millis>
>  <sequence>92</sequence>
>  <logger>org.apache.solr.core.MultiCore</logger>
>  <level>SEVERE</level>
>  <class>org.apache.solr.common.SolrException</class>
>  <method>log</method>
>  <thread>10</thread>
>  <message>java.lang.RuntimeException: java.io.FileNotFoundException:
> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
> directory)
> at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:733)
> at org.apache.solr.core.SolrCore.<init>(SolrCore.java:387)
> at org.apache.solr.core.MultiCore.create(MultiCore.java:255)
> at org.apache.solr.core.MultiCore.load(MultiCore.java:139)
> at  
> org
> .apache
> .solr
> .servlet.SolrDispatchFilter.initMultiCore(SolrDispatchFilter.java:147)
> at  
> org
> .apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:
> 75)
> at org.mortbay.jetty.servlet.FilterHolder.doStart(FilterHolder.java:
> 99)
> at  
> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:
> 40)
> at  
> org
> .mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:
> 594)
> at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
> at  
> org
> .mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:
> 1218)
> at  
> org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:
> 500)
> at  
> org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:448)
> at  
> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:
> 40)
> at  
> org
> .mortbay
> .jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
> at  
> org
> .mortbay
> .jetty
> .handler
> .ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)
> at  
> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:
> 40)
> at  
> org
> .mortbay
> .jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
> at  
> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:
> 40)
> at  
> org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:
> 117)
> at org.mortbay.jetty.Server.doStart(Server.java:210)
> at  
> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:
> 40)
> at org.mortbay.xml.XmlConfiguration.main(XmlConfiguration.java:929)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at  
> sun
> .reflect
> .NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at  
> sun
> .reflect
> .DelegatingMethodAccessorImpl
> .invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:616)
> at org.mortbay.start.Main.invokeMain(Main.java:183)
> at org.mortbay.start.Main.start(Main.java:497)
> at org.mortbay.start.Main.main(Main.java:115)
> Caused by: java.io.FileNotFoundException:
> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
> directory)
> at java.io.RandomAccessFile.open(Native Method)
> at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
> 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.openInput(FSDirectory.java:

On Sat, Aug 16, 2008 at 4:33 AM, Grant Ingersoll <[EMAIL PROTECTED]> wrote:
> What version of Java do you have on Linux?

The Java version on *Linux* (where I'm seeing the trouble):

    java version "1.6.0"
    OpenJDK Runtime Environment (build 1.6.0-b09)
    OpenJDK 64-Bit Server VM (build 1.6.0-b09, mixed mode)

I'm pretty sure this is the latest one from the Ubuntu repository.

Maybe I should try the official Sun HotSpot build instead. I'm not
finding any complaints about OpenJDK on the Lucene list, though.

The Java version on *Windows* (where I created the initial compound
format index) is an official Sun build:

    java version "1.6.0_06"
    Java(TM) SE Runtime Environment (build 1.6.0_06-b02)
    Java HotSpot(TM) Client VM (build 10.0-b22, mixed mode, sharing)

> Also, is this easily reproducible?  How many threads are you adding
> documents with?  What is your Auto Commit setting?

I think it takes 12-24hr to get the index to screw up, so while I did
reproduce it once, I haven't yet tried again. Intuition says that if I
repeat the same procedure the same problem would arise. Of course,
what would be nice is if I could figure out how to reproduce it more
quickly, with a smaller index, and a simpler schema.

I'm adding documents with 5-10 threads. Since I'm using the rich
document update handler
(https://issues.apache.org/jira/browse/SOLR-284), there's going to be
PDF and HTML conversion going on within Solr alongside the normal
analysis and indexing.

Autocommit is:

    <autoCommit>
      <maxDocs>100000</maxDocs>
      <maxTime>1800000</maxTime>  <!-- 30 min -->
    </autoCommit>

> Can you try Lucene's CheckIndex tool on it and report what it says?

Working on that now. It should take some time, though, due to the index size.

>
> On Aug 15, 2008, at 1:35 PM, Chris Harris wrote:
>
>> I have an index (different from the ones mentioned yesterday) that was
>> working fine with 3M docs or so, but when I added a bunch more docs,
>> bringing it closer to 4M docs, the index seemed to get corrupted. In
>> particular, now when I start Solr up, or when when my indexing process
>> tries add a document, I get a complaint about missing index files.
>>
>> The error on startup looks like this:
>>
>> <record>
>>  <date>2008-08-15T10:18:54</date>
>>  <millis>1218820734592</millis>
>>  <sequence>92</sequence>
>>  <logger>org.apache.solr.core.MultiCore</logger>
>>  <level>SEVERE</level>
>>  <class>org.apache.solr.common.SolrException</class>
>>  <method>log</method>
>>  <thread>10</thread>
>>  <message>java.lang.RuntimeException: java.io.FileNotFoundException:
>> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
>> directory)
>>        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:733)
>>        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:387)
>>        at org.apache.solr.core.MultiCore.create(MultiCore.java:255)
>>        at org.apache.solr.core.MultiCore.load(MultiCore.java:139)
>>        at
>> org.apache.solr.servlet.SolrDispatchFilter.initMultiCore(SolrDispatchFilter.java:147)
>>        at
>> org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:75)
>>        at
>> org.mortbay.jetty.servlet.FilterHolder.doStart(FilterHolder.java:99)
>>        at
>> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>>        at
>> org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:594)
>>        at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
>>        at
>> org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1218)
>>        at
>> org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:500)
>>        at
>> org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:448)
>>        at
>> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>>        at
>> org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
>>        at
>> org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)

On Sat, Aug 16, 2008 at 4:33 AM, Grant Ingersoll <[EMAIL PROTECTED]> wrote:
> Can you try Lucene's CheckIndex tool on it and report what it says?
>
> On Aug 15, 2008, at 1:35 PM, Chris Harris wrote:
>
>> I have an index (different from the ones mentioned yesterday) that was
>> working fine with 3M docs or so, but when I added a bunch more docs,
>> bringing it closer to 4M docs, the index seemed to get corrupted. In
>> particular, now when I start Solr up, or when when my indexing process
>> tries add a document, I get a complaint about missing index files.
>>
>> The error on startup looks like this:
>>
>> [...]

So I've run the Lucene CheckIndex tool twice.

First I ran it on my Windows machine, on the original compound format
index, which I then moved over to Linux and added to. It checked out
ok:
  NOTE: testing will be more thorough if you run java with
'-ea:org.apache.lucene', so assertions are enabled

  Opening index @ E:\solr-9999\solr\exhibitcore\data\index

  Segments file=segments_2 numSegments=1
version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]
    1 of 1: name=_0 docCount=2829254
      compound=true
      numFiles=1
      size (MB)=30,423.298
      no deletions
      test: open reader.........OK
      test: fields, norms.......OK [21 fields]
      test: terms, freq, prox...OK [20208545 terms; 1092415125
terms/docs pairs; 6041972577 tokens]
      test: stored fields.......OK [82628579 total field count; avg
29.205 fields per doc]
      test: term vectors........OK [0 total vector count; avg 0
term/freq vector fields per doc]

  No problems were detected with this index.
Then I ran it on Linux, against the index in its problematic state.
(Note: This is the end of my message. Everything that follows is
output from the tool):
  Opening index @
/home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/

  Segments file=segments_10tu numSegments=48
version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]
    1 of 48: name=_0 docCount=2829254
      compound=true
      numFiles=1
      size (MB)=30,423.298
      no deletions
      test: open reader.........OK
      test: fields, norms.......OK [21 fields]
      test: terms, freq, prox...OK [20208545 terms; 1092415125
terms/docs pairs; 6041972577 tokens]
      test: stored fields.......OK [82628579 total field count; avg
29.205 fields per doc]
      test: term vectors........OK [0 total vector count; avg 0
term/freq vector fields per doc]

    2 of 48: name=_uz docCount=1567952
      compound=false
      numFiles=8
      size (MB)=17,238.136
      no deletions
      test: open reader.........OK
      test: fields, norms.......OK [21 fields]
      test: terms, freq, prox...OK [11529959 terms; 613302128
terms/docs pairs; 3503689207 tokens]
      test: stored fields.......OK [45879263 total field count; avg
29.261 fields per doc]
      test: term vectors........OK [0 total vector count; avg 0
term/freq vector fields per doc]

    3 of 48: name=_v7 docCount=24507
      compound=false
      numFiles=0
      size (MB)=0
      no deletions
      test: open reader.........FAILED
      WARNING: would remove reference to this segment (-fix was not
specified); full exception:
  java.io.FileNotFoundException:
/home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/_v7.fnm
(No such file or directory)
   at java.io.RandomAccessFile.open(Native Method)
   at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
   at org.apache.lucene.store.FSDirectory$FSIndexInput$Descriptor.<init>(FSDirectory.java:539)
   at org.apache.lucene.store.FSDirectory$FSIndexInput.<init>(FSDirectory.java:569)
   at org.apache.lucene.store.FSDirectory.openInput(FSDirectory.java:478)
   at org.apache.lucene.store.FSDirectory.openInput(FSDirectory.java:473)
   at org.apache.lucene.index.FieldInfos.<init>(FieldInfos.java:57)
   at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:300)
   at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:264)
   at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:199)
   at org.apache.lucene.index.CheckIndex.check(CheckIndex.java:178)
   at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:433)

    4 of 48: name=_v6 docCount=1
      compound=false
      numFiles=0
      size (MB)=0
      docStoreOffset=6095
      docStoreSegment=_v4
      docStoreIsCompoundFile=false
      no deletions
      test: open reader.........FAILED
      WARNING: would remove reference to this segment (-fix was not
specified); full exception:
  java.io.FileNotFoundException:
/home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/_v6.fnm
(No such file or directory)
   at java.io.RandomAccessFile.open(Native Method)
   at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
   at org.apache.lucene.store.FSDirectory$FSIndexInput$Descriptor.<init>(FSDirectory.java:539)
   at org.apache.lucene.store.FSDirectory$FSIndexInput.<init>(FSDirectory.java:569)
   at org.apache.lucene.store.FSDirectory.openInput(FSDirectory.java:478)
   at org.apache.lucene.store.FSDirectory.openInput(FSDirectory.java:473)
   at org.apache.lucene.index.FieldInfos.<init>(FieldInfos.java:57)
   at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:300)
   at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:264)
   at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:199)
   at org.apache.lucene.index.CheckIndex.check(CheckIndex.java:178)
   at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:433)

    5 of 48: name=_v8 docCount=1714
      compound=false
      numFiles=0
      size (MB)=0
      docStoreOffset=0
      docStoreSegment=_v8
      docStoreIsCompoundFile=false
      no deletions
      test: open reader.........FAILED
      WARNING: would remove reference to this segment (-fix was not
specified); full exception:
  java.io.FileNotFoundException:
/home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/_v8.fnm
(No such file or directory)
   at java.io.RandomAcce

I'd ignore Otis' message from 2005.  I haven't followed the thread carefully, but it looks like a bug deep in the guts of Lucene.
Otis --
Sematext -- http://sematext.com/ -- Lucene - Solr - Nutch

----- Original Message ----
> From: Chris Harris <[EMAIL PROTECTED]>
> To: [EMAIL PROTECTED]
> Sent: Friday, August 15, 2008 4:30:07 PM
> Subject: Re: "Auto commit error" and java.io.FileNotFoundException
>
> I've done some more sniffing on the Lucene list, and noticed that Otis
> made the following comment about a FileNotFoundException problem in
> late 2005:
>
>     Are you using Windows and a compound index format (look at your index
>     dir - does it have .cfs file(s))?
>
>     This may be a bad combination, judging from people who reported this
>     problem so far.
>
> (http://www.nabble.com/fnm-file-disappear-td1531775.html#a1531775)
>
> Again, a CFS index was indeed involved in my case, but my experience
> comes almost three years after Otis' message...
>
> On Fri, Aug 15, 2008 at 10:35 AM, Chris Harris wrote:
> >
> > The following may or may not be relevant: I built the base 3M-ish doc
> > index on a Windows machine, and it's a compound (.cfs) format index.
> > (I actually created it not with Solr, but by using the index merging
> > tool that comes with Lucene in order to merge three different
> > non-compound format indexes that I'd previously made with Solr into a
> > single index.) Before I started adding documents, I moved the index to
> > a Linux machine running a newer version of Solr/Lucene than was on the
> > Windows machine. The stuff described above all happened on Linux.
> >
> > Any thoughts?
> >
> > Thanks a bunch,
> > Chris
> >

How are you adding documents?  One at a time?  Multiple at a time?  From a single thread or multiple threads?
Have you tried building the latest and greatest Lucene from trunk and using that with Solr on the Linux box?

Otis
--
Sematext -- http://sematext.com/ -- Lucene - Solr - Nutch

----- Original Message ----
> From: Chris Harris <[EMAIL PROTECTED]>
> To: [EMAIL PROTECTED]
> Sent: Friday, August 15, 2008 1:35:20 PM
> Subject: "Auto commit error" and java.io.FileNotFoundException
>
> I have an index (different from the ones mentioned yesterday) that was
> working fine with 3M docs or so, but when I added a bunch more docs,
> bringing it closer to 4M docs, the index seemed to get corrupted. In
> particular, now when I start Solr up, or when when my indexing process
> tries add a document, I get a complaint about missing index files.
>
> The error on startup looks like this:
>
>
>   2008-08-15T10:18:54
>   1218820734592
>   92
>   org.apache.solr.core.MultiCore
>   SEVERE
>   org.apache.solr.common.SolrException
>   log
>   10
>   java.lang.RuntimeException: java.io.FileNotFoundException:
> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
> directory)
>     at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:733)
>     at org.apache.solr.core.SolrCore.<init>(SolrCore.java:387)
>     at org.apache.solr.core.MultiCore.create(MultiCore.java:255)
>     at org.apache.solr.core.MultiCore.load(MultiCore.java:139)
>     at
> org.apache.solr.servlet.SolrDispatchFilter.initMultiCore(SolrDispatchFilter.java:147)
>     at
> org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:75)
>     at org.mortbay.jetty.servlet.FilterHolder.doStart(FilterHolder.java:99)
>     at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>     at
> org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:594)
>     at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
>     at
> org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1218)
>     at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:500)
>     at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:448)
>     at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>     at
> org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
>     at
> org.mortbay.jetty.handler.ContextHandlerCollection.doStart(ContextHandlerCollection.java:161)
>     at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>     at
> org.mortbay.jetty.handler.HandlerCollection.doStart(HandlerCollection.java:147)
>     at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>     at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:117)
>     at org.mortbay.jetty.Server.doStart(Server.java:210)
>     at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>     at org.mortbay.xml.XmlConfiguration.main(XmlConfiguration.java:929)
>     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>     at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>     at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>     at java.lang.reflect.Method.invoke(Method.java:616)
>     at org.mortbay.start.Main.invokeMain(Main.java:183)
>     at org.mortbay.start.Main.start(Main.java:497)
>     at org.mortbay.start.Main.main(Main.java:115)
> Caused by: java.io.FileNotFoundException:
> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
> directory)
>     at java.io.RandomAccessFile.open(Native Method)
>     at java.io.RandomAccessFile.<init>(RandomAccessFile.java:233)
>     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.openInput(FSDirectory.java:445)

I hate to blame the JDK, but we tried 1.6 for our production
webapp and it was crashing too often. Unless you need 1.6,
you might try 1.5. --wunder

On 8/16/08 1:54 PM, "Chris Harris" <[EMAIL PROTECTED]> wrote:

> On Sat, Aug 16, 2008 at 4:33 AM, Grant Ingersoll <[EMAIL PROTECTED]> wrote:
>> What version of Java do you have on Linux?
>
> The Java version on *Linux* (where I'm seeing the trouble):
>
>     java version "1.6.0"
>     OpenJDK Runtime Environment (build 1.6.0-b09)
>     OpenJDK 64-Bit Server VM (build 1.6.0-b09, mixed mode)
>
> I'm pretty sure this is the latest one from the Ubuntu repository.
>
> Maybe I should try the official Sun HotSpot build instead. I'm not
> finding any complaints about OpenJDK on the Lucene list, though.
>
> The Java version on *Windows* (where I created the initial compound
> format index) is an official Sun build:
>
>     java version "1.6.0_06"
>     Java(TM) SE Runtime Environment (build 1.6.0_06-b02)
>     Java HotSpot(TM) Client VM (build 10.0-b22, mixed mode, sharing)
>
>> Also, is this easily reproducible?  How many threads are you adding
>> documents with?  What is your Auto Commit setting?
>
> I think it takes 12-24hr to get the index to screw up, so while I did
> reproduce it once, I haven't yet tried again. Intuition says that if I
> repeat the same procedure the same problem would arise. Of course,
> what would be nice is if I could figure out how to reproduce it more
> quickly, with a smaller index, and a simpler schema.
>
> I'm adding documents with 5-10 threads. Since I'm using the rich
> document update handler
> (https://issues.apache.org/jira/browse/SOLR-284), there's going to be
> PDF and HTML conversion going on within Solr alongside the normal
> analysis and indexing.
>
> Autocommit is:
>
>     <autoCommit>
>       <maxDocs>100000</maxDocs>
>       <maxTime>1800000</maxTime>  <!-- 30 min -->
>     </autoCommit>
>
>> Can you try Lucene's CheckIndex tool on it and report what it says?
>
> Working on that now. It should take some time, though, due to the index size.
>
>>
>> On Aug 15, 2008, at 1:35 PM, Chris Harris wrote:
>>
>>> I have an index (different from the ones mentioned yesterday) that was
>>> working fine with 3M docs or so, but when I added a bunch more docs,
>>> bringing it closer to 4M docs, the index seemed to get corrupted. In
>>> particular, now when I start Solr up, or when when my indexing process
>>> tries add a document, I get a complaint about missing index files.
>>>
>>> The error on startup looks like this:
>>>
>>> <record>
>>>  <date>2008-08-15T10:18:54</date>
>>>  <millis>1218820734592</millis>
>>>  <sequence>92</sequence>
>>>  <logger>org.apache.solr.core.MultiCore</logger>
>>>  <level>SEVERE</level>
>>>  <class>org.apache.solr.common.SolrException</class>
>>>  <method>log</method>
>>>  <thread>10</thread>
>>>  <message>java.lang.RuntimeException: java.io.FileNotFoundException:
>>> /ssd/solr-9999/solr/exhibitcore/data/index/_p7.fdt (No such file or
>>> directory)
>>>        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:733)
>>>        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:387)
>>>        at org.apache.solr.core.MultiCore.create(MultiCore.java:255)
>>>        at org.apache.solr.core.MultiCore.load(MultiCore.java:139)
>>>        at
>>> org.apache.solr.servlet.SolrDispatchFilter.initMultiCore(SolrDispatchFilter.
>>> java:147)
>>>        at
>>> org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:75)
>>>        at
>>> org.mortbay.jetty.servlet.FilterHolder.doStart(FilterHolder.java:99)
>>>        at
>>> org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:40)
>>>        at
>>> org.mortbay.jetty.servlet.ServletHandler.initialize(ServletHandler.java:594)
>>>        at org.mortbay.jetty.servlet.Context.startContext(Context.java:139)
>>>        at
>>> org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1218)
>>>        at
>>> org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:500)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57>>>
)

The output from CheckIndex shows quite a few missing files!  Is there  
any possibility that two instances of Solr were somehow sharing the  
same index directory?

It looks like you are using the 2.3 version of the Lucene jar (not the  
trunk version).  Which version of Solr are you using?

Since it seems reproducible, could you turn on debugging output  
(IndexWriter.setInfoStream(...)), get the FileNotFoundException to  
happen again, and post the resulting output?

Mike

Chris Harris wrote:

> On Sat, Aug 16, 2008 at 4:33 AM, Grant Ingersoll  
> <[EMAIL PROTECTED]> wrote:
>> Can you try Lucene's CheckIndex tool on it and report what it says?
>>
>> On Aug 15, 2008, at 1:35 PM, Chris Harris wrote:
>>
>>> I have an index (different from the ones mentioned yesterday) that  
>>> was
>>> working fine with 3M docs or so, but when I added a bunch more docs,
>>> bringing it closer to 4M docs, the index seemed to get corrupted. In
>>> particular, now when I start Solr up, or when when my indexing  
>>> process
>>> tries add a document, I get a complaint about missing index files.
>>>
>>> The error on startup looks like this:
>>>
>>> [...]
>
> So I've run the Lucene CheckIndex tool twice.
>
> First I ran it on my Windows machine, on the original compound format
> index, which I then moved over to Linux and added to. It checked out
> ok:
>
>
>  NOTE: testing will be more thorough if you run java with
> '-ea:org.apache.lucene', so assertions are enabled
>
>  Opening index @ E:\solr-9999\solr\exhibitcore\data\index
>
>  Segments file=segments_2 numSegments=1
> version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]
>    1 of 1: name=_0 docCount=2829254
>      compound=true
>      numFiles=1
>      size (MB)=30,423.298
>      no deletions
>      test: open reader.........OK
>      test: fields, norms.......OK [21 fields]
>      test: terms, freq, prox...OK [20208545 terms; 1092415125
> terms/docs pairs; 6041972577 tokens]
>      test: stored fields.......OK [82628579 total field count; avg
> 29.205 fields per doc]
>      test: term vectors........OK [0 total vector count; avg 0
> term/freq vector fields per doc]
>
>  No problems were detected with this index.
>
>
> Then I ran it on Linux, against the index in its problematic state.
> (Note: This is the end of my message. Everything that follows is
> output from the tool):
>
>
>  Opening index @
> /home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/
>
>  Segments file=segments_10tu numSegments=48
> version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]
>    1 of 48: name=_0 docCount=2829254
>      compound=true
>      numFiles=1
>      size (MB)=30,423.298
>      no deletions
>      test: open reader.........OK
>      test: fields, norms.......OK [21 fields]
>      test: terms, freq, prox...OK [20208545 terms; 1092415125
> terms/docs pairs; 6041972577 tokens]
>      test: stored fields.......OK [82628579 total field count; avg
> 29.205 fields per doc]
>      test: term vectors........OK [0 total vector count; avg 0
> term/freq vector fields per doc]
>
>    2 of 48: name=_uz docCount=1567952
>      compound=false
>      numFiles=8
>      size (MB)=17,238.136
>      no deletions
>      test: open reader.........OK
>      test: fields, norms.......OK [21 fields]
>      test: terms, freq, prox...OK [11529959 terms; 613302128
> terms/docs pairs; 3503689207 tokens]
>      test: stored fields.......OK [45879263 total field count; avg
> 29.261 fields per doc]
>      test: term vectors........OK [0 total vector count; avg 0
> term/freq vector fields per doc]
>
>    3 of 48: name=_v7 docCount=24507
>      compound=false
>      numFiles=0
>      size (MB)=0
>      no deletions
>      test: open reader.........FAILED
>      WARNING: would remove reference to this segment (-fix was not
> specified); full exception:
>  java.io.FileNotFoundException:
> /home/guy/corrupt-solr-9999-from-ssd/solr/exhibitcore/data/index/
> _v7.fnm
> (No such file or directory)
>   at java.io.RandomAccessFile.open(Native Method)

I'm assuming that one way to do this would be to set the logging level
to "FINEST" in the "logging" page in the solr admin tool, and then to
make sure my logging.properties file is also set to record the FINEST
logging level. Let me know if that won't enable to sort of debugging
info you are talking about. (I do understand that the logging page in
the admin tool makes temporary changes that will get reverted when you
restart Solr.)

On Mon, Aug 18, 2008 at 3:05 AM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
>
> Since it seems reproducible, could you turn on debugging output
> (IndexWriter.setInfoStream(...)), get the FileNotFoundException to happen
> again, and post the resulting output?
>
> Mike

Alas, I think this won't actually turn on IndexWriter's infoStream.

I think you may need to modify the SolrIndexWriter.java sources, in  
the init method, to add a call to setInfoStream(...).

Can any Solr developers confirm this?

Mike

Chris Harris wrote:

> I'm assuming that one way to do this would be to set the logging level
> to "FINEST" in the "logging" page in the solr admin tool, and then to
> make sure my logging.properties file is also set to record the FINEST
> logging level. Let me know if that won't enable to sort of debugging
> info you are talking about. (I do understand that the logging page in
> the admin tool makes temporary changes that will get reverted when you
> restart Solr.)
>
> On Mon, Aug 18, 2008 at 3:05 AM, Michael McCandless
> <[EMAIL PROTECTED]> wrote:
>>
>> Since it seems reproducible, could you turn on debugging output
>> (IndexWriter.setInfoStream(...)), get the FileNotFoundException to  
>> happen
>> again, and post the resulting output?
>>
>> Mike

Lucene v.2.1 has a bug with autocommit...

On Mon, Aug 18, 2008 at 1:12 PM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
>
> Alas, I think this won't actually turn on IndexWriter's infoStream.
>
> I think you may need to modify the SolrIndexWriter.java sources, in the init
> method, to add a call to setInfoStream(...).
>
> Can any Solr developers confirm this?

Yeah, we don't have that feature yet.

-Yonik

On Mon, Aug 18, 2008 at 6:05 AM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
> The output from CheckIndex shows quite a few missing files!  Is there any
> possibility that two instances of Solr were somehow sharing the same index
> directory?

To eliminate that possibility, the lock factory should be set to
"simple" and unlockOnStartup should be "false" in solrconfig.xml

-Yonik

Ok, I did what you suggested, giving each SolrIndexWriter its own
"infoStream" log file, created in the init() method. The thing is, I
now have like 3400 infostream log files, I guess reflecting how solr
created like 3400 SolrIndexWriters over the course of the run.
(Hopefully this is plausible.) Could you explain what I should be
looking for in these files? (Posting the whole bunch of it doesn't
sound very useful.)

Thanks,
Chris

On Mon, Aug 18, 2008 at 10:12 AM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
>
> Alas, I think this won't actually turn on IndexWriter's infoStream.
>
> I think you may need to modify the SolrIndexWriter.java sources, in the init
> method, to add a call to setInfoStream(...).
>
> Can any Solr developers confirm this?
>
> Mike
>
> Chris Harris wrote:
>
>> I'm assuming that one way to do this would be to set the logging level
>> to "FINEST" in the "logging" page in the solr admin tool, and then to
>> make sure my logging.properties file is also set to record the FINEST
>> logging level. Let me know if that won't enable to sort of debugging
>> info you are talking about. (I do understand that the logging page in
>> the admin tool makes temporary changes that will get reverted when you
>> restart Solr.)
>>
>> On Mon, Aug 18, 2008 at 3:05 AM, Michael McCandless
>> <[EMAIL PROTECTED]> wrote:
>>>
>>> Since it seems reproducible, could you turn on debugging output
>>> (IndexWriter.setInfoStream(...)), get the FileNotFoundException to happen
>>> again, and post the resulting output?
>>>
>>> Mike
>
>

Did the same FileNotFoundException / massive deletion of files occur?

Actually if you could zip them all up and post them, I'll dig through  
them to see if they give any clues...

Mike

Chris Harris wrote:

> Ok, I did what you suggested, giving each SolrIndexWriter its own
> "infoStream" log file, created in the init() method. The thing is, I
> now have like 3400 infostream log files, I guess reflecting how solr
> created like 3400 SolrIndexWriters over the course of the run.
> (Hopefully this is plausible.) Could you explain what I should be
> looking for in these files? (Posting the whole bunch of it doesn't
> sound very useful.)
>
> Thanks,
> Chris
>
> On Mon, Aug 18, 2008 at 10:12 AM, Michael McCandless
> <[EMAIL PROTECTED]> wrote:
>>
>> Alas, I think this won't actually turn on IndexWriter's infoStream.
>>
>> I think you may need to modify the SolrIndexWriter.java sources, in  
>> the init
>> method, to add a call to setInfoStream(...).
>>
>> Can any Solr developers confirm this?
>>
>> Mike
>>
>> Chris Harris wrote:
>>
>>> I'm assuming that one way to do this would be to set the logging  
>>> level
>>> to "FINEST" in the "logging" page in the solr admin tool, and then  
>>> to
>>> make sure my logging.properties file is also set to record the  
>>> FINEST
>>> logging level. Let me know if that won't enable to sort of debugging
>>> info you are talking about. (I do understand that the logging page  
>>> in
>>> the admin tool makes temporary changes that will get reverted when  
>>> you
>>> restart Solr.)
>>>
>>> On Mon, Aug 18, 2008 at 3:05 AM, Michael McCandless
>>> <[EMAIL PROTECTED]> wrote:
>>>>
>>>> Since it seems reproducible, could you turn on debugging output
>>>> (IndexWriter.setInfoStream(...)), get the FileNotFoundException  
>>>> to happen
>>>> again, and post the resulting output?
>>>>
>>>> Mike
>>
>>

Well shoot, upon further examination it appears that this time around
there weren't actually any segment deletion problems. The "only"
problem was a "doc counts differ" error. Interestingly, the count is
only off by one.

>From the CheckIndex tool:

****

Opening index @ /ssd/solr-9999/solr/exhibitcore/data/index

Segments file=segments_qc3 numSegments=31
version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]

[...]

  4 of 31: name=_3r docCount=23673
    compound=false
    numFiles=8
    size (MB)=203.217
    no deletions
    test: open reader.........FAILED
    WARNING: would remove reference to this segment (-fix was not
specified); full exception:
org.apache.lucene.index.CorruptIndexException: doc counts differ for
segment _3r: fieldsReader shows 23672 but segmentInfo shows 23673
at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:315)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:264)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:199)
at org.apache.lucene.index.CheckIndex.check(CheckIndex.java:178)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:433)

[...]

WARNING: 1 broken segments detected
WARNING: 23673 documents would be lost if -fix were specified

***

I don't know if they would still help in light of this, but I've got
12MB of infoStream data from this round here:

    http://www.knowledgemosaic.com/public/infoStream.tar.gz

As for the normal Solr log (I now have a log for the whole round), the
first relevant SEVERE error was this:

<record>
  <date>2008-08-20T16:42:06</date>
  <millis>1219275726747</millis>
  <sequence>587322</sequence>
  <logger>org.apache.solr.core.SolrCore</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.common.SolrException</class>
  <method>log</method>
  <thread>13</thread>
  <message>java.lang.NullPointerException
</message>
</record>

Curiously there is no stack trace.

The next relevant error:

<record>
  <date>2008-08-20T16:42:52</date>
  <millis>1219275772073</millis>
  <sequence>590946</sequence>
  <logger>org.apache.solr.update.UpdateHandler</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.update.DirectUpdateHandler2$CommitTracker</class>
  <method>run</method>
  <thread>16</thread>
  <message>auto commit error...</message>
</record>

Then there's another NullPointerException, now from a different logger

<record>
  <date>2008-08-20T16:53:46</date>
  <millis>1219276426304</millis>
  <sequence>640371</sequence>
  <logger>org.apache.solr.servlet.SolrDispatchFilter</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.common.SolrException</class>
  <method>log</method>
  <thread>17</thread>
  <message>java.lang.NullPointerException</message>
</record>

And later on the "corrupt index" fun begins:

<record>
  <date>2008-08-20T17:02:18</date>
  <millis>1219276938663</millis>
  <sequence>731205</sequence>
  <logger>org.apache.solr.core.SolrCore</logger>
  <level>SEVERE</level>
  <class>org.apache.solr.common.SolrException</class>
  <method>log</method>
  <thread>13</thread>
  <message>org.apache.lucene.index.CorruptIndexException: doc counts
differ for segment _3r: fieldsReader shows 23672 but segmentInfo shows
23673
at org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:313)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:262)
at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:197)
at org.apache.lucene.index.MultiSegmentReader.<init>(MultiSegmentReader.java:55)
at org.apache.lucene.index.DirectoryIndexReader$1.doBody(DirectoryIndexReader.java:75)
at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:636)
at org.apache.lucene.index.DirectoryIndexReader.open(DirectoryIndexReader.java:63)
at org.apache.lucene.index.IndexReader.open(IndexReader.java:209)
at org.apache.lucene.index.IndexReader.open(IndexReader.java:173)
at org.apache.solr.search.SolrIndexSearcher.<init>(SolrIndexSearcher.java:93)
at org.apache.solr.core.SolrCore.newSearcher(SolrCore.java:213)
at org.apache.solr.update.DirectUpdateHandler2.openSearcher(DirectUpdateHandler2.java:207)
at org.apache.solr.update.DirectUpdateHandler2.doDeletions(DirectUpdateHandler2.java:466)
at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:295)
at org.apache.solr.handler.RichDocumentLoader.doAdd(RichDocumentRequestHandler.java:231)
at org.apache.solr.handler.RichDocumentLoader.addDoc(RichDocumentRequestHandler.java:236)
at org.apache.solr.handler.RichDocumentLoader.load(RichDocumentRequestHandler.java:278)
at org.apache.solr.handler.RichDocumentRequestHandler.handleRequestBody(RichDocumentRequestHandler.java:80)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:125)
at org.apache.solr.core.RequestHandlers$LazyRequestHandlerWrapper.handleRequest(RequestHandlers.java:228)
at org.apache.solr.core.SolrCore.execute(SolrCore.java:965)
at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:339)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:274)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1089)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:365)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:712)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:211)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:285)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:502)
at

Urgh, I was hoping we could repro the "massive deletion" with  
infoStream turned on.

Uh-oh: that "off by 1" corruption is very likely due to the Sun JRE  
bug described here:

     https://issues.apache.org/jira/browse/LUCENE-1282

Can you downgrade to 1.6.0_03, or, upgrade to the latest beta build  
(b28) of Sun's 1.6 JRE, from here:

     http://download.java.net/jdk6/binaries/

I agree you should stick with the older stuff to reproduce this bug,  
but, do you know which svn rev of Lucene's JAR you are using?  I had  
committed a workaround for LUCENE-1282 to trunk.

Mike

On Aug 21, 2008, at 2:55 PM, Chris Harris wrote:

> Well shoot, upon further examination it appears that this time around
> there weren't actually any segment deletion problems. The "only"
> problem was a "doc counts differ" error. Interestingly, the count is
> only off by one.
>
> From the CheckIndex tool:
>
> ****
>
> Opening index @ /ssd/solr-9999/solr/exhibitcore/data/index
>
> Segments file=segments_qc3 numSegments=31
> version=FORMAT_SHARED_DOC_STORE [Lucene 2.3]
>
> [...]
>
>  4 of 31: name=_3r docCount=23673
>    compound=false
>    numFiles=8
>    size (MB)=203.217
>    no deletions
>    test: open reader.........FAILED
>    WARNING: would remove reference to this segment (-fix was not
> specified); full exception:
> org.apache.lucene.index.CorruptIndexException: doc counts differ for
> segment _3r: fieldsReader shows 23672 but segmentInfo shows 23673
> at  
> org.apache.lucene.index.SegmentReader.initialize(SegmentReader.java:
> 315)
> at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:264)
> at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:199)
> at org.apache.lucene.index.CheckIndex.check(CheckIndex.java:178)
> at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:433)
>
> [...]
>
> WARNING: 1 broken segments detected
> WARNING: 23673 documents would be lost if -fix were specified
>
> ***
>
> I don't know if they would still help in light of this, but I've got
> 12MB of infoStream data from this round here:
>
>    http://www.knowledgemosaic.com/public/infoStream.tar.gz
>
> As for the normal Solr log (I now have a log for the whole round), the
> first relevant SEVERE error was this:
>
> <record>
>  <date>2008-08-20T16:42:06</date>
>  <millis>1219275726747</millis>
>  <sequence>587322</sequence>
>  <logger>org.apache.solr.core.SolrCore</logger>
>  <level>SEVERE</level>
>  <class>org.apache.solr.common.SolrException</class>
>  <method>log</method>
>  <thread>13</thread>
>  <message>java.lang.NullPointerException
> </message>
> </record>
>
> Curiously there is no stack trace.
>
> The next relevant error:
>
> <record>
>  <date>2008-08-20T16:42:52</date>
>  <millis>1219275772073</millis>
>  <sequence>590946</sequence>
>  <logger>org.apache.solr.update.UpdateHandler</logger>
>  <level>SEVERE</level>
>  <class>org.apache.solr.update.DirectUpdateHandler2$CommitTracker</
> class>
>  <method>run</method>
>  <thread>16</thread>
>  <message>auto commit error...</message>
> </record>
>
> Then there's another NullPointerException, now from a different logger
>
> <record>
>  <date>2008-08-20T16:53:46</date>
>  <millis>1219276426304</millis>
>  <sequence>640371</sequence>
>  <logger>org.apache.solr.servlet.SolrDispatchFilter</logger>
>  <level>SEVERE</level>
>  <class>org.apache.solr.common.SolrException</class>
>  <method>log</method>
>  <thread>17</thread>
>  <message>java.lang.NullPointerException</message>
> </record>
>
> And later on the "corrupt index" fun begins:
>
> <record>
>  <date>2008-08-20T17:02:18</date>
>  <millis>1219276938663</millis>
>  <sequence>731205</sequence>
>  <logger>org.apache.solr.core.SolrCore</logger>
>  <level>SEVERE</level>
>  <class>org.apache.solr.common.SolrException</class>
>  <method>log</method>
>  <thread>13</thread>
>  <message>org.apache.lucene.index.CorruptIndexException: doc counts
> differ for segment _3r: fieldsReader shows 23672 but segmentInfo shows
> 23673

I'll see about using a newer/older JVM.

In the meantime, according to the Solr admin page, which seems to get
its info like so

    LucenePackage.class.getPackage().getImplementationVersion()

what I've been testing is Lucene r652650. The Solr version is r654965,
now modified of course to do some more debug logging. Unless I've
screwed things up, this is the version of Lucene that comes with this
version of Solr.

On Thu, Aug 21, 2008 at 12:49 PM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
>
> Urgh, I was hoping we could repro the "massive deletion" with infoStream
> turned on.
>
> Uh-oh: that "off by 1" corruption is very likely due to the Sun JRE bug
> described here:
>
>    https://issues.apache.org/jira/browse/LUCENE-1282
>
> Can you downgrade to 1.6.0_03, or, upgrade to the latest beta build (b28) of
> Sun's 1.6 JRE, from here:
>
>    http://download.java.net/jdk6/binaries/
>
> I agree you should stick with the older stuff to reproduce this bug, but, do
> you know which svn rev of Lucene's JAR you are using?  I had committed a
> workaround for LUCENE-1282 to trunk.
>
> Mike

OK indeed that revision of Lucene is before the workaround for that  
nasty JRE bug was committed.

Can you test one of those JRE versions (known not to have this  
particular JRE bug) and see if you can get the original "massive  
deletion" problem to happen.  I guess first try it without the  
infoStream change, since it's possible the infoStream change prevented  
the issue from happening?

Mike

Chris Harris wrote:

> I'll see about using a newer/older JVM.
>
> In the meantime, according to the Solr admin page, which seems to get
> its info like so
>
>    LucenePackage.class.getPackage().getImplementationVersion()
>
> what I've been testing is Lucene r652650. The Solr version is r654965,
> now modified of course to do some more debug logging. Unless I've
> screwed things up, this is the version of Lucene that comes with this
> version of Solr.
>
> On Thu, Aug 21, 2008 at 12:49 PM, Michael McCandless
> <[EMAIL PROTECTED]> wrote:
>>
>> Urgh, I was hoping we could repro the "massive deletion" with  
>> infoStream
>> turned on.
>>
>> Uh-oh: that "off by 1" corruption is very likely due to the Sun JRE  
>> bug
>> described here:
>>
>>   https://issues.apache.org/jira/browse/LUCENE-1282
>>
>> Can you downgrade to 1.6.0_03, or, upgrade to the latest beta build  
>> (b28) of
>> Sun's 1.6 JRE, from here:
>>
>>   http://download.java.net/jdk6/binaries/
>>
>> I agree you should stick with the older stuff to reproduce this  
>> bug, but, do
>> you know which svn rev of Lucene's JAR you are using?  I had  
>> committed a
>> workaround for LUCENE-1282 to trunk.
>>
>> Mike

Well I've done two or three more runs with Sun java build
1.6.0_10-rc-b28, with and without the infoStream change, and I can't
reproduce the problem. So maybe everything was indeed the fault of the
release version of Sun hotspot. Not too confident about that. Maybe
instead I let the disk get too full before or something.

In any case I'm unfortunately not sure I have time to keep trying to
reproduce the problem on old versions of Solr/Lucene that aren't
candidates for going into production. It's a pity.

One thing that's bugging me is when I get errors in my log that look like this:

<record>
 <date>2008-08-22T13:00:48</date>
 <millis>12194352486770</millis>
 <sequence>8387379</sequence>
 <logger>org.apache.solr.core.SolrCore</logger>
 <level>SEVERE</level>
 <class>org.apache.solr.common.SolrException</class>
 <method>log</method>
 <thread>56</thread>
 <message>java.lang.NullPointerException
</message>
</record>
<record>
 <date>2008-08-22T13:00:48</date>
 <millis>1219435248676</millis>
 <sequence>8387381</sequence>
 <logger>org.apache.solr.servlet.SolrDispatchFilter</logger>
 <level>SEVERE</level>
 <class>org.apache.solr.common.SolrException</class>
 <method>log</method>
 <thread>56</thread>
 <message>java.lang.NullPointerException
</message>
</record>

I get these NullPointException records every once and a while, always
from SolrCore and SolrDispatchFilter. Don't get a stack trace, and no
nearby errors seem to clarify what might have happened.

On Thu, Aug 21, 2008 at 3:52 PM, Michael McCandless
<[EMAIL PROTECTED]> wrote:
>
> OK indeed that revision of Lucene is before the workaround for that nasty
> JRE bug was committed.
>
> Can you test one of those JRE versions (known not to have this particular
> JRE bug) and see if you can get the original "massive deletion" problem to
> happen.  I guess first try it without the infoStream change, since it's
> possible the infoStream change prevented the issue from happening?
>
> Mike
>
> Chris Harris wrote:
>
>> I'll see about using a newer/older JVM.
>>
>> In the meantime, according to the Solr admin page, which seems to get
>> its info like so
>>
>>   LucenePackage.class.getPackage().getImplementationVersion()
>>
>> what I've been testing is Lucene r652650. The Solr version is r654965,
>> now modified of course to do some more debug logging. Unless I've
>> screwed things up, this is the version of Lucene that comes with this
>> version of Solr.
>>
>> On Thu, Aug 21, 2008 at 12:49 PM, Michael McCandless
>> <[EMAIL PROTECTED]> wrote:
>>>
>>> Urgh, I was hoping we could repro the "massive deletion" with infoStream
>>> turned on.
>>>
>>> Uh-oh: that "off by 1" corruption is very likely due to the Sun JRE bug
>>> described here:
>>>
>>>  https://issues.apache.org/jira/browse/LUCENE-1282
>>>
>>> Can you downgrade to 1.6.0_03, or, upgrade to the latest beta build (b28)
>>> of
>>> Sun's 1.6 JRE, from here:
>>>
>>>  http://download.java.net/jdk6/binaries/
>>>
>>> I agree you should stick with the older stuff to reproduce this bug, but,
>>> do
>>> you know which svn rev of Lucene's JAR you are using?  I had committed a
>>> workaround for LUCENE-1282 to trunk.
>>>
>>> Mike
>
>

: I get these NullPointException records every once and a while, always
: from SolrCore and SolrDispatchFilter. Don't get a stack trace, and no
: nearby errors seem to clarify what might have happened.

that's really strange ... i'm not sure what's causing those, or why you
aren't seeing a stack trace.  i'm not too familiar with the XmlFormatter,
but according to the docs it does support an <exception> section with
multiple <frame>s.

any chance you could configure an additional SimpleFormatter
just for SEVERE messages to help us track it down?
-Hoss