All findings · Lucene finding · LFV-1084 · finishfullflush-log-failure-leaves-writer-in-full-flush

A throw from IndexWriter's InfoStream as a commit's full flush ends leaves the writer in full-flush mode, so it stops flushing

If IndexWriter's InfoStream throws on the "finishFullFlush" log line that ends a commit's full flush (before the commit point is written), the open writer stays in full-flush mode: it stops flushing (with maxBufferedDocs=2, 10 more documents all stay in memory), and with RAM-based flushing a lone indexer later blocks in addDocument until another thread acts. Affected since 4.0.0.

Summary

Priority
Low, rank 802If the opt-in InfoStream throws on the finishFullFlush log line, the still-open writer stays in full-flush mode and stops flushing in every release since 4.0.0, and since 8.8.0 a lone indexing thread with RAM-based flushing can then block forever in addDocument. The trigger is contrived, no document was lost in the executed cases with assertions off and the next full flush heals it, so it is Low.
Impact
minor
Since
4.0.0-ALPHA (2012; commit 78d186e081f, 2011)introduced 2011-08-09 · over 15 years
Affected
every release from 4.0.0-ALPHA through 10.6.0 (10 executed) and main
Status
documented
Found by
semi-formal: a single-fault injection sweep through the InfoStream callback, then code reading

AI-assisted page: this finding was first signalled by a semi-formal check (an exact check of the real jar, or a modelling hypothesis that a tool then witnessed) and then checked with AI tools; the checks it went through, and what each found, are under Prior reports, history and checks. Not yet triaged by a human. Snapshot of 2026-11-06.

The finding in 30 seconds

When the full flush of a commit, flush() or NRT refresh ends (for a commit: before the commit point is written), DocumentsWriter.finishFullFlush writes a log line and only then switches full-flush mode off. If the log call throws, the switch never happens. The writer stays open, but in that mode it parks every buffer that should be written instead of writing it.

Background

  1. Buffers and flushes. IndexWriter collects new documents in in-memory buffers, one per indexing thread. When a buffer reaches maxBufferedDocs documents or the RAM budget, it is flushed: written to disk as a new segment.
  2. Full flush. commit(), flush() and opening an NRT reader flush all buffers at once. While such a full flush runs, a buffer that becomes due is parked instead of flushed; the end of the full flush releases the parked buffers.
  3. Stall control. If buffers being flushed or parked take more than twice the RAM budget, indexing threads wait in addDocument until flushing catches up.
  4. InfoStream. An optional debug log (off by default) that IndexWriter calls at many points. An application can plug in its own implementation or pass any PrintStream.
Diagram of the bug: commit() reaches DocumentsWriter.finishFullFlush, whose first step logs "finishFullFlush success=true"; the InfoStream throws, so the step that sets fullFlush back to false never runs; commit() throws but the writer stays open; the next buffers that reach maxBufferedDocs=2 are parked as blocked flushes instead of written, so 10 documents stay in memory; with RAM-based flushing addDocument finally waits in the stall control.
A commit's full flush step by step: the log line throws before full-flush mode is switched off, so every later buffer that should be flushed is parked instead, until a lone indexing thread stalls. Select the still to open it at full size. Generated with AI, checked against the code.

