[
https://issues.apache.org/jira/browse/HDDS-17269?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Siyao Meng updated HDDS-17269:
------------------------------
Attachment: TestBugMC6EndpointTaskBacklog.java
> Datanode heartbeat queued behind a slow one runs after SCM asks to reregister
> and drops pending container actions
> -----------------------------------------------------------------------------------------------------------------
>
> Key: HDDS-17269
> URL: https://issues.apache.org/jira/browse/HDDS-17269
> Project: Apache Ozone
> Issue Type: Bug
> Affects Versions: 0.5.0, 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-6-wait-for-running-endpoint-task-instead-of-queuing.patch,
> TestBugCR1StaleEndpointBacklog.java,
> TestBugMC11HeartbeatAfterReregister.java, TestBugMC6EndpointTaskBacklog.java
>
>
> h3. Mechanism
> {{RunningDatanodeState.execute}} builds one task per endpoint on every
> heartbeat cycle, from the endpoint's state at that moment, and submits it to
> the endpoint's single thread executor (created in {{EndpointStateMachine}},
> unbounded queue). It waits for the task for at most one heartbeat interval,
> does not cancel it when that wait times out, and does not check whether the
> endpoint's previous task is still running. A queued task runs later for the
> endpoint state and the endpoint object it was built for.
> {{VersionEndpointTask}} and {{RegisterEndpointTask}} check the endpoint state
> under the endpoint lock and do nothing if it has moved on.
> {{HeartbeatEndpointTask.call}} has no such check: it drains the incremental
> reports and container actions queued for that SCM address and sends them
> (close pipeline actions are only read: {{PipelineActionMap.getActions}} keeps
> them queued until the pipeline is gone). If the call fails with an
> {{IOException}}, only incremental container reports and command status
> reports are put back.
> A cycle starts while the previous task is still running in two ways. The
> heartbeat RPC takes longer than {{hdds.heartbeat.interval}} (with the
> defaults, a call to an SCM that accepts the connection but does not answer
> takes about 95s by calculation: 16 attempts of the 5s
> {{ozone.scm.heartbeat.rpc-timeout}} and 15 retry sleeps of 1s). Or
> {{DatanodeStateMachine.triggerHeartbeat}} (immediate ICR, close container
> action, pipeline close) interrupts the state machine thread while a heartbeat
> is in flight, and the next cycle starts at once.
> This shows up in three ways:
> # *Backlog and burst.* While an SCM is reachable but answers more slowly than
> the heartbeat interval, the endpoint queue grows by one task per heartbeat
> cycle (every interval, and on every immediate heartbeat trigger) for as long
> as that lasts, and the queue is replayed back to back as soon as the SCM
> answers again.
> # *Heartbeat after a reregister command.* If the heartbeat in flight gets a
> reregister command (the SCM restarted or failed over and lost the
> registration), {{HeartbeatEndpointTask.processReregisterCommand}} moves the
> endpoint to GETVERSION. The queued heartbeat task then runs in GETVERSION,
> drains what was raised in the meantime and sends it to an SCM that does not
> consider the datanode registered. {{SCMDatanodeHeartbeatDispatcher}} answers
> with another reregister command and processes none of the reports or actions.
> # *Old endpoint after a DNS refresh.* This path was added by HDDS-15533 and
> is not released yet. With {{ozone.client.failover.resolve-needed=true}}
> (default false), a heartbeat that fails with a connection class error after
> {{hdds.heartbeat.address.refresh.missed-count-threshold}} misses calls
> {{SCMConnectionManager.refreshSCMServer}}. That replaces the endpoint under
> the same {{HostAndPort}} key and calls {{EndpointStateMachine.close}} on the
> old one, which uses {{ExecutorService.shutdown()}}. Tasks already queued on
> the old endpoint still run: they heartbeat to the old address and drain the
> queues that the rebuilt endpoint shares under the same {{HostAndPort}}.
> h3. Trigger
> * Backlog: an SCM that stays reachable but answers heartbeats more slowly
> than the heartbeat interval, for example with saturated handlers or a long GC
> pause.
> * Heartbeat after a reregister command: an SCM restart or failover while a
> heartbeat to that SCM is in flight and the next cycle starts before it
> returns. Either the first heartbeat after the restart takes longer than the
> interval, or an immediate heartbeat trigger lands while its RPC is in flight.
> * Old endpoint (HDDS-15533, not yet released): DNS refresh enabled, the SCM
> moves to a new IP, and the old IP still accepts connections but does not
> answer (when the old IP refuses connections the IPC client re-resolves the
> host by itself and the refresh path is not reached). Heartbeats queued during
> the misses before the refresh form the old endpoint's backlog.
> h3. Impact
> * The SCM receives the queued heartbeats as a burst after it recovers. Each
> one is built when it runs, so it carries current data, and SCM's heartbeat
> handling is idempotent, so on its own this is extra load on SCM and one small
> queued task per interval in the datanode heap.
> * After a reregister command, the reports and actions drained by the queued
> heartbeat are gone from the datanode. Shown for a close container action and
> an incremental container report. The replica state in the lost ICR is also in
> the full container report sent at re-registration. A lost close container
> action is added again by {{HddsDispatcher.sendCloseContainerActionIfNeeded}}
> on the next write to that container, so it only stays lost if no write
> reaches the container afterwards; then the container stays OPEN in SCM until
> its pipeline is closed. That last step is argued from the code, not run here.
> * After a DNS refresh, a container action drained by the old endpoint's
> backlog is lost the same way when the call to the old address fails (shown).
> Incremental reports drained there are put back, but only after each such call
> fails (about 95s each with the defaults). The old endpoint also logs "Unable
> to communicate to SCM server at <host>:<port>/<new IP>" because it shares the
> updated {{HostAndPort}} (code reading).
> h3. Reproduction
> Three self contained classes for {{hadoop-hdds/container-service}} (target
> path and Maven command in each class comment). Each one runs heartbeat cycles
> through {{StateContext.execute}}, the call the datanode state machine thread
> makes every interval, with the real {{RunningDatanodeState}},
> {{EndpointStateMachine}} and {{HeartbeatEndpointTask}}. Only the SCM RPC
> proxy is a stub; it holds the first heartbeat until the test releases it,
> which stands for a slow call. The third class also runs the real
> {{SCMConnectionManager.refreshSCMServer}} and {{EndpointStateMachine.close}},
> with the DNS answer stubbed ({{HostAndPort.resolveLatest}}). They pass on
> unmodified source when the bug is present.
> * [^TestBugMC6EndpointTaskBacklog.java]: 10 cycles while the SCM holds the
> first heartbeat. Output without the fix:
> {noformat}Heartbeat cycles while SCM was slow: 10, heartbeats SCM received
> right after it answered again: 10{noformat}
> * [^TestBugMC11HeartbeatAfterReregister.java]: the SCM answers every
> heartbeat with a reregister command; a close container action and an ICR are
> raised while the first heartbeat is in flight and a second cycle starts.
> Output without the fix:
> {noformat}Heartbeats sent: [endpoint HEARTBEAT, container actions 0, ICRs 0,
> endpoint GETVERSION, container actions 1, ICRs 1]; endpoint now GETVERSION;
> container actions still queued for SCM: 0, ICRs: 0{noformat}
> * [^TestBugCR1StaleEndpointBacklog.java]: refresh threshold 1, the old
> address holds the first heartbeat and then times out, a close container
> action is raised right after the rebuild. Output without the fix:
> {noformat}Endpoint rebuilt: true, now dialing /10.0.0.7:9861; container
> actions in each heartbeat to the old address: [0, 1, 0]; actions still queued
> for the rebuilt endpoint: 0{noformat}
> The full chain on a real cluster (SCM restart under load, then a container
> that stays OPEN) was not run.
> h3. Patch
> [^MC-6-wait-for-running-endpoint-task-instead-of-queuing.patch], against
> b10a7d427bdf83807a7e48a1be507d3b02d5a503. It also applies to master at
> e0de543cbe9.
> {{RunningDatanodeState}} remembers the last task it submitted to each
> endpoint. If that task is still running when the next cycle starts, the cycle
> waits for it (with the same bounded wait as before) instead of building and
> queuing another one. If it finishes during that cycle, the next cycle starts
> right away, so a heartbeat triggered while it was running is sent as soon as
> it returns, as before (this also happens when nothing was triggered, which
> costs at most one early heartbeat after a slow call). Every task is therefore
> built after the previous one finished, from the current endpoint state and
> the current endpoint list, which removes all three symptoms with one change:
> there is no backlog, no heartbeat built before a reregister command runs
> after it, and the replaced endpoint gets no new task after the refresh. The
> task is now submitted to the endpoint executor from the state machine thread;
> an endpoint closed between listing and submitting is skipped. Nothing changes
> for an SCM that answers within the interval.
> HDDS-17267 puts container actions back when a heartbeat fails or is answered
> with a reregister command, which also covers the first heartbeat sent
> normally after an SCM restart; this patch stops queued heartbeats from
> draining the queues at all, so the two changes are independent, touch
> different files and apply together.
> Alternatives considered: a state check in {{HeartbeatEndpointTask.call}}
> fixes only the second symptom, and {{shutdownNow()}} in
> {{EndpointStateMachine.close}} only the third (it would also interrupt an in
> flight call on SCM removal). Neither bounds the queue.
> Covered by three cases in the existing {{TestRunningDatanodeState}}:
> {{testEndpointTaskIsNotQueuedBehindRunningOne}},
> {{testTaskAfterReregisterIsBuiltForNewEndpointState}} and
> {{testReplacedEndpointRunsNoQueuedTask}}, plus
> {{testClosedEndpointIsSkipped}} for the closed endpoint path (it passes
> without the change too, where the same race only logged an error). Without
> the change they fail ("Wanted 1 time ... But was 4 times" for
> {{sendHeartbeat}}, and the close container action missing from the queue in
> the other two). With it they pass, together with the existing tests of
> {{TestRunningDatanodeState}}, {{TestDatanodeStateMachine}},
> {{TestHeartbeatEndpointTask}}, {{TestHeartbeatEndpointTaskDnsRefresh}},
> {{TestSCMConnectionManager}}, {{TestStateContext}}, the command handler
> tests, {{TestEndPoint}} and the mini cluster suite
> {{TestDatanodeSCMNodesReconfiguration}} (SCM nodes added and removed at
> runtime). Checkstyle is clean. With the change the three attached
> reproductions fail at their bug assertions: the SCM gets 1 heartbeat instead
> of 10, and in the other two only the first heartbeat is sent and the close
> container action is still queued.
> Found by TLA+ model checking and code review of the datanode registration and
> heartbeat paths under HDDS-15926, on commit
> b10a7d427bdf83807a7e48a1be507d3b02d5a503. Checked against HDDS issues and
> apache/ozone pull requests for duplicates before filing. Related but not
> duplicates: HDDS-4386 (introduced the per endpoint executor to stop thread
> growth with a slow SCM), HDDS-13126 (datanode down after an endpoint task
> timeout), HDDS-6634 (reregister goes to GETVERSION), HDDS-15533 (the DNS
> refresh on heartbeat failure) and HDDS-16723 (oversized heartbeat from queued
> ICRs on re-registration). 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]
