[#889] Keep a change the replay could not apply out of the ServerState - #892
[#889] Keep a change the replay could not apply out of the ServerState#892vharseko wants to merge 2 commits into
Conversation
…ut of the ServerState A change whose replay failed with anything other than NO_OPERATION, BUSY or UNAVAILABLE was recorded as replayed: the ServerState advanced past it, the replication server never sent it again, and an assured SAFE_READ ack went back to the originating master as if the change had been applied. The replica silently diverged while reporting itself fully caught up. The four solveNamingConflict() overloads collapsed two different outcomes into one "return true": the operation became a no-op after conflict resolution, and the operation simply failed. They now report a ConflictResolution, so replay() can tell them apart, and the four copies of the error log move to the single place which decides what to do. A failure of the server itself - the backend being offline or rebuilt, or the storage failing to serve the operation, which BackendImpl reports with the server-error-result-code - is now retried like an unavailable backend and, if it keeps failing, left out of the ServerState: the replication server still owns the change, so the session is restarted and the change is delivered and replayed again. Every failed replay reports the error in the ack, so an assured write is no longer told it is durable here, and counts in the new replayed-updates-failed monitor attribute. A change which can never be applied on this replica would otherwise stop it for good, so after MAX_REPLAY_ATTEMPTS deliveries it is skipped - but loudly, with the new UnreplayedChange alert telling the administrator that this replica has diverged and must be reinitialized. Failures which are not the server's fault keep being skipped as before, with the same ack, counter and alert. Tests: RemotePendingChangesTest covers the bookkeeping the fix relies on, UpdateOperationTest.failedReplayIsNotRecordedAsReplayed covers the redelivery and the give-up, and a new test in AssuredReplicationPluginTest covers the error ack, which the upstream TODO left untested.
maximthomas
left a comment
There was a problem hiding this comment.
The diagnosis is right and the direction is right — a replay failure must not advance the ServerState. But in the
exact scenario this targets, a backend outage failing several in-flight changes, the new recovery path restarts the
session without bound and re-applies changes that were already applied. Two blockers, three majors below. Nothing
was executed; all of it is traced from source.
The MAX_REPLAY_ATTEMPTS bound is unreachable (blocker)
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2639
The attempt count lives in two scalar fields, not a per-CSN map:
lastFailedCSNAttempts = csn.equals(lastFailedCSN) ? lastFailedCSNAttempts + 1 : 1;
lastFailedCSN = csn;A failure for a different CSN resets the count to 1, so attempts > MAX_REPLAY_ATTEMPTS (:2644) is only reached
when one CSN fails four times with nothing else failing in between. A backend outage fails every change in flight.
With two failing changes:
recover(c1) lastFailedCSN=null -> attempts=1 -> disableService/clear/enableService
recover(c2) c2 != c1 -> attempts=1 -> restart
RS resumes from a ServerState covering neither, resends both
recover(c1) c1 != c2 -> attempts=1 -> restart ...
The counter never leaves 1 and there is no sleep or backoff anywhere in :2623-2671. The escape hatch the PR
describes — "a change which can never be applied here does not stop the replica for good" — is dead code, and the
replica restarts its replication session indefinitely.
This holds single-threaded too; two CSNs alternating through one thread reset each other identically.
synchronized (replayFailureLock) at :2644 does not help: it makes the read-modify-write atomic, but one slot is
still one slot.
UpdateOperationTest.failedReplayIsNotRecordedAsReplayed misses it because it publishes exactly one DeleteMsg, so
the counter walks 1,2,3,4 and the skip fires as intended. A test with two concurrent failing CSNs would catch it.
Suggested: key the count on the CSN (a bounded map or small LRU), dropping entries on successful replay and on skip.
RemotePendingChanges.clear() re-arms OPENDJ-1115 (blocker)
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/RemotePendingChanges.java:212
clear() empties pendingChanges unconditionally, but commit() flushes only the contiguous committed prefix —
it breaks at the first uncommitted entry. This fix deliberately leaves the failing change uncommitted, so every
later change that another replay thread applies successfully stays in the map as committed-but-unflushed, with its
CSN absent from the ServerState. clear() drops those too.
c1 fails, stays uncommitted
c2, c3 applied OK but sit behind c1 -> ServerState covers none of the three
clear() -> all three forgotten
enableService() -> RS resends c2, c3 -> putRemoteUpdate() now returns true (map is empty)
-> c2, c3 replayed and acked a second time
That putRemoteUpdate() check at LDAPReplicationDomain.java:4425 is the OPENDJ-1115 guard, and its own comment
says surviving pendingChanges is exactly what makes session failover safe. Correctness now rests entirely on
conflict resolution being idempotent for a replayed Add/Modify/Delete — the reliance OPENDJ-1115 was filed to remove.
The pre-existing session restarts (disable() at :3304, the fractional reconnect at :702/:729) do not call
clear().
Only the uncommitted changes need forgetting. Keeping the committed ones is still correct: once the failing CSN
commits, the prefix flushes and the state advances over them. A selective removal gets the stated benefit without
reopening OPENDJ-1115.
clear() runs against a replay queue nobody drained (major)
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/RemotePendingChanges.java:234
recoverFromReplayFailure does disableService(); clear(); enableService();. disableService() stops the broker
and joins the listener thread only — it never stops the replay threads, and updateToReplayQueue is a static
10 000-entry queue shared by every domain. Messages for this domain are still in it, pollable, while the map is
empty. Then:
// markInProgress, no null guard; activeAndDependentChanges is a ConcurrentSkipListSet
activeAndDependentChanges.add(pendingChanges.get(msg.getCSN()));Two outcomes, depending on whether the redelivered copy has re-run putRemoteUpdate() yet:
- not yet —
get()returnsnull,add(null)throws NPE intoReplayThread's catch-all.replay()never runs:
no replay, noprocessUpdateDone(), no assured ack, so the originating master waits out its SAFE_READ
timeout instead of getting the honest error ack this PR adds. OneERR_EXCEPTION_REPLAYINGper queued change. - already — the stale copy and the redelivered copy are both replayed: same CSN, two threads, one map entry. The
loser hitscommit()->NoSuchElementException->ERR_OPERATION_NOT_FOUND_IN_PENDINGand returns early, so it
is applied but never recorded.
switchQueueLock does not serialise this — it is released before domain.replay(), and clear() is reached from
inside replay(). A null guard alone would turn the first case into a silent drop; the queue needs draining for
this domain before clear().
The shutdown guard reads the wrong flag (major)
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2630
private boolean recoverFromReplayFailure(CSN csn, AtomicBoolean shutdown) {
if (shutdown.get() || disabled) return true;That shutdown is the parameter threaded down from replay(LDAPUpdateMsg, AtomicBoolean) — the ReplayThread's
flag — and it shadows the domain field at :352. disabled is set only inside disable(), and shutdown() (:2242)
calls disableService() directly rather than disable(), so it stays false. Neither guard sees domain shutdown.
MultimasterReplication.finalizeSynchronizationProvider() runs domain.shutdown() for every domain at :572 and
stopReplayThreads() only at :576, so the thread flag is false throughout — and that is precisely when replays fail,
because the backend is going offline and returns a code isServerFailure() now routes here. Both guards pass,
enableService() runs, ReplicationBroker.start() clears its own shutdown flag and reconnects: a broker and a fresh
listener thread come back up on a domain whose alert generator, flush thread and RSUpdater are already gone.
Before this PR no replay failure ever called enableService(). Checking the domain's own state (and renaming the
parameter — the shadowing is what hid this) is enough.
isServerFailure() keys off ResultCode.OTHER (major)
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2583
return result == ResultCode.UNAVAILABLE
|| result == getServerContext().getCoreConfigManager().getServerErrorResultCode();server-error-result-code defaults to ResultCode.OTHER — not a storage-specific code, but what the server returns
whenever nothing more specific applies. ReferentialIntegrityPlugin.java:1155 does
catch (Exception de) { stopProcessing(ResultCode.OTHER, ...) }, reached from doPreOperation(add):1054 and
doPreOperation(modify):985, neither guarded by isSynchronizationOperation(); SaltedSHA1PasswordStorageScheme
and SaltedSHA512PasswordStorageScheme do the same at :447/:451.
So a deterministic referential-integrity failure now costs, per delivery, ten rounds of Thread.sleep(50) at :2375
plus a full session restart, three times over — where before it fell into solveNamingConflict, was logged, and was
stepped over in one pass. It is also a realistic input for the first blocker: one misconfiguration fails many
changes at once.
Separately, the branch sits ahead of conflict resolution (:2375 vs :2386) and the knob is unvalidated —
GlobalConfiguration.xml:181 constrains it only with <adm:integer lower-limit="0"/> and CoreConfigManager does a
bare ResultCode.valueOf(). Setting it to 32, 66, 67 or 68 makes those codes bypass solveNamingConflict entirely.
Detecting the storage failure at its source — a marker exception type, or the exception cause — would be sturdier
than matching a configurable result code. Failing that, move the branch after conflict resolution.
Nits
replayed-updates-failedcounts attempts, not changes: the threenumFailedReplayedUpdates.incrementAndGet()
sites (:2441, :2467, :2512) are all insidereplay(), re-entered on every redelivery, whilereplayed-updates-ok
is incremented once per committed change (:2018). One unreplayable change contributes up to 4 — and unboundedly
once the first blocker fires.- Off-by-one in the skip:
attempts > MAX_REPLAY_ATTEMPTSwithattemptsstarting at 1 skips on the fourth
delivery, andERR_REPLAY_SKIPPING_CHANGE_308("after %d attempts") prints 4 while the constant and the PR
description both say 3. - The attempt counter is never reset:
lastFailedCSN/lastFailedCSNAttemptsare assigned only at :2639-2640
— not on a successful replay, not after a skip. A CSN skipped once is skipped again with zero retries if
redelivered; a change that fails, succeeds, then fails much later starts at attempt 2. - The new alert type is undocumented:
org.opends.server.replication.UnresolvedConflictis listed in
opendj-doc-generated-ref/src/main/asciidoc/admin-guide/chap-monitoring.adoc:2179and the docbkx copy at
chap-monitoring.xml:980;UnreplayedChangeappears in neither.enabled-alert-typeis an allow-list — "if
there are any values for this attribute, then only alerts with one of the specified types are allowed" — so an
operator with a non-empty list gets no notification of a diverged replica and no documented string to add. - A self-healing retry is logged at ERROR:
ERR_REPLAY_RETRYING_CHANGE_307fires vialogger.erroron every
attempt of a path the code expects to recover from; the neighbouring retry messages are
WARN_RETRYING_BIND_CHANGELOG_301/NOTE_BOUND_CHANGELOG_AFTER_RETRY_302. Worth aWARN_prefix — and worth
mentioning in the description, which announces onlyERR_REPLAY_SKIPPING_CHANGE. - The advertised retry-in-place success is untested: both new tests keep the short circuit registered for the
whole run, so all ten in-loop attempts fail and only the give-up path is observed — nothing shows that a transient
failure clearing within the window is replayed exactly once and committed. Both injectResultCode.OTHER, so the
UNAVAILABLEhalf ofisServerFailure()is unexercised, and the alert assertion is
assertThat(DummyAlertHandler.getAlertCount()).isGreaterThan(initialAlerts)— any alert emitted during the three
session restarts satisfies it, including one of a different type.
…nd forget only what was not replayed The count of failed replays lived in two scalar fields, so a backend which fails every change in flight had each of them reset the count of the previous one: the give up after MAX_REPLAY_ATTEMPTS was never reached and the replica restarted its session to the replication server without end. The count is kept per CSN now and dropped as soon as the change is replayed or given up on, and the session is left down for a moment before the change is asked for again. Restarting the session forgot every pending change, including the ones replayed while an older change was failing: those are not in the ServerState yet, so the replication server sends them again and an empty pending list had them replayed and acked a second time - the duplicate check of OPENDJ-1115. Only the changes which were not replayed are forgotten now, and putRemoteUpdate() no longer overwrites the copy which is listed with the one the new delivery came with, which lost the fact that it had been replayed. A message which is not the delivery listed as pending is dropped rather than replayed: it was waiting in the replay queue, shared by every domain, while the session was restarted. markInProgress() reports it instead of adding a null to activeAndDependentChanges, which threw an NPE into the replay thread and left the assured ack unsent. A duplicate delivery no longer has the listener push its CSN to the ServerState either: the copy which is listed owns the change and records it once it really has been replayed, while the ack and the window credit stay per delivery. The guard of the recovery read the AtomicBoolean of the replay thread, which shadowed the field of the domain, and the "disabled" flag which shutdown() does not set: a replay failing while the domain was being shut down brought a broker and a listener thread back up on it. It reads the state of the domain now, and reads it again after the wait. isServerFailure() no longer takes a change away from conflict resolution: server-error-result-code is configurable and is not validated as a result code, so the codes solveNamingConflict() solves are excluded from it. replayed-updates-failed counts changes really skipped, not attempts; the change is skipped on the MAX_REPLAY_ATTEMPTS-th attempt and the message says so; the retry is logged as WARN_REPLAY_RETRYING_CHANGE; the UnreplayedChange alert is documented in the admin guide and is not raised again for a minute, since one cause makes every change in flight unreplayable. Tests: two changes failing at once are both given up on, a failure which clears within the retry window has its change replayed exactly once, committed changes survive a session restart and the previous delivery of a change is not replayed.
|
Thanks - the review was traced from the source and it holds. Both blockers and all three majors are fixed in 8d3a0cc, together with every nit. Two of the fixes turned out to need more than what was suggested, and one of the majors is answered rather than applied; details below. The
|
Fixes #889.
A change whose replay fails with anything other than
NO_OPERATION,BUSYorUNAVAILABLEis recorded as replayed: the ServerState advances past it, the replication server never sends it again, and an assured (SAFE_READ) ack goes back to the originating master as if the change had been applied. The replica silently diverges while reporting itself fully caught up, withunresolved-naming-conflictsat 0 and a single line in the error log. This is storage-agnostic: JE, PersistIt and JDBC all reach it on anyStorageRuntimeException.What changed
The four
solveNamingConflict()overloads no longer collapse two outcomes into onereturn true. They report aConflictResolution(REPLAY_AGAIN/NOTHING_TO_DO/FAILED), soreplay()can tell "the operation became a no-op after conflict resolution" from "the operation failed". The four copies of theERR_ERROR_REPLAYING_OPERATIONlog move to the single place which decides what to do with the failure.A failure of the server itself is no longer recorded as applied.
UNAVAILABLEand theserver-error-result-code- the codeBackendImpl.createDirectoryException()puts on everyStorageRuntimeException, 80 by default - are retried in place, and if they keep failing the change is deliberately left out of the ServerState. The replication server still owns it, so the domain restarts its session and the change is delivered and replayed again on a backend which has hopefully recovered. The codes conflict resolution knows how to solve (NO_SUCH_OBJECT,ENTRY_ALREADY_EXISTS,NOT_ALLOWED_ON_RDN,NOT_ALLOWED_ON_NONLEAF) are excluded from that test:server-error-result-codeis configurable and is not validated as a result code, and it must never take a change away fromsolveNamingConflict().The bookkeeping of the pending changes follows.
RemotePendingChanges.clearUncommitted()forgets the changes which were not replayed, soprocessUpdate()does not discard them as duplicates when the replication server sends them again (the check of OPENDJ-1115). The ones which were replayed stay: they sit behind the failing change, so the ServerState does not cover them yet and they are sent again too - forgetting them would have them applied and acked a second time. Two things follow from keeping them:putRemoteUpdate()no longer overwrites the copy which is listed with the one the new delivery came with (which lost the fact that it had been replayed), and a duplicate delivery no longer has the listener thread push its CSN to the ServerState - the copy which is listed owns the change and records it once it really has been replayed, while the ack and the window credit stay per delivery. A message left in the replay queue by the restarted session is dropped when a replay thread takes it out:markInProgress()only accepts the delivery which is listed as pending.Every failed replay is now reported.
replayErrorMsgis set on all failure paths, so the SAFE_READ ack carries the replay error instead of telling the originating master that the write is durable here. The newreplayed-updates-failedmonitor attribute counts the changes this replica gave up on - once each, likereplayed-updates-okcounts the ones it applied.A change which can never be applied here does not stop the replica for good. The failures are counted per CSN - a backend which is failing fails every change in flight, and a single counter would be reset by each of them in turn - and on the
MAX_REPLAY_ATTEMPTS-th (3rd) failed attempt the change is skipped, but loudly:ERR_REPLAY_SKIPPING_CHANGEplus the newUnreplayedChangealert telling the administrator that this replica has diverged and must be reinitialized. The attempts in between are logged asWARN_REPLAY_RETRYING_CHANGE, and the session is left down for a moment before the change is asked for again, so that a backend which keeps failing is not asked for every change as fast as the replication server can send them.What deliberately did not change
Failures which are not the server's fault - a schema or constraint violation, or the conflict-resolution loop of #798 - keep being skipped, as they always were: redelivering them cannot help, and stopping the domain on them would turn a one-entry divergence into an outage. They now carry the same honest ack, counter and alert, so the divergence is visible instead of silent. Restarting the session on those failures was tried first and is what
UpdateOperationTest.infiniteReplayLoopandnamingConflictsrightly rejected.Tests
RemotePendingChangesTest(new)clearUncommitted()forgets the changes which were not replayed and lets the same CSN be accepted again, while the ones which were replayed stay and are not accepted again; only the delivery which is listed as pending is replayedUpdateOperationTest.failedReplayIsNotRecordedAsReplayed(new)UnreplayedChangealertUpdateOperationTest.everyChangeWhichCanNotBeReplayedIsGivenUpOn(new)UpdateOperationTest.transientReplayFailureIsRetriedAndTheChangeApplied(new)UNAVAILABLEbackend which serves the operation again within the retry window has its change replayed exactly once, with no session restart and nothing counted as failedAssuredReplicationPluginTest.testSafeReadModeReplyWithReplayError(new)hasReplayErrorandfailedServers=[1]The
AssuredReplicationPluginTestone closes a TODO which has been in the tree since upstream: "make the domain return an error: use a plugin? The resolution code does not generate any error so we need to find a way to have the replay not working to test this...". The short circuit has to be set at the pre-parse plugin point -LocalBackendDeleteOperationand friends skip the pre-operation plugins for synchronization operations.UpdateOperationTest,NamingConflictTest,AssuredReplicationPluginTest,ModifyConflictTest,DependencyTest,IsolationTest,StateMachineTestandRemotePendingChangesTest: 82/82 green.