ArrayIndexOutOfBoundsException in TermsHashPerField.writeByte during indexing [LUCENE-8118]

[asfimport]

Indexing a large collection of about 20 million paragraph-sized documents results in an ArrayIndexOutOfBoundsException in org.apache.lucene.index.TermsHashPerField.writeByte (full stack trace below).

The bug is possibly related to issues described in here and SOLR-10936 – but I am not using SOLR, I am directly using Lucene Core.

The issue can be reproduced using code from GitHub trec-car-tools-example

• compile with mvn compile assembly:single
• run with java -cp ./target/treccar-tools-example-0.1-jar-with-dependencies.jar edu.unh.cs.TrecCarBuildLuceneIndex paragraphs paragraphCorpus.cbor indexDir

Where paragraphCorpus.cbor is contained in this archive

Exception in thread "main" java.lang.ArrayIndexOutOfBoundsException: -65536 at org.apache.lucene.index.TermsHashPerField.writeByte(TermsHashPerField.java:198) at org.apache.lucene.index.TermsHashPerField.writeVInt(TermsHashPerField.java:224) at org.apache.lucene.index.FreqProxTermsWriterPerField.addTerm(FreqProxTermsWriterPerField.java:159) at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:185) at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:786) at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:430) at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:392) at org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:281) at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:451) at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1532) at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:1508)
at edu.unh.cs.TrecCarBuildLuceneIndex.main(TrecCarBuildLuceneIndex.java:55)

---

Migrated from LUCENE-8118 by Laura Dietz, 2 votes, updated Aug 19 2022
Environment:

Debian/Stretch
java version "1.8.0_144"                                                                                                                                                                                       Java(TM) SE Runtime Environment (build 1.8.0_144-b01)                                                                                                                                                          Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)

Attachments: LUCENE-8118_test.patch
Linked issues:

• LUCENE-10681

[asfimport]

Diego Ceccarelli (migrated from JIRA)

Looking at your code it seems that there is only one commit at the end, and your collection is big. What if you try to commit every, let's say, 50k docs?

[asfimport]

Laura Dietz (migrated from JIRA)

Yes, that works - Thanks, Diego!

I think I could have been helped with an Exception message that indicates "Buffer full, call index.commit!"

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

Issuing unnecessary commits is just masking the issue: you shouldn't see this exception.

[asfimport]

Diego Ceccarelli (migrated from JIRA)

I agree, that was just a workaround for Laura Dietz :)

[asfimport]

Laura Dietz (migrated from JIRA)

Robert, that would be even better!

It is difficult to guess what the right interval of issuing a commits is. I understand that some hand tuning might be necessary to get the highest performance for given resource constraints. If the issue is a buffer that is filling up, it would be helpful to have some form of an emergency auto-commit.

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

It is nothing like that, it is simply a bug.

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

Well, I understand the bug, but not sure what the fix is.

Indexing code implements Iterable etc to pull in the docs, and makes one single call to addDocuments().

This is supposed to be an "atomic add" of multiple documents at once which gives certain guarantees: needed for nested documents and features like that so they document IDs will be aligned in a particular way.

In your case, its too much data, IndexWriter isn't going to be able to do 200M docs in one operation like this.

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

whatever we decide to do, we can be sure that AIOOBE is not the right answer :)

[asfimport]

Laura Dietz (migrated from JIRA)

I think my mistake was to abuse addDocuments(iterator).

I switched to addDocument(doc) with a commit every so often (see master branch)

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

yeah, but we still need to fix the case where someone passes too many documents for addDocuments to succeed: it needs to be better than AIOOBE.

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

Here's a really bad test, but it works (takes about 2 minutes).

lucene/core$ ant test -Dtestcase=TestIndexWriter -Dtestmethod=testAddDocumentsMassive -Dtests.heapsize=4G

  [junit4] <JUnit4> says مرحبا! Master seed: 1655BF16A8843A6A
   [junit4] Executing 1 suite with 1 JVM.
   [junit4] 
   [junit4] Started J0 PID(22813@localhost).
   [junit4] Suite: org.apache.lucene.index.TestIndexWriter
   [junit4] HEARTBEAT J0 PID(22813@localhost): 2018-01-05T11:27:48, stalled for 71.2s at: TestIndexWriter.testAddDocumentsMassive
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestIndexWriter -Dtests.method=testAddDocumentsMassive -Dtests.seed=1655BF16A8843A6A -Dtests.locale=fr-FR -Dtests.timezone=Asia/Oral -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR    121s | TestIndexWriter.testAddDocumentsMassive <<<
   [junit4]    > Throwable #1: java.lang.ArrayIndexOutOfBoundsException: -65536
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1655BF16A8843A6A:2B0B86082D338FEA]:0)
   [junit4]    > 	at org.apache.lucene.index.TermsHashPerField.writeByte(TermsHashPerField.java:198)
   [junit4]    > 	at org.apache.lucene.index.TermsHashPerField.writeVInt(TermsHashPerField.java:224)
   [junit4]    > 	at org.apache.lucene.index.FreqProxTermsWriterPerField.writeProx(FreqProxTermsWriterPerField.java:80)
   [junit4]    > 	at org.apache.lucene.index.FreqProxTermsWriterPerField.addTerm(FreqProxTermsWriterPerField.java:171)
   [junit4]    > 	at org.apache.lucene.index.TermsHashPerField.add(TermsHashPerField.java:185)
   [junit4]    > 	at org.apache.lucene.index.DefaultIndexingChain$PerField.invert(DefaultIndexingChain.java:786)
   [junit4]    > 	at org.apache.lucene.index.DefaultIndexingChain.processField(DefaultIndexingChain.java:430)
   [junit4]    > 	at org.apache.lucene.index.DefaultIndexingChain.processDocument(DefaultIndexingChain.java:392)
   [junit4]    > 	at org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:281)
   [junit4]    > 	at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:452)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1530)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:1506)
   [junit4]    > 	at org.apache.lucene.index.TestIndexWriter.testAddDocumentsMassive(TestIndexWriter.java:2994)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/rmuir/workspace/lucene-solr/lucene/build/core/test/J0/temp/lucene.index.TestIndexWriter_1655BF16A8843A6A-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2a213e8b), locale=fr-FR, timezone=Asia/Oral
   [junit4]   2> NOTE: Linux 4.4.0-104-generic amd64/Oracle Corporation 1.8.0_45 (64-bit)/cpus=8,threads=1,free=543468648,total=2733637632
   [junit4]   2> NOTE: All tests run in this JVM: [TestIndexWriter]
   [junit4] Completed [1/1 (1!)] in 121.55s, 1 test, 1 error <<< FAILURES!
   [junit4] 
   [junit4] 
   [junit4] Tests with failures [seed: 1655BF16A8843A6A]:
   [junit4]   - org.apache.lucene.index.TestIndexWriter.testAddDocumentsMassive
   [junit4] 
   [junit4] 
   [junit4] JVM J0:     0.38 ..   122.56 =   122.18s
   [junit4] Execution time total: 2 minutes 2 seconds
   [junit4] Tests summary: 1 suite, 1 test, 1 error

BUILD FAILED
/home/rmuir/workspace/lucene-solr/lucene/common-build.xml:1512: The following error occurred while executing this line:
/home/rmuir/workspace/lucene-solr/lucene/common-build.xml:1038: There were test failures: 1 suite, 1 test, 1 error [seed: 1655BF16A8843A6A]

Total time: 2 minutes 5 seconds

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

the test had to work hard to hit AIOOBE instead of OOM.

I think most users that do something like this will hit OOM which is just as confusing and bad. it may technically be a different problem but due to the names of the methods and the apis, i think its easy someone will hit it too. Seems like add/updateDocuments need some sanity checks...

[asfimport]

Michael McCandless (@mikemccand) (migrated from JIRA)

Note that committing only once at the end is entirely normal and often exactly the right choice.

It's hard to know how to fix this – we could add a best effort check that if the RAM usage of that one in-memory segment (DWPT) exceeds the hard limit (IWC.setRAMPerThreadHardLimitMB) we throw a better exception?

[asfimport]

Robert Muir (@rmuir) (migrated from JIRA)

Well, I think a simple limit can work. For this API, e.g a simple counter, throw exc if the iterator has over 100k docs.

[asfimport]

Michael McCandless (@mikemccand) (migrated from JIRA)

Well, I think a simple limit can work. For this API, e.g a simple counter, throw exc if the iterator has over 100k docs.

+1