[
https://issues.apache.org/jira/browse/HDDS-17603?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Siyao Meng updated HDDS-17603:
------------------------------
Attachment: TestFailedEntryIndexFlushedBeforeTerminate.java
> OM persists the index of a write that fails with INTERNAL_ERROR before it
> terminates, so after restart it never applies that write
> ----------------------------------------------------------------------------------------------------------------------------------
>
> Key: HDDS-17603
> URL: https://issues.apache.org/jira/browse/HDDS-17603
> Project: Apache Ozone
> Issue Type: Bug
> Affects Versions: 1.0.0, 1.1.0, 1.2.0, 1.3.0, 1.2.1, 1.4.0, 2.0.0, 1.4.1,
> 2.1.0, 2.2.0, 2.1.1, 2.1.2, 2.2.1
> Reporter: Siyao Meng
> Priority: Major
> Attachments:
> MC-2-do-not-flush-index-of-entry-that-terminates-om.patch,
> TestFailedEntryIndexFlushedBeforeTerminate.java
>
>
> h3. Mechanism
> {{RequestHandler.handleWriteRequest}} adds every response to the double
> buffer, including INTERNAL_ERROR and METADATA_ERROR responses, and
> {{OzoneManagerStateMachine.createErrorResponse}} does the same for an
> {{IOException}} thrown out of the request. {{OzoneManagerDoubleBuffer.add}}
> wakes the flush thread at once. Only after that does
> {{OzoneManagerStateMachine.processResponse}} call {{ExitUtils.terminate}} for
> these statuses. The flush thread skips the DB batch of a non OK response
> ({{OMClientResponse.checkAndUpdateDB}}), but {{flushBatch}} still writes
> TRANSACTION_INFO as the highest index in the batch, failed entry included. On
> restart {{OzoneManagerStateMachine}} reports that index to Ratis, which
> applies the log from the next index, so the failed entry is never applied
> again on that OM.
> The comment in {{processResponse}} says OM is terminated so that it does not
> "continue applying transactions which leads to an inconsistent state", and
> HDDS-17270 relies on the same thing for a partially applied snapshot purge
> ("On restart the chain is rebuilt from snapshotInfoTable"). That only holds
> if the failed entry is applied again after restart. A {{RuntimeException}}
> from a request already behaves that way, because {{runCommand}} terminates
> before anything is added to the buffer.
> HDDS-16860 reports the same mechanism through a different trigger
> ({{CompleteFinalizeUpgrade}} while a quota repair runs). Its attached patch
> removes that trigger only and states that the general mechanism remains. This
> issue is about the mechanism itself.
> h3. Trigger
> Any fault local to one OM that makes a write fail with INTERNAL_ERROR or
> METADATA_ERROR on that OM only, while the other OMs apply the entry. Two
> examples in the snapshot code, both reproduced:
> # A snapshot purge for [s2, s1]. On one OM, s2 is purged in cache and chain,
> then reading s1 from {{snapshotInfoTable}} fails (a {{CodecException}} or
> RocksDB read error on that OM's disk; the table is not fully cached, so the
> read reaches RocksDB). {{OMSnapshotPurgeRequest}} returns INTERNAL_ERROR (or
> METADATA_ERROR for a RocksDB error); both terminate.
> # A snapshot chain load that hits a read error on OM start marks the chain
> corrupted on that OM ({{SnapshotChainManager}}). The next snapshot create
> fails there with "Snapshot chain is corrupted." (INTERNAL_ERROR).
> The flush thread is woken before {{processResponse}} runs, and the double
> buffer is only stopped late in the shutdown hook ({{OzoneManager.stop}} stops
> the RPC servers first), so the failed index is normally persisted before the
> process exits. With a real process exit this is a race. In a unit level run
> not attached here, with the real flush thread and the buffer stopped right
> after the terminate (earlier than the shutdown hook does), the failed index
> was already persisted in 20 of 20 runs. HDDS-16860 reports that on a mini
> cluster the double buffer always flushed the failed entry before the OM was
> stopped.
> h3. Impact
> * The OM that hit the fault restarts after the failed entry and never applies
> it, while its peers did. Its snapshot table and chain then permanently differ
> from theirs. In the purge case it keeps s1 and s2, so a later create of a
> snapshot with one of those names fails on that OM only (FILE_ALREADY_EXISTS)
> while the others succeed. In the create case it never has the new snapshot,
> so a later delete of it fails there (FILE_NOT_FOUND) and succeeds elsewhere.
> This was run with three OMs in one JVM (each with its own DB, chain and
> double buffer, the log replayed by hand, no Ratis) in a test not attached
> here; the attached reproduction keeps the single OM part. With the patch the
> same three OM run converges: the restarted OM applies the failed entry again
> and the later create or delete gives the same result on all three.
> * Nothing repairs it later short of a Ratis snapshot install from another OM
> (argued, not run). Reads served by that OM, and its behaviour if it becomes
> leader, follow its own diverged state.
> * The same applies to any other request that fails with INTERNAL_ERROR or
> METADATA_ERROR because of a local fault.
> * Affects 1.0.0 onward: TRANSACTION_INFO has been written by the double
> buffer flush since HDDS-3475, and error status responses have always been
> added to the buffer before the terminate.
> h3. Reproduction
> PASS on the unmodified source.
> [^TestFailedEntryIndexFlushedBeforeTerminate.java]
> ({{hadoop-ozone/ozone-manager}}): one OM with a real metadata DB, snapshot
> chain, {{OzoneManagerRequestHandler}} and a running double buffer flush
> thread. Each entry goes through {{OzoneManagerStateMachine.runCommand}} and
> {{processResponse}}, with system exit disabled so the terminate shows as an
> {{ExitException}}. Ratis is not run: the restart is modelled by reading
> TRANSACTION_INFO from the DB. The test waits for the flush the failed entry
> woke before it stops the buffer. The only faults are a read error injected on
> one {{snapshotInfoTable}} row during a purge, and on the table iterator while
> the chain is loaded. Both tests show TRANSACTION_INFO at the failed entry's
> index while the DB holds none of its effect. A passing test means the defect
> is present.
> h3. Suggested fix
> Do not put a response that terminates OM into the double buffer. Entries
> applied before it in the same batch are still flushed with their own index.
> No later entry can be in the buffer, because the apply thread is the one
> calling {{System.exit}}. The alternative of cutting the batch at the failed
> entry in {{flushBatch}} would have to stop every later flush as well, so it
> amounts to the same thing with more code.
> h3. Patch
> [^MC-2-do-not-flush-index-of-entry-that-terminates-om.patch], against
> 284fad307bfd129fca3f4966d854ac45ea3b0d11. It also applies to master at
> 6135e81a09a.
> {{OzoneManagerDoubleBuffer.add}} now drops a response on which OM terminates,
> that is a response that is not successful and has status INTERNAL_ERROR or
> METADATA_ERROR. The check is a new
> {{OzoneManagerStateMachine.isCriticalError}}, which {{processResponse}} now
> uses as well, so the two cannot drift apart. That covers both callers of
> {{add}}. The restarted OM then applies the failed entry again, which is what
> the terminate is meant to achieve. Argued from the code, not run: this also
> removes the lasting part of HDDS-16860, because the restarted OM replays
> {{CompleteFinalizeUpgrade}} before it can be the ready leader, so
> {{QuotaRepairUpgradeAction}} is skipped and that OM finalizes. Covered by
> {{testCriticalErrorDoesNotAdvanceTransactionInfo}} (both statuses, including
> a flush that holds only the failed entry) and
> {{testNonCriticalErrorAdvancesTransactionInfo}} in the existing
> {{TestOzoneManagerDoubleBufferTransactionInfo}}. Without the change the first
> fails with {{expected: <(t:~, i:1)> but was: <(t:~, i:2)>}}. With it,
> {{TestOzoneManagerDoubleBuffer*}}, {{TestOzoneManagerStateMachine}},
> {{TestOzoneManagerRatisServer}}, {{TestOMSnapshotPurgeRequestAndResponse}}
> and {{TestOMSnapshotCreateRequest}} pass (144 tests), and checkstyle is
> clean. With the patch both tests of the reproduction fail ({{expected: 2L but
> was: 1L}}): the failed entry's index is no longer persisted, so a restart
> applies it again.
> Behaviour change: an INTERNAL_ERROR that is deterministic on every OM (a bug
> rather than a local fault) is today applied as a no-op after one terminate
> per OM, if the flush wins the race. With the patch every OM terminates again
> when it replays the entry, until the cause is fixed. That is the fail stop
> behaviour {{processResponse}} documents, and the same as today for an
> unchecked exception or a failure while the flush thread builds the batch,
> both of which already fail again on every restart. It turns such a failure
> into an outage that lasts until the cause is fixed or the operator, with each
> OM stopped, moves TRANSACTION_INFO past the entry with {{ozone repair om
> update-transaction --db <om.db> --term <term> --index <index>}}, instead of a
> silent skip.
> Found by TLA+ model checking and code review of the OM snapshot purge, set
> property and double buffer apply paths under HDDS-15926, on commit
> 284fad307bfd129fca3f4966d854ac45ea3b0d11. Checked against HDDS issues and
> apache/ozone pull requests for duplicates before filing. The attached patch
> is a proposal for review. Generated with Specula (Claude Opus 5.5).
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
