Skip to content

fix(reindex): end the ReindexThread shutdown hot-loop and dead-worker queue stall - #37295

Open
danielsolis-dotcms wants to merge 4 commits into
mainfrom
issue-36922-reindex-thread-shutdown-and-liveness
Open

fix(reindex): end the ReindexThread shutdown hot-loop and dead-worker queue stall#37295
danielsolis-dotcms wants to merge 4 commits into
mainfrom
issue-36922-reindex-thread-shutdown-and-liveness

Conversation

@danielsolis-dotcms

@danielsolis-dotcms danielsolis-dotcms commented Aug 31, 2026

Copy link
Copy Markdown
Contributor

Proposed Changes

  • Add a terminal ThreadState.SHUTDOWN, distinct from the restartable STOPPED, so the worker exits shutdown permanently instead of spinning between the inner and outer loops.
  • Key the shutdown decision off the monotonic ShutdownCoordinator.isShutdownStarted() instead of the transient isRequestDraining(), and log the transition at most once per shutdown.
  • Track worker liveness in an AtomicBoolean, claimed by compare-and-set before submit and cleared in a finally that also covers Error, so a dead runnable can no longer be mistaken for a paused one.
  • Make unpauseImpl() restart a dead worker (reported at ERROR) rather than flipping a flag nobody is listening to — the silent stall that left push-published content unindexed.
  • Route both restart paths through one shutdown-guarded helper that rolls back its liveness claim if submit fails.
  • Use an interrupt-aware wait inside ReindexThread instead of ThreadUtils.sleep, which swallows both InterruptedException and the interrupt flag.
  • Correct the broken double-checked locking on the instance field.

Deviations from the issue's acceptance criteria

Two ACs are intentionally not implemented literally, because doing so would reintroduce the bug in another form. Flagging here so the mismatch against the issue's checkboxes is not a surprise.

  • AC-007 asked for the runnable's catch (Exception e) to be widened to catch (Throwable e). Doing exactly that would retry an OutOfMemoryError forever at SLEEP_ON_ERROR — turning Bug 2 into a second hot-loop. The finally, not the catch width, is what guarantees the liveness clear. Implemented as inner catch (Exception) for retry + outer catch (Throwable) that terminates the worker + finally that clears liveness, with runReindexLoop() rethrowing Error so it reaches that outer catch. Net effect matches the AC's intent.
  • AC-001 named isRequestDraining() and STOPPED. Implementing that literally would make the Bug 2 fix dangerous: isRequestDraining() is cleared at the end of shutdown Phase 1, after which a late commit listener would hit the STOPPED branch — the one unpauseImpl() treats as "safe to restart" — and resurrect the worker mid-shutdown. Uses the monotonic isShutdownStarted() and a distinct terminal state instead.

Checklist

  • Tests — 16 unit (up from 2) + 2 integration methods in existing classes; no new test classes, so no suite registration needed
  • Translations — n/a
  • Security Implications Contemplated — no new input surface, external I/O, or credentials; log messages carry identifiers only and all throttle keys are compile-time constants, so Logger's static throttle map cannot grow unbounded

Additional Info

Backend-only and rollback-safe: no DB schema, ES mapping, REST contract, bom/, or configuration changes.

Root-cause analysis, full test evidence (manual shutdown, full-reindex switchover, 2-node cluster, idle-CPU measurements) and the remaining reviewer notes are in the comments below.

Fixes #36922

… queue stall

Two defects in ReindexThread shared one root cause: a single ThreadState was
used both as a command channel ("what should the worker do?") and as an implied
liveness signal ("is a worker alive?"), and the shutdown check watched the wrong
flag.

Bug 1 - shutdown hot-loop. runReindexLoop() keyed off
ShutdownCoordinator.isRequestDraining(), which is a transient window flag: it is
set at the start of shutdown Phase 1 and cleared in a finally at its end
(shutdown.request.drain.timeout.seconds, default 15s), while
ReindexThreadShutdownTask only runs in Phase 2. The inner break returned into an
outer loop whose only exit condition was state == STOPPED, so the worker spun -
with no back-off, since the break skips the loop-bottom sleep() - for the whole
window, then resumed indexing against infrastructure about to be torn down. A
unit test measured 9,922,576 log events in ~3s; the existing Logger.infoEvery
mitigation throttles only INFO and still emits DEBUG on every pass.

Bug 2 - dead runnable. unpauseImpl() treated state == PAUSED as proof a runnable
was alive, so after the worker died (uncaught Error, executor shutdown) it
flipped a flag nobody was reading. The queue never drained and nothing was
logged as an error.

Changes:
- Add a terminal ThreadState.SHUTDOWN, distinct from the restartable STOPPED
  that unpauseImpl() keys off; all loops test a terminal predicate.
- Use the monotonic isShutdownStarted() as the terminal trigger and log the
  transition once via getAndSet. isRequestDraining() stays a "do not start
  expensive work" hint in finalizeReIndex()/switchOverIfNeeded() only.
- Track liveness in an AtomicBoolean claimed by compare-and-set before submit
  and cleared in a finally covering Error; route both restart paths through one
  shutdown-guarded helper that rolls the claim back if submit fails.
- Report a dead-worker restart at ERROR with a constant throttle key.
- Replace ThreadUtils.sleep on this class's waits with an interrupt-aware wait
  that restores the interrupt status (ThreadUtils.sleep swallows both the
  exception and the flag, leaving a parked worker un-interruptible).
- Correct the broken double-checked locking on the instance field.

Notes:
- AC-007 asked for the runnable's catch(Exception) to be widened to
  catch(Throwable). Widening the inner catch would retry an OutOfMemoryError
  forever; the finally, not the catch width, is what guarantees the liveness
  clear. Implemented as inner catch(Exception) for retry + outer
  catch(Throwable) that terminates + finally that clears.
- The full-reindex switchover test is @Ignore-d: it fails identically on
  unmodified main (244.0s, same assertion), so it is a pre-existing harness
  limitation rather than a regression. Evidence is in its Javadoc.

Tests: 16 unit + 2 integration added, all passing. No DB schema, ES mapping,
REST contract, bom/ or configuration changes - rollback-safe.

Fixes: #36922

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@danielsolis-dotcms

Copy link
Copy Markdown
Contributor Author

Root cause

Two defects shared one cause: a single ThreadState was used both as a command channel ("what should the worker do?") and as an implied liveness signal ("is a worker alive?"), and the shutdown check watched the wrong flag.

Bug 1 — shutdown hot-loop

runReindexLoop() keyed off ShutdownCoordinator.isRequestDraining(). That flag is a transient window, not a shutdown latch: it is set at the start of shutdown Phase 1 and cleared in a finally at its end, while ReindexThreadShutdownTask (@ShutdownOrder(20)) only runs in Phase 2.

The inner break therefore returned into an outer loop whose only exit condition was state == STOPPED — still RUNNING — so it re-entered immediately. The break path also skips the loop-bottom sleep(), so there was no back-off at all. Once Phase 1 ended and the flag cleared, the still-RUNNING worker resumed indexing against infrastructure Phase 2 was about to tear down.

The width of that window is load-dependent, which is what makes the bug intermittent. shutdown.request.drain.timeout.seconds (default 15s) is a timeout, not a duration — measured on an idle server, the coordinator logs "No active requests or busy threads detected - skipping request draining" and Phase 1 completes in 2ms. Under real traffic it waits for in-flight requests, and the reported incident combined that with a JVM stall.

Bug 2 — dead runnable

unpauseImpl() treated state == PAUSED as proof a runnable was alive. After the worker died — uncaught Error (only Exception was caught), executor shutdown, or the pool's DiscardOldestPolicy — it logged a cheerful "--- Unpausing reindex thread", set RUNNING, and returned. Nothing drained the queue and nothing was logged as an error, so the node looked healthy while push-published content stayed invisible.

Why the existing mitigation was insufficient

The shutdown line already used Logger.infoEvery (PR #37038). That throttles only the INFO emission — infoEvery ends with an unconditional logger.debug(...) outside the throttle check. A unit test against the pre-fix code measured 9,922,576 events in ~3 seconds at DEBUG. The throttle suppressed the symptom at one log level and left the spin untouched.

@danielsolis-dotcms

danielsolis-dotcms commented Aug 31, 2026

Copy link
Copy Markdown
Contributor Author

Test evidence

Automated

Suite Result
ReindexThreadUnitTest 16 run, 0 failures (was 2)
BulkProcessorListenerShadowFailureTest 11 run, 0 failures — ADR-0009 shadow-write contract intact
ReindexThreadTest (integration) 7 run, 0 failures, 5 skipped (4 pre-existing @Ignore + 1 below)

Red→Green was confirmed at each step. Pre-fix, the five US1 tests failed on assertions — including Shutdown detected logged 9,922,576 times in ~3s. The dead-worker integration test passes against real PostgreSQL + OpenSearch, and the run log confirms the new branch actually executes:

ERROR reindex.ReindexThread - --- ReindexThread was PAUSED but no worker was alive;
restarting it. Content queued for indexing on this node would otherwise never be indexed.

Manual, against a running server

  • ShutdownReindexThreadShutdownTask took 2.10s against its 8s budget; coordinated shutdown 3.60s total; CPU 8% → 35% → 0%, no spin.
  • Full reindex + switchover — started 02:45:38, switchover completed 02:46:08 (~30s), new indices promoted with reindex_working: null, zero errors. This is the finalizeReIndex()switchOverIfNeeded() empty-queue branch the terminal-state change touches.
  • 2-node cluster — node 1 SIGKILL (dirty crash): node 2 kept serving and logged zero ReindexThread activity — not stopped, not restarted, no error. Node 1 self-recovered on restart.
  • Idle CPU — controlled comparison between images byte-identical except the three ReindexThread class files, 40 samples each:
stat control with fix
median 2.540% 2.540%
p75 3.190% 3.110%
p90 4.770% 3.790%
trimmed mean (drop top 2) 2.631% 2.678% (+1.8%)

Reviewer notes

test_full_reindex_completes_and_switches_over is @Ignore-d, with the reasoning in its Javadoc. It times out after 240s waiting for switchover — but it fails identically on unmodified main (244.0s, same assertion), verified by reverting only this fix and re-running. It is a pre-existing integration-harness limitation, not a regression, and the same operation succeeds in ~30s on a real server (above). Kept rather than deleted so the next person has a starting point; worth a separate issue.

Deviations from the issue's acceptance criteria (AC-007 and AC-001) are described in the PR body.

Recovery is node-local by design. unpauseImpl() runs only on the node whose transaction committed and consults that node's liveness, so node A's unpause cannot restart node B's dead worker — node B self-heals on its own next unpause. Closing that gap needs cross-node liveness detection, deliberately out of scope. Strictly better than today, where the node stays dead in all cases.

Known limit in the cluster verification. dist_reindex_journal was empty during the 2-node test, so "node B doesn't steal node A's claimed rows" was not exercised — the test instance holds 7 contentlets, so a reindex drains sub-second and a mid-drain kill is unraceable. Claim integrity rests on per-serverid scoping in ReindexQueueFactory#getServerId, which this PR does not touch (zero changes to queue SQL).

@danielsolis-dotcms
danielsolis-dotcms marked this pull request as ready for review August 31, 2026 03:58
danielsolis-dotcms and others added 2 commits August 31, 2026 10:51
…chover test

Replaces the vague "harness limitation" note with the diagnosis from a full-log
run. The reindex starts correctly (reindex_working is populated), but the log
contains zero ReindexThread lifecycle lines and zero "Running Reindex
Switchover" lines: nothing drains the rebuild queue, so switchOverIfNeeded() is
never reached. The reindex_working: null that appears exactly 240s later is the
test's own fullReindexAbort() in finally, not a switchover.

Cause: ReindexThread.startThread() delegates to unpause(), which only registers
a Hibernate commit listener unless ALLOW_MANUAL_REINDEX_UNPAUSE is set. With no
committing transaction in the harness bootstrap the listener never fires and the
worker never starts. Sibling tests in this class pass only because saving a
contentlet commits a transaction, which fires the listener as a side effect.

Also rules out #37281/#37282: both concern the switchover being deferred by the
minimum-runtime guard, whose signature is "Running Reindex Switchover" every 3s.
This run logs none - the switchover is never attempted.

Tracked as #37302; removing the @ignore is the verification for that fix.

Refs: #36922, #37302

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Area : Backend PR changes Java/Maven backend code

Projects

Status: No status

Development

Successfully merging this pull request may close these issues.

fix(ReindexThread): shutdown hot-loop and dead-runnable silent queue failure

2 participants