[jira] [Updated] (HDDS-17280) Datanode command processor thread busy-spins and SCM heartbeats come too often while Recon or another endpoint keeps failing GETVERSION

["Siyao Meng (Jira)" <ji...@apache.org>]

     [ https://issues.apache.org/jira/browse/HDDS-17280?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Siyao Meng updated HDDS-17280:
------------------------------
    Affects Version/s: 2.2.1
                       2.2.0

> Datanode command processor thread busy-spins and SCM heartbeats come too often while Recon or another endpoint keeps failing GETVERSION
> ---------------------------------------------------------------------------------------------------------------------------------------
>
>                 Key: HDDS-17280
>                 URL: https://issues.apache.org/jira/browse/HDDS-17280
>             Project: Apache Ozone
>          Issue Type: Bug
>    Affects Versions: 2.2.0, 2.2.1
>            Reporter: Siyao Meng
>            Priority: Major
>         Attachments: CR-2-skip-heartbeat-wait-only-after-successful-getversion.patch, TestBugCR2ReconDownHeartbeatInterval.java
>
>
> h3. Mechanism
> {{RunningDatanodeState.buildEndPointTask}} calls {{DatanodeStateMachine.setNextHB(now)}} whenever it builds the task for an endpoint in GETVERSION (added by HDDS-13981 so that REGISTER can follow GETVERSION without waiting a full interval). The call happens before the task runs and regardless of its result. The main loop in {{DatanodeStateMachine.startStateMachineThread}} sleeps only until {{nextHB}}, so while an endpoint keeps failing GETVERSION it never sleeps: each cycle starts as soon as the previous one ends, and the cycle lasts as long as the failing {{getVersion}} call. All SCM heartbeats are sent at that pace. The command processor thread started by {{DatanodeStateMachine.initCommandHandlerThread}} sleeps only while {{nextHB}} is in the future; with {{nextHB}} set to the cycle start it loops on {{StateContext.getNextCommand}} without sleeping until it happens to see the next cycle's {{nextHB}} before the GETVERSION task resets it, then sleeps one interval and spins again in a later cycle.
> h3. Trigger
> An endpoint stays in GETVERSION because its server cannot be reached and the call fails faster than {{hdds.heartbeat.interval}}. The common case is a datanode that starts (or restarts) while Recon is down with the connection refused: each Recon {{getVersion}} fails after {{ozone.scm.heartbeat.rpc-retry-count}} x {{ozone.scm.heartbeat.rpc-retry-interval}} (15 x 1s by default), so SCM gets a heartbeat about every 15s instead of every 30s until Recon is back, or for good if Recon is configured but not deployed. A datanode that registered with Recon before the outage is not affected, because a failed heartbeat leaves the endpoint in HEARTBEAT. The code has no Recon specific check, so an SCM endpoint stuck in GETVERSION (for example one SCM of an HA group down while the datanode starts) does the same (argued from the code, the end to end run used Recon). If connection attempts time out instead of being refused, a call outlasts the interval and the heartbeat interval is not shortened, but {{nextHB}} stays in the past for the whole cycle, so the command processor thread would spin almost continuously (argued from the code, not run).
> h3. Impact
> * The command processor thread of each affected datanode busy-spins, taking {{StateContext.lock}} on every iteration. With a 10s interval and a 5s failing call it used 4.0s of CPU over 15s of heartbeats (1 ms with the patch). With default settings the same arithmetic gives about 14s of spinning in every 45s, roughly a third of one core (argued, not run at production timings).
> * SCM receives heartbeats from the affected datanodes about twice as often as configured with default settings, faster with fewer retries. {{hdds.heartbeat.interval}} is not honoured for that time.
> * No correctness impact.
> h3. Reproduction
> [^TestBugCR2ReconDownHeartbeatInterval.java] ({{hadoop-hdds/container-service}}) runs a real {{DatanodeStateMachine}} against an in process SCM ({{ScmTestMock}} behind a real RPC server) with {{ozone.recon.address}} pointing at a closed port. Timings are scaled: heartbeat interval 10s, Recon connection retries 5 x 1s. Over three SCM heartbeats it asserts that they are more than 8s apart and that the command processor thread used less than 1s of CPU. On unmodified code both fail: gaps of [4946, 5006, 5028] ms (the length of the failing Recon call) and 4009 ms of CPU. With the patch it passes (gaps of [9891, 10002, 10003] ms, 1 ms of CPU). An earlier run at production defaults (30s interval, 15 x 1s retries) measured gaps of about 15.0s with Recon down and 30.0s without Recon; it was not repeated for the final test.
> h3. Patch
> [^CR-2-skip-heartbeat-wait-only-after-successful-getversion.patch], against b10a7d427bdf83807a7e48a1be507d3b02d5a503. It also applies to master at e0de543cbe9.
> The GETVERSION task now calls {{setNextHB(now)}} after the {{VersionEndpointTask}} has moved the endpoint to REGISTER, instead of when the task is built. REGISTER still follows a successful GETVERSION at once, and a failing GETVERSION is retried once per heartbeat interval as before HDDS-13981. This also covers SCM endpoints, which a check for the Recon endpoint alone would not.
> Covered by {{testOnlySuccessfulGetVersionSkipsHeartbeatWait}} in the existing {{TestRunningDatanodeState}}, for a Recon and an SCM endpoint: {{setNextHB}} must not be called after a failed GETVERSION and must be called once after the successful one. This is also what prevents the spin, which needs a real state machine and seconds of timing and is therefore checked only by the reproduction. Without the change the test fails for both endpoint types; with it {{TestRunningDatanodeState}}, {{TestHeartbeatEndpointTask}} and {{TestStateContext}} pass, checkstyle is clean.
> Found by code review of the datanode registration and heartbeat paths, as part of the TLA+ verification effort under HDDS-15926, on commit b10a7d427bdf83807a7e48a1be507d3b02d5a503. Checked against HDDS issues and apache/ozone pull requests for duplicates before filing. Related but not duplicates: HDDS-13981 (added the {{setNextHB}} call) 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: issues-unsubscribe@ozone.apache.org
For additional commands, e-mail: issues-help@ozone.apache.org