[#956] Tell a failed entryUUID search apart from an entry which is not there - #968
Conversation
|
Ordinal moved: Six open branches had each read 310 as the first ordinal free in master and taken it - #935, #945, Nothing catches this on the way in. The additions land in different parts of the file, so git merges The open PRs which add to the file now hold 310-325 with nothing claimed twice:
No Java moved with it: the generated constant is the key name without its ordinal, so the rename is |
4110d0c to
bdb4f49
Compare
|
Rebased on master; the conflict was #948 moving the block this change rewrites (bdb4f49) Master carries #948 now, which put the whole in-place attempt of a replayed change - building the Resolved by dropping the copy this branch carried and applying its three edits to the block where
The 50 ms are now waited holding the replay read lock, which is where the
The diff is the same 270 insertions / 37 deletions over the same three files as before the rebase, |
bdb4f49 to
d68a79c
Compare
|
Rebased again, on master with #965 (d68a79c) #965 landed while this was waiting, and it reads the same entryUUID search this change is about: The conflict was in The diff is unchanged at 270 insertions / 37 deletions over the same three files. The The |
maximthomas
left a comment
There was a problem hiding this comment.
praise: the fix is small and lands where the read happens.
SearchFailedException is thrown at the one site that reads the data (findEntryDN),
every caller either answers SEARCH_FAILED or stops the pre-op with UNAVAILABLE, and the
replay loop needs one flag on top of the server-failure retry it already had. NamingConflictTest
is 10/10 at HEAD, and the OOME / alert contract below the loop is untouched. The comments at
LDAPReplicationDomain.java:2876-2894 and the PR body state the deliberate choices (the parse
failure retried, the error naming the conflict code) instead of leaving the reader to guess, and
ShortCircuitPlugin with a bounded maxTimes is the right tool for "fails, then serves again".
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:3524
issue (blocking): findEntryDN() now throws on NO_SUCH_OBJECT, so a replayed Add of the
domain base entry into an empty replica never lands.
Two empty replicas share EMPTY_BACKEND_GENERATION_ID (48), so no initialize is needed and the
first change replayed is the base entry itself. Its pre-op hook runs findEntryDN(uuid) at
:1856, before the parentEntryUUID == null short-cut at :1875. A backend that serves the base
DN but has no base entry answers NO_SUCH_OBJECT on every route (EntryContainer.fetchBaseEntry);
there is no "SUCCESS with zero entries" path. At BASE that was null -> the Add went through. At
HEAD it is SearchFailedException -> UNAVAILABLE -> 10 attempts -> redeliveries until
replay-give-up-delay (300 s) -> the change is skipped with a "replica diverged" alert.
The same code comes back when no backend serves the DN (SearchOperationBasis:1211,
backend offline or being rebuilt), which is the case this PR must keep catching — so a bare
NO_SUCH_OBJECT whitelist would reopen #956. Ask the backend instead:
if (search.getResultCode() != ResultCode.SUCCESS)
{
if (search.getResultCode() == ResultCode.NO_SUCH_OBJECT && baseEntryIsAbsentFromALiveBackend())
{
// The backend serves the base DN and has no base entry yet: the search ran, and nothing
// is below a base entry which is not there. This is the empty replica about to receive it.
return null;
}
throw new SearchFailedException(uuid, ...);
}
private boolean baseEntryIsAbsentFromALiveBackend()
{
final LocalBackend<?> backend =
getServerContext().getBackendConfigManager().findLocalBackendForEntry(getBaseDN());
if (backend == null)
{
return false; // nothing serves the DN: offline or being rebuilt - the search did not run
}
try
{
return !backend.entryExists(getBaseDN());
}
catch (DirectoryException e)
{
return false; // the storage failed to answer - the search did not run
}
}And a test that would have caught it — no test in src/test/.../replication replays the
base-entry AddMsg into a backend without one:
@Test
public void baseEntryIsAddedToAnEmptyReplica() throws Exception
{
TestCaseUtils.initializeTestBackend(false); // the backend, without its base entry
final Entry base = TestCaseUtils.makeEntry("dn: " + TEST_ROOT_DN_STRING,
"objectClass: top", "objectClass: organization", "o: test");
final CSN csn = gen.newCSN();
replayMsg(addMsg(base, csn, null, "7c1a0d2e-4b6f-4c8a-9e1d-3f5b7a9c1e2d"));
assertTrue(DirectoryServer.entryExists(base.getName()),
"the base entry of an empty replica must land: its search found nothing, it did not fail");
assertTrue(domain.getServerState().cover(csn));
}opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2899
issue (blocking): the exhaustion exit — || searchFailedResolvingConflict, the half of the
fix that closes #889 — is pinned by no test.
Both new cases fail the search 2 and 3 times against a budget of 10 and then succeed, so the loop
leaves on replayDone and the gate is never reached with this flag as the deciding term. Measured:
with the term removed, NamingConflictTest is still 10/10; with the whole case SEARCH_FAILED
arm deleted (falls into default:), still 10/10. A regression of the exact #889 shape — attempts
spent, CSN committed, change lost — passes CI.
@Test
public void modifyIsLeftOutOfTheServerStateWhenTheEntryUUIDSearchNeverRuns() throws Exception
{
final Entry entry = createAndAddEntry("modifyWhoseSearchNeverRuns");
final String entryUUID = getEntryUUID(entry.getName());
final DN staleDN = DN.valueOf("cn=movedAway," + TEST_ROOT_DN_STRING);
final CSN csn = gen.newCSN();
// No maxTimes: every attempt in place fails its search.
ShortCircuitPlugin.registerShortCircuit(OperationType.SEARCH, "PreParse", ResultCode.UNAVAILABLE.intValue());
try
{
replayMsg(new ModifyMsg(csn, staleDN, generatemods("telephonenumber", "01 02 45"), entryUUID));
}
finally
{
ShortCircuitPlugin.deregisterShortCircuit(OperationType.SEARCH, "PreParse");
}
assertFalse(domain.getServerState().cover(csn),
"a change whose search never ran is not in the data and must not advance the ServerState");
assertTrue(ShortCircuitPlugin.getShortCircuitCount(OperationType.SEARCH, "PreParse") >= 10,
"every attempt in place must have made its search");
}This assert kills the mutant: without the term the gate falls into the ERR_LOOP branch at
:2913-2924, which commits the CSN. (The exit requests a session restart; the fixture has no
replication server, so if that blocks, replay with a shutdown flag set to true so
runRequestedSessionRestarts(false) returns at once.)
opendj-server-legacy/src/test/java/org/opends/server/replication/plugin/NamingConflictTest.java:328
issue (blocking): this comment, and the PR's "searches ... are treated the same way",
describe a flow the test does not run; the parent-search catch at
LDAPReplicationDomain.java:1884-1887 is never reached.
Every attempt makes the first findEntryDN(uuid) at :1856; under the short circuit it fails and
the hook returns before :1882. maxTimes=3 is three attempts, one failed search each; the
fourth attempt passes every search. Measured: reverting the parent catch to BASE semantics
(parentDnFromCtx = null) keeps the class 10/10. Of the three new production lines in the hook the
test sees one.
Minimum: fix the comment (one search per attempt, the first one) and the PR text, and say the
parent catch is pinned by symmetry with :1858, not by a test. ShortCircuitPlugin cannot select
by filter, so pinning the parent search itself needs a skip-first-N short circuit or a filter-aware
one — worth it only if the plugin grows that anyway.
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2765
suggestion (non-blocking): WARN_REPLAY_ENTRYUUID_SEARCH_FAILED is logged once per attempt
in place — up to 10 lines per delivery, plus 10 more for every redelivery
(WARN_REPLAY_RETRYING_CHANGE at :3296 is one per delivery). The sibling isServerFailure arm
at :2692 logs nothing per attempt. A backend offline for the whole 300 s budget on a busy domain
is changes x 10 x redeliveries lines. Log once per delivery — on the first SEARCH_FAILED, or at
the exhaustion exit where the failure is already reported.
opendj-server-legacy/src/test/java/org/opends/server/replication/plugin/NamingConflictTest.java:291
suggestion (non-blocking): neither new case checks that the short circuit fired. A run where
it never does (plugin not loaded in the fixture, search routed elsewhere) stays green on the
sibling assertions. One line per case, after deregisterShortCircuit:
// The count includes the searches let through once maxTimes was spent: > 2 says the
// budget was used and the search after it ran.
assertTrue(ShortCircuitPlugin.getShortCircuitCount(OperationType.SEARCH, "PreParse") > 2,
"the short circuit must have been spent by the attempts in place");opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2756
suggestion (non-blocking): the SearchFailedException -> SEARCH_FAILED switch serves all
four conflict resolutions, but only Modify and Add have a case; Delete and ModifyDN are pinned by
nothing. Same mechanism, so low risk — either one case each (a DeleteMsg / ModifyDNMsg on a
stale DN with maxTimes=2, same assertions as the Modify case), or a sentence in the PR saying
they ride on the shared switch.
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:3517
note (non-blocking): a filter that does not parse is a permanent condition retried as a
transient one — 10 attempts, then redeliveries until the give-up budget, for an entryUUID that
will never parse. The PR body says this is deliberate and the cost is bounded, so nothing to
change; only noting that this branch is reached by no test, and that the unescaped
"entryuuid=" + uuid it guards is pre-existing.
…d, and look the entryUUID up as a value Review round 1 of OpenIdentityPlatform#968. A backend which serves the base DN and has no base entry answers NO_SUCH_OBJECT to a search under it, on every route - and so does a backend which is not there. findEntryDN() read every non-SUCCESS code as a search which did not run, so the base entry of a domain replayed into an empty replica was retried until the give-up budget skipped it: two empty replicas share the generation ID of an empty backend, and the base entry is the first change. baseEntryIsAbsentFromALiveBackend() asks the backend which of the two it is. The entryUUID is looked up as the value it is rather than read as part of a filter string: it comes off the wire and nothing validates it as one, and a value which does not parse as a filter was a search which never runs, retried as a transient failure for as long as the change was asked for. There is no filter to parse now, and no branch left. Nothing is logged per attempt in place any more, as nothing is for a storage which failed to serve the operation: the attempt keeps the search failure and the exhaustion exit reports it in the ERR_ERROR_REPLAYING_OPERATION line it already logs, in place of the error of the operation, which for this case only named the conflict. The Add hook puts the same text on the operation it stops. The message is ERR_REPLAY_ENTRYUUID_SEARCH_FAILED now that it is never logged on its own; the ordinal stays. Tests: the exhaustion exit is pinned by a case whose search never runs; Delete and ModifyDN get a case each; the Add hook is three cases, one per search, on a ShortCircuitPlugin which can let the first searches through before it applies; every bounded short circuit asserts, before it is deregistered, that its budget was spent and the search after it ran; the base entry of an empty replica and an entryUUID no filter string parses each get a case.
|
Review round 1 addressed (68cff84)
|
… this replica, and keep the replay out of the data it replaces A change queued for replay before the InitializeTargetMsg arrived was replayed into no backend: preBackendImport() takes the backend away without disabling the domain, so the operation got NO_SUCH_OBJECT, the entryUUID search did not run, and once the attempts in place were spent the session was restarted for the change to be delivered again - the session the import was reading. The import ended on the entries which had arrived and was reported as finished, since receiveEntryBytes() records no exception for a broker which is shutting down. importBackend() now holds the replay off the way disable() does - a flag the replay threads read where they read `disabled`, and the drain of the attempts in flight - before the backend is taken away; the restart after a failed or abandoned replay is refused for the whole of the total update (sessionHasAnOwner(): ownsItsSession() || importInProgress()), from the request rather than from the first entry; and once the state is loaded from the imported data, the pending changes, the restart request and the backoff are reset, as disable() resets them - a change given back during the import would otherwise stay listed and uncommitted, and hold the ServerState back for good, since the imported state already covers it. Review round 3, with the flush thread's Modify kept out of the MODIFY short circuit (a predicate on the replayed operation, pinned by the case making that Modify inside the window) and the text of the exhaustion exit asserted positively.
03ed5cf to
3368a1d
Compare
|
Review round 3 addressed, and rebased on master with #974 (3368a1d)
The rebase: #974 landed since round 3 and moved
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: the blocker is closed for real, and pinned.
ReplayDuringImportTestrun over the previous head's production code is red 2/2 (case 1 at:159, on its own assertion); at head it is green,NamingConflictTest18/18.- The fix has the right shape: the total update owns the session from the request (
sessionHasAnOwner()), andimportingDatagives a queued change back on its first attempt instead of its tenth — the half the round-4 sketch did not have. ShortCircuitPlugin.registerShortCircuit(..., Predicate<PluginOperation>)withcsn.equals(OperationContext.getCSN(op)): the flusher's Modify has no CSN, so the short circuit is blind to it by construction, not by timing.- The 322 wording now has its positive twin (
NamingConflictTest.java:585-590:isNotEmpty()and every record names the entryUUID). - The rebase over #974 is textually identical to the reviewed head (range-diff
=on all four commits). - The silent truncation named in round 4 is confirmed and filed as its own issue.
issue (blocking): the importingData hold-off is pinned by no test.
opendj-server-legacy/src/test/java/org/opends/server/replication/plugin/ReplayDuringImportTest.java:156-164
With || importingData deleted from both goingDown reads (opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:2818, :2831) the class is green 2/2: each replay ran its ten attempts into no backend and left through ERR_ERROR_REPLAYING_OPERATION; the session was saved by sessionHasAnOwner() at :3638 alone. The WARN_REPLAY_RETRYING_CHANGE check is negative by construction — the :3638 guard returns before that warn — so it is green under any mutant of this shape. One assertion pins the mechanism the commit message names:
assertThat(errorLogRecordsOf(ERR_ERROR_REPLAYING_OPERATION.ordinal(), csn))
.as("the change was attempted into no backend instead of being given back at once")
.isEmpty();Zero records at head, one under the mutant.
issue (blocking): two comments describe the road before this commit.
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:3327-3328
// The ack has been published and the change, still owned by the replication
// server, is being delivered again: there is nothing left to replay here.On the owner road nobody delivers it again until the import restarts the session. Suggested:
// The ack has been published and the change is given back: the replication server
// delivers it again, now or - while a total update owns the session - after the
// import restarts it. There is nothing left to replay here.opendj-server-legacy/src/test/java/org/opends/server/replication/plugin/ReplayDuringImportTest.java:127-135
The javadoc says the attempts are spent and the restart truncates the import. At head the case never makes an attempt — the hold-off gives the change back at the top — and the truncation is what the case asserts does not happen. Describe the head road: the change is given back at once, the session is left to the import, every exported entry arrives.
suggestion (non-blocking): a request-window case would pin sessionHasAnOwner() at :3638 and the stated "from the request rather than from the first entry".
opendj-server-legacy/src/test/java/org/opends/server/replication/plugin/ReplayDuringImportTest.java
Neither case reaches :3638: with the hold-off up the replay leaves at :2818, so swapping sessionHasAnOwner() for ownsItsSession() there alone also survives. Shape: the ieCtx acquired before the InitializeTargetMsg arrives (a locally requested initialize, or its hook), backend live, the replay short-circuited to exhaustion — then assert the broker is still connected and sessionRestartRequested is false. Fixture work; a follow-up is fine.
issue (non-blocking): the owner read and the listener's acquireIEContext share no lock — a few-statement race, remote-initiated import only.
opendj-server-legacy/src/main/java/org/opends/server/replication/plugin/LDAPReplicationDomain.java:3787
opendj-server-legacy/src/main/java/org/opends/server/replication/service/ReplicationDomain.java:2561
A replay thread on the recovery road reads ieCtx == null at :3787, then disableService() → broker.stop(), while the listener CASes the ieCtx for an InitializeTargetMsg and enters importBackend: receiveEntryBytes returns null (ReplicationDomain.java:2130) and the import ends truncated — the round-4 shape, now a few statements wide instead of the whole import. Stopped before the dequeue, the listener exits and the InitializeTargetMsg is dropped on this replica. Needs a ten-attempt exhaustion timed at the message; rare. Not for this PR — a design change (the listener re-checks shuttingDown() after its CAS and records the stop as the import's exception, or the CAS takes the lock the restart guard holds). Please file it.
note (non-blocking): restartService() (the #974 configuration road, LDAPReplicationDomain.java:5486, :5558) still restarts under ownsItsSession() — an import in flight is not an owner there. isConfigurationChangeAcceptable refusing while ieRunning() (:5624-5627) covers it, except an import starting between acceptable and apply. "Not in this change" acknowledged; worth its own issue.
suggestion (non-blocking): an export-direction case.
importInProgress() is direction-aware by design: an export is not an owner, so a replay failure during an export restarts the session the EntryMsgs go out over. Pre-existing shape and the exporter reports the cut — but nothing pins that the split is intended. One case with acquireIEContext(false) (ReplicationDomain.java:1614) asserting the restart happens.
suggestion (if-minor): one sentence in the sessionHasAnOwner() javadoc (LDAPReplicationDomain.java:5544-5546): a change left listed also freezes the ServerState — RemotePendingChanges.commit() stops at the first uncommitted entry — and the persisted state with it, until that next restart.
…quest, and describe the road as it is The importingData hold-off was pinned by no test: with `|| importingData` deleted from both goingDown reads, the change was attempted ten times into no backend and the session was saved by sessionHasAnOwner() alone, which the retry-warning check could not tell from the hold-off - that guard returns before the warning. aReplayDuringTheImportLeavesTheSessionToTheImport now asserts that no ERR_ERROR_REPLAYING_OPERATION record names the change: none at head, one under that mutant. sessionHasAnOwner() in recoverFromReplayFailure() was reached by neither case, since the hold-off gives the change back at the top of its first attempt. aRequestOnItsWayOwnsTheSessionTheAnswerArrivesOver reaches it: a total update this replica asked for, the answer held by the exporter, the backend live, a change whose entryUUID search never runs spent in place - the exhaustion exit reports it, no retry warning follows, and the import then runs to its end over the session the request was made over. With that guard on ownsItsSession() alone, the warning is logged and the case is red on it. Two comments described the road before the previous commit - the change given back is delivered again after the import restarts the session, not now, and the first case of ReplayDuringImportTest never spends an attempt - and the javadoc of sessionHasAnOwner() says that a change left listed holds the ServerState back, in memory and as persisted, until the next restart. Review round 4.
|
Review round 4 addressed (00798ab)
|
…a configuration change asks for a restart A configuration change which restarts the session of a domain for what it carries - the broker properties, the assured or fractional configuration, the attributes published to the external changelog - restarted it while a total update into this replica was reading it: restartService() and allowReconnection refused the restart under ownsItsSession() alone, and a total update into this replica never sets disabled. Made through the server configuration the restart does not end: the change holds the lock of the configuration, disableService() joins the listener thread the import runs on, and the import needs that lock to enable the backend back once its stream ends - the change never returns, and every configuration change of the server, the shutdown of the domain and every later total update wait behind it. The external changelog entry accepted every change, and the domain entry one which started an import between "acceptable" and "apply". restartService() and allowReconnection take sessionHasAnOwner(), the predicate OpenIdentityPlatform#968 gave the restart a failed replay asks for; the restart is reported as it is for a disabled domain, and the import starts the next session itself when it ends, on the configuration stored meanwhile. The listener of the external changelog entry refuses a change while a total update runs, as the listener of the domain entry does. Message 327 names the third case. ConfigChangeDuringImportTest: the change of the external changelog entry made through the server configuration while the import streams is refused - on the base it does not return, and the case captures the two stacks and interrupts it - the domain entry refuses as it did, and the two restarts reached directly leave the session to the import and report it.
…backoff is forgotten, and pin every reset Review round 2. The count of deliveries folded into no warning went back to zero where a change was replayed and nothing was failing anymore, and nowhere else: disable() cleared the pending changes and the session restart backoff and left the count, as did the end of a total update - the same triple, landed by OpenIdentityPlatform#968 after the review - and so did giving up on the change which was the last one failing. The first warning over the next failure, a day later, then read as counting the deliveries of the failure before. The count goes with the backoff in disable() and after the import now, and on the give-up road it goes alone, under the guard the recovery reset has: the backoff deliberately stays there, and ERR_REPLAY_SKIPPING_CHANGE reports every delivery the change had, so nothing is lost. Neither zeroing of the count was pinned - the test reset zeroed it itself. It resets the timestamp only now, the interval is a @VisibleForTesting knob the way the drain timeout is, and five cases pin one mechanism each, watched red on the mutant which removes it: the third warning of a change which keeps failing stands for the deliveries since the second one only, and the first warning over a new failure says 0 further after a change was replayed, after one was given up on, after the domain was disabled and enabled, and after a total update. The warning says "without a warning of their own" rather than "without being logged" - the folded deliveries are traced - and the test reads it by message rather than by record: the two error log publishers of the test server read the clock one after the other, so a second turning over between them would count one warning as two. Each message is counted half as many times as it is kept, since two warnings read the same to the letter once the domain has forgotten the change and asks for it again.
…count the wakes, and pin the clears and the give-back level Review round 2. - SessionRestartBackoffTest times disable() as it times shutdown(), against the one bound both wakes share: a checkpointer which sleeps the backoff through while it holds the monitor holds disable() for the rest of it, and the disable case was green under that shape of the sleep mutant. Both shapes are in the mutant table now. - The wake of the backoff is counted as well as flagged, and the count is read where the session is stopped, under serviceStateLock: `disabled` does not stay set, so a checkpointer descheduled between disable()'s notifyAll() and its own re-check for as long as enable() takes would wait out the rest of the backoff for a session it has nothing left to start. - aSessionRestartWhichCouldNotRunIsRunAgain accepts the checkpointer's report twice, on the road its own comment names: its tick landing between the replay thread's request and the CAS. - requestSessionRestart() (@VisibleForTesting) leaves a request standing, and two cases pin the clears in enable() and importBackend() on it - the second in OpenIdentityPlatform#968's ReplayDuringImportTest, which has the import fixture. - aRestartAskedForWithoutTheBackoffIsGivenBackWithIt pins the level a restart which could not run is given back with, on the abandonReplay() road OpenIdentityPlatform#941's fixture reaches: a NOW request given back as taken has the session back a second early. - startDomain() asserts nothing, so that a case which fails on its way up still holds the domain to delete, and the cleanup chains its three steps. - The comment on the OOME road of replay() and ERR_REPLAY_GIVE_BACK_FAILED say what happens: the restart is asked for, and the last resort re-runs a given-back request on the same thread, backoff and all.
…count the wakes, and pin the clears and the give-back level Review round 2. - SessionRestartBackoffTest times disable() as it times shutdown(), against the one bound both wakes share: a checkpointer which sleeps the backoff through while it holds the monitor holds disable() for the rest of it, and the disable case was green under that shape of the sleep mutant. Both shapes are in the mutant table now. - The wake of the backoff is counted as well as flagged, and the count is read where the session is stopped, under serviceStateLock: `disabled` does not stay set, so a checkpointer descheduled between disable()'s notifyAll() and its own re-check for as long as enable() takes would wait out the rest of the backoff for a session it has nothing left to start. - aSessionRestartWhichCouldNotRunIsRunAgain accepts the checkpointer's report twice, on the road its own comment names: its tick landing between the replay thread's request and the CAS. - requestSessionRestart() (@VisibleForTesting) leaves a request standing, and two cases pin the clears in enable() and importBackend() on it - the second in OpenIdentityPlatform#968's ReplayDuringImportTest, which has the import fixture. - aRestartAskedForWithoutTheBackoffIsGivenBackWithIt pins the level a restart which could not run is given back with, on the abandonReplay() road OpenIdentityPlatform#941's fixture reaches: a NOW request given back as taken has the session back a second early. - startDomain() asserts nothing, so that a case which fails on its way up still holds the domain to delete, and the cleanup chains its three steps. - The comment on the OOME road of replay() and ERR_REPLAY_GIVE_BACK_FAILED say what happens: the restart is asked for, and the last resort re-runs a given-back request on the same thread, backoff and all.
…backoff is forgotten, and pin every reset Review round 2. The count of deliveries folded into no warning went back to zero where a change was replayed and nothing was failing anymore, and nowhere else: disable() cleared the pending changes and the session restart backoff and left the count, as did the end of a total update - the same triple, landed by OpenIdentityPlatform#968 after the review - and so did giving up on the change which was the last one failing. The first warning over the next failure, a day later, then read as counting the deliveries of the failure before. The count goes with the backoff in disable() and after the import now, and on the give-up road it goes alone, under the guard the recovery reset has: the backoff deliberately stays there, and ERR_REPLAY_SKIPPING_CHANGE reports every delivery the change had, so nothing is lost. Neither zeroing of the count was pinned - the test reset zeroed it itself. It resets the timestamp only now, the interval is a @VisibleForTesting knob the way the drain timeout is, and five cases pin one mechanism each, watched red on the mutant which removes it: the third warning of a change which keeps failing stands for the deliveries since the second one only, and the first warning over a new failure says 0 further after a change was replayed, after one was given up on, after the domain was disabled and enabled, and after a total update. The warning says "without a warning of their own" rather than "without being logged" - the folded deliveries are traced - and the test reads it by message rather than by record: the two error log publishers of the test server read the clock one after the other, so a second turning over between them would count one warning as two. Each message is counted half as many times as it is kept, since two warnings read the same to the letter once the domain has forgotten the change and asks for it again.
solveNamingConflict()decides an entry is gone by searching for its entryUUID and getting nothing back, andgetFirstResult()answers the same thing for a search which found nothing and for a search which never ran:Every caller in conflict resolution read that
nullas "the entry has been deleted" and answeredNOTHING_TO_DO, and that branch commits the CSN unconditionally - it never got the guard #892 added two lines below it, oncase FAILED. So a change which was never applied was recorded as replayed, the replication server never sent it again because this replica reported itself past that CSN, and no alert was raised: the #889 failure mode, through a branch #892 did not harden.What this changes
findEntryDN()reports a search which did not run instead of answering "no entry" out of it: a non-SUCCESSresult code is aSearchFailedException. One result code is looked at twice: a backend which serves the base DN and has no base entry answersNO_SUCH_OBJECTon every route (EntryContainer.searchIndexedfetches the base entry before it returns success,MemoryBackend.searchchecks it first) - and so does a backend which is not there. The backend itself tells the two apart,baseEntryIsAbsentFromALiveBackend(): the search ran over a backend which is there and empty, and it did not run over one which is gone or fails to answer. Without that, the base entry of a domain replayed into an empty replica - two empty replicas share the generation ID of an empty backend, so no initialization is needed and the base entry is the first change - would be retried until the give-up budget skipped it."entryuuid=" + uuidmade a value which does not parse - a dangling escape - a search which never runs, retried as a transient failure for as long as the change was asked for. Looked up as a value, such an entryUUID names no entry, which is what a search which ran and found nothing says. The// never happens because the filter is always validcomment is true now.ConflictResolution.SEARCH_FAILEDgets the in-place attempts a storage which failed gets, and the change is left out of the ServerState once they are spent, so the replication server delivers it again. The result code of the attempt says nothing of it - it is the conflict the operation failed on - so the attempt keeps the search failure and the exhaustion exit reports it, in theERR_ERROR_REPLAYING_OPERATIONline it already logs, in place of the error of the operation. Nothing is logged per attempt in place, as nothing is for a storage which failed to serve the operation: a backend which is down for a while fails every attempt of every change delivered meanwhile. What the exit reports is the attempt which spent the last of them: the mark an attempt leaves is reset at the top of every attempt, so one the server refused before it reached the data reports that refusal rather than the search of an earlier attempt (review round 2).handleConflictResolution(PreOperationAddOperation)) are treated the same way: the operation is stopped withUNAVAILABLEand the search which did not run as its error message, which is what the exhaustion exit reports. Reading the first of them as "not replayed here yet" adds an entry a second time when it was renamed since; reading the second as a parent which is gone hands the Add to conflict resolution as the naming conflict it is not, and renames the entry under the base DN as a conflicting entry when the search conflict resolution makes fails as well.preBackendImport()takes the backend away without disabling the domain - it can not stop the session it is about to import over - so a change queued for replay before theInitializeTargetMsgarrived was replayed into no backend:NO_SUCH_OBJECTfrom the workflow element, then a search which did not run,SEARCH_FAILEDten times, the change given back and the session restarted for it - which stopped the broker the import was reading.receiveEntryBytes()records no exception for a broker which is shutting down, so the import ended on the entries which had arrived and was reported as finished, a truncated dataset under the exporter's generationId. On the base the same change wasNOTHING_TO_DO, and its CSN wiped byloadDataState(). NowimportBackend()setsimportingDataand drains the attempts in flight before the backend is taken away, the waydisable()does for an import run on this server; the replay threads read the flag where they readdisabledand give the change back without a restart;sessionHasAnOwner()-ownsItsSession() || importInProgress()- refuses the restart inrecoverFromReplayFailure(),abandonReplay()andrestartSession()for the whole of the total update, from the request rather than from the first entry, since theInitializeTargetMsgwhich answers the request arrives over that session too; and once the state is loaded from the imported data, the pending changes, the restart request and the backoff are reset, asdisable()resets them. Without that reset a change given back during the import stays listed and uncommitted,commit()never moves the ServerState past the oldest uncommitted change, and the imported state already covers it, so the replication server never sends it again - the ServerState of the replica would stop for good. The guard after the backoff inrestartSession()stays onownsItsSession(): the session that thread stopped is the one an import would stream over, so none is streaming, and a total update asked for meanwhile needs the session started back to be answered at all.findEntryUUID()is deliberately left alone: a search which fails there leaves a locally originated ModifyDN published without the entryUUID of its new superior, which is a bug on what this server sends rather than on what it records. It deserves an issue of its own.Rebased on master
The branch sits on master as it is now, which carries #948, #965 and - since the review round - #935, #959, #969, #970, #972, #973, #975, #976, and - since round 2 - #958 and #964, and - since round 3 - #974: the commits rebased without a conflict each time,
git range-diffreads them as the same text on both bases, and what #958 adds toLDAPReplicationDomainsits above the replay loop and below its verdict, with the loop body between them as it was. #974 movedserviceStateLockand the session generation intoReplicationDomainand put the guards ofrestartSession()onownsItsSession(); the round-3 change is written on that shape -sessionHasAnOwner()isownsItsSession()with the total update added, and the post-backoff guard is #974's as it is. The only conflict of the rebase before it wasreplication.properties, where #959 and #972 added 326 and 327 next to this branch's 322; both sides are kept. The Java merged on its own, and #972 reads the same situation this change lets through: a suffix whose base entry is not in the backend is "what a suffix waiting to be initialized looks like", and its generationId is now left unstored rather than written to the configuration entry -StateWithoutBaseEntryTestis 3/3 on this branch.#948 put the in-place attempt of a replayed change under the replay read lock it introduced, and
the
SEARCH_FAILEDretry is inside it: its 50 ms are waited where theFAILEDretry of #892already waits - a domain on its way down takes that lock exclusively and waits out the attempt in
flight, as it does for every other in-place retry.
#965 answers a ModifyDN whose entry is gone before the new superior is looked up, so
solveNamingConflict(ModifyDNOperation)reads the entryUUID search first and returns on it. Asearch which did not run now leaves that method rather than being read as an entry which is gone -
it declares
throws Exception, so theSearchFailedExceptionreaches thecatchin the replayloop, which is where it is turned into
SEARCH_FAILED.Tests
Ten cases in
NamingConflictTest, driven byShortCircuitPluginonSEARCH/PreParse. The plugin grew aregisterShortCircuit(..., letThroughFirst, maxTimes)so that a failure can start part way through the searches of an attempt - the second search failing while the first ran - and every case which registers a bounded short circuit asserts, before it is deregistered (which drops the count), that the budget was spent and the search after it ran. Round 3 added an overload with aPredicate<PluginOperation>, for a short circuit which is for the replayed operation only - the ones the predicate does not accept are neither refused nor counted - because the ServerState flush thread writes the base entry with a Modify of its own on its tick, and aMODIFYshort circuit which counted it took the let-through, or a refusal, meant for the replayed operation.modifyIsRetriedWhileTheEntryUUIDSearchCanNotRun,deleteIsRetriedWhileTheEntryUUIDSearchCanNotRun,modifyDnIsRetriedWhileTheEntryUUIDSearchCanNotRun- a change on an entry which was renamed here, so that only the entryUUID search finds it; the search fails twice and is served on the third attempt. Without the fix:NOTHING_TO_DOafter a single search, the change dropped and the CSN recorded as replayed.addIsNotReplayedTwiceWhileTheEntryUUIDSearchCanNotRun- an Add delivered a second time whose entry was renamed since; the first search of the first attempt fails. Without the fix the entry is added a second time under its former DN, one entryUUID twice in the data.addIsRetriedWhileTheParentEntryUUIDSearchCanNotRun- the parent check fails while the search before it ran; pinned by the monitor: no naming conflict is counted for a search which read nothing. Without the fix conflict resolution counts one and rewrites the message to the DN it already carries.addIsRetriedWhileTheConflictResolutionSearchCanNotRun- the parent was renamed here, so the Add fails on a genuine conflict, and the search conflict resolution reads the data with fails. Without the fix the entry is renamed under the base DN as a conflicting entry; with it, the conflict is counted once, when it is solved.modifyIsLeftOutOfTheServerStateWhenTheEntryUUIDSearchNeverRuns- every attempt in place fails its search: the change is not in the ServerState and the entry untouched. This is the case which pins the exhaustion exit: with|| searchFailedResolvingConflict != nullremoved, the exit falls into theERR_LOOPbranch and commits the CSN. Since round 3 it also pins what the exit reports: everyERR_ERROR_REPLAYING_OPERATIONrecord of the CSN names the entryUUID, which only the search failure carries - a mutant which always reportsop.getErrorMessage()fails here.theExhaustionExitReportsTheAttemptWhichSpentTheLastOfThem- the first attempt ends on a search which did not run, and the Modify itself is refused withUNAVAILABLEon the nine after it (letThroughFirst=1onMODIFY, for the replayed operation only, named by its CSN): theERR_ERROR_REPLAYING_OPERATIONrecord of the CSN must not name the entryUUID, which only the search failure carries. Without the reset it readserror Unavailable Could not read the data to check change ... the search of the entry with entryUUID ... did not run- two causes on one line. The flush thread's Modify of the base entry is made inside the window, by the case itself rather than left to the tick, and the case asserts it was not counted: without the predicate it is, and the tick landing before the first attempt or between two of them is a red under load.baseEntryIsAddedToAnEmptyReplica- the base entry replayed into a backend without one. Fails on the previous head of this branch: tenUNAVAILABLEattempts, the change left out of the ServerState, no base entry.anEntryUUIDWhichIsNotOneNamesNoEntry- an entryUUID no filter string parses; the change is resolved as one on an entry which is not in the data, and recorded.Three cases in
ReplayDuringImportTest, a class of its own because a total update needs theuserRootbackend - the memory backend ofo=testloses its data when it is disabled and enabled back, which is what an import does to the backend it replaces. The exporter is a broker of the test, so that the test says when the entries arrive: it publishes theInitializeTargetMsg, waits for the backend of the domain to be deregistered, replays a Modify on a stale DN through the synchronous replay queue while the import waits for its entries, and only then sends them and theDoneMsg. For the request window it is the domain which asks (initializeFromRemote(), no task, so no stalled-request watchdog), and the exporter holds theInitializeRequestMsguntil the change has been replayed.aReplayDuringTheImportLeavesTheSessionToTheImport- every entry the exporter sent is in the backend once the import ends, noWARN_REPLAY_RETRYING_CHANGEnames the change, and - since round 4 - noERR_ERROR_REPLAYING_OPERATIONdoes either: the hold-off gives the change back before an attempt is made, and that record is the one thing which tells it from the owner guard saving the session after ten attempts into no backend. On 03ed5cf it fails on the second entry: the log reads the exhaustion exit, the retry line, thenProcessed 0 entries, imported 0. With|| importingDatadeleted from bothgoingDownreads it fails on the exhaustion record, the other cases green.aRequestOnItsWayOwnsTheSessionTheAnswerArrivesOver(round 4) - the total update asked for and its answer held by the exporter, the backend live, a Modify whose entryUUID search never runs (ShortCircuitPluginonSEARCH) spent in place: the exhaustion exit reports it, noWARN_REPLAY_RETRYING_CHANGEfollows, the domain is still connected, and the import then runs to its end over that session. This is the case which reachessessionHasAnOwner()inrecoverFromReplayFailure()- the other two leave at the hold-off - and with that guard onownsItsSession()alone it fails on the retry warning, the other cases green.aChangeGivenBackDuringTheImportDoesNotHoldTheServerStateBack- a Modify on an entry the import brought, replayed once the import is over, is applied and covered by the ServerState. With the reset afterloadDataState()removed it is applied and not covered: the change given back during the import is the barrier.Mutation runs, each on the final tests: with
findEntryDN()answeringnullfor a search which did not run and the exhaustion term removed, seven of the nine round-1 cases fail (baseEntryIsAddedToAnEmptyReplicaand the filter case are the two that behaviour does not reach); with the two catches of the Add hook reverted to "no entry" and everything else kept,addIsNotReplayedTwice...fails on the duplicate entry andaddIsRetriedWhileTheParent...on the conflict counted.NamingConflictTestis 18/18 andReplayDuringImportTest3/3 on the round-4 head (the two classes rerun there; the round-4 change to production code is two comments), andReplayDuringImportTest2/2 at 3368a1d, and thereplication/pluginpackage withUpdateOperationTest,AssuredReplicationPluginTest,InitOnLineTest,GenerationIdTestandReSyncTest- the suites which drive a total update - is 314/314 on the rebased tree, nothing skipped. Before round 3 thereplication/pluginpackage withUpdateOperationTestandAssuredReplicationPluginTestwas 294/294 on the tree with #958 and #964 -UpdateOperationTest31/31,StateWithoutBaseEntryTest3/3, nothing skipped. Theorg.opends.server.replication.**package ran on the review-round commit before the rebase: 3595 tests with 2 failures, bothsetUpof an embedded server which did not get the admin port it binds (Address already in useon 65534 and 65530 - test servers of other checkouts on the same machine), which took the 65 methods ofProtocolCompatibilityTestandFileChangeNumberIndexDBTestintoskipped; on the rebased tree the two classes are 58/58 and 5/5, andNamingConflictTest17/17 again.Not in this change
SUCCESS,NO_OPERATIONandBUSYbeing read before either guard is consulted.solveNamingConflict(ModifyDNOperation)when both the moved entry and its new parent are gone: fixed on master by [#955] Answer a ModifyDN whose entry is gone before the new superior is looked up #965, which this branch sits on. What this change adds there is that a search which did not run no longer reaches that decision at all.case NOTHING_TO_DOrefusing to commit the CSN while the result code is the configuredserver-error-result-code. With the search telling a failure from an empty answer,NOTHING_TO_DOis only reached when the search did run and the entry really is not in the data, and the guard would refuse legitimate no-ops - a Modify on an entry genuinely deleted elsewhere would be retried until the give-up budget raised a false "this replica diverged" alert.restartService(), the restart a configuration change asks for, cuts an import into this replica the way the replay did:ownsItsSession()reads "disabled for the length of a total update", and the total update into this replica never setsdisabled. Pre-existing and [#926] Restart the session of a replication domain in one place, under the lock and the generation #974's shape, on a road rarer than a replay - a change of the domain's configuration while it is being initialized, or of its external changelog entry, whose listener refuses nothing.sessionHasAnOwner()is the predicate it would take.entryLeftCountonly drives the progress of the task, nothing compares it with zero on the way out, and a broker which stopped ends the stream the way the exporter'sDoneMsgdoes. This change keeps the replay from stopping that broker; what would make the import say it was cut is that issue.restartSession()and the listener'sacquireIEContext()for a remote-initiatedInitializeTargetMsgshare no lock: a restart decided between the dequeue of the message and the CAS stops the broker the import is about to read - the round-3 shape, a few statements wide instead of the whole import. A design change on the listener side, and rare: it needs the ten attempts of a change spent inside that window.importInProgress()is direction-aware on purpose - an export is not an owner, a failed replay during one restarts the session theEntryMsgs go out over, and the exporter reports the cut; owning the session for an export would leave the change given back with nothing to restart the session for it, since an export reloads no state. Pre-existing, and pinned by nothing yet: a case with the export held in flight (a window smaller than the entry count and the ack withheld) asserting the restart happens is fixture work of its own.findEntryDN()makes carries no ManageDsaIT - none of the internal searches of the domain do - so the backend answersREFERRALbefore it streams an entry. That is aSearchFailedExceptionnow, the give-up an administrator sees, where it was a CSN committed for a change never applied; the topology is buildable and unsupported in practice, and reading through the referral there is not what this change is about.Fixes #956
Ordinal
ERR_REPLAY_ENTRYUUID_SEARCH_FAILED_322, moved off 310 in 4110d0c and renamed fromWARN_once it stopped being logged on its own: it is the error message of the operation the Add hook stops, and the error the exhaustion exit reports. Six open branches had each read310 as the first ordinal free in master and taken it, and git merges those additions without
reporting a conflict - they land in different places in the file - so the duplicate would only have
surfaced afterwards, as two unrelated messages sharing one support ID. The generator does not check
either: it keys on name and ordinal together, so both compile. The open PRs which add to
replication.propertiesnow hold 310-325 with nothing claimed twice.