[
https://issues.apache.org/jira/browse/HDDS-17574?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Siyao Meng updated HDDS-17574:
------------------------------
Attachment: TestBugCR1TakeSnapshotBlocksAfterInstallPause.java
> Ratis snapshot taken while an OM checkpoint install has paused the state
> machine can block the follower's apply thread forever
> ------------------------------------------------------------------------------------------------------------------------------
>
> Key: HDDS-17574
> URL: https://issues.apache.org/jira/browse/HDDS-17574
> Project: Apache Ozone
> Issue Type: Bug
> Affects Versions: 2.0.0, 2.1.0, 2.2.0, 2.1.1, 2.1.2, 2.2.1
> Reporter: Siyao Meng
> Priority: Major
> Attachments:
> CR-1-fail-flush-wait-while-om-state-machine-paused.patch,
> TestBugCR1TakeSnapshotBlocksAfterInstallPause.java
>
>
> h3. Mechanism
> {{OzoneManagerStateMachine.takeSnapshot}} first waits until the applied index
> reaches {{lastSkippedIndex}}, calling {{OzoneManagerDoubleBuffer.awaitFlush}}
> in a loop. During a checkpoint install, {{OzoneManager.installCheckpoint}}
> calls {{OzoneManagerStateMachine.pause}}, which stops that double buffer.
> Only its flush thread completes the futures {{awaitFlush}} waits on, and
> {{unpause}} replaces the buffer with a new one, so a wait started on the
> stopped buffer never returns. The {{isStopped}} check in the loop runs only
> between waits.
> The loop is entered while paused when, after the install read the commit
> index and paused, Ratis applies an OM request (rejected while paused, so the
> applied index stays) followed by a Raft configuration entry
> ({{notifyTermIndexUpdated}} is not gated by the pause and raises
> {{lastSkippedIndex}}). OM turns Ratis log metadata entries off, so this is a
> new leader's first entry, a membership change, or the priority change
> {{RatisHelper.transferRatisLeadership}} writes around an admin leader
> transfer. Ratis does not know that OM paused itself, so its
> {{StateMachineUpdater}} stays running and calls {{takeSnapshot}} from
> {{checkAndTakeSnapshot}} after that batch when OM's applied index is at least
> {{ozone.om.ratis.snapshot.auto.trigger.threshold}} (enabled by default) past
> the last Ratis snapshot. OM's applied index is frozen while paused, so the
> late batch cannot cross the threshold itself: the flush that the install
> waited for before pausing must already have moved it past the threshold. The
> updater checks right after each batch, before the double buffer has flushed
> it, and does not check the threshold while idle, so that crossing is first
> seen after the late batch. Besides the automatic trigger, an admin snapshot
> request to the follower ({{ozone ratis snapshot create}} with {{-peerId}})
> reaches the same call during the pause without any threshold (argued from
> code, not run).
> In releases before HDDS-16275, {{pause}} stops the double buffer without a
> final flush and applies during the pause go to the stopped buffer, so the
> applied index can lag the skipped index without a late commit (argued from
> the code at those tags, not run).
> The comment in {{OzoneManager.installSnapshotFromLeader}} assumes the commit
> index is fixed during the install. In Ratis 3.3.1 it is not: an append the
> follower accepted before the install notification raises the commit index
> when its log write completes ({{RaftServerImpl.appendEntriesAsync}} updates
> it after the write, without checking the install in progress).
> h3. Trigger
> # A follower OM accepts appends whose log write is slow, then gets an install
> notification.
> # Its install downloads the checkpoint, reads the commit index, waits until
> it is applied and pauses the state machine.
> # The slow write completes, the commit index rises, and the batch Ratis
> applies contains an OM request followed by a configuration entry (for example
> from a leader transfer).
> # OM's applied index, which the flush before the pause advanced, is already
> {{ozone.om.ratis.snapshot.auto.trigger.threshold}} past the last Ratis
> snapshot, so the check after that batch calls {{takeSnapshot}} on the paused
> state machine (or an admin snapshot request arrives).
> h3. Impact
> * The follower's {{StateMachineUpdater}} thread blocks for good. It is the
> thread that applies entries and reloads the state machine after an install,
> so the follower OM never applies another entry until it is restarted.
> Depending on where the late write leaves its log, it either keeps
> acknowledging appends without applying them or refuses every append (argued
> from code, not run).
> * The trigger is rare: it needs a log write that stays pending across the
> checkpoint download, plus either a threshold crossing by the last flush
> before the pause or an admin snapshot request during the pause.
> h3. Reproduction
> Two parts, neither of which drives the whole chain in an OM cluster.
> * The hang: PASS on unmodified source (the defect is present), 12 s.
> [^TestBugCR1TakeSnapshotBlocksAfterInstallPause.java]
> ({{hadoop-ozone/ozone-manager}}) uses the real {{OzoneManagerStateMachine}},
> {{OzoneManagerDoubleBuffer}} and {{OmMetadataManagerImpl}} with a mock
> OzoneManager. It calls the state machine in the order Ratis and the install
> would: wait for applied index 10 and pause, reject the apply of index 11,
> notify index 12 (standing for a configuration entry), take a snapshot. The
> snapshot call is still blocked 3 s later, and still blocked 5 s after
> {{unpause(20, 1)}}, with the thread waiting in
> {{OzoneManagerDoubleBuffer.awaitFlush}}. The late commit of 11 and 12 is
> injected by calling the state machine directly. A control without the late
> commit shows {{takeSnapshot}} returning at once while paused.
> * The late commit on real Ratis: in the reproduction attached to HDDS-17573
> (three unmodified Ratis 3.3.1 servers, a follower whose log flush is stalled
> once), in one run the follower's commit index rose from 17 to 79 after it had
> received the install notification, while the install was in progress.
> * That Ratis calls {{takeSnapshot}} in this state is argued from
> {{StateMachineUpdater}} (its state stays RUNNING during OM's own pause and
> {{checkAndTakeSnapshot}} runs after each applied batch), not run.
> h3. Patch
> [^CR-1-fail-flush-wait-while-om-state-machine-paused.patch], against
> 424482eb9cfc4b835e1bf73bcdaa9e7d70df59f0. It also applies to master at
> 257a71ab277.
> {{takeSnapshot}} and {{awaitApplied}} now share one wait helper that fails
> with an IOException while the state machine is paused instead of waiting on
> the stopped buffer. Ratis catches an IOException from {{takeSnapshot}}, logs
> it and goes on, so the updater stays free to apply and reload, and the next
> snapshot is taken after unpause. The check and the registration of the wait
> are done under the state machine lock that {{pause}} also takes, so a wait
> registered before the pause is completed by the flush {{pause}} waits for
> before it stops the buffer. A snapshot whose applied index is already caught
> up is still taken during a pause as before. Covered by
> {{testTakeSnapshotFailsWhilePausedBelowSkippedIndex}} in
> {{TestOzoneManagerStateMachine}}, which uses a real double buffer: without
> the change the snapshot call times out, with it the call fails with "paused"
> and, after unpause, a snapshot is taken at the restored index. The same test
> checks that a caught up snapshot is still taken while paused and that
> {{awaitApplied}} fails with "paused" while paused. Two existing tests now
> stub {{awaitFlushAsync}} instead of {{awaitFlush}}.
> Found by code review of the OM and SCM Ratis state machine integration
> (leader readiness, snapshot install and log failure handling), as part of the
> TLA+ verification effort under HDDS-15926, on commit
> 424482eb9cfc4b835e1bf73bcdaa9e7d70df59f0. 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]
