Siyao Meng created HDDS-17603:
---------------------------------
Summary: 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
Reporter: Siyao Meng
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]
