[
https://issues.apache.org/jira/browse/HDDS-16899?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18126187#comment-18126187
]
Siyao Meng commented on HDDS-16899:
-----------------------------------
A second symptom of the null result, independent of bootstrap, is also fixed by
the attached patch. With {{ozone.scm.ha.ratis.log.purge.enabled=true}} (default
false), Ratis (3.3.1) clears its install in progress index at once only when
the {{notifyInstallSnapshotFromLeader}} future fails. After a null result it
keeps the index until the next install notification, and while it is set
{{RaftServerImpl.checkInconsistentAppendEntries}} rejects every append ("Failed
appendEntries as snapshot (...) installation is in progress"). If the leader
stops while a follower downloads its checkpoint, the download fails, and the
new leader's log still contains the follower's next entry, the new leader sends
that follower only appends and never a notification. So the follower rejects
all of them. With three SCMs and the old leader down, the new leader cannot
commit and no SCM is a ready leader. After the old leader returns, the follower
stays behind until it is restarted.
Run with [^TestBugMC9PendingInstallAfterLeaderChange.java]
({{hadoop-ozone/integration-test}}) on
b0aa6475b7856d2c7f467dd3db12b9a1dd116f63: three SCMs, purge enabled with gap 5,
automatic snapshots off, only the first leader purged past the stopped
follower's next index. The leader's inter SCM gRPC endpoint is replaced by a
socket that accepts and never answers, the follower restarts and starts its
download, the leader stops, and the socket is closed so the download fails with
a real connection error.
* Unmodified source: the test passes (the defect is present). The new leader
was elected but its commit index stayed at 342 for 30 s, no SCM was a ready
leader, and the follower stayed at applied index 42. After the old leader
returned, the leader reached applied index 388 while the follower stayed at 42
and kept rejecting appends (146 rejection lines).
* With the attached patch: the test fails as intended, at its assertion that no
SCM is a ready leader while the old leader is down. The follower rejected
appends only while its download was in flight, then caught up with the new
leader by replaying its log (applied index 344, equal to the new leader's
commit index), and the new leader stayed ready.
A second, independent run gave the same outcome both ways. The patch does not
cover a download that succeeds while leadership moves to another SCM that stays
up; that is filed as a separate issue.
> SCM bootstrap falls back to Raft log replay when the checkpoint download
> fails, so the new SCM lacks DB state that is not in the log
> ------------------------------------------------------------------------------------------------------------------------------------
>
> Key: HDDS-16899
> URL: https://issues.apache.org/jira/browse/HDDS-16899
> Project: Apache Ozone
> Issue Type: Bug
> Reporter: Siyao Meng
> Priority: Major
> Attachments:
> MC-3-retry-failed-scm-bootstrap-checkpoint-download.patch,
> TestBugMC3BootstrapReplayAfterFailedCheckpoint.java
>
>
> h3. Mechanism
> A bootstrapping SCM is meant to get its DB from the leader's checkpoint
> (HDDS-5016). Ratis (3.3.1) keeps notifying a bootstrapping follower to
> install a snapshot only until it gets a reply other than {{IN_PROGRESS}}.
> When the download fails, {{SCMHAManagerImpl.downloadCheckpointFromLeader}}
> logs the exception and returns null, and
> {{SCMStateMachine.notifyInstallSnapshotFromLeader}} returns null as well. It
> does the same when {{getSecretKeysFromLeader}} fails. Ratis reports a null
> result to the leader as {{SNAPSHOT_UNAVAILABLE}}. If the leader's Raft log
> still starts at index 0, the leader then appends the whole log, and the new
> SCM applies it over its own freshly initialized DB and joins the ring.
> Whatever the leader's DB holds that the log does not explain is then missing
> on the new SCM for good. For {{sequenceIdTable}} this is visible directly.
> Every SCM start runs {{SequenceIdGenerator.upgradeToSequenceId}}, which
> writes absent rows from local data, and each replicated {{allocateBatch}} is
> a compare and set that every replica judges against its own row. If the new
> SCM's row differs from what the leader's row was at the start of the log, the
> two SCMs accept different requests and keep different rows. Only a WARN
> ("Failed to allocate a batch for ...") is logged.
> h3. Trigger
> # The leader's Raft log still starts at index 0. That is the case for the SCM
> the cluster was initialized on until its first log purge
> ({{ozone.scm.ha.ratis.log.purge.gap}} defaults to 1000000 entries). A leader
> that was bootstrapped itself has a log that starts after the checkpoint it
> installed, and it keeps notifying the new SCM instead (run).
> # The leader's DB holds state that is not in the Raft log. Two cases were
> looked at: (a) a cluster upgraded from SCM without Ratis (HDDS-12031
> initializes Ratis on the existing DB), where everything written before the
> upgrade is in the DB only, and (b) the {{localId}} row, whose seed depends on
> the year of the SCM's first start and, since HDDS-14337, on the release.
> # A new SCM is bootstrapped and its first checkpoint download fails. This
> need not be a transient error: when the leader's inter SCM gRPC service
> ({{ozone.scm.grpc.port}}) cannot be reached while its Ratis port can, every
> bootstrap joins by replay after one failed download (run with that service
> stopped on the leader: the new SCM was added within a second of the failure).
> The other fault used in the runs is a Ratis snapshot directory on the new SCM
> that is not writable.
> h3. Impact
> * Case (a), run with a {{containerId}} row written directly into the DB of
> the existing SCMs, not with a real upgrade: the new SCM ended with a lower
> {{containerId}} row than the leader (1000 against 1005). After leadership was
> transferred to it, {{allocateContainer}} for another owner returned an
> existing container, because the ID it drew was already in use. The rows were
> still different after leadership went back. On a really upgraded cluster the
> new SCM would also lack every container, pipeline and deleted block
> transaction from before Ratis was enabled (argued from the code, not run).
> * Case (b), run: the {{localId}} rows stay different for good. No ID was
> issued twice. The two seeds are at least one day (5.66e12 IDs) apart and each
> SCM allocates from its own row.
> * On a cluster that never ran without Ratis, the {{containerId}},
> {{delTxnId}} and {{CertificateId}} rows were equal after the replay (run on
> an unsecured cluster, a secure cluster was not run).
> h3. Reproduction
> PASS in each of my three runs, unmodified source, default Ratis settings.
> [^TestBugMC3BootstrapReplayAfterFailedCheckpoint.java]
> ({{hadoop-ozone/integration-test}}) starts an SCM HA mini cluster with one
> SCM left inactive, makes that SCM's Ratis snapshot directory read only until
> its first download attempt has failed, and then starts it. The first test
> writes a {{containerId}} row of 5 into the existing SCMs before the first
> container ID is allocated and shows the lower row on the new SCM and the
> existing container returned by {{allocateContainer}} after a leadership
> transfer. The second test gives the leader the {{localId}} seed of an older
> release and shows equal {{containerId}}, {{delTxnId}} and {{CertificateId}}
> rows, different {{localId}} rows and disjoint local IDs. Both tests need the
> SCM the cluster was initialized on to lead when the new SCM joins and fail
> with a message saying so if it does not (that did not happen). A passing test
> means the defect is present.
> h3. Suggested fix
> Fail the install snapshot attempt when the checkpoint cannot be obtained, so
> that the leader asks again and the log is not replayed (the attached patch).
> The patch retries without a bound of its own, as an SCM behind a purged
> leader log already does. The alternative for a bootstrapping SCM is a bounded
> number of attempts that ends the bootstrap with an error naming the failed
> checkpoint download. That needs a policy and probably a configuration key, so
> it is not in the patch.
> h3. Patch
> [^MC-3-retry-failed-scm-bootstrap-checkpoint-download.patch], against
> b0aa6475b7856d2c7f467dd3db12b9a1dd116f63. It also applies to master at
> f650a22f3e3.
> {{SCMStateMachine.notifyInstallSnapshotFromLeader}} now fails its future when
> the checkpoint download or the secret key fetch fails, instead of returning
> null. Ratis answers a failed future with {{IN_PROGRESS}} and the leader
> notifies the follower again, so the download is retried and the log is not
> replayed. The failure is reported after a pause of one second, because the
> leader notifies again at once, and the downloaded checkpoint is removed when
> the secret key fetch fails. {{SCMSnapshotProvider.getSCMDBSnapshot}} no
> longer sets the interrupt flag of the calling thread for a failed download
> that was not an interrupt. With the flag set the pause was skipped (2048
> failed downloads in 10 s, against 10 with the change). Null is still returned
> when the downloaded checkpoint is not ahead of the follower. Only the
> follower's install path changes, not how a logged request is applied.
> Behaviour change, as run on a mini cluster with the leader's inter SCM gRPC
> service stopped and {{hdds.scmclient.rpc.timeout}} lowered to 20s: a
> bootstrap whose download keeps failing no longer joins by log replay. The new
> SCM retries once per second and logs five ERROR lines per attempt, one of
> which says that it cannot join without the leader's checkpoint. The start
> does not wait forever. When its {{addSCM}} call times out, the client retries
> 15 times at intervals of 2 s, the leader refuses each retry because the first
> reconfiguration is still in progress, and the start fails with
> {{ReconfigurationInProgressException}} (after 50 s in the run). With the
> default timeout of 15m that is about 15.5 minutes (from the configuration
> defaults, not run). The {{ozone scm}} process then exits (read from
> {{StorageContainerManagerStarter}}, not run) and has to be started again once
> the download can work.
> Until then the leader stays in the Ratis staging state. In the run it
> notified the new SCM about 200 times per second, each notification logged at
> INFO on both SCMs, and 16 s after the new SCM had been stopped it gave up the
> pending reconfiguration with {{ReconfigurationTimeoutException}}. Read from
> the Ratis code and not run: a leadership transfer is refused in that state,
> and the leader checks the progress of the new peer in place of its periodic
> leadership check. The repeated notifications are not new, a leader whose log
> does not start at index 0 already sends them while the download fails (seen
> on the unfixed code with a leader that had been bootstrapped itself). For a
> leader whose log starts at index 0 they replace a join that took one attempt.
> An SCM behind a purged leader log already retried a failing download without
> end, now it does so once per second. SCMs that have already joined by replay
> are not repaired.
> Not covered: {{SCMHAManagerImpl.verifyCheckpointFromLeader}} returns null
> both when the downloaded checkpoint is not ahead of this SCM and when reading
> it throws, and the second case still ends in the replay. It is left alone
> because the existing {{TestSCMHAManagerImpl.testAddSCM}} adds its second SCM
> through exactly that exit (its mocked checkpoint cannot be read), so closing
> it means reworking that test.
> Covered by {{testBootstrapRetriesFailedCheckpointDownload}} in the existing
> {{TestStorageContainerManagerHA}}, by
> {{testFailedCheckpointDownloadFailsInstallSnapshotAttemptAfterPause}},
> {{testSecretKeyFailureFailsInstallSnapshotAttempt}} and
> {{testCheckpointNotAheadOfFollowerIsReportedAsUnavailable}} in
> {{TestSCMStateMachine}}, and by
> {{testFailedDownloadDoesNotInterruptCallingThread}} in
> {{TestSCMSnapshotProvider}}. Without the change the first fails with
> "expected: 1005L but was: 1000L", the second and third because the future
> completes with null, and the last because the thread is left interrupted. The
> fourth is the negative case and passes either way. With the change the SCM HA
> unit suites around the state machine, snapshot provider, sequence ID
> generator and inter SCM gRPC service (40 tests) and
> {{TestStorageContainerManagerHA}}, {{TestSCMInstallSnapshot}} and
> {{TestSCMInstallSnapshotWithHA}} (9 tests) pass, checkstyle is clean.
> {{TestSecretKeySnapshot}} could not be run in my environment (its secure mini
> cluster does not start, with or without the change). With the patch both
> tests of the reproduction fail, because the new SCM then has the leader's
> rows.
> Found by TLA+ model checking and code review of the SCM sequence ID generator
> and its startup and checkpoint paths under HDDS-15926, on commit
> b0aa6475b7856d2c7f467dd3db12b9a1dd116f63. Checked against HDDS issues and
> apache/ozone pull requests for duplicates before filing. HDDS-5016 states the
> requirement that a bootstrapping SCM always downloads the checkpoint, this
> issue is the case where it does not. The attached patch is a proposal for
> review. Generated with Specula (Claude Opus 5.5).
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
