IndexWriter blocks in its own rollback until interrupted after an Error thrown while logging a checked-out merge

IndexWriterMergeSource.getNextMerge() first calls IndexWriter.getNextMerge(), which moves the next merge from pendingMerges to runningMerges. Only then, when the merge scheduler is verbose (InfoStream enabled for component "MS"), does it build and log " checked out merge " + segString(...). If that statement throws, getNextMerge() throws instead of returning the merge, so no scheduler ever receives it: nobody runs it and nobody calls mergeFinish for it, and it stays in runningMerges. abortMerges() and waitForMerges() wait while runningMerges is not empty.

After an Error (such as an OutOfMemoryError; the repros throw it from the InfoStream, and by reading it can also hit while Lucene builds the message string), the indexing call's tragic handling runs rollbackInternal() -> abortMerges(), which waits for that merge: addDocument blocks until interrupted and the writer does not finish closing itself, although the IndexWriter class javadoc says it "will close itself". After an unchecked exception from the application's InfoStream, addDocument throws, the writer stays open, and close() blocks in waitForMerges() (after a first interrupt, again in the rollback that follows). Both stock merge schedulers are affected; no scale is needed.

The window came with LUCENE-9345 (2020, first released in 8.6.0), which moved this log line out of ConcurrentMergeScheduler.merge's try/finally that called mergeFinish on failure. It is opt-in (the InfoStream is off by default) and rare, so the priority is Low. The recommended fix finishes the merge when the log call throws, as 8.5.x did and as ConcurrentMergeScheduler.merge still does for its own failures.

1. Check-out. IndexWriter.getNextMerge() (IndexWriter.java:2538-2551, synchronized) does pendingMerges.removeFirst() then runningMerges.add(merge) (:2547-2548).
2. The unprotected statement. IndexWriterMergeSource.getNextMerge() (IndexWriter.java:6859-6869):

MergePolicy.OneMerge nextMerge = writer.getNextMerge();      // pending -> running
if (nextMerge != null) {
  if (writer.mergeScheduler.verbose()) {                      // InfoStream enabled for "MS"
    writer.mergeScheduler.message(
        "  checked out merge " + writer.segString(nextMerge.segments));   // a throw here ...
  }
}
return nextMerge;                                             // ... means no caller gets the merge

verbose() is infoStream != null && infoStream.isEnabled("MS") (MergeScheduler.java:93-95). The stock PrintStreamInfoStream, which IndexWriterConfig.setInfoStream(PrintStream) installs, is enabled for every component (PrintStreamInfoStream.java:60-62).

1. No caller can hand it back. The throw leaves getNextMerge() before it returns. ConcurrentMergeScheduler.merge calls it (ConcurrentMergeScheduler.java:570) before the try whose catch (Throwable t) { mergeSource.onMergeFinished(merge); throw t; } hands back a merge it could not start (:578-595). SerialMergeScheduler.merge (SerialMergeScheduler.java:32-40) has no hand-back.
2. The waits. abortMerges() loops while (runningMerges.size() + runningAddIndexesMerges.size() != 0) doWait(); (IndexWriter.java:2849-2861); waitForMerges() loops while (pendingMerges.size() > 0 || runningMerges.size() > 0) doWait(); (:2891-2893). doWait() is wait(1000); an interrupt ends it with ThreadInterruptedException (:5860-5870).
3. Error path. updateDocuments records an Error as tragic and calls maybeCloseOnTragicEvent() (IndexWriter.java:1630-1641), which sets closing = true through shouldClose(false) and calls rollbackInternal() (:6098-6106, :1374-1393). rollbackInternal takes commitLock (:2589); the abortMerges() call in rollbackInternalNoCommit() (:2590, :2621) waits. Other threads (executed in a fact-check probe): commit() and prepareCommit() fail at once with AlreadyClosedException, because ensureOpen() also rejects a closing writer (:4213-4214, :3735-3736, :913-917); rollback() and a later close() wait in shouldClose for the unfinished self-close (:2581, :1387).
4. Exception path. A non-Error is not tragic (:1633-1635), so the writer stays open and close() -> shutdown() -> waitForMerges() waits; after a first interrupt, shutdown()'s catch calls rollbackInternal() (:1328-1331), whose abortMerges() waits again, so it takes two interrupts (executed).

A second site with the same gap, by reading: ConcurrentMergeScheduler.MergeThread.run logs "merge thread %s start" after the check-out and before doMerge (ConcurrentMergeScheduler.java:720-726), and its catch (Throwable) (:747-754) neither runs the merge nor calls onMergeFinished/mergeFinish. An unminimised hunt probe reported forceMerge(1) waiting after a throw there; no verifier re-ran it, and the fixes below do not cover it.

A second caller of the same method, by reading (not run): a merge thread that finished its merge calls runOnMergeFinished -> merge(mergeSource, MergeTrigger.MERGE_FINISHED) (ConcurrentMergeScheduler.java:742, :678-686), which checks out the next pending merge through this same getNextMerge(). A throw at "checked out merge" there strands that merge too, but it surfaces in MergeThread.run's catch (Throwable), not in an indexing call: no indexing call needs to see the Error, and a later close() would wait in waitForMerges. The recommended fix covers this caller as well, because it sits inside getNextMerge().

• Default or opt-in. Opt-in. A new IndexWriterConfig takes InfoStream.getDefault() (LiveIndexWriterConfig.java:142), which is InfoStream.NO_OUTPUT (InfoStream.java:57) unless the application changed it with InfoStream.setDefault (:74); then verbose() is false, the message is never built and the window is empty.
• Triggers. An Error such as OutOfMemoryError at this call: every repro injects it from the application's InfoStream, as Lucene's own tests do; by reading (not executed) it can also hit while segString builds the message under heap pressure (IndexWriter.java:5845-5849). Or an exception from an application-supplied InfoStream. The stock PrintStreamInfoStream does not throw (a PrintStream swallows IOExceptions).
• What breaks. After an Error: addDocument blocks until the thread is interrupted and the writer does not finish closing itself; meanwhile other threads' commit() fails with AlreadyClosedException and rollback() or close() wait. After the interrupt, addDocument throws ThreadInterruptedException, not the OutOfMemoryError. After an exception: the writer stays open and usable (a probe indexed 4 more documents and committed; a reader saw all 8), but close() blocks until it is interrupted twice. All executed. The repros did not run CheckIndex; by reading, the last commit is untouched.
• Scale. None: 4 empty documents, deterministic, default ConcurrentMergeScheduler and SerialMergeScheduler alike.
• Existing mitigations. An application that terminates the JVM on OutOfMemoryError is not hit by the Error variant; turning the "MS" component off avoids both.
• Likelihood. Rare: it needs the opt-in logging and a throw at exactly this statement; no outside report of the hang was found.

The InfoStream is enabled only for "MS" and throws OutOfMemoryError from message() for any message starting with " checked out merge"; only one merge is ever checked out here. On the stock code the test framework also reports the stuck thread as a suite-level ThreadLeakError; that second failure is the same hang (its stack shows the thread in abortMerges), and the framework's interrupt then ends the wait.

Regression test: this same test. It passes with either fix.

The exception variant (not in this test): an IllegalStateException thrown once at the same line makes addDocument fail, keeps the writer open, and close() then blocks in waitForMerges (executed in the hunt's 4-test verifier class on main with assertions on and off, 10.5.2 and 9.12.3).

cp $REPRO/TestErrorLoggingCheckedOutMerge.java $LUCENE/lucene/core/src/test/org/apache/lucene/index/
cd $LUCENE && ./gradlew :lucene:core:test --tests TestErrorLoggingCheckedOutMerge -Ptests.seed=DEADBEEF
# the same result with -Ptests.asserts=false; about 30 s on the stock code (10 s join + 20 s leak linger)

# gradle, stock 645d4fe14a20, -Ptests.seed=DEADBEEF (assertions on; the same with -Ptests.asserts=false)
TestErrorLoggingCheckedOutMerge > testWriterClosesItselfAfterError FAILED
    java.lang.AssertionError: expected addDocument to throw the Error, still blocked after 10 s
        at __randomizedtesting.SeedInfo.seed([DEADBEEF:65A6CF6E564F8E86]:0)
        at org.junit.Assert.fail(Assert.java:89)
        at org.junit.Assert.assertTrue(Assert.java:42)
        at org.junit.Assert.assertFalse(Assert.java:65)
        at org.apache.lucene.index.TestErrorLoggingCheckedOutMerge.testWriterClosesItselfAfterError(TestErrorLoggingCheckedOutMerge.java:61)

TestErrorLoggingCheckedOutMerge > executionError FAILED
    com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.lucene.index.TestErrorLoggingCheckedOutMerge:
       1) Thread[id=21, name=Thread-3, state=TIMED_WAITING, group=TGRP-TestErrorLoggingCheckedOutMerge]
            at java.base/java.lang.Object.wait0(Native Method)
            at java.base/java.lang.Object.wait(Object.java:389)
            at org.apache.lucene.index.IndexWriter.doWait(IndexWriter.java:5868)
            at org.apache.lucene.index.IndexWriter.abortMerges(IndexWriter.java:2860)
            at org.apache.lucene.index.IndexWriter.rollbackInternalNoCommit(IndexWriter.java:2621)
            at org.apache.lucene.index.IndexWriter.rollbackInternal(IndexWriter.java:2590)
            at org.apache.lucene.index.IndexWriter.maybeCloseOnTragicEvent(IndexWriter.java:6104)
            at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1639)
            at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1913)
            at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1492)
            ...
  2> INFO: Starting to interrupt leaked threads:
  2> INFO: All leaked threads terminated.

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

