Skip to content

[#802] Fail fast when the replication server cannot read its changelog - #805

Merged
vharseko merged 5 commits into
OpenIdentityPlatform:masterfrom
vharseko:issues/802-fail-fast-unreadable-changelog
Aug 4, 2026
Merged

[#802] Fail fast when the replication server cannot read its changelog#805
vharseko merged 5 commits into
OpenIdentityPlatform:masterfrom
vharseko:issues/802-fail-fast-unreadable-changelog

Conversation

@vharseko

@vharseko vharseko commented Jul 31, 2026

Copy link
Copy Markdown
Member

Fixes #802.

Builds on #795, now merged: the cleanup of a half initialized replication server
(abortInitialization()) comes from there. Rebased on master, so this PR carries only its
own commits.

Problem

FileChangelogDB.initializeDB() caught ChangelogException and only logged
ERR_COULD_NOT_READ_DB — a message whose own text says "The replication server failed to
start because the database %s could not be read"
. It did start:
ReplicationServer.initialize() went on to bind the listen port and start its threads, so a
replication server whose changelog could not be read accepted connections and replication
traffic, and the failure surfaced later, somewhere else. Three distinct shapes, depending on
where the read failed:

  • The ReplicationEnvironment could not be created at all (unreadable or incoherent
    domains.state, corrupted offline.state): replicationEnv stays null and the rest of
    FileChangelogDB dereferences it unguarded. The first update to persist ends in a
    NullPointerException in FileReplicaDB.createLog() — and because that is not a
    ChangelogException, it does not even reach the handler in
    ReplicationServerDomain.publishUpdateMsg(), which exists precisely to shut the replication
    server down when the changelog cannot be written (ERR_CHANGELOG_SHUTDOWN_DATABASE_ERROR).
    applyConfigurationChange() hits the same null through setPurgeDelay().
  • The state was restored only partially: the domains processed before the failure got
    their generation id, the others did not. For those, setGenerationIdIfUnset() then adopts
    the generation id of the first replica to connect — without clearing the changelog, which
    changeGenerationId() does — over on-disk logs which belong to another generation, and
    getOrCreateReplicaDB() writes a second generation<id>.id file next to the existing one.
    On the next start retrieveGenerationIdFile() picks generationIds[0], i.e. whichever the
    file system returns first.
  • The CN indexer or the purger never started: cn=changelog silently answers from an
    index which is not maintained, and the changelog is never purged.

Changes

  • ChangelogDB.initializeDB() declares throws ChangelogException, and documents that the
    DB may be left half open and must then be released with shutdownDB().
  • FileChangelogDB.initializeDB() wraps the cause in the same localized
    ERR_COULD_NOT_READ_DB message — which already names the changelog directory — and
    rethrows it instead of logging it. Logging happens once, where the failure is reported.
  • ReplicationServer.initialize() reports it as a ConfigException, exactly like a listen
    port which cannot be bound. The constructor already routes that through
    abortInitialization(), so no half initialized instance is left behind.
  • abortInitialization() shuts the restored domains down, as shutdown() does. Reading the
    changelog restores one ReplicationServerDomain per domain it holds, and each of them
    starts its assured timer and its status analyzer threads, and registers its monitor
    provider — getReplicationServerDomain() calls start() since Fix CodeQL warning-severity alerts: missed wakeups, resource leaks, escaping threads #790. Every failure of that
    reading happens after that first loop — getReplicationServerDomain() and
    initGenerationID() cannot throw — and so does a listen port which cannot be bound, so
    both aborts used to leave those domains behind. One domain at a time, so that an unchecked
    failure of one of them does not skip the changelog shutdown which follows it.
  • setServerURL() runs before the changelog is read. The monitor instance name of a domain,
    and of its changelog, embeds the URL of its replication server, which used to be assigned
    only after the changelog had been read: the domains restored from it registered under a
    name holding a null URL, and the name looked up to deregister them, built from the assigned
    URL, could never match it again. That leaked their monitor providers on the normal
    shutdown() path too, i.e. on every restart over an existing changelog.
  • The listen thread owns the socket it was started on, instead of reaching for the current
    one through a shared stopListen flag. A port change can then start the new listener
    before it stops the previous one, so an interrupted wait for the previous listen thread —
    which used to close the current listen socket, fail the change and rebind nothing — can no
    longer leave the replication server with no listener at all. The field holding that thread
    is volatile, as the one holding its socket already was: the port change reads it from the
    configuration thread, and a stale read would skip the wait it was captured for.
  • The interrupt which cut short that wait is restored once the whole configuration change
    has run, instead of inside the port switch. Some of what follows the switch is
    interruptible — stopping the handlers of replication servers removed by the same change
    locks the domain interruptibly, after a one-shot engageShutdown() — and an interrupt
    status left set would have failed those steps while the change reported SUCCESS.
    localPorts is updated as soon as the new listener serves, instead of trailing
    getReplicationPort() for as long as the wait for the previous listen thread blocks.

FileChangelogDB is the only implementation and ReplicationServer.initialize() the only
caller; the ChangelogDB used in ChangeNumberIndexerTest is a Mockito mock, unaffected by
the new throws.

Upgrade note

Same shape as the one in #795, for the changelog instead of the listen port. Four points for
the release note:

  • A replication server which cannot read its changelog no longer starts, and neither does
    the directory server.
    The ConfigException propagates from
    MultimasterReplication.initializeSynchronizationProvider() through
    SynchronizationProviderConfigManager.initializeSynchronizationProviders() to
    DirectoryServer.startServer(). Previously such a server came up degraded, without a usable
    changelog, and the failure surfaced later and somewhere else. This is a larger blast radius
    than the existing ERR_CHANGELOG_SHUTDOWN_DATABASE_ERROR path, which stops the replication
    server only. The operator's remedy is the one the message already points at: repair or
    remove the changelog directory named in ERR_COULD_NOT_READ_DB.
  • msgID 11 is no longer logged. ERR_COULD_NOT_READ_DB had exactly one logging site, in
    FileChangelogDB.initializeDB(), and it is now thrown instead. Its text still reaches the
    log, but inside ERR_CONFIG_SYNCH_ERROR_INITIALIZING_PROVIDER — CONFIG category, rendered
    through stackTraceToSingleLineString(). Anyone alerting on msgID 11 has to follow it
    there.
  • msgID 71 is no longer logged either. ERR_COULD_NOT_STOP_LISTEN_THREAD reported a port
    change which gave up on its listen thread, and a port change no longer gives up: the new
    listener is already serving when the previous one is stopped, so an interrupted wait is not
    a failure of the change. The message is kept, with its translations, for the release which
    removes it from the logs.
  • ChangelogDB.initializeDB() declares throws ChangelogException. Source incompatible
    for out-of-tree implementations of that interface.

Tests

ReplicationServerDynamicConfTest:

  • replServerFailsWhenChangelogCannotBeRead: the first shape, a corrupted domains.state.
    The creation fails with a ConfigException whose cause is the ChangelogException and
    whose message names the changelog directory, leaves no instance registered in
    ReplicationServer.getAllInstances(), and leaves the listen port free — it is never bound
    when the changelog cannot be read.
  • replServerFailsWhenAReplicaChangelogCannotBeRead: the second shape, a partial restore.
    The changelog of a replication server which ran and served one replica has the head log
    file of that replica replaced by a directory, so its state is still readable and the changes
    of the domain it names are not. The failure then happens after the domain was restored, and
    that domain is left neither running nor registered. The changelog of the change number
    index holds a head log file of its own, created when the replication server starts, so the
    lookup which picks the file to corrupt is scoped to the domain directories, and the test
    asserts that the failure names the log it corrupted: it cannot pass while exercising
    another failure shape.
  • abortedStartReleasesTheRestoredDomains: the same changelog, a listen port which is taken.
    The changelog is read, its domain restored, the bind fails, and the domain is released.
  • restartedReplServerReleasesTheRestoredDomains: the same changelog, a free port. The
    replication server starts, its restored domain is registered — asserted, so that the test
    cannot pass by testing nothing — and stopping it deregisters the domain again.
  • replServerKeepsListeningWhenAPortChangeIsInterrupted: the interrupt status is set before
    the port change, so its wait for the previous listen thread fails at once. The change
    succeeds, the replication server listens on the new port and serves a broker on it.
    Thread.join() only throws while the thread it waits for is alive, so the test first keeps
    that thread busy with a connection which says nothing — off accept(), it cannot terminate
    until its socket is closed — and asserts
    interruptedListenThreadStops, which only the interrupted path increments: the test cannot
    pass over the interruption it is named after. That the connection is accepted is waited for
    on both sides of it — the listen thread inside accept() before it is made, and out of it
    afterwards — since a connection completes against the listen backlog of the kernel and a
    bound socket says nothing of the thread which serves it.
mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='ReplicationServerDynamicConfTest'

Tests run: 9, Failures: 0, Errors: 0, Skipped: 0

The two tests which cover the released domains were checked against the unfixed code: with
the loop removed from abortInitialization(), each of them reports the registrations the
restored domain left behind.

The whole replication package passes as well:

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='org.opends.server.replication.**.*Test'

Tests run: 3482, Failures: 0, Errors: 0, Skipped: 0

Follow-up

#813, found while these tests were being stabilised: a FileReplicaDB created while the
changelog is shutting down is never released, so its monitor provider stays registered and
its log stays referenced. It predates this PR, and the domain-scoped wait added here stops
these tests from racing into it.

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One code change requested, plus two items to confirm before merge.

Aborted initialization leaks the per-domain timer thread (medium)

FileChangelogDB.initializeToChangelogState() calls getReplicationServerDomain(dn, true) for every restored domain, and each ReplicationServerDomain constructor starts an assuredTimeoutTimer thread. abortInitialization() does not do what shutdown() does — cancel them:

// ReplicationServer.shutdown(), missing from abortInitialization()
for (ReplicationServerDomain domain : getReplicationServerDomains())
{
  domain.shutdown();
}

Reproduced with a probe (changelog holding one domain, second RS whose listen port is taken):

assuredTimers baseline=[]
assuredTimers after  =[Replication server RS(1) assured timer for domain "o=test"]

This is guaranteed, not an edge case: loop 1 of initializeToChangelogState() cannot throw (getReplicationServerDomain and initGenerationID are both non-throwing), so every partial-restore failure happens after all domains were created. It also affects the listen-port abort from #795, where initializeDB() succeeded and all domains exist. Adding the loop at the top of abortInitialization() is safe on a partially constructed instance — baseDNs is initialized at its declaration.

File: opendj-server-legacy/src/main/java/org/opends/server/replication/server/ReplicationServer.java

Startup semantics change needs an explicit sign-off (discussion)

Confirmed that the ConfigException propagates uncaught: MultimasterReplication.initializeSynchronizationProvider()SynchronizationProviderConfigManager.initializeSynchronizationProviders()DirectoryServer.startServer(). A corrupted changelog — a rebuildable structure, unlike the user backends — now stops the whole directory server, including its ability to serve reads. That is a strictly larger blast radius than the existing ERR_CHANGELOG_SHUTDOWN_DATABASE_ERROR path, which shuts down only the replication server.

The choice is defensible and consistent with #795, but since #795 and #805 together change directory-server startup behaviour, this warrants a maintainer's explicit decision plus a release-note entry rather than landing as an implementation detail.

Test covers one of the three documented failure shapes (low)

replServerFailsWhenChangelogCannotBeRead corrupts domains.state, which fails the ReplicationEnvironment constructor before any domain is created — the cleanest shape. Shape 2 from the PR description (partial restore) and shape 3 (indexer/purger) are uncovered, and shape 2 is the one that exposes the timer leak above. A fixture with a valid domains.state plus a corrupted per-domain state would cover it; assert on thread names containing assured timer for domain, not on DirectoryServer.getMonitorProviders() (see the last nit).

File: opendj-server-legacy/src/test/java/org/opends/server/replication/server/ReplicationServerDynamicConfTest.java

Nits

  • msgID 11 disappears from the logs: not logging at the throw site is right, but ERR_COULD_NOT_READ_DB had exactly one logging site and it is now removed. The text reaches the operator only inside ERR_CONFIG_SYNCH_ERROR_INITIALIZING_PROVIDER, rendered through stackTraceToSingleLineString() — CONFIG category, single-line stack trace. Worth a line in the release note for anyone alerting on msgID 11.
  • ChangelogDB.initializeDB() signature: adding a checked exception is source-incompatible for out-of-tree implementers. Nothing in-tree breaks, but it belongs in the changelog.
  • switchListenPort() interrupt window (carried from #795): stopListenThread() closes listenSocket before listenThread.join(). If the join is interrupted, the catch restores config/serverURL and closes the new socket, but nothing rebinds — the RS is left with no listener at all, which is the state this series set out to eliminate. Narrow, but the comment there describes the thread, not the released port.
  • Comment volume: the blocks in initializeDB() and initialize() (6 and 4 lines) largely restate the PR description; a sentence plus the issue reference would read better.
  • Pre-existing, not this PR: two monitor providers also leak here, but they leak identically on the normal shutdown() path (probed with no abort involved: replication server rs(3) null,cn=o_test,...). Cause is separate — getMonitorInstanceName() embeds serverURL, which is null while initializeDB() registers and non-null when deregisterMonitorProvider() looks the name up, so the key never matches. Worth its own issue; the loop requested above does not fix it.

@vharseko vharseko added java Pull requests that update java code tests Test suites: fixing, enabling, un-disabling concurrency Thread-safety / race-condition bugs labels Jul 31, 2026
@vharseko

Copy link
Copy Markdown
Member Author

Thanks — all of it addressed in the last commit, including the two items you left as
follow-ups.

Aborted initialization leaks the per-domain timer thread

Confirmed and fixed: abortInitialization() now runs the same loop as shutdown(), before
the changelog it writes to is shut down. One correction to the diagnosis, which does not
change the conclusion: the timer is created as new Timer(name, true), i.e. its thread is a
daemon and does not hold the JVM. What it does hold, for the lifetime of the process, is the
ReplicationServerDomain and everything it references — and the domain also leaks a monitor
provider, which is the second half of the last nit below.

Your reading of initializeToChangelogState() is what the fix relies on: the first loop
cannot throw, so every failure of the restore, and every failure after it, happens with all
domains already created.

Startup semantics change needs an explicit sign-off

Signed off: a replication server which cannot read its changelog fails to start, and takes
the directory server with it, consistently with #795. The alternative — a directory server
which serves reads over a replication server that silently stopped replicating — is the state
this series exists to remove, and the changelog is rebuildable, so the remedy is bounded. The
release note is in the description, with the propagation path spelled out.

Test covers one of the three documented failure shapes

Shape 2 is covered now, by replServerFailsWhenAReplicaChangelogCannotBeRead: a changelog
written by a replication server which actually ran and served one replica, with the head log
file of that replica replaced by a directory. readOnDiskChangelogState() never opens the
logs, so the state is still readable and the failure lands in getOrCreateReplicaDB(), after
the domain was restored.

Two more tests come with it: abortedStartReleasesTheRestoredDomains (same changelog, listen
port taken, i.e. the #795 path with domains to release) and
restartedReplServerReleasesTheRestoredDomains (same changelog, free port, normal shutdown —
the monitor provider case). Both assert on thread names containing assured timer for domain
and on DirectoryServer.getMonitorProviders(), which is now meaningful, see below.

Both were checked against the unfixed code: with the loop removed from
abortInitialization(), each reports exactly the two registrations you predicted, the timer
thread and the monitor provider of the domain.

Shape 3 is still uncovered on purpose: it needs computeChangeNumber enabled and a corrupted
change number index, and it fails in startIndexer(), i.e. at the same point of the same
abort path as shape 2. Happy to add it if you would rather have it explicit.

Nits

  • msgID 11: in the release note, with the message it now travels in.

  • ChangelogDB.initializeDB() signature: in the release note as a source-incompatible
    change for out-of-tree implementations.

  • switchListenPort() interrupt window: fixed rather than documented. The listen thread
    now owns the socket it was started on — runListen(ServerSocket), and the socket is a
    field of ReplicationServerListenThread — instead of reaching for the current one through
    the shared stopListen flag, which is gone. Closing a socket therefore stops that thread
    and only that one, so the port change starts the new listener before it stops the previous
    one, and the interrupted wait no longer has anything to roll back:
    replServerKeepsListeningWhenAPortChangeIsInterrupted sets the interrupt status before the
    change, which makes join() fail at once, and asserts that the replication server listens
    on the new port and serves a broker on it.

  • Comment volume: the two blocks are down to two and three lines, with the issue number
    instead of the retelling.

  • Monitor providers: root cause fixed here, since it is one line and it also removes the
    null from cn=monitor on the normal path. initializeDB() ran before setServerURL(),
    so the domains restored from the changelog — and their replica DBs, whose monitor name
    embeds the domain's — registered with a null URL in their name, and no later lookup could
    match it. setServerURL() now runs first; it only reads the configuration, so it can.

    One narrower case remains, which predates this series as well: a listen port change
    reassigns serverURL, so those names shift again and the entries registered under the
    previous URL are never deregistered. Fixing that properly means either re-registering the
    replica DB monitors too, which needs a ChangelogDB addition, or making the monitor name
    independent of a mutable field. I would rather do it in its own issue than grow this PR —
    say the word if you prefer it here.

…ot read its changelog

FileChangelogDB.initializeDB() caught ChangelogException and only logged
ERR_COULD_NOT_READ_DB, whose text already says the replication server failed to
start. It did start: ReplicationServer.initialize() went on to bind the listen
port and start its threads over a changelog it never opened, so the failure
surfaced much later and somewhere else - as a failure on the first update to be
persisted when the replication environment does not exist at all, or as a domain
adopting the generation id of the first replica to connect over a changelog
which holds another generation.

initializeDB() now declares ChangelogException, FileChangelogDB wraps the cause
in the same localized ERR_COULD_NOT_READ_DB message and rethrows it, and
initialize() reports it as a ConfigException, exactly like a listen port which
cannot be bound. The constructor already releases a half initialized instance
through abortInitialization(), which shuts the changelog DB down.

ReplicationServerDynamicConfTest.replServerFailsWhenChangelogCannotBeRead covers
it: a corrupted domains.state makes the creation fail with a ConfigException
naming the changelog directory, leaves no instance registered and no listen port
bound.
@vharseko
vharseko requested a review from maximthomas July 31, 2026 17:39
…hangelog read

Reading the changelog restores one ReplicationServerDomain per domain it holds, and each of
them starts its assured timer thread and registers its monitor provider. Every failure of
that reading happens after that first loop, and so does a listen port which cannot be bound:
abortInitialization() now shuts those domains down, as shutdown() does.

The monitor instance name of a domain, and of its changelog, embeds the URL of its
replication server, which was assigned only after the changelog had been read: the restored
domains registered under a name holding a null URL, which no later lookup could match, so
they leaked on the normal shutdown path too. setServerURL() now runs first.

The listen thread owns the socket it was started on instead of reaching for the current one
through a shared stopListen flag, so a port change starts the new listener before it stops
the previous one. An interrupted wait for the previous listen thread can no longer leave the
replication server with no listener at all.
@vharseko
vharseko force-pushed the issues/802-fail-fast-unreadable-changelog branch from 83b9e25 to ec16a29 Compare August 2, 2026 08:49

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All round-4 items are addressed — the abortInitialization() loop, the setServerURL() reordering that root-causes the monitor leak, shape 2 coverage, and the switchListenPort() interrupt window fixed rather than documented. One blocker before merge: 3 of 9 build jobs fail, in this PR's own test helper.

The changelog wait matches the change number index, not the replica (blocker)

ReplicationServerDynamicConfTest.createPopulatedChangelog() waits for the published change to be persisted:

// opendj-server-legacy/src/test/java/org/opends/server/replication/server/ReplicationServerDynamicConfTest.java:509
waitFor(dbDirectory, "head", ".log");

findFile recurses from the changelog root, so this matches <changelogDb>/changenumberindex/head.log. That file already exists: ReplServerFakeConfiguration:71-73 rewrites purgeDelay = 0 into 24 h, so FileChangelogDB.initializeDB():293 always reaches startCNPurger(), and ChangelogDBPurger.run():897-898 opens the CN index DB as its first statement.

A probe at :509 printed the same thing on every invocation, on every JVM, including runs where all 9 tests passed:

waitFor-matched=changenumberindex/head.log  generationIdFile=<none>
tree=[changenumberindex changenumberindex/head.log]

The wait is a no-op, so stop(broker) and replicationServer.shutdown() at :513-514 race the persistence of the change instead of following it. Both resulting shapes are in CI:

Job Failing tests Assertion
ubuntu 21 replServerFailsWhenAReplicaChangelogCannotBeRead, restartedReplServerReleasesTheRestoredDomains :517 and :521→:539
ubuntu 25 abortedStartReleasesTheRestoredDomains, restartedReplServerReleasesTheRestoredDomains :517 and :521→:539
ubuntu 26 restartedReplServerReleasesTheRestoredDomains :517

:343 uses the same unscoped lookup to pick the file it replaces with a directory, so it can corrupt the change number index instead of the replica changelog — the test then passes while exercising a different failure shape than its javadoc claims.

Scoping the lookup to domain directories fixes both. ReplicationEnvironment.getOrCreateReplicaDB():352-372 writes domains.state<serverId>.server/generation<id>.idhead.log, so the replica changelog is last of the four and waiting for it makes the other three exist:

private static final String DOMAIN_DIRECTORY_SUFFIX = ".dom";

/** Returns the head log file of a replica changelog, i.e. the one under a domain directory. */
private File findReplicaLogFile(File dbDirectory)
{
  final File[] entries = dbDirectory.listFiles();
  if (entries == null)
  {
    return null;
  }
  for (File entry : entries)
  {
    if (entry.isDirectory() && entry.getName().endsWith(DOMAIN_DIRECTORY_SUFFIX))
    {
      final File replicaLogFile = findFile(entry, "head", ".log");
      if (replicaLogFile != null)
      {
        return replicaLogFile;
      }
    }
  }
  return null;
}

with waitFor replaced by a waitForReplicaLogFile polling on it, and the call at :343 switched to findReplicaLogFile. Verified: asserting the invariant at :509 reproduces CI's exact message on the unfixed helper (2 of 9 failing), and the fixed helper is 9/9 green, 3482/0 for org.opends.server.replication.**.*Test.

A replica DB created during shutdown leaks its monitor provider (medium)

The :521 failures report found [1] — exactly one leftover registration. That identifies it: FileChangeNumberIndexDB's monitor is "ChangeNumber Index Database" and ReplicationServer's is "Replication Server <port> <id>", so neither matches the test's replication server rs(<id>) filter; a leaked ReplicationServerDomain would leave two entries, because assuredTimeoutTimer is created unconditionally in its constructor. Only a FileReplicaDB monitor leaves one, and its sole deregistration site is FileReplicaDB.shutdown():221, reachable only from the drain in shutdownDB(). A surviving registration therefore proves the DB was absent from domainToReplicaDBs when the drain ran.

In FileChangelogDB, getOrCreateReplicaDB():193 checks the shutdown flag before getExistingOrNewDomainMap() inserts the domain map at :230, so an insertion can land after shutdownDB():359 has already drained. Corroborated in CI by msgID 274 (Log.releaseLog(), "must be released but it is not referenced") on 1.dom/42.server.

One line closes it, inside the existing synchronized (domainMap) block:

// opendj-server-legacy/src/main/java/org/opends/server/replication/server/changelog/file/FileChangelogDB.java:266
if (domainToReplicaDBs.get(baseDN) != domainMap)
{
  return null;
}
if (shutdown.get())
{ // a shutdown was initiated after the domain map was inserted: it would not be drained
  return null;
}

Reading false under that lock means shutdownDB()'s CAS at :336 has not run, so its iterator at :359 does not exist yet, so it will see the map — inserted before the lock was taken — and must block on the same monitor to drain it. Reading true returns null, and the loop at :193 throws ERR_CANNOT_CREATE_REPLICA_DB_BECAUSE_CHANGELOG_DB_SHUTDOWN, which is the intended behaviour. There is one insertion site and two removal sites, so the case analysis is complete.

This predates the PR and the fix above stops these tests from reaching it, so its own issue is fine.

Nits

  • msgID 71 is now dead: ERR_COULD_NOT_STOP_LISTEN_THREAD has zero call sites after the switchListenPort() rework, but remains in ReplicationMessages.java and nine locale files. Same release-note treatment as msgID 11, or drop it.
  • Double-listen window: both ports accept between startListenThread(newListenSocket) at ReplicationServer.java:667 and close(previousListenSocket) at :671, and localPorts still names only the old port. A peer connecting to the old port in that window gets a session that outlives the change. This is the inverse trade of the bug being fixed and it is the right one, but the javadoc's "there is nothing to roll back" should say so.
  • replServerKeepsListeningWhenAPortChangeIsInterrupted does not reliably exercise the interrupt path: Thread.join() only throws while isAlive(). If the previous listen thread has already exited, join() returns without throwing and the pre-set flag is never cleared, so assertTrue(interrupted) passes without the catch block running. Verified on JDK 26: join() on a terminated thread with the interrupt set gives threw=false, interruptStillSet=true. Assert on something only the catch produces.
  • abortInitialization() robustness: an unchecked throw from domain.shutdown() at ReplicationServer.java:781-784 skips shutdownExternalChangelog() and changelogDB.shutdownDB(). shutdown() has the same shape, but on the abort path the changelog is known broken, which makes it likelier.

…l-fast changelog read

The changelog of the change number index holds a head log file of its own, created when the
replication server starts, so the unscoped lookup in the test helper could match it instead
of the log of the replica: the wait then waited for nothing and the corruption hit the wrong
log. The lookup is now scoped to the domain directories, and the test asserts that the
failure names the replica log it corrupted, so it cannot pass while exercising another
failure shape.

A port change whose wait for the previous listen thread is interrupted is now exercised
rather than passed over: Thread.join() only throws while the thread it waits for is alive, so
the test keeps that thread in its handshake with a connection which says nothing, and asserts
the counter which only the interrupted path increments.

abortInitialization() shuts each restored domain down on its own, so that an unchecked
failure of one of them does not skip the changelog shutdown which follows.
@vharseko

vharseko commented Aug 3, 2026

Copy link
Copy Markdown
Member Author

Blocker confirmed and fixed, and it was worse than the review says. Everything else is in too.

The changelog wait matched the change number index

Reproduced the whole chain: ReplServerFakeConfiguration:71-73 turns purgeDelay = 0 into
24 h, so initializeDB() always reaches startCNPurger(), and ChangelogDBPurger.run()
opens the CN index DB as its first statement — changenumberindex/head.log exists from the
moment the replication server starts, before any replica data. findFile recursed from the
changelog root and returned whatever File.listFiles() yielded first, which is why it was
green on APFS, where 1.dom sorts before changenumberindex, and red on ubuntu.

One addition to the diagnosis. Where the review says the test "passes while exercising a
different failure shape", it would in fact not pass at all: computeChangenumber defaults to
false in the fake configuration, so startIndexer() is never called and the CN index DB is
opened inside the purger thread. A corrupted changenumberindex/head.log therefore never
reaches initializeDB(), which returns normally — the replication server starts and the test
fails on its own fail("...should have failed"). CI never got that far because the helper
blew up first.

Fixed as proposed: findReplicaLogFile() scoped to *.dom, used both for the wait and for
picking the file to corrupt. Your note that the replica log is written last of the four is
what makes the single wait sufficient — worth recording that my earlier attempt at this waited
for generation<id>.id instead, which ReplicationEnvironment.getOrCreateReplicaDB():352-372
writes before the log, so it would not have helped.

On top of that the test now asserts that the failure names the log it corrupted, so it cannot
drift to another shape again:

Could not get or create replica DB for baseDN 'o=test', serverId '42', generationId '5055':
ChangelogException: Could not initialize the log '.../1.dom/42.server'
  (Log.java:364 ... ReplicationEnvironment.java:371 FileReplicaDB.java:138
   FileChangelogDB.java:275 FileChangelogDB.java:196 FileChangelogDB.java:317
   FileChangelogDB.java:288 ReplicationServer.java:517 ...)

initializeToChangelogState()getOrCreateReplicaDB(): shape 2, from the stack.

The replica DB created during shutdown

Agreed, and filed as #813 with your analysis and your patch. Two corrections which do not
change the conclusion:

  • a leaked ReplicationServerDomain now leaves three entries, not two: since Fix CodeQL warning-severity alerts: missed wakeups, resource leaks, escaping threads #790,
    getReplicationServerDomain() calls start(), so the domain holds its status analyzer
    thread as well as its assured timer, and the test counts both;
  • the elimination is not quite closed by the count alone — DataServerHandler's monitor name
    ends in ",cn=" + replicationServerDomain.getMonitorInstanceName(), so it matches the
    test's filter too and would also leave exactly one entry. What settles it is your other
    observation, msgID 274 on 1.dom/42.server, which names the replica log itself.

Nits

  • msgID 71: release note, next to msgID 11. The message and its nine translations stay.
  • Double-listen window: the javadoc of switchListenPort() now states the trade — a peer
    which connects to the previous port just before it is released gets a session which
    outlives the change, and that is the deliberate inverse of a window during which nothing
    listens at all.
  • The interrupt test: fixed, and made deterministic rather than just observable. The test
    now opens a connection which says nothing, waits for the previous listen thread to leave
    accept(), and only then sets the interrupt status: the thread is inside its handshake,
    whose timeout is 5 s, so join() really blocks and really throws. It then asserts
    interruptedListenThreadStops, a counter incremented only in that catch — the
    listenPortBindFailures pattern already used in this class. assertTrue(interrupted) has
    become meaningful as a result: join() clears the interrupt status when it throws, so the
    flag is only set again by the catch.
  • abortInitialization() robustness: each domain is shut down in its own try/catch, so an
    unchecked failure of one does not skip shutdownExternalChangelog() and shutdownDB().

Tests

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='ReplicationServerDynamicConfTest'
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='org.opends.server.replication.**.*Test'
Tests run: 3482, Failures: 0, Errors: 0, Skipped: 0

@vharseko
vharseko requested a review from maximthomas August 3, 2026 09:55

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All round-5 items are addressed, and the blocker is genuinely fixed. findReplicaLogFile() is scoped to .dom, matching ReplicationEnvironment.DOMAIN_SUFFIX (ReplicationEnvironment.java:148), and the new assertion that the failure names the corrupted log's directory means the test can no longer drift to another shape. Your correction on the diagnosis holds: computeChangenumber defaults to false, so initializeDB():289-292 skips startIndexer() and the CN index DB is only reached through setPurgeDelay()startCNPurger(), i.e. inside the purger thread — a corrupted changenumberindex/head.log never propagates out of initializeDB() and the test would have failed on its own fail(...).

One test-only item before merge.

waitForListenThreadOf() can return before the connection is accepted (medium)

opendj-server-legacy/src/test/java/org/opends/server/replication/server/ReplicationServerDynamicConfTest.java

The helper returns as soon as the listen thread is observed not inside ServerSocket.accept. But silent.connect() completes against the kernel listen backlog — it does not require the thread to be in accept() at all — and assertTrue(replicationServer.isListening()) only proves the socket is bound: listenSocket is assigned at ReplicationServer.java:520, before startListenThread() at :535.

So if the getAllStackTraces() snapshot catches the listen thread after Thread.start() but before its first accept() — it is in logger.info(NOTE_REPLICATION_SERVER_LISTENING, ...), a localized-message format — the helper returns with the connection still queued, join() races the thread's exit, and the test fails on its own interruptedListenThreadStops assertion. Narrow window and a low-probability flake rather than a repeat of the blocker, but determinism is what round 5 was for.

A two-state wait closes it:

waitForListenThread(port, true);    // seen inside accept()
silent.connect(new InetSocketAddress("127.0.0.1", ports[0]), 5000);
waitForListenThread(port, false);   // left accept() with our connection

Related implicit dependency, worth a comment if not a guard: everything between the helper returning and join()bindListenPort(), setServerURL() (which can reach InetAddress.getLocalHost()), Thread.start() — must fit inside MultimasterReplication.connectionTimeoutMS, default 5000 (MultimasterReplication.java:118), which is how long session.receive() keeps the previous thread alive.

Merge gate

The three blocker failures only ever reproduced on ubuntu — macOS and Windows were green with the broken helper, so their being green now is not evidence. All five build-maven (ubuntu-latest, …) jobs are still pending on the current head.

Nits

  • listenThread is not volatile while listenSocket is: switchListenPort() at ReplicationServer.java:667 now reads the plain field to capture the thread it will join, and the config-change thread is not the constructing thread. Worst case is a stale read that skips the join — the socket close still stops the thread, so it degrades to the pre-PR behaviour rather than breaking. One word at ReplicationServer.java:109, and it removes the asymmetry with the volatile ServerSocket listenSocket on the line above.
  • waitForListenThreadOf() hardcodes rs(1): every other new helper takes the server id. A copy of the test with a different id fails as a 60 s timeout instead of a clear error — pass replicationServer.getServerId().
  • .dom duplicated from a private constant: DOMAIN_DIRECTORY_SUFFIX mirrors ReplicationEnvironment.DOMAIN_SUFFIX, which is private. The javadoc pointing at the class is the right mitigation; just note that a rename there surfaces as a 60 s wait in waitForReplicaLogFile() before assertNotNull reports it.
  • abortInitialization() catches RuntimeException, not Error: given the stated intent — "what follows still has to run" over a changelog known to be broken — an Error still skips shutdownExternalChangelog() and shutdownDB(). Not worth churning; the comment just claims slightly more than the code guarantees.

…l-fast changelog read

The wait for the listen thread of the interrupted port change returned as soon as that thread
was seen outside accept(), which a thread that has not reached accept() yet also satisfies: a
connection completes against the listen backlog of the kernel, and isListening() only reports
a bound socket, so the connection could still be queued when the port change closed the socket
under it. The previous listen thread then died before the wait for it began, and the test
failed on its own interruptedListenThreadStops assertion. The helper now waits for that thread
to be inside accept() before the connection is made and to have left it afterwards, which it
can only have done for that connection, and it takes the server id instead of hardcoding rs(1).

listenThread becomes volatile, like the listen socket it goes with: a port change reads it
from the configuration thread, and a stale read would skip the join it was captured for.

The comment of abortInitialization() no longer promises more than its catch of RuntimeException
delivers, and the wait for a replica changelog names the domain directory suffix it looks for,
so that a rename of the constant which owns it reads as such.
@vharseko

vharseko commented Aug 3, 2026

Copy link
Copy Markdown
Member Author

All round-6 items are in, in fe88515f40.

waitForListenThreadOf() could return before the connection was accepted

Confirmed, and the consequence goes one step further than "the connection is still queued".
The helper returned on "the listen thread is not inside accept()", which a thread that has
not reached accept() yet satisfies as well: isListening() only reports listenSocket,
assigned at ReplicationServer.java:520, while the thread starts at :535, and connect()
completes against the listen backlog of the kernel. If the helper returned in that state, the
port change closed the previous socket under a connection which was never accepted, accept()
threw, the thread left its loop on !socket.isClosed() and was already dead when the join
began — and join() on a dead thread does not throw, so the run failed on the test's own
interruptedListenThreadStops assertion. A flake which fails rather than one which passes
quietly, which is what that counter is there for, but not the determinism round 5 was about.

Fixed as proposed, as waitForListenThread(serverId, port, accepting):

waitForListenThread(serverId, ports[0], true);
silent.connect(new InetSocketAddress("127.0.0.1", ports[0]), 5000);
waitForListenThread(serverId, ports[0], false);

Waiting for accept() first is what makes the second wait conclusive rather than merely
likelier: this test opens the only connection that port ever gets, so leaving accept() can
only be for it.

The implicit dependency you noted is documented at the call site rather than guarded, because
it cannot be: MultimasterReplication.connectionTimeoutMS (:118) is only ever assigned from
the configuration, getConnectionTimeoutMS() is the only accessor, so a test cannot widen the
5 s the handshake gives it. The comment now names what has to fit inside it — bindListenPort(),
setServerURL() and Thread.start() — which is what keeps the previous listen thread alive
long enough for the wait for it to block.

Nits

  • listenThread volatile: done, one word, with the reason next to it. The asymmetry with
    the volatile ServerSocket on the line above was the tell.
  • rs(1) hardcoded: gone, the helper takes replicationServer.getServerId(), and its
    fail(...) now tells the two waits apart instead of reporting one message for both.
  • .dom duplicated from a private constant: kept, with the javadoc pointing at
    ReplicationEnvironment, and the failure of waitForReplicaLogFile() now names the suffix
    it looked for and where it comes from, so a rename there reads as a rename rather than as a
    60 s wait ending in an empty assertion.
  • Error in abortInitialization(): the comment is fixed, the code is left alone — it
    now says "one unchecked exception at a time" instead of "one failure at a time". Catching
    Error there would swallow an OOM to save a monitor registration on a path which is already
    failing, which is the worse trade of the two.

Merge gate

Agreed. The five build-maven (ubuntu-latest, …) jobs of the previous head were still queued
when this one was pushed, so nothing of that run is evidence either way; this head re-queues
them.

Tests

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='ReplicationServerDynamicConfTest'
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0

The whole replication package is running again on this head; I will post the count when it
finishes rather than carry the round-5 one over.

PR description

Rechecked against the current head: "Three points for the release note" had been left behind
by the msgID 71 entry which round 5 added, so it says four; the volatile field is in the
listen-thread entry, and the two-sided wait in the entry of
replServerKeepsListeningWhenAPortChangeIsInterrupted.

@maximthomas maximthomas left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

All round-6 items are in and verified.

The two-sided wait holds up, and I checked it empirically rather than by reading. createServerSession() has no non-SSL branch — it always reaches startHandshake() with setSoTimeout(getConnectionTimeoutMS()) (opendj-server-legacy/src/main/java/org/opends/server/replication/protocol/ReplSessionSecurity.java:237,250), and connection-timeout defaults to 5 s, its synopsis being "the timeout used when connecting to peers and when performing SSL negotiation". A standalone probe of the same shape on JDK 17 gives:

[1] isAccepting()==true while blocked in accept()   -> 4 matching java.net.ServerSocket frames
[2] isAccepting()==false after the silent connection
[3] join() threw InterruptedException: true after 0ms  (thread alive)
    interrupt status still set after join(): false
[4] startHandshake() outcome: SocketTimeoutException: Read timed out after 5014ms

Two things worth recording. [4] is the ~5 s of aliveness the wait is buying, against a main-thread path (bind, setServerURL(), Thread.start()) that is sub-millisecond — the margin is thousands-fold, so the test is deterministic. And [3] confirms the round-5 claim independently: join() clears the interrupt status when it throws, so assertTrue(interrupted) can only pass because the catch block re-asserts it — the test really does prove the catch ran.

One refinement to the comment, not a defect: at the moment the second wait returns the thread has left accept() but is typically still in JCA warm-up (ProviderList.<clinit>, Properties$LineReader.readLine), not yet in the handshake. The load-bearing invariant is not "it is in the handshake" but "it is off accept() and cannot terminate until its socket is closed" — which stopListenThread() does immediately before join(). The javadoc reads as if the former; the latter is what makes it sound.

setServerURL() reads only the configuration (opendj-server-legacy/src/main/java/org/opends/server/replication/server/ReplicationServer.java:1327-1348), so moving it ahead of the bind is safe, and getReplicationServerDomain(dn, true) does call .start() (:1107), so the abortInitialization() loop has both threads to release.

One new item, from the same interrupt path.

The restored interrupt escapes into the rest of applyConfigurationChange() (low-medium)

opendj-server-legacy/src/main/java/org/opends/server/replication/server/ReplicationServer.java:687-698

Previously an interrupted join ended the change: the catch set OPERATIONS_ERROR, switchListenPort() returned false, applyConfigurationChange() returned at :1250. Now it re-asserts the flag and returns true, so everything after the port switch runs interrupted — and some of it is interruptible:

// ReplicationServerDomain.stopServer(), reached from disconnectRemovedReplicationServers()
if (!sHandler.engageShutdown())   // MessageHandler:164 - shuttingDown.getAndSet(true), one-shot
{
  if (!shutdown)
  {
    try { lock(); }               // :2281 - lock.lockInterruptibly()
    catch (InterruptedException ex) { Thread.currentThread().interrupt(); return; }

lockInterruptibly() throws on entry, stopServer() returns having already flipped shuttingDown, so the handler is neither unregistered nor stoppable through that path again — and the change is still reported SUCCESS. Same shape, less sharply, in ServerHandler.shutdown(), whose writer.join(SHUTDOWN_JOIN_TIMEOUT) / reader.join(...) throw at once and are skipped.

It needs one modify changing both the listen port and the replication-server list, plus an interrupt of the config thread. Narrow — but "reported SUCCESS while part of it silently did not apply" is the class of failure this series removes. Restoring the flag after the work that would misread it keeps the contract:

// switchListenPort(): record it instead of re-asserting it here
catch (InterruptedException e)
{
  interruptedListenThreadStops.incrementAndGet();
  listenThreadStopInterrupted = true;   // field, not Thread.interrupt()
  logger.traceException(e);
}
// applyConfigurationChange(), just before `return ccr`
if (listenThreadStopInterrupted) { Thread.currentThread().interrupt(); }

replServerKeepsListeningWhenAPortChangeIsInterrupted passes unchanged: its change is port-only, so assertTrue(interrupted) still observes the flag on return.

Merge gate — not met (blocker for merge, not for the code)

Round 5's failures only ever reproduced on ubuntu. On the current head only Analyze (actions), Analyze (ruby) and build-maven (macos-latest, 26) have finished; all five build-maven (ubuntu-latest, ...) jobs, both windows jobs and Analyze (java-kotlin) are still pending. macOS was green with the broken helper, so the one green build job is not evidence. Same gate as round 6 — the run just needs to finish.

Nits

  • waitForListenThread() polls every 10 ms: opendj-server-legacy/src/test/java/org/opends/server/replication/server/ReplicationServerDynamicConfTest.java — that is a full VM thread dump per iteration in a JVM running a whole directory server, ~6000 of them on the 60 s failure path, which will dominate the timeout it is reporting. The passing case is satisfied in the first iteration or two, so 50-100 ms costs nothing. domainRegistrationsOf() has the same shape at 10 s.
  • "the only connection that port ever gets": what makes the second wait conclusive, and it rests on hygiene this class lacks — openReplicationSession() (opendj-server-legacy/src/test/java/org/opends/server/replication/ReplicationTestCase.java:206) does not register the broker for cleanup, and replServerApplyChangeTest, replServerKeepsItsConfigurationWhenAPortChangeFails and this new test each leave one reconnecting until @AfterClass. A stale broker on a recycled port would satisfy the accepting=false wait spuriously. Pre-existing; a line in the javadoc would do.
  • localPorts stale for the whole join window: startListenThread(newListenSocket) (ReplicationServer.java:681) makes the new port accept, but localPorts.remove/add runs at :696-697, after a stopListenThread() that now blocks for as long as the previous thread takes to finish its current connection setup. Throughout that window isLocalReplicationServerPort(newPort) is false while getReplicationPort() already returns the new port, so a shutdown() landing there removes a port never added and leaks the old one into that static set for the life of the JVM. Predates the PR; only the window widened. Moving the two lines above stopListenThread() closes it.
  • toLowerCase() without a Locale: in waitForListenThread() and domainRegistrationsOf(). No dotted-I in these names, so theoretical — noted only because they are matched with equals().
  • #813 and the new assertions: assertNothingLeftBehind() matches replica-DB monitor names too, since FileReplicaDB's name embeds the domain's. The domain-scoped wait makes the race hard to hit, but if these three tests ever flake on ubuntu that is the first place to look — not a regression here.

…l-fast changelog read

The interrupt of a cut-short wait for the previous listen thread escaped into the rest of
applyConfigurationChange(): some of what follows the port switch is interruptible — stopping
the handlers of removed replication servers takes the domain lock interruptibly, after a
one-shot engageShutdown() — so a change combining a port change with a server list change
could leave a handler engaged but not stopped while reporting SUCCESS. switchListenPort()
now records the interrupt in a holder its caller passes, and applyConfigurationChange()
restores it once the rest of the change has run: a parameter rather than a field, so nothing
survives the call. localPorts is updated as soon as the new listen thread serves, instead of
trailing getReplicationPort() for as long as the wait for the previous thread blocks.

In the test, the two waits built on thread dumps poll every 50ms instead of every 10ms, so
that their failure path is not dominated by the dumps it takes, the thread names they match
with equals() are lowercased with Locale.ROOT, and the javadoc of waitForListenThread()
states the invariant it establishes — the thread is off accept() and cannot terminate until
its socket is closed — instead of claiming the connection is served, along with the
assumption that this connection is the only one its port ever gets.
@vharseko

vharseko commented Aug 3, 2026

Copy link
Copy Markdown
Member Author

All round-7 items are in, in c3b1349029.

The restored interrupt escaped into the rest of the change

Confirmed, including the sharp end of the chain: stopServer() one-shots engageShutdown()
before lock() throws, so the handler would stay engaged yet never stopped, unreachable
through that path again, while the change reported SUCCESS.

Fixed with one deviation from the proposed shape: the record is an AtomicBoolean which
applyConfigurationChange() passes to switchListenPort(), not a field. A field needs a
reset per change — a stale true left by an earlier change would re-interrupt a later one
which was never interrupted — and the parameter scopes it to the call, so the question does
not arise. The restore sits immediately before the final return ccr; the early return when
the switch fails restores nothing, since the catch only runs on the path which returns
true. replServerKeepsListeningWhenAPortChangeIsInterrupted passes unchanged, as you
predicted: its change is port-only, so the flag survives to its Thread.interrupted()
assertion — which now proves the deferred restore instead of the in-place one.

Nits

  • localPorts: the two lines moved above stopListenThread(), right after
    startListenThread() — in step with getReplicationPort() from the moment the new port
    serves, instead of trailing it for the whole join window. The only exception out of the
    region they moved over is the InterruptedException already caught, so the move loses no
    path they used to run on.
  • Poll interval: 50 ms in both thread-dump waits, waitForListenThread() and the drain
    loop over domainRegistrationsOf(), with a comment stating why the failure path sets the
    pace.
  • waitForListenThread() javadoc: rewritten on the invariant you named — off accept()
    and unable to terminate until its socket is closed, which is what stopping it does —
    instead of claiming the connection is served, and it now carries the assumption the second
    wait rests on: that this connection is the only one the port ever gets, which a stale
    broker of an earlier test reconnecting to a recycled port would break.
  • Locale.ROOT: on both toLowerCase() matched with equals(). The third one, in
    changelogVirtualAttributeNames(), predates this PR and matches with contains() against
    lowercase literals — left alone.
  • FileChangelogDB.getOrCreateReplicaDB() races shutdownDB(): a replica DB created during shutdown is never released #813: noted as the first place to look if these three tests ever flake on ubuntu.

The PR description carries a bullet for the deferred restore and the localPorts timing, and
its account of the interrupted-port-change test now says what the silent connection buys —
off accept(), the thread cannot terminate until its socket is closed — rather than placing
the thread in its handshake.

Tests

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='ReplicationServerDynamicConfTest'
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0

mvn -o -pl opendj-server-legacy verify -P precommit -Dit.test='org.opends.server.replication.**.*Test'
Tests run: 3482, Failures: 0, Errors: 0, Skipped: 0

On the merge gate: agreed — holding for all five build-maven (ubuntu-latest, …) jobs on
c3b1349029 before this is called done.

@vharseko
vharseko requested a review from maximthomas August 3, 2026 14:36
@vharseko
vharseko merged commit bed2b17 into OpenIdentityPlatform:master Aug 4, 2026
17 checks passed
@vharseko
vharseko deleted the issues/802-fail-fast-unreadable-changelog branch August 4, 2026 06:30
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug concurrency Thread-safety / race-condition bugs java Pull requests that update java code replication tests Test suites: fixing, enabling, un-disabling

Projects

None yet

Development

Successfully merging this pull request may close these issues.

FileChangelogDB.initializeDB() swallows ChangelogException: a replication server with an unreadable changelog starts anyway

2 participants