The finding, step by step

  1. Turn on an InfoStream (IndexWriter's debug log, off by default) and set maxBufferedDocs=2, so the writer should flush every 2 documents. Add 1 document and call commit(); the log sink throws once, on the log line that ends the commit's full flush, "finishFullFlush success=true" (before the commit point is written).
  2. commit() throws that exception, as expected. The writer stays open and is not marked broken (getTragicException() is null), so you keep indexing.
  3. Add 10 more documents. You expect at most 1 to be left in memory; instead all 10 are (numRamDocs() = 10), with assertions on and off.
  4. Why: the log call runs before the code that ends the commit's full-flush mode. In that mode Lucene parks every buffer that is due for flushing until the full flush ends, and now it does not end until the next full flush.
  5. With the default RAM-based flushing, a lone indexing thread then blocks in addDocument once about twice the RAM buffer is parked (1 MB buffer: after 1,186 documents, no progress for 15 s). Another thread's commit or refresh clears it (in the executed add-only case nothing was lost); a rollback() or close() ends it by closing the writer.

Who is affected

Only applications that turn on IndexWriter's InfoStream (off by default) with a sink that can throw an unchecked exception, when it throws on this one line during a commit, flush or NRT refresh, and that keep using the writer afterwards. The writer then silently ignores its flush settings; a lone indexing thread with no other commits or refreshes stalls.

Mechanism, terms and numbers949 words

prepareCommit(), commit() (unless an earlier prepareCommit() is still pending), flush() and an NRT reader open each run a full flush. DocumentsWriter.flushAllThreads() starts it by calling DocumentsWriterFlushControl.markForFullFlush(), which sets fullFlush = true, and it must end in DocumentsWriter.finishFullFlush(boolean). That method first logs "<thread> finishFullFlush success=" + success to the InfoStream; only then does it call flushControl.finishFullFlush() or abortFullFlushes(), the only code that sets fullFlush back to false (the first passes the flushes parked during the full flush on to be flushed, the second aborts them). Its finally only resets a flag and applies deletes.

If the log call throws a RuntimeException, commit() (or the flush or NRT open) rethrows it, and because IndexWriter treats only an Error as tragic, the writer stays open with getTragicException() == null. But fullFlush stays true. From then on every in-memory segment buffer that becomes due for flushing is checked out and blocked instead of flushed, so maxBufferedDocs and the RAM buffer no longer flush anything. With RAM-based flushing the parked bytes count as flushing, the stall control engages at twice the RAM buffer, and an indexing thread waits in addDocument until another thread's full flush releases the parked buffers, or a rollback() or close() closes the writer.

With assertions off, the next full flush from any thread (commit, refresh, flush(), close()) clears the state; in the executed single-thread, add-only cases no document was lost. With assertions on, that next full flush trips the internal assertion "called DWFC#markForFullFlush() while full flush is still running" and the writer closes. By code reading, an Error from the log call is tragic and closes the writer. The trigger is opt-in and contrived, so the bug is Low priority; calling rollback() after the failed commit avoids it, and the fix is to end the full flush before logging.

The code (main e1faeba08bde)

  1. The protocol. The comment in IndexWriter.getReader (IndexWriter.java:572-581) says the full flush "informs the FlushControl (#markForFullFlush()) that it should prevent any new DWPTs from flushing until we are ... done (DocumentsWriter#finishFullFlush(boolean))". The entry points end it in a finally or right after: prepareCommitInternal (IndexWriter.java:3872-3877), getReader (:671, :680) and flush (:4410-4412).
  2. Log before release. DocumentsWriter.finishFullFlush (DocumentsWriter.java:727-745): the infoStream.message("DW", ... + " finishFullFlush success=" + success) call, inside an isEnabled("DW") guard (:729-732), is the first thing the try does; flushControl.finishFullFlush() / abortFullFlushes() follow (:733-739); the finally (:740-744) only sets pendingChangesInCurrentFullFlush = false and calls applyAllDeletes().
  3. The only way out of full-flush mode. DocumentsWriterFlushControl.finishFullFlush() (:661-676) and abortFullFlushes() (:685-692) are the only code that sets fullFlush = false (:672, :689). Parked buffers return to the flush queue only through pruneBlockedQueue (:647-659), which runs in finishFullFlush() (:666-670) and in the next markForFullFlush (:624); abortFullFlushes() and a rollback() abort them instead (abortPendingFlushes, :694-724).
  4. Not tragic. The throw comes from prepareCommitInternal's finally (IndexWriter.java:3872-3877); only the outer catch (Error tragedy) (:3879-3881) records a tragedy. So after a RuntimeException the writer is open and getTragicException() is null.
  5. Every later flush is parked. DocumentsWriterFlushControl.checkout (:261-268): while fullFlush is set, a flush-pending buffer goes to checkoutAndBlock (:408-418, into blockedFlushes), and nextPendingFlush (:452-480) hands out only buffers from the (empty) flush queue during a full flush.
  6. The stall. setFlushPending (:376-387) moves a buffer's bytes from activeBytes to flushBytes, where parked buffers keep them. updateStallState stalls when activeBytes + flushBytes exceeds twice the RAM buffer while activeBytes stays below it (:114-119, :326). DocumentsWriter.preUpdate (DocumentsWriter.java:386-397) then loops maybeFlush(); waitIfStalled(); (DocumentsWriterStallControl.java:61-78, up to 1 s per round), and nothing can flush; only another thread's full flush, rollback() or close() ends it (a closed writer never stalls, :326). With only maxBufferedDocs (RAM flushing disabled) the stall limit is Long.MAX_VALUE (:116-118): an add-only workload does not stall, it buffers without bound. Deletes are never applied while fullFlush is set (DocumentsWriter.java:174-176), and on main (since #16867, 2026-10-30) buffered delete bytes at maxDeleteBytes (1945 MB) also stall indexing during a full flush (:327-329), so there a delete-heavy workload can stall too.
  7. Healing. The next full flush runs markForFullFlush again. With assertions off it moves the parked buffers to the flush queue (:624), flushes them and ends normally (a second commit kept all 11 documents). With assertions on, assert fullFlush == false : "called DWFC#markForFullFlush() while full flush is still running" (:573-574) fails, and as an Error it closes the writer.

Executed consequences (supplementary probes, not the repro)

scenarioresult
1 MB RAM buffer, one indexing thread, keep adding after the failed commit (two probes, different documents)addDocument blocked in DocumentsWriterStallControl.waitIfStalled with about 2.1 MB buffered (2,111,264 and 2,104,920 bytes; limit 2 x 1 MB), the finder's probe still blocked at its 60 s deadline after 15,785 documents, the other with no progress for 15 s after 1,186
same probes without the throw200,000 and 100,000 documents indexed
a second commit(), assertions offsucceeds, all 11 documents committed (one thread, adds only)
a second commit(), assertions onAssertionError "called DWFC#markForFullFlush() while full flush is still running"; the writer closes
8.7.0 vs 8.8.0, stall-rate probe, 1 MB buffer8.7.0: 20 documents in 20 s (a crawl); 8.8.0: 0 (a full stop)

That it stays stalled indefinitely is from code reading: nothing on the stalled thread's own path ends it; another thread's full flush releases the parked buffers, and a rollback() or close() ends the stall by closing the writer.

Exposure and likelihood307 words
  • Who. Applications that set an InfoStream with IndexWriterConfig.setInfoStream (a new config takes InfoStream.getDefault(), LiveIndexWriterConfig.java:142, which is NO_OUTPUT unless replaced process-wide). The sink must throw an unchecked exception on exactly this line: a custom InfoStream, a PrintStream passed to setInfoStream(PrintStream) whose underlying stream throws an unchecked exception (a PrintStream only turns IOException into its error flag), or a logging bridge set to pass appender failures to the caller. The stock PrintStreamInfoStream and JavaLoggingInfoStream do not throw by themselves.
  • When. During commit(), prepareCommit(), flush() or an NRT open or reopen (all end their full flush here), and the application keeps using the writer after that exception instead of calling rollback().
  • What breaks. The writer stops flushing without any sign: memory grows past maxBufferedDocs or the RAM buffer until some thread runs another full flush. With RAM-based flushing (the default) a lone indexing thread with no other thread to commit, refresh, roll back or close the writer stays blocked in addDocument after about twice the RAM buffer (executed with a 1 MB buffer; about 32 MB with the default 16 MB buffer, by reading). An application that refreshes or commits on another thread is released at the next refresh (no document was lost in the executed add-only cases, assertions off).
  • Scale. None needed: one failed commit and a few documents.
  • How likely. Contrived: an opt-in log, a sink that throws on this one line, and continued use of the writer instead of rollback(); the recorded searches found no outside report since 4.0 (2012). Before 8.8.0 indexing crawls (about one document per second) instead of stopping.
  • Remedy. Calling rollback() after the failed commit (the remedy a maintainer gives in #9738) avoids it: it discards the buffered documents and closes the writer. Continuing to use the open writer is the case this bug is about.

Minimal repro

One JUnit test, one method, single thread, using only public classes and methods (the InfoStream it subclasses is marked @lucene.internal). An InfoStream throws once on the "finishFullFlush" message during commit(); with maxBufferedDocs=2, 10 more empty documents should leave at most 1 in memory.

TestCommitLogFailureStopsFlushing.java (one test)65 lines
/*
 * Licensed to the Apache Software Foundation (ASF) under one or more
 * contributor license agreements.  See the NOTICE file distributed with
 * this work for additional information regarding copyright ownership.
 * The ASF licenses this file to You under the Apache License, Version 2.0
 * (the "License"); you may not use this file except in compliance with
 * the License.  You may obtain a copy of the License at
 *
 *     http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */
package org.apache.lucene.index;

import java.util.concurrent.atomic.AtomicBoolean;
import org.apache.lucene.document.Document;
import org.apache.lucene.store.ByteBuffersDirectory;
import org.apache.lucene.store.Directory;
import org.apache.lucene.tests.util.LuceneTestCase;
import org.apache.lucene.util.InfoStream;

public class TestCommitLogFailureStopsFlushing extends LuceneTestCase {

  public void testFlushesAfterCommitFailedOnLogMessage() throws Exception {
    AtomicBoolean failNext = new AtomicBoolean();
    InfoStream infoStream =
        new InfoStream() {
          @Override
          public void message(String component, String message) {
            if (message.contains("finishFullFlush") && failNext.getAndSet(false)) {
              throw new IllegalStateException("log failure");
            }
          }

          @Override
          public boolean isEnabled(String component) {
            return true;
          }

          @Override
          public void close() {}
        };
    IndexWriterConfig iwc = new IndexWriterConfig().setMaxBufferedDocs(2).setInfoStream(infoStream);
    try (Directory dir = new ByteBuffersDirectory()) {
      IndexWriter w = new IndexWriter(dir, iwc);
      try {
        w.addDocument(new Document());
        failNext.set(true);
        expectThrows(IllegalStateException.class, w::commit);
        assertNull(w.getTragicException());
        for (int i = 0; i < 10; i++) {
          w.addDocument(new Document());
        }
        // expected: the open writer still flushes every 2 docs (numRamDocs < 2); actual: 10
        assertTrue("numRamDocs=" + w.numRamDocs(), w.numRamDocs() < 2);
      } finally {
        w.rollback();
      }
    }
  }
}
Command
cd $LUCENE && ./gradlew :lucene:core:test --tests TestCommitLogFailureStopsFlushing -Ptests.seed=DEADBEEF
Expected
commit() throws, the writer stays open, and after 10 more documents at most 1 is left in memory (numRamDocs() < 2).
Observed
numRamDocs() is 10: nothing was flushed, with assertions on and off (AssertionError: numRamDocs=10).

All files of this repro: repro/LFV-1084/

More files, environment, full output266 words

The test sits in org.apache.lucene.index only for placement next to TestIndexWriterExceptions; it uses only public classes and methods (IndexWriterConfig, InfoStream, ByteBuffersDirectory, numRamDocs()), though InfoStream is marked @lucene.internal (a debugging API), the default RAM buffer and merge policy (the test framework randomizes the default codec, which by reading plays no part), and empty documents. It is deterministic: the throw is keyed on the message text, and the seed does not matter (this one-method test failed with seeds DEADBEEF and 5EEDF1F0; the independent reproduction's earlier, longer test, a different file of the same name, failed with 5EEDF1F0, 5EEDF1F1, A0D14941 and A0D14942).

Regression test: this same test; it passes with either fix and fits in TestIndexWriterExceptions.

A variant without the anonymous InfoStream (an internal API): a stock java.io.PrintStream over an OutputStream whose write throws an IllegalStateException once the text contains "finishFullFlush success=", passed to setInfoStream(PrintStream), fails the same way with assertions on and off (the intended-lens reviewer's test).

Environment

lucenemain e1faeba08bde (12.0.0-SNAPSHOT): fails; with either fix: passes. 10.6.0, 10.5.2 and 9.12.3 release jars: fail (assertions on and off)
jdkOpenJDK 25.0.3 (build 25.0.3+9-LTS)
osLinux, aarch64 (the only platform run; the code path is pure Java)
Command (environment)
cp $REPRO/TestCommitLogFailureStopsFlushing.java $LUCENE/lucene/core/src/test/org/apache/lucene/index/
cd $LUCENE && ./gradlew :lucene:core:test --tests TestCommitLogFailureStopsFlushing -Ptests.seed=DEADBEEF
# the same result with -Ptests.asserts=false

Observed output

# gradle, stock e1faeba08bde, -Ptests.seed=DEADBEEF (assertions on; the same with -Ptests.asserts=false)
TestCommitLogFailureStopsFlushing > testFlushesAfterCommitFailedOnLogMessage FAILED
    java.lang.AssertionError: numRamDocs=10
        at __randomizedtesting.SeedInfo.seed([DEADBEEF:CBAFFB174CCC737E]:0)
        at org.junit.Assert.fail(Assert.java:89)
        at org.junit.Assert.assertTrue(Assert.java:42)
        at org.apache.lucene.index.TestCommitLogFailureStopsFlushing.testFlushesAfterCommitFailedOnLogMessage(TestCommitLogFailureStopsFlushing.java:59)
1 test completed, 1 failed

# with either fix: 1 test, 0 failures (assertions on and off)

Why it looks unintended

  • setMaxBufferedDocs promises "the writer will flush every maxBufferedDocs added documents"; this writer stays open and reports no tragedy, yet stops flushing.
  • Lucene's own tests already inject RuntimeExceptions through InfoStream.message; the public setInfoStream(PrintStream) sets no no-throw rule.
  • The code requires every full flush to end; the log line was put first in 2011 and kept there since.
The full argument323 words
  • The flush contract. setMaxBufferedDocs (LiveIndexWriterConfig.java:213): "When this is set, the writer will flush every maxBufferedDocs added documents." The class javadoc (IndexWriter.java:162-165) names when the writer closes itself: "if you hit an Error, or disaster strikes during a checkpoint then IndexWriter will close itself". Here it does not close (getTragicException() is null), so its documented flush behaviour still applies.
  • The code's own invariant. The full flush prevents new DWPTs from flushing "until we are ... done (DocumentsWriter#finishFullFlush(boolean))" (IndexWriter.java:572-581). Here "done" does not come until the next full flush.
  • Lucene's tests. TestIndexWriterExceptions.testExceptionDuringRollback (:1980-2052) throws RuntimeException("BOOM!") from InfoStream.message at the ordinary message "rollback: done finish merges" (IndexWriter.java:2626) or at the test point "rollback before checkpoint", and asserts "even though we hit exception: we are closed, no locks or files held, index in good state" (:2042). testOutOfMemoryErrorRollback (:1150-1166) throws an Error at "startFullFlush". None throws at "finishFullFlush". These tests check cleanup and close after a logging failure, not continued use of an open writer after a failed commit: they show that a throwing InfoStream is a case Lucene already exercises, not a documented contract.
  • The public API. IndexWriterConfig.setInfoStream(PrintStream) (IndexWriterConfig.java:440-446) is public and states no no-throw condition; MIGRATE.md:1147-1148 presents JavaLoggingInfoStream for logging IndexWriter events through java.util.logging, with a Log4j adapter.
  • History. LUCENE-3348 (78d186e081f, 2011) added the log line as the method's first action, when the info stream was a plain PrintStream; the pluggable InfoStream (LUCENE-2621, 7877d1ff072, 2011-11, which also converted this line to infoStream.message("DW", ...)) and its rework in LUCENE-3598 (2011-12) kept the order. The recorded searches found no commit or issue that discusses a throw from it.
  • Precedent. #6053 (LUCENE-4989, 2013): an exception in abortPendingFlushes skipped cleanup and threads hung in waitIfStalled; fixed with a finally (via #6066). #10547 (LUCENE-9508, 2020): "we can't let blocked flushes go unless the full flush is over" (s1monw).
The devil's-advocate check201 words

The intended-lens reviewer (OpenAI GPT-5.6) and the intended-behaviour check built the case for "not a bug": InfoStream, PrintStreamInfoStream and JavaLoggingInfoStream are @lucene.internal, and InfoStream is a "Debugging API" (InfoStream.java:23-29). A sink that throws is abnormal application behaviour; Lucene does not wrap every InfoStream call and promises no strong exception safety after an arbitrary callback RuntimeException. A maintainer may add #9738 (LUCENE-8692): non-tragic exceptions from prepareCommitInternal "might cause documents go missing", and rollback() is the remedy. The cross-model reviewers rated this argument moderate.

Why it fails: the trigger is reachable through the public setInfoStream(PrintStream) overload with a stock PrintStream over a failing OutputStream (executed); Lucene's own tests already inject RuntimeExceptions through InfoStream.message (during rollback); the writer reports itself open and healthy while silently breaking a documented setting; and the fix is a reorder with no measured cost (it moves the message after the release; it does not make the other InfoStream call sites safe). #9738 is about a failed commit losing documents, which the caller sees; here the writer keeps accepting documents and quietly stops flushing them. Still, rollback() after the failed commit is the practical remedy, and a maintainer could reasonably call the fix low-priority hardening.

Suggested fix

Recommended End the full flush, then log

End the full flush first, then log: move the "finishFullFlush success=" message after flushControl.finishFullFlush() / abortFullFlushes() (one hunk in DocumentsWriter). commit() still reports the logging failure, but the writer keeps flushing. Validated: the repro and 265 tests in 12 closest suites pass, and so do the core format and lint checks.

      assert setFlushingDeleteQueue(null);
      if (success) {
        // Release the flush lock
        flushControl.finishFullFlush();
      } else {
        flushControl.abortFullFlushes();
      }
      // log only once the full flush has ended: a failing InfoStream must not leave the writer in
      // full-flush mode, where every later flush is blocked
      if (infoStream.isEnabled("DW")) {
        infoStream.message(
            "DW", Thread.currentThread().getName() + " finishFullFlush success=" + success);
      }
All options and trade-offs3 options ยท 514 words

Both options were validated in a scratch worktree of e1faeba08bde with gradle (OpenJDK 25.0.3, seed DEADBEEF, 2026-11-02): the minimal test fails on stock and passes with each fix, with assertions on and off. Neither fixes the sibling InfoStream sites (LFV-842, LFV-844, LFV-846), which need their own changes. Open PR #14837 (open, last updated 2025-10-16) rewords this log line and keeps it before the release; if it merges first, either fix needs a trivial rebase.

End the full flush, then log (validated by the checks) (recommended)

One file, DocumentsWriter.java, +6/-4 (fix-reorder.diff): the infoStream.isEnabled("DW") / message(...) block moves from the start of the try to just after flushControl.finishFullFlush() / abortFullFlushes(), with a comment saying why.

      assert setFlushingDeleteQueue(null);
      if (success) {
        // Release the flush lock
        flushControl.finishFullFlush();
      } else {
        flushControl.abortFullFlushes();
      }
      // log only once the full flush has ended: a failing InfoStream must not leave the writer in
      // full-flush mode, where every later flush is blocked
      if (infoStream.isEnabled("DW")) {
        infoStream.message(
            "DW", Thread.currentThread().getName() + " finishFullFlush success=" + success);
      }

Trade-offs

Smallest change. Without a throw the behaviour is identical except the log order: "finishFullFlush success=" now comes after the release (and after a "done stalling flushes" line, if the release logs one). No test keys on this message. With a throw, commit() still fails with the logging exception, but the writer is out of full-flush mode.

What the checks validated

  • Stock: the minimal test fails with assertions on and off.
  • With the fix: the minimal test passes with assertions on and off.
  • Closest suites with the fix (assertions on, seed DEADBEEF): TestIndexWriterExceptions (40 tests), TestIndexWriterExceptions2, TestIndexWriterCommit, TestIndexWriterReader, TestIndexWriterNRTIsCurrent, TestIndexWriterFromReader, TestFlushByRamOrCountsPolicy, TestDocumentsWriterStallControl, TestIndexWriterWithThreads, TestIndexWriter, TestInfoStream, TestIndexWriterDelete: 12 classes, 265 tests, 0 failures, 13 skipped.
  • :lucene:core:checkGoogleJavaFormat, ecjLintMain and forbiddenApisMain pass.
  • Earlier: the finder's test, the independent reproduction's test (with the independent reproduction's own one-hunk reorder) and the cross-model reviewers' tests pass with it, assertions on and off; the refute reviewer also ran two existing TestIndexWriterExceptions rollback tests with it (pass).
  • Not run: nightly tests, benchmarks.

Keep the log line first, end the full flush in a finally (validated by the checks)

DocumentsWriter.java, +14/-10 (fix-finally.diff): wrap the log call in try { ... } finally { assert setFlushingDeleteQueue(null); finishFullFlush() or abortFullFlushes(); }.

Trade-offs

Keeps the log order and ends the full flush whatever the log call throws, at the cost of one more nesting level. If the release itself also throws, its exception replaces the logging one (ordinary finally semantics).

What the checks validated

  • The minimal test passes with assertions on and off (same gradle run).
  • The same 12 closest suites: 265 tests, 0 failures, 13 skipped; checkGoogleJavaFormat and ecjLintMain pass.

Not recommended: swallow logging failures

Catch RuntimeException around the message and ignore it.

Trade-offs

Hides the failure from the caller and would have to be repeated at every sibling site. IndexWriter swallows an InfoStream failure only where it already has a primary exception to report (onTragicEvent adds it to the tragedy as suppressed). Not run.

Downstream note

Servers that forward IndexWriter's InfoStream into their own logging are the group to check: if that logging can throw and the writer is kept after a failed commit or refresh, indexing buffers without flushing until the next refresh.

How it was found

A fault-injection sweep made each InfoStream call of a small indexing script throw once during a commit, flush or NRT refresh and then retried the call (2,502 cases); in 10 cases the retry failed at this log line. Code reading found why, and the effect was cut down to one small JUnit test.

The method in full152 words

Method: bounded-exhaustive single-fault injection, then code reading (the hunt's "semi-formal" tier).

  • A hunt unit studies retrying a commit after a non-tragic exception from a public callback. Its sweep ran the real lucene-core jar and made the k-th call, for every k, of InfoStream.message or isEnabled (and of other public callbacks) throw once during commit, prepareCommit, DirectoryReader.open(writer), openIfChanged, flush or flushNextBuffer, over 6 configurations, then retried the call.
  • Its message pass with assertions on (2,502 cases) reported RETRYFAIL at DocumentsWriter.finishFullFlush:730 in 10 cases over commit, prepareCommit, flush and NRT open and reopen: the retried call hit "called DWFC#markForFullFlush() while full flush is still running".
  • Code reading then showed the assertions-off consequence (blocked flushes, maxBufferedDocs ignored, the stall); probes confirmed it, and the finder reduced it to a small JUnit test. The independent reproducer wrote its own test; the one-method test used here is a trimmed copy of it.

Prior reports, history and checks

Prior reports

No prior report found: 4 scripted prior-report searches (GitHub, mailing lists, JIRA archive, downstream projects), 66 manual GitHub searches, 8 web searches and the files of all 410 open PRs, 2026-11-02; re-checked the same day. Closest: #6053 and #10547, the same failure family at other sites.

Searches5 searches

The recorded searches found no issue, PR, review comment, commit, JIRA entry, list thread or downstream report that describes the log call running before the full flush is ended, or a writer left in full-flush mode after a logging failure.

  • Same family, other sites or causes (all fixed): #6053 (LUCENE-4989, 2013), an exception in abortPendingFlushes skipped cleanup and threads hung in waitIfStalled; #10547 (LUCENE-9508, 2020), blocked flushes during a full flush stuck on a busy buffer, whose fix is why this state now stops instead of crawling; #5345 (LUCENE-4277, 2012), the only hit for the assertion text, a full-flush race in a test; #7276 (LUCENE-6214), a lock-order deadlock in a tragic getReader.
  • Context, not overlap: open #9738 (LUCENE-8692, 2019) has s1monw's general statement that non-tragic exceptions from getReader(), prepareCommitInternal() and doFlush() "might cause documents go missing", with rollback() as the remedy. It names no mechanism and not this symptom.
  • Open PR #14837 (2025, stale) rewords this exact log line and keeps it before the release; it neither fixes nor discusses the bug.
  • Related findings: LFV-842, LFV-844 and LFV-846, InfoStream calls at other points that are not exception-safe (separate fix sites).
  • The tracking issue #16937 does not list this bug.
  • Limits: GitHub search is keyword-based and reads at most 50 results per query; private reports are invisible.
What was searched, when, and what turned up
WhereWhenHowFound
scripted prior-report search, 4 runs (identifiers, symptoms, mechanism, the finder's)2026-11-0251 queries per run: GitHub issues, PRs and commits; Elasticsearch, OpenSearch and Solr; the dev@, java-user@, issues@ and commits@ lists; the JIRA archiveno report of this defect
GitHub (apache/lucene), manual2026-11-0263 issue/PR queries and 3 commit queries: finishFullFlush, abortFullFlushes, markForFullFlush, checkoutAndBlock, blockedFlushes, the log and assertion texts, symptom and InfoStream phrasings, the last-48-hour legsrelated fixed bugs only: #6053, #10547, #5345, #7276; context #9738; open PR #14837
Open PRs2026-11-02the changed files of all 410 open apache/lucene PRs#13409, #14837, #15330 and #16847 touch these files; only #14837 touches finishFullFlush, without changing the order
Mailing lists, JIRA archive, web2026-11-02manual list and JQL queries; 8 web queriesnothing relevant ("full flush is still running" has 0 list hits)
GitHub re-check2026-11-02finishFullFlush, InfoStream and symptom phrasings, the assertion text, every issue and PR created since 2026-11-01; upstream main head; PR #14837 statenothing new; upstream main still e1faeba08bde; #14837 still open

History

Introduced by 78d186e081f (LUCENE-3348, 2011-08-09), which added the log line ahead of the release; first released in 4.0.0-ALPHA (2012). Bisected to that commit; 10 releases from 4.0.0-ALPHA to 10.6.0 and main fail, 3.6.2 is not affected. The full stop dates from 8.8.0 (LUCENE-9508); before, indexing crawls.

Versions tested6 rows

Introduced by 78d186e081f56b1e53d8bd8aef4e90d3cf81dbab (Simon Willnauer, 2011-08-09, "LUCENE-3348: IndexWriter applies wrong deletes during concurrent flush-all", trunk r1155278; patch by mikemccand and s1monw; Subversion era, no PR). It added the log line as the first action of finishFullFlush; git log -S 'finishFullFlush success=' lists only this commit. Its parent fda091ef24e logs nothing there and passes.

Later changes kept the order: LUCENE-3551 (73dec384b40, 2011-11-04) wrapped the body in try/finally with only the flag reset in the finally; LUCENE-2621 (7877d1ff072, 2011-11-09) introduced the pluggable InfoStream and converted this line to infoStream.message("DW", ...); LUCENE-3598 (21989c90c26, 2011-12-01) reworked it and changed the guard to isEnabled("DW"); LUCENE-8317 (2018) added applyAllDeletes() to the finally.

LUCENE-9508 (2020-11-24; c71f119e9ac on main, first released in 9.0.0, and its branch_8x backport 9057bb927be in 8.8.0) made stalled threads wait until unstalled, which turns the earlier crawl (about one document per second) into a full stop.

124 release tags contain the commit, plus the 8.8.2 to 8.11.4 releases of the lucene-solr branch_8x. Not new in 10.6.

Versions and branches executed, with results
Version or commitVerdictResult
main e1faeba08bde affectedthe minimal test fails with assertions on and off (gradle and the standalone runner); passes with either fix
10.6.0, 10.5.2, 9.12.3 affectedthe minimal test fails on the release jars with assertions on and off (numRamDocs=10)
4.0.0-ALPHA, 4.0.0, 4.10.4, 5.5.5, 6.6.6, 7.7.3, 8.11.4 affectedthe version-port probe fails (numRamDocs=10); its control passes
8.7.0 / 8.8.0 stall rate1 MB buffer: 20 documents in 20 s on 8.7.0 (crawl), 0 on 8.8.0 (full stop)
trunk fda091ef24e / 78d186e081f bisectionthe parent passes (no log line); the introducing commit fails with assertions on and off
3.3.0, 3.6.2 not affectedno full flush in 3.x; the trigger never fires

Independent checks

A finder, verifiers, cross-model reviews and an adjudication checked it; every executed check reproduced it and all said real. The cross-model reviewers rated the "InfoStream is internal" counter-argument moderate. The adjudication confirmed it with high confidence; a credibility audit kept it at Low.

Checks and verdicts341 words

Each check ran independently; the table lists what each one executed.

Each independent check and its verdict
CheckVerdictWhat it found
Finder (a hunt unit) reproducedSweep: 10 retry failures at this log line; the JUnit fails on main (assertions on and off), 10.6.0, 10.5.2 and 9.12.3; stall probe still blocked at its 60 s deadline after 15,785 documents; the reorder fix passes.
Refute review (OpenAI GPT-5.6, executed) real (high)Its own test through the public setInfoStream(PrintStream) fails on 3 seeds with assertions on and off; control and fix pass; two existing rollback tests pass with the fix.
Independent reproducer realIts own test (the longer version the minimal repro was cut from) fails on main, 10.6.0, 10.5.2 and 9.12.3; control passes; own reorder passes; stall after 1,186 documents; the next commit heals with assertions off.
Intended-lens review (OpenAI GPT-5.6, executed) real (high); intended case moderateFails with an injected InfoStream and with a stock PrintStream over a throwing OutputStream, assertions on and off; control and fix pass, also when re-run on e1faeba.
Intended-behaviour devil's advocate realRe-ran the finder's test on main (fail); the @lucene.internal argument is answered by the public overload, MIGRATE.md and Lucene's own tests.
Adjudication confirmed (high), LowRe-ran the test on e1faeba with assertions on and off: numRamDocs=10.
History step history correctedBisected to 78d186e081f (LUCENE-3348), not LUCENE-3551; first affected release 4.0.0-ALPHA.
Registration check and credibility audit confirmed (Low)The independent reproduction's earlier, longer version of the test fails on main with four more seeds; the one-method test fails on main and passes with the fix; impact lowered to minor (contrived trigger, healed by the next full flush, no data loss seen in the executed cases).
This brief real; both fixes validatedGradle in a scratch worktree: the minimal test fails on stock and passes with each fix (assertions on and off); 265 tests in 12 closest suites pass with each fix; the minimal test fails on the 10.6.0, 10.5.2 and 9.12.3 release jars.

Diagram file

The diagram as a still image, generated with AI and checked against the code. It is under 10 MB, the limit for a GitHub attachment.

Sources and provenance

Finding record, Lucene and upstream sources, repro files and diagram notes1,613 words

Finding record

LFV-1084, snapshot of 2026-11-06

Registry title
If IndexWriter's InfoStream throws on the 'finishFullFlush' log line of a commit, flush or NRT open, the still-open writer never leaves full-flush mode, so it stops flushing in-memory segments (maxBufferedDocs is ignored) and, with RAM-based flushing, a lone indexing thread later blocks forever in addDocument (every release since 4.0.0)
Area
index / IndexWriter full flush (DocumentsWriter.finishFullFlush, DocumentsWriterFlushControl blocked flushes and stall control)
Priority
Low, rank 802: If the opt-in InfoStream throws on the finishFullFlush log line, the still-open writer stays in full-flush mode and stops flushing in every release since 4.0.0, and since 8.8.0 a lone indexing thread with RAM-based flushing can then block forever in addDocument. The trigger is contrived, no document was lost in the executed cases with assertions off and the next full flush heals it, so it is Low.
Impact class
minor
Impact note
Hits only applications that turn on IndexWriter's InfoStream (off by default) with a sink that can throw an unchecked exception (a custom InfoStream, a PrintStream passed to setInfoStream(PrintStream) whose write throws, or a logging bridge set to pass appender failures to the caller), when it throws on this one line during commit(), prepareCommit(), flush() or an NRT open, and that keep using the writer after that non-tragic exception: the writer then buffers documents without flushing until some thread runs another full flush (with assertions off no document was lost in the executed add-only cases), and an indexer that is the only thread and does not commit or refresh again stalls forever once about twice the RAM buffer is buffered (1 MB buffer: after 1,186 and 15,785 documents in two probes); no scale is needed, and every release from 4.0.0-ALPHA to 10.6.0 and main is affected (the full stop since 8.8.0, earlier releases crawl at about one document per second).
Summary
You enable an InfoStream on an IndexWriter, and the logging sink throws a RuntimeException once, on the message DocumentsWriter.finishFullFlush logs at the end of a commit (prepareCommit, flush() and NRT opens take the same path). You expect commit() to fail with that exception and the writer, which stays open and has no tragic exception, to keep honouring its flush settings ('the writer will flush every maxBufferedDocs added documents'). Instead the log call runs before the code that ends the full flush, so the writer stays in full-flush mode: every in-memory segment that should flush is parked as blocked (10 more adds with maxBufferedDocs=2 leave 10 documents buffered), and with the default RAM-based flushing a thread that keeps indexing without another commit or refresh eventually waits forever in addDocument.
Introduced
78d186e081f56b1e53d8bd8aef4e90d3cf81dbab (LUCENE-3348 'IndexWriter applies wrong deletes during concurrent flush-all', Subversion trunk r1155278, committed by s1monw, patch by mikemccand and s1monw; LUCENE-3348 = apache/lucene#4421; svn era, no pull request) [exec: commit-level bisection with lucene-core built from the history clone: the parent fda091ef24e logs nothing in finishFullFlush and passes, 78d186e081f fails with -ea and -da (numRamDocs 10), controls pass; git log -S 'finishFullFlush success=' lists only this commit]. It added the log line as the first statement of finishFullFlush, ahead of flushControl.finishFullFlush()/abortFullFlushes(). LUCENE-3551 (73dec384b40, 2011-11-04) later wrapped the body in try/finally with only pendingChangesInCurrentFullFlush in the finally, and LUCENE-8317 (2018) added applyAllDeletes() there, both keeping the release behind the log line [read: git log -L] (2011-08-09 (78d186e081f, author date = commit date 2011-08-09T09:22:15Z, git-svn import))
First affected version
4.0.0-ALPHA [exec: version-port main() probe on the SHA-1-checked release jar fails with -ea and -da (numRamDocs 10 after 10 adds; with -ea close() then throws 'called DWFC#markForFullFlush() while full flush is still running'), its control passes]; first GA release 4.0.0 [exec]; not affected: 3.6.2 and every earlier release, which have no per-thread writers and no finishFullFlush [exec on 3.3.0 and 3.6.2: the trigger never fires]
Affected versions
every release from 4.0.0-ALPHA through 10.6.0 (released 2026-10-29, 4ae946e5a9b) and main e1faeba08bde (unreleased) [exec: the claimed JUnit TestCommitLogFailureStopsFlushing fails on main with -ea and -da (the independent reproduction; registration check with seeds 5EEDF1F0 and 5EEDF1F1), on 10.6.0 with -da and on 10.5.2 and 9.12.3 with -ea and -da; the finder's JUnit fails on main with -ea and -da (finder, the cross-model review, the intended-behaviour check, adjudication), on 10.6.0 and 9.12.3 with -ea and -da and on 10.5.2 with -da; version-port main() probes fail on trunk 78d186e081f, 4.0.0-ALPHA, 4.0.0, 4.10.4, 5.5.5, 6.6.6, 7.7.3, 8.11.4, 9.12.3, 10.6.0 and main with their controls passing]; the releases in between by git tag --contains 78d186e081f (124 release tags, plus the 8.8.2-8.11.4 releases of the separate lucene-solr branch_8x) and git log -L of the method (no later change moves the release ahead of the log line) [read]. The permanent addDocument stall exists from 8.8.0 on (LUCENE-9508, c71f119e9ac, made stalled threads wait until unstalled); in 8.7.0 and earlier indexing crawls instead (stall-rate probe with a 1 MB buffer: 20 documents in 20 s on 8.7.0, 0 on 8.8.0) [exec]. Not affected: 3.6.2 and earlier, and trunk fda091ef24e [exec]. Not new in 10.6. All runs on aarch64 with JDK 25
Status
documented (brief, checks and a per-finding doc exist)
Verification
Confirmed by AI-run checks: an independent repro, a cross-model review that agreed, an intended-behaviour check, a prior-report search and a skeptical audit; not yet triaged by a person.
Found by
semi-formal; also reached by exhaustive check, code reading
Upstream and prior reports
none found (2026-11-02, re-checked the same day; none of the hits is the same bug). No issue, PR, review comment, commit, JIRA entry, mailing-list thread, downstream report or web page names this root cause: finishFullFlush logs first and only then calls flushControl.finishFullFlush()/abortFullFlushes(), so a throwing log call leaves DocumentsWriterFlushControl.fullFlush set. Searches: four scripted prior-report searches (identifiers, symptoms, mechanism, and the finder's; each 51 queries over GitHub issues, PRs and commits, Elasticsearch, OpenSearch and Solr, the dev@, java-user@, issues@ and commits@ lists, and JIRA), 63 manual GitHub issue and PR searches plus 3 commit searches including the last-48-hour legs, manual list and JIRA queries, 8 web queries, the changed files of all 410 open apache/lucene PRs, and git history; the independent reproduction's and the intended-behaviour check's own searches and the adjudication's agree. Same failure family at other sites or with other causes, all different bugs: #6053 (LUCENE-4989, 2013, an exception in abortPendingFlushes skipped doAfterFlush and threads hung in waitIfStalled; fixed with a finally), #10547 (LUCENE-9508, fixed 2020: stall mode with blocked flushes from a full flush stuck on a busy DWPT; its fix is why this state now hangs instead of buffering), #5345 (LUCENE-4277, 2012, the only hit for the assertion text, a full-flush race in a test), #7276 (LUCENE-6214), #4766 (LUCENE-3692). Open #9738 (LUCENE-8692, 2019) has a general maintainer statement (s1monw) that non-tragic exceptions from getReader(), prepareCommitInternal() and doFlush() 'might cause documents go missing', with rollback() as the remedy; it names no mechanism and not this symptom. Open PR #14837 (mikemccand, stale since 2025-10-16) edits this exact log line and keeps it before the release; it neither fixes nor discusses the bug. The tracking issue #16937 does not list it.
Lucene commit tested
main e1faeba08bde (2026-11-02, also upstream main that day): the minimal test fails with assertions on and off, through gradle in a scratch worktree and through a standalone runner; with either fix it passes, and with each fix 265 tests in 12 closest suites pass (0 failures, 13 skipped). The minimal test also fails on the 10.6.0, 10.5.2 and 9.12.3 release jars (assertions on and off); version ports fail on every executed release back to 4.0.0-ALPHA.

Lucene and upstream sources

Finding record
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriter.java:727-745 (at e1faeba08bde) (finishFullFlush: infoStream.message 'finishFullFlush success=' at :729-732 is the first statement in the try; flushControl.finishFullFlush()/abortFullFlushes() at :733-739; the finally at :740-744 only resets pendingChangesInCurrentFullFlush and applies deletes), :386-397 (preUpdate loops while threads are stalled)
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriterFlushControl.java:261-267 (at e1faeba08bde) (checkout: while fullFlush is set a flush-pending DWPT is checked out and blocked), :572-573 (markForFullFlush: assert fullFlush == false 'called DWFC#markForFullFlush() while full flush is still running'), :661-675 and :684-690 (finishFullFlush and abortFullFlushes: the only code that resets fullFlush and releases blocked flushes)
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriterStallControl.java:66-70 (at e1faeba08bde) (waitIfStalled: wait(1000), re-entered by preUpdate while still stalled)
  • lucene/core/src/java/org/apache/lucene/index/IndexWriter.java:3866-3880 (at e1faeba08bde) (prepareCommitInternal: catch logs and rethrows, the finally calls docWriter.finishFullFlush(flushed); only an Error is tragic), :671 and :680 (getReader), :4412 (flush), :576-579 (comment: everything happens between flushAllThreads and finishFullFlush)
  • lucene/core/src/java/org/apache/lucene/index/LiveIndexWriterConfig.java:213 (at e1faeba08bde) (setMaxBufferedDocs: 'When this is set, the writer will flush every maxBufferedDocs added documents')
  • lucene/core/src/java/org/apache/lucene/index/IndexWriterConfig.java:430, (at e1faeba08bde) :441 (setInfoStream(InfoStream) and the public setInfoStream(PrintStream) overload); util/InfoStream.java:23-28 ('Debugging API', @lucene.internal)
  • lucene/core/src/test/org/apache/lucene/index/TestIndexWriterExceptions.java:1150-1162 (at e1faeba08bde) (testOutOfMemoryErrorRollback: Error at the 'startFullFlush' message), :1980-1991 (testExceptionDuringRollback: RuntimeException at 'rollback: done finish merges' or 'rollback before checkpoint'); lucene/core/src/java/org/apache/lucene/index/IndexWriter.java:2626 (at e1faeba08bde) (the ordinary IW message), :2664 (the test point)
The finding in 30 seconds
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriter.java:174-176 (at e1faeba08bde) (no deletes applied during a full flush), :667-680 (flushAllThreads: startFullFlush, markForFullFlush); IndexWriter.java:4249-4258 (commit after prepareCommit); DocumentsWriterFlushControl.java:49, :327-329 (delete-bytes stall, #16867 2813efa40a3), :694-724 (abortPendingFlushes)
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriter.java:386-397, (at e1faeba08bde) :727-745 (:729-732, :733-739, :740-744)
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriterFlushControl.java:114-119, (at e1faeba08bde) :261-268, :326, :376-387, :408-418, :452-480, :569-576 (:573-574), :592-627 (:624), :647-659, :661-676 (:672), :685-692 (:689)
  • lucene/core/src/java/org/apache/lucene/index/DocumentsWriterStallControl.java:61-78 (at e1faeba08bde)
  • lucene/core/src/java/org/apache/lucene/index/IndexWriter.java:572-581, (at e1faeba08bde) :669-680, :3867-3881, :4410-4412
Who is affected
  • lucene/core/src/java/org/apache/lucene/index/LiveIndexWriterConfig.java:142; (at e1faeba08bde) lucene/core/src/java/org/apache/lucene/index/IndexWriterConfig.java:430-446; lucene/core/src/java/org/apache/lucene/util/PrintStreamInfoStream.java:45-57
Why it looks unintended
  • lucene/core/src/java/org/apache/lucene/index/LiveIndexWriterConfig.java:209-225 (at e1faeba08bde) (:213)
  • lucene/core/src/java/org/apache/lucene/index/IndexWriter.java:162-165, (at e1faeba08bde) :572-581, :2626, :2664
  • lucene/core/src/test/org/apache/lucene/index/TestIndexWriterExceptions.java:1150-1166, (at e1faeba08bde) :1980-2052 (:2042)
  • lucene/core/src/java/org/apache/lucene/index/IndexWriterConfig.java:430-446; (at e1faeba08bde) lucene/core/src/java/org/apache/lucene/util/InfoStream.java:23-29; lucene/MIGRATE.md:1140-1152
Suggested fix
  • lucene/core/src/java/org/apache/lucene/index/IndexWriter.java:6075-6083 (at e1faeba08bde) (onTragicEvent suppresses a logging failure)

Other statements trace to the hunt's working files (models, logs, reviews and briefs), which are not published.

Repro files

About the diagrams

Made from the code at e1faeba08bde and the executed minimal test.

Built 2026-11-06 from the hunt's record of this finding and its doc file. Lucene main under test in this hunt: ea57360912ed. Every listed finding was re-run on Lucene main e1faeba08bde on 2026-11-02.