• The contract. IndexWriter.java:162-165: "if you hit an Error, or disaster strikes during a checkpoint then IndexWriter will close itself. This is a defensive measure in case any internal state (buffered documents, deletions, reference counts) were corrupted." close() (:1345) is documented as "waiting for any running merges, committing, and closing"; here no merge is running.
• The control. The same OutOfMemoryError thrown at "now merge" (ConcurrentMergeScheduler.java:558, logged before the loop that checks merges out), while the merge is still pending, closes the writer with the Error as its tragic exception (executed on main with assertions on and off, 10.5.2 and 9.12.3).
• IndexWriter's own rule. The comment at IndexWriter.java:5110-5111: "Important that tragicEvent is called after mergeFinish, else we hang waiting for our merge thread to be removed from runningMerges". ConcurrentMergeScheduler.merge hands back a merge it cannot start (:592-595).
• The tests. TestIndexWriterExceptions.testOutOfMemoryErrorCausesCloseToFail (LUCENE-1429, TestIndexWriterExceptions.java:1110-1147) and testOutOfMemoryErrorRollback (:1150) throw OutOfMemoryError from InfoStream.message and assert that the writer recovers or closes.
• The history. In 8.5.2 the line (then " consider merge ") sat inside ConcurrentMergeScheduler.merge's try { ... } finally { if (!success) writer.mergeFinish(merge); }. LUCENE-9345 (d7e0b906abc, apache/lucene-solr#1451) moved it after the check-out without the hand-back; the PR's two review comments are about the index(source) string. CHANGES: "LUCENE-1210: Fix deadlock case on hitting an exception while starting a merge when using ConcurrentMergeScheduler" (#2287, "mergeInit hits an exception (eg OOME)"); "LUCENE-1171: Fixed some cases where OOM errors could cause deadlock in IndexWriter".

The strongest case: InfoStream is a "Debugging API" tagged @lucene.internal (InfoStream.java:24-28); MergeScheduler and MergeSource are @lucene.experimental; the stock InfoStreams do not throw; close() promises no bounded wait; so a throwing logger is misuse of a debugging hook. The refute-lens cross-model reviewer (OpenAI GPT-5.6) argued this and said not real, while agreeing with the root cause.

It fails for the Error variant: the class javadoc's promise covers Errors without exception, wherever they are raised, and an OutOfMemoryError is not a misbehaving logger (by reading it can also hit while Lucene builds this message; the repros inject it from InfoStream.message, as Lucene's own tests do); IndexWriterConfig.setInfoStream(InfoStream) and setInfoStream(PrintStream) are public and untagged (IndexWriterConfig.java:430-446), and nothing says message() must not throw; Lucene's own tests inject Errors through InfoStream.message; the code itself treats a merge left in runningMerges at tragedy time as a hang to avoid. It carries weight for the RuntimeException variant, which needs a throwing logger: present that one as secondary hardening. Verdict: not intended (judge confidence medium because of that variant).

Two fixes were validated in a scratch worktree of 645d4fe14a20; both close the demonstrated cases. A drops the merge (the policy can select it again later); B keeps it for a later pass but, by reading, can leave a merge in an already-cleared pending queue when a rollback runs at the same time. Neither covers the MergeThread.run log line (the same gap by reading, not run) or the throw point open PR #16889 would add. By reading, A leaves two small gaps a maintainer may want closed (below): the verbose() check stays outside its try, and the dropped merge is not closed.

One file, +9/-2 in IndexWriterMergeSource.getNextMerge(). It restores the pre-8.6 hand-back for the log call and matches ConcurrentMergeScheduler.merge's own catch (Throwable). mergeFinish removes the merge from runningMerges, releases its segments and calls notifyAll() (IndexWriter.java:5375-5391). Code is added only on the verbose path; it also covers a merge thread's own call of getNextMerge().

        if (writer.mergeScheduler.verbose()) {
          try {
            writer.mergeScheduler.message(
                "  checked out merge " + writer.segString(nextMerge.segments));
          } catch (Throwable t) {
            // no merge scheduler holds this merge yet: finish it, else abortMerges and
            // waitForMerges keep waiting for it in runningMerges
            writer.mergeFinish(nextMerge);
            throw t;
          }
        }

Trade-offs

The merge is dropped, not retried; its segments stay unmerged until the merge policy selects them again on a later merge pass (by reading). It does not cover the MergeThread.run site. By reading (not run): (1) not exactly 8.5.2, where the verbose() check (InfoStream.isEnabled("MS")) was inside the protected try as well (8.5.2 ConcurrentMergeScheduler.java:538-541); here it stays outside, so a throw from isEnabled would still strand the merge, and moving the check inside the try closes that. (2) Like ConcurrentMergeScheduler.merge's existing hand-back (onMergeFinished -> mergeFinish), it does not call OneMerge.close, the only place that completes the merge's completion future and calls its mergeFinished hook (MergePolicy.java:192, :285-299): timed waits such as merge-on-commit (IndexWriter.java:739, :3894) return at their timeout, and a caller in the untimed MergeObserver.await() (MergePolicy.java:915, from forceMergeDeletes(false)) for a merge dropped this way would keep waiting. Closing the merge with success=false, as abortMerges does for pending merges (IndexWriter.java:2831, :5133-5136), would avoid that; not written or tested.

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, with no leaked thread.
• The hunt's 4-test verifier class (both schedulers, the exception-then-close() variant, the pre-check-out control): 4 tests, 0 failures.
• Closest suites with the fix: TestIndexWriterExceptions, TestIndexWriterExceptions2, TestConcurrentMergeScheduler, TestIndexWriterMerging, TestIndexWriterForceMerge, TestIndexWriterMergePolicy, TestIndexWriterOnError, TestTragicIndexWriterDeadlock, TestIndexWriterWithThreads, TestIndexWriter, TestMergeSchedulerExternal: 11 classes, 244 tests, 0 failures, 9 skipped.
• :lucene:core:checkGoogleJavaFormat, ecjLintMain and forbiddenApisMain pass.
• Re-run by the independent fact check: the documented gradle command with the fix passes with assertions on and off, and the 4-test verifier class passes 4 of 4.
• Not run: nightly tests, benchmarks; a concurrent rollback() during the log call (by reading only); a throw from isEnabled; a test of the completion future.

The hunt's first fix (plus a notifyAll()): on a throw, under the writer lock, runningMerges.remove(nextMerge) then pendingMerges.addFirst(nextMerge), and rethrow.

Trade-offs

It keeps the merge for a later scheduler pass. By reading (not run): if another thread's rollback() is already in abortMerges() (pending queue cleared, waiting for running merges, IndexWriter.java:2824-2861), the merge lands in the cleared queue with its segments still registered, and assert mergingSegments.isEmpty() (:2622-2623) would trip. That is why A is recommended.

What the checks validated

• The minimal test passes with assertions on and off.
• The 4-test verifier class: 4 tests, 0 failures.
• The same 11 closest classes: 244 tests, 0 failures, 9 skipped. Lint was not re-run for this option.
• Earlier: the finder's 2-test repro (2 of 2) and the verifier's version (4 of 4, re-run by the adjudication).

Logging the merge before IndexWriter.getNextMerge() moves it would also close the window (a throw would leave the merge pending, like the control), but the message would have to be built from the queue under the writer's lock. Not written or run.

Method: semi-formal (a bounded-exhaustive single-fault sweep, then code reading).

• The hunt unit on error handlers and errors raised through public callbacks ran its sweep against the real lucene-core jar: a 24-operation script with SerialMergeScheduler, one fresh run per InfoStream call, with an OutOfMemoryError thrown at that call. 9 runs at the merge scheduler's message from IndexWriterMergeSource.getNextMerge hung in IndexWriter.abortMerges, with assertions on and off.
• The same unit's static scan of catch handlers did not flag the site: no catch handler is involved; the defect is a missing hand-back.
• Code reading reduced it to a 4-document JUnit on the default ConcurrentMergeScheduler; independent checks then reproduced it (below).