Siyao Meng created HDDS-17673:
---------------------------------
Summary: WriteChunk appended after its container's CloseContainer
commits with no data on the leader, so a lagging follower makes it close the
pipeline
Key: HDDS-17673
URL: https://issues.apache.org/jira/browse/HDDS-17673
Project: Apache Ozone
Issue Type: Bug
Reporter: Siyao Meng
Attachments: TestBugCR4LaggingFollowerReread.java
h3. Mechanism
{{ContainerStateMachine.startTransaction}} checks that the container is open,
but the entry only gets its log index later, in
{{RaftServerImpl.appendTransaction}}. {{CloseContainerCommandHandler}} marks
the container CLOSING and submits a CloseContainer through Raft, and that entry
can be appended between the check and the append of a WriteChunk. The
WriteChunk then follows the CloseContainer in the log. If its data stage on the
leader runs after the CloseContainer was applied, {{KeyValueHandler}} returns
CLOSED_CONTAINER_IO, which {{ContainerStateMachine.handleCommandResult}} treats
as success, so the entry commits although the leader wrote none of its bytes.
With {{hdds.datanode.wait.on.all.followers=false}} (the default) the leader
drops the entry from {{stateMachineDataCache}} when it applies it. A follower
that does not have the entry yet is then served by
{{ContainerStateMachine.readStateMachineData}}, which reads the chunk range
back from the leader's block file. That read fails ("Unexpected read size"),
the leader marks its state machine unhealthy and the pipeline is closed. The
follower never receives the entry.
CHUNK_FILE_INCONSISTENCY, the other result tolerated in the data stage, does
not add a separate case: it marks the replica UNHEALTHY and the apply of the
same WriteChunk then fails with CONTAINER_UNHEALTHY, which closes the pipeline
anyway.
h3. Trigger
# A RATIS/THREE pipeline where one follower is behind (for example stopped or
restarting) while the leader and the other follower commit.
# A client WriteChunk passes the leader's {{startTransaction}} check while the
container is OPEN.
# Before that WriteChunk is appended, SCM's close command reaches the leader
and the CloseContainer is appended.
# The leader runs the WriteChunk's data stage only after the CloseContainer has
been committed and applied. If it runs while the container is still CLOSING,
the bytes are written and nothing goes wrong.
# The lagging follower comes back and needs the WriteChunk.
The first window is short. The second needs the chunk writer thread on the
leader to be backlogged for longer than the CloseContainer takes to commit and
apply, which a busy disk can cause (argued, not measured). On top of that a
follower has to be behind at the same time, so this is a rare race.
h3. Impact
* The leader's state machine goes unhealthy and the pipeline is closed. Writes
to every other open container on the pipeline fail and clients have to continue
on another pipeline.
* The lagging follower does not catch up through Raft. Its replica is closed
with the pipeline and repaired by replication.
* No data is lost and no wrong data is served: the CloseContainer precedes the
WriteChunk on every replica, so the WriteChunk and any later PutBlock for that
container fail at apply on every replica.
h3. Reproduction
[^TestBugCR4LaggingFollowerReread.java] ({{hadoop-ozone/integration-test}}),
unmodified source. One mini cluster with three datanodes, one follower stopped
while the race happens and restarted afterwards. The only timing control is
Ratis' {{CodeInjectionForTesting}} hook at
{{RaftServerImpl.appendTransaction}}, which holds one WriteChunk after
{{startTransaction}} while a real SCM close command is processed by the leader.
A passing test means the defect is present; it passed in every run. Example
output on the unfixed code (indexes, counts and the exact client error vary per
run):
{noformat}
W1 result=CLOSED_CONTAINER_IO, leader block file length=1024, leader
healthy=true, leader applied=10
ReadStateMachine failed. cmd ReadChunk logIndex 9 msg : Unexpected read size.
expected: 1024, actual: -1 Container Result: CONTAINER_INTERNAL_ERROR
pipeline Action CLOSE on pipeline Pipeline-...Reason : Unexpected read size.
expected: 1024, actual: -1
Pipeline Pipeline-... moved to CLOSED state
after follower restart: leader healthy=false, read failures=1, follower
applied=3 of 10
write to the other open container on the same pipeline:
java.util.concurrent.ExecutionException:
org.apache.ratis.protocol.exceptions.RaftRetryFailureException: ...
{noformat}
The read failure is logged thousands of times per run because the leader keeps
retrying the follower. The follower's applied index stays below the leader's
(or reads as -1 when its division has not started yet), and the write to the
other container fails with {{RaftRetryFailureException}} or a timeout,
depending on the run.
h3. Suggested fix
Re-check the container state of a WriteChunk in
{{ContainerStateMachine.preAppendTransaction}}, which Ratis calls on the leader
under the log lock right before the entry gets its index, and reject it with a
{{StateMachineException}} ({{leaderShouldStepDown=false}}) wrapping
{{ContainerNotOpenException}} if the container is no longer open. Since the
CloseContainer is submitted only after the container is marked CLOSING, a
WriteChunk can then no longer follow it in the log, and the client sees the
same error as for a rejection in {{startTransaction}}. With this change applied
locally, the reproduction above fails at its first assertion: the held
WriteChunk is rejected, the follower catches up and the pipeline stays open.
This depends on RATIS-2722, fixed in Ratis 3.4.0, which is not released yet.
Ratis 3.3.1, used by Ozone today, does not release the leader's pending write
quota for a request rejected in {{preAppendTransaction}}, so on 3.3.1 enough
rejections in one leader term would leave the leader refusing all writes. The
change should land together with or after the upgrade to Ratis 3.4.0.
Related: HDDS-1753 and HDDS-11955 hit the same re-read failure in
{{readStateMachineData}} for a lagging follower, with a different cause (the
block was deleted by a later entry).
Found by code review of the datanode container state machine apply and block
commit paths, as part of the TLA+ verification effort under HDDS-15926, on
commit ec5ed5f7ea0e4b406aee53aae4906616819cba2b. Checked against HDDS issues
and apache/ozone pull requests for duplicates before filing. 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]
