Skip to content

Body field has been indexed TWICE per document since Nov 2021 #616

Description

@neoremind

What the bug is

Since 11/18/2021, nightly indexing benchmark has been indexing the body field twice per document.

This looks like a one-line bug introduced in #144 to LineFileDocs.java.

Look at

body = new Field("body", "", bodyFieldType);
doc.add(body); 

randomLabel = new Field("randomLabel", "", StringField.TYPE_NOT_STORED);
doc.add(body);  <- here!

The body field gets inverted twice per doc, doubles the term freqs, pos, norms. And the actual randomLabel StringField is useless and never indexed.

Verification

Look at the nightly charts, I choose below screenshots, they all show a sharp change since 2021/11/21 right after the bug was introduced.

Image Image Image

I also run locally indexing the first 100k wikipedia docs, look at the postings to double click, I check the frequent terms "the" and "of" using query like below.

Terms terms = MultiTerms.getTerms(reader, "body");
IndexSearcher searcher = new IndexSearcher(reader);
TermsEnum te = terms.iterator();
for (String word : new String[] {"the", "of"}) {
  if (te.seekExact(new BytesRef(word))) {
    Term term = new Term("body", word);
    TopDocs td = searcher.search(new TermQuery(term), 1);
    System.out.printf("TermQuery body:%-8s hits=%-8d docFreq=%-8d totalTermFreq=%-10d",
        word, searcher.count(new TermQuery(term)), te.docFreq(), te.totalTermFreq());
  }
}

Current code with bug:

TermQuery body:the      hits=90758    docFreq=90758    totalTermFreq=1510152
TermQuery body:of       hits=90553    docFreq=90553    totalTermFreq=909762

With the fix to index correct randomLabel:

TermQuery body:the      hits=90758    docFreq=90758    totalTermFreq=755076
TermQuery body:of       hits=90553    docFreq=90553    totalTermFreq=454881

totalTermFreq is exactly 2x, while hit counts and docFreq are correct.

Performance recovery

Run nightly benchon c5.4xlarge, 1 thread, jdk-25.0.2, -Xms12g -Xmx12g:

configuration
candidate_index = comp.newIndex(
      args.candidate,
      sourceData,
      extraNamePart="candidate",
      postingsFormat="Lucene104",
      idFieldPostingsFormat="Lucene104",
      directory="MMapDirectory",
      ramBufferMB=2048,
      waitForMerges=True,
      waitForCommit=True,
      grouping=False,
      verbose=False,
      mergePolicy="NoMergePolicy",
      useCMS=True,
      bodyTermVectors=False
    )
metric buggy now fixed delta
docs/sec 11,356.9 17,596.5 +54.9%
GB/hour plain text 35.94 55.31 +53.9%
Index size (committed) 15,649,897,632 bytes 10,656,036,011 bytes −31.9%
Segments (2GB RAM buffer) 15 10 fewer flushes
Raw currenct log
Indexer: 33330000 docs (2934.8 sec); 11356.9 docs/sec

Indexer: stopping threads took 0.4 msec

Indexer: indexing done (2935003 msec); total 33332620 docs

Indexer: waitForMerges done (8007 msec)

Indexer: commit multi (took 4 msec)

Index size (as committed): 15649897632 bytes

Indexer: at close: 15 segments: segments_2: _0(11.0.0):C2158952 _1(11.0.0):C2177859 _2(11.0.0):C2270023 _3(11.0.0):C2316578 _4(11.0.0):C2351932 _5(11.0.0):C2389381 _6(11.0.0):C2419638 _7(11.0.0):C2364854 _8(11.0.0):C2437134 _9(11.0.0):C2461839 _a(11.0.0):C2428393 _b(11.0.0):C2458928 _c(11.0.0):C2349401 _d(11.0.0):C2328510 _e(11.0.0):C419198

Indexer: close took 6 msec
Directory total size: 15649898964 bytes

Indexer: net bytes indexed 31549968277

Indexer: finished (2943022 msec)

Indexer: 35.942480778322526 GB/hour plain text
- - - - - - - - - - - - - - - - - - - - 
Statistics Ended at Fri Sep 04 13:48:53 UTC 2026
Elapsed time: 2943267 ms
  Time in JIT compilation: 14491 ms
  Time in Young Generation GC: 3896 ms (100 collections)
  Time in Old Generation GC: 557 ms (4 collections)
Garbage Generated in Young Generation: 0.0 MiB
Garbage Generated in Survivor Generation: 0.0 MiB
Garbage Generated in Old Generation: 0.0 MiB
Average CPU Load: 102.860504/1600
----------------------------------------
Raw fixed log (index randomLable not body again)
Indexer: 33330000 docs (1894.1 sec); 17596.5 docs/sec

Indexer: stopping threads took 0.4 msec

Indexer: indexing done (1894321 msec); total 33332620 docs

Indexer: waitForMerges done (18005 msec)

Indexer: commit multi (took 4 msec)

Index size (as committed): 10656036011 bytes

Indexer: at close: 10 segments: segments_2: _0(11.0.0):C3381786 _1(11.0.0):C3464179 _2(11.0.0):C3540270 _3(11.0.0):C3604998 _4(11.0.0):C3525481 _5(11.0.0):C3530993 _6(11.0.0):C3638868 _7(11.0.0):C3693318 _8(11.0.0):C3569616 _9(11.0.0):C1383111

Indexer: close took 5 msec
Directory total size: 10656036928 bytes

Indexer: net bytes indexed 31549968277

Indexer: finished (1912336 msec)

Indexer: 55.31429187401184 GB/hour plain text
- - - - - - - - - - - - - - - - - - - - 
Statistics Ended at Fri Sep 04 10:51:18 UTC 2026
Elapsed time: 1912565 ms
  Time in JIT compilation: 14510 ms
  Time in Young Generation GC: 3492 ms (95 collections)
  Time in Old Generation GC: 302 ms (2 collections)
Garbage Generated in Young Generation: 0.0 MiB
Garbage Generated in Survivor Generation: 0.0 MiB
Garbage Generated in Old Generation: 0.0 MiB
Average CPU Load: 103.71356/1600
----------------------------------------

To be fair, the "gains" are back, we should recover what it should be. Maybe in https://lucene.apache.org/core/, we could claim **over 1T/hour** rather than 800GB/hour on modern hardware if this ships.

I'd like to ship a fix, but before that, two questions I am not sure.

  1. Should the fix be a change of doc.add(body) -> doc.add(randomLabel), or facet-only? The former adds a new inverted field that has never existed in any index built by luceneutil changing schema. The latter keeps the schema unchanged.

  2. What will be the impact against the query benchmarks? I am not sure how those performance numbers will change, probably need some deep dives but I am not an expert for the queries, would require some guidance.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions