docs out of order [LUCENE-140]

[asfimport]

Hello,
I can not find out, why (and what) it is happening all the time. I got an
exception:
java.lang.IllegalStateException: docs out of order
at
org.apache.lucene.index.SegmentMerger.appendPostings(SegmentMerger.java:219)
at
org.apache.lucene.index.SegmentMerger.mergeTermInfo(SegmentMerger.java:191)
at
org.apache.lucene.index.SegmentMerger.mergeTermInfos(SegmentMerger.java:172)
at org.apache.lucene.index.SegmentMerger.mergeTerms(SegmentMerger.java:135)
at org.apache.lucene.index.SegmentMerger.merge(SegmentMerger.java:88)
at org.apache.lucene.index.IndexWriter.mergeSegments(IndexWriter.java:341)
at org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:250)
at Optimize.main(Optimize.java:29)

It happens either in 1.2 and 1.3rc1 (anyway what happened to it? I can not find
it neither in download nor in version list in this form). Everything seems OK. I
can search through index, but I can not optimize it. Even worse after this
exception every time I add new documents and close IndexWriter new segments is
created! I think it has all documents added before, because of its size.

My index is quite big: 500.000 docs, about 5gb of index directory.

It is repeatable. I drop index, reindex everything. Afterwards I add a few
docs, try to optimize and receive above exception.

My documents' structure is:
static Document indexIt(String id_strony, Reader reader, String data_wydania,
String id_wydania, String id_gazety, String data_wstawienia)
{
Document doc = new Document();

doc.add(Field.Keyword("id", id_strony ));
doc.add(Field.Keyword("data_wydania", data_wydania));
doc.add(Field.Keyword("id_wydania", id_wydania));
doc.add(Field.Text("id_gazety", id_gazety));
doc.add(Field.Keyword("data_wstawienia", data_wstawienia));
doc.add(Field.Text("tresc", reader));

return doc;

}

Sincerely,
legez

---

Migrated from LUCENE-140 by legez, 5 votes, resolved Jan 11 2007
Environment:

Operating System: Linux
Platform: PC

Attachments: ASF.LICENSE.NOT.GRANTED--bug23650.txt, corrupted.part1.rar, corrupted.part2.rar, indexing-failure.log, LUCENE-140-2007-01-09-instrumentation.patch

[asfimport]

Otis Gospodnetic (migrated from JIRA)

Since the bug submitter hasn't followed up to this 'repeatable' issue in almost
two months, I shall assume that this was not a bug in Lucene, but a misuse of
Lucene.

There is also no self-contained code that demonstrates the bug.

If this is indeed a Lucene bug, please re-open this bug entry, and provise
self-sufficient unit test that demonstrates this problem.

[asfimport]

Arvind Srinivasan (migrated from JIRA)

More Data Integrity Issue: Docs out of Order

Hi,
Seeing similar issue to the one reported in:
http://nagoya.apache.org/bugzilla/show_bug.cgi?id=23650
On examining the segments, following inconsistencies were found
(a) The merging segments had doc number that is greater than maxDoc.
Don't know how it go in this state, but this occurs using standard lucene
code.
(b) Strangely, some documents had terms with zero frequency. And when it
occurred,
the zero frequency term has several posting as (docid 0)
Example.. (docid freq) – MaxDoc = 7749 - NO DELETION.
Merging msgBody; text=it; sz=2 — The field name is msgBody and term is "it"
and two segments have the term.
(0 0)(0 0)(0 0)..........(0 0)(4 6)(5 3)(6 1)(9 1)(10 2)(12 1)......
...(6791 2)(6794 3)(6796 2)(6798 16)(6801 1)(6805 1)(6806 5)
(6808 1)(6810 1)(6815 2)(6816 3)(6817 1)(6818 1)(6821 4)(6822 1)
(6824 3)(6826 4)(6828 1)(6829 3)(12549 2)doc exceeds count
749(13570 1)doc exceeds count 7749(14896 1)doc exceeds count 7749
(15028 1)doc exceeds count 7749(15357 1)doc exceeds count 7749
(15427 1)doc exceeds count 7749(15534 1)doc exceeds count 7749
(15535 1)doc exceeds count 7749(15653 1)doc exceeds count 7749
(16530 1)doc exceeds count 7749(17108 1).......
(c) Also the zero frequency was not limited to the 0 document, there was
another instance.

One work around that seemed to resolve the issue was to:
(a) keep the maxDoc as a member variable in SegmentMergeInfo
and ignore/throw exception if an inconsistent state is detected.

****ADD To SegmentMerger just before "docs out of order" check.
if (postings.freq() == 0) {
continue;
}
if (doc >= smi.maxDoc) {
//sbLog.append("doc exceeds count \r\n " + smi.maxDoc);
continue;
}
****

Atleast putting a check would not corrupt the segments and would
get us closer to the real problem as to why freq=0 and doc number exceeds
maxDoc. Note, the code has had the fix to the other Segment corruption issue
that I previously reported (namely, Using a zero length file).

[asfimport]

Arvind Srinivasan (migrated from JIRA)

Created an attachment (id=15405)
Analysis of corrupted segments and suggestions.

[asfimport]

Otis Gospodnetic (migrated from JIRA)

Arvind, thanks for following up on this issue. From your report I can see that
the index really ends up containing invalid data, but I've never even seen this
happen myself. Could you please put together sample code that gets the index in
this state?

[asfimport]

Yonik Seeley (@yonik) (migrated from JIRA)

I've never seen this... can anyone reproduce with Lucene 1.9?
CCing this to Arvind's email...

[asfimport]

Otis Gospodnetic (@otisg) (migrated from JIRA)

2 years later, I still haven't seen this error.

[asfimport]

Jarrod Cuzens (migrated from JIRA)

First I think that Lucene is great and it manages to do an incredible job. However, this issue is also causing us significant problems. We originally had an AOP interceptor that would update documents in our HTTP threads however when we started to see this issue we were concerned that it was caused by multiple threads accessing the index at the same time. We put extra concurrency controls on the updates using the LuceneIndexAccess API that was posted into bugzilla by another user. This issue still remained after we added the extra concurrency control.

Since then we have abandoned the AOP approach completely and moved the index rebuild to a scheduled thread which collects things that were modified from the database (using datestamp versioning) and then proceeds to update their lucene indexes. We hoped this would solve the problem because only 1 thread in 1 process would be modifying the index at any given time. Alas, we are still getting docs out of order exceptions. It is difficult for us to reproduce as it mainly happens in production and we cannot provide a testcase for it (I wish we could!).

I know that this must be a difficult issue because it is difficult to reproduce. I can't think of anything strange that we are doing with the indexes (one process, one thread modifying). This probably isn't much help but I just wanted to let you know that we are also experiencing the problem.

[asfimport]

Doug Cutting (@cutting) (migrated from JIRA)

File corruption could cause this. Please look in your system logs to see if there are any reports of problems accessing the drive that stores this index.

[asfimport]

Jarrod Cuzens (migrated from JIRA)

Hi Doug,

Thanks for your suggestion (and great work on Lucene!). I looked in the logs and could not find any indication of corruption. In addition we actually have the system running in a cluster where each node in the cluster has its own lucene search index. We had the issue on a different machine before we moved to the cluster and we now see it on both machines in our cluster :(. Next time it occurs I will get the indexes and try to post them here if you think that would be helpful.

Just some additional info:

1. We are running SUSE 10 Linux.
2. We run two quartz jobs: One job runs every 2 minutes and updates lucene with changes from the db if necessary. The other job runs at 3:30AM in the morning and does full index rebuilds. We use the LuceneIndexAccess api when working with the IndexReader/IndexWriter. Only one thread should modify the index at any time although it is possible that the full rebuild job and the update job execute concurrently they shouldn't both modify the index due to the LuceneIndexAccess API's synchronization.
3. Currently when doing searches we create a new IndexSearcher everytime a search is to be performed; We do not use the LuceneIndexAccess API.

When I refer to the LuceneIndexAccess API I am referring to the contribution by Mark Schreiber:
http://www.blizzy.de/lucene/lucene-indexaccess-0.1.0.zip

Thanks for any help!

[asfimport]

Rafal Majewski (migrated from JIRA)

Hi,

I have recently experienced the same problem on relase 1.4.3. It happended in production(more than once). Filesystem index directory is used. One application is accountable for indexing, another for searching the index(it also uses IndexReader for query rewriting). Access to index directory(which is singleton) is synchronized within each application's scope. These two applications create separate directory instances and access it independently. Unfortunately, the code doesn't lead to repeatable occurances of this exception. I assume that these two applications having not synchronized access to the index might couse the problem, but I have received information that it had also occured with the searching application being down.

Thanks in advance for any help.

[asfimport]

Jarrod Cuzens (migrated from JIRA)

I am posting our corrupted index (I have to do it in two parts because it is 14.5M). I looked at it in Luke but Luke doesn't really have any tools to help really diagnose corruption issues. At this point we are considering changing our system to do builds on one machine, test them, and then have them distributed to the other machines in our cluster.

If anybody could look at this it would be greatly appreciated!
Thanks!
Jarrod

[asfimport]

Jarrod Cuzens (migrated from JIRA)

Second part. :)

[asfimport]

Ales Justin (migrated from JIRA)

We used Lucene 1.4.3. for a half year now.
But just out of the sudden this issue appeared.

We have synchronized access to index - synchronized singleton handling all write / read operations.

Is there any progress on finding the cause?

[asfimport]

Jason Lambert (migrated from JIRA)

I was having this problem intermittently while indexing over multiple threads and I have found that the following steps can cause this error (with Lucene 1.3 and 1.4.x):

• Open an IndexReader (LUCENE-9375: check github actions #1) over an existing index (this reader is used for searching while updating the index)
• Using this reader (LUCENE-9375: check github actions #1) do a search for the document(s) that you would like to update; obtain their document ID numbers
• Create an IndexWriter and add several new documents to the index (for me, this writing is done in other threads) ⭐
• Close the IndexWriter ⭐
• Open another IndexReader (LUCENE-9825: Hunspell: reverse the "words" trie for faster word lookup/suggestions (lucene repo) #2) over the index
• Delete the previously found documents by their document ID numbers using reader #2
• Close the #2 reader
• Create another IndexWriter (LUCENE-9825: Hunspell: reverse the "words" trie for faster word lookup/suggestions (lucene repo) #2) and re-add the updated documents
• Close the IndexWriter #2
• Close the original IndexReader (LUCENE-9375: check github actions #1) and open a new reader for general searching

If I ensure that the steps marked with an asterisk ⭐ do not happen (i.e. using thread synchronization), I never get this error. Otherwise, it will happen intermittently while closing the second IndexWriter (#2) (sometimes I get an ArrayIndexOutOfBoundsException during the deletion). These 'extra' writes cause the initial 'segments' file to be updated after which it is re-read while opening the second IndexReader (#2).

This can end up deleting documents using possibly non-existent IDs, most likely causing the index corruption that this error signals.

[asfimport]

Jed Wesley-Smith (migrated from JIRA)

We have seen this one as well. We don't have the same usage as above, we only ever delete documents with IndexReader.deleteDocuments(Term)

We are using Lucene 1.9.1

It occurs in two places, inside IndexWriter.addDocument():

java.lang.IllegalStateException: docs out of order
at org.apache.lucene.index.SegmentMerger.appendPostings([Lorg/apache/lucene/index/SegmentMergeInfo;I)I(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTermInfo([Lorg/apache/lucene/index/SegmentMergeInfo;I)V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTermInfos()V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTerms()V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.merge()I(Optimized Method)
at org.apache.lucene.index.IndexWriter.mergeSegments(II)V(IndexWriter.java:681)
at org.apache.lucene.index.IndexWriter.mergeSegments(I)V(IndexWriter.java:658)
at org.apache.lucene.index.IndexWriter.maybeMergeSegments()V(IndexWriter.java:646)
at org.apache.lucene.index.IndexWriter.addDocument(Lorg/apache/lucene/document/Document;Lorg/apache/lucene/analysis/Analyzer;)V(IndexWriter.java:453)
at org.apache.lucene.index.IndexWriter.addDocument(Lorg/apache/lucene/document/Document;)V(IndexWriter.java:436)

and inside IndexWriter.close():

java.lang.IllegalStateException: docs out of order
at org.apache.lucene.index.SegmentMerger.appendPostings([Lorg/apache/lucene/index/SegmentMergeInfo;I)I(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTermInfo([Lorg/apache/lucene/index/SegmentMergeInfo;I)V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTermInfos()V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.mergeTerms()V(Optimized Method)
at org.apache.lucene.index.SegmentMerger.merge()I(Optimized Method)
at org.apache.lucene.index.IndexWriter.mergeSegments(II)V(IndexWriter.java:681)
at org.apache.lucene.index.IndexWriter.mergeSegments(I)V(IndexWriter.java:658)
at org.apache.lucene.index.IndexWriter.flushRamSegments()V(IndexWriter.java:628)
at org.apache.lucene.index.IndexWriter.close()V(IndexWriter.java:375)

The second one exposes a problem in the close() method which is that the index write.lock is not released when exceptions are thrown in close() causing subsequent attempts to open an IndexWriter to fail.