[#802] Fail fast when the replication server cannot read its changelog - #805
Conversation
maximthomas
left a comment
There was a problem hiding this comment.
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_DBhad exactly one logging site and it is now removed. The text reaches the operator only insideERR_CONFIG_SYNCH_ERROR_INITIALIZING_PROVIDER, rendered throughstackTraceToSingleLineString()— 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()closeslistenSocketbeforelistenThread.join(). If the join is interrupted, the catch restoresconfig/serverURLand 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()andinitialize()(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()embedsserverURL, which isnullwhileinitializeDB()registers and non-null whenderegisterMonitorProvider()looks the name up, so the key never matches. Worth its own issue; the loop requested above does not fix it.
|
Thanks — all of it addressed in the last commit, including the two items you left as Aborted initialization leaks the per-domain timer threadConfirmed and fixed: Your reading of Startup semantics change needs an explicit sign-offSigned off: a replication server which cannot read its changelog fails to start, and takes Test covers one of the three documented failure shapesShape 2 is covered now, by Two more tests come with it: Both were checked against the unfixed code: with the loop removed from Shape 3 is still uncovered on purpose: it needs Nits
|
…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.
…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.
83b9e25 to
ec16a29
Compare
maximthomas
left a comment
There was a problem hiding this comment.
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>.id → head.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_THREADhas zero call sites after theswitchListenPort()rework, but remains inReplicationMessages.javaand nine locale files. Same release-note treatment as msgID 11, or drop it. - Double-listen window: both ports accept between
startListenThread(newListenSocket)atReplicationServer.java:667andclose(previousListenSocket)at:671, andlocalPortsstill 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. replServerKeepsListeningWhenAPortChangeIsInterrupteddoes not reliably exercise the interrupt path:Thread.join()only throws whileisAlive(). If the previous listen thread has already exited,join()returns without throwing and the pre-set flag is never cleared, soassertTrue(interrupted)passes without the catch block running. Verified on JDK 26:join()on a terminated thread with the interrupt set givesthrew=false, interruptStillSet=true. Assert on something only the catch produces.abortInitialization()robustness: an unchecked throw fromdomain.shutdown()atReplicationServer.java:781-784skipsshutdownExternalChangelog()andchangelogDB.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.
|
Blocker confirmed and fixed, and it was worse than the review says. Everything else is in too. The changelog wait matched the change number indexReproduced the whole chain: One addition to the diagnosis. Where the review says the test "passes while exercising a Fixed as proposed: On top of that the test now asserts that the failure names the log it corrupted, so it cannot
The replica DB created during shutdownAgreed, and filed as #813 with your analysis and your patch. Two corrections which do not
Nits
Tests |
maximthomas
left a comment
There was a problem hiding this comment.
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 connectionRelated 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
listenThreadis not volatile whilelistenSocketis:switchListenPort()atReplicationServer.java:667now 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 atReplicationServer.java:109, and it removes the asymmetry with thevolatile ServerSocket listenSocketon the line above.waitForListenThreadOf()hardcodesrs(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 — passreplicationServer.getServerId()..domduplicated from a private constant:DOMAIN_DIRECTORY_SUFFIXmirrorsReplicationEnvironment.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 inwaitForReplicaLogFile()beforeassertNotNullreports it.abortInitialization()catchesRuntimeException, notError: given the stated intent — "what follows still has to run" over a changelog known to be broken — anErrorstill skipsshutdownExternalChangelog()andshutdownDB(). 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.
|
All round-6 items are in, in
|
maximthomas
left a comment
There was a problem hiding this comment.
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, andreplServerApplyChangeTest,replServerKeepsItsConfigurationWhenAPortChangeFailsand this new test each leave one reconnecting until@AfterClass. A stale broker on a recycled port would satisfy theaccepting=falsewait spuriously. Pre-existing; a line in the javadoc would do. localPortsstale for the whole join window:startListenThread(newListenSocket)(ReplicationServer.java:681) makes the new port accept, butlocalPorts.remove/addruns at:696-697, after astopListenThread()that now blocks for as long as the previous thread takes to finish its current connection setup. Throughout that windowisLocalReplicationServerPort(newPort)is false whilegetReplicationPort()already returns the new port, so ashutdown()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 abovestopListenThread()closes it.toLowerCase()without aLocale: inwaitForListenThread()anddomainRegistrationsOf(). No dotted-I in these names, so theoretical — noted only because they are matched withequals().- #813 and the new assertions:
assertNothingLeftBehind()matches replica-DB monitor names too, sinceFileReplicaDB'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.
|
All round-7 items are in, in The restored interrupt escaped into the rest of the changeConfirmed, including the sharp end of the chain: Fixed with one deviation from the proposed shape: the record is an Nits
The PR description carries a bullet for the deferred restore and the TestsOn the merge gate: agreed — holding for all five |
Fixes #802.
Builds on #795, now merged: the cleanup of a half initialized replication server
(
abortInitialization()) comes from there. Rebased onmaster, so this PR carries only itsown commits.
Problem
FileChangelogDB.initializeDB()caughtChangelogExceptionand only loggedERR_COULD_NOT_READ_DB— a message whose own text says "The replication server failed tostart 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 areplication 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:
ReplicationEnvironmentcould not be created at all (unreadable or incoherentdomains.state, corruptedoffline.state):replicationEnvstaysnulland the rest ofFileChangelogDBdereferences it unguarded. The first update to persist ends in aNullPointerExceptioninFileReplicaDB.createLog()— and because that is not aChangelogException, it does not even reach the handler inReplicationServerDomain.publishUpdateMsg(), which exists precisely to shut the replicationserver down when the changelog cannot be written (
ERR_CHANGELOG_SHUTDOWN_DATABASE_ERROR).applyConfigurationChange()hits the samenullthroughsetPurgeDelay().their generation id, the others did not. For those,
setGenerationIdIfUnset()then adoptsthe generation id of the first replica to connect — without clearing the changelog, which
changeGenerationId()does — over on-disk logs which belong to another generation, andgetOrCreateReplicaDB()writes a secondgeneration<id>.idfile next to the existing one.On the next start
retrieveGenerationIdFile()picksgenerationIds[0], i.e. whichever thefile system returns first.
cn=changelogsilently answers from anindex which is not maintained, and the changelog is never purged.
Changes
ChangelogDB.initializeDB()declaresthrows ChangelogException, and documents that theDB may be left half open and must then be released with
shutdownDB().FileChangelogDB.initializeDB()wraps the cause in the same localizedERR_COULD_NOT_READ_DBmessage — which already names the changelog directory — andrethrows it instead of logging it. Logging happens once, where the failure is reported.
ReplicationServer.initialize()reports it as aConfigException, exactly like a listenport 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, asshutdown()does. Reading thechangelog restores one
ReplicationServerDomainper domain it holds, and each of themstarts its assured timer and its status analyzer threads, and registers its monitor
provider —
getReplicationServerDomain()callsstart()since Fix CodeQL warning-severity alerts: missed wakeups, resource leaks, escaping threads #790. Every failure of thatreading happens after that first loop —
getReplicationServerDomain()andinitGenerationID()cannot throw — and so does a listen port which cannot be bound, soboth 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.one through a shared
stopListenflag. A port change can then start the new listenerbefore 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 theconfiguration thread, and a stale read would skip the wait it was captured for.
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 interruptstatus left set would have failed those steps while the change reported SUCCESS.
localPortsis updated as soon as the new listener serves, instead of trailinggetReplicationPort()for as long as the wait for the previous listen thread blocks.FileChangelogDBis the only implementation andReplicationServer.initialize()the onlycaller; the
ChangelogDBused inChangeNumberIndexerTestis a Mockito mock, unaffected bythe 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:
the directory server. The
ConfigExceptionpropagates fromMultimasterReplication.initializeSynchronizationProvider()throughSynchronizationProviderConfigManager.initializeSynchronizationProviders()toDirectoryServer.startServer(). Previously such a server came up degraded, without a usablechangelog, and the failure surfaced later and somewhere else. This is a larger blast radius
than the existing
ERR_CHANGELOG_SHUTDOWN_DATABASE_ERRORpath, which stops the replicationserver 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.ERR_COULD_NOT_READ_DBhad exactly one logging site, inFileChangelogDB.initializeDB(), and it is now thrown instead. Its text still reaches thelog, but inside
ERR_CONFIG_SYNCH_ERROR_INITIALIZING_PROVIDER— CONFIG category, renderedthrough
stackTraceToSingleLineString(). Anyone alerting on msgID 11 has to follow itthere.
ERR_COULD_NOT_STOP_LISTEN_THREADreported a portchange 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()declaresthrows ChangelogException. Source incompatiblefor out-of-tree implementations of that interface.
Tests
ReplicationServerDynamicConfTest:replServerFailsWhenChangelogCannotBeRead: the first shape, a corrupteddomains.state.The creation fails with a
ConfigExceptionwhose cause is theChangelogExceptionandwhose message names the changelog directory, leaves no instance registered in
ReplicationServer.getAllInstances(), and leaves the listen port free — it is never boundwhen 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. Thereplication 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 beforethe 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 keepsthat thread busy with a connection which says nothing — off
accept(), it cannot terminateuntil its socket is closed — and asserts
interruptedListenThreadStops, which only the interrupted path increments: the test cannotpass 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 itafterwards — since a connection completes against the listen backlog of the kernel and a
bound socket says nothing of the thread which serves it.
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 therestored domain left behind.
The whole replication package passes as well:
Follow-up
#813, found while these tests were being stabilised: a
FileReplicaDBcreated while thechangelog 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.