Siyao Meng created HDDS-16960:
---------------------------------
Summary: One failed poll for the current secret key permanently
stops the secret key refresh in OM and datanodes
Key: HDDS-16960
URL: https://issues.apache.org/jira/browse/HDDS-16960
Project: Apache Ozone
Issue Type: Bug
Reporter: Siyao Meng
Attachments:
MC-4-keep-secret-key-poller-running-after-failed-poll.patch,
TestBugMC4FailedPollStopsKeyRefresh.java
h3. Mechanism
{{DefaultSecretKeySignerClient.scheduleSecretKeyPoller}} runs
{{checkAndRefresh}} with {{ScheduledExecutorService.scheduleAtFixedRate}}. When
{{SecretKeyProtocol.getCurrentSecretKey}} fails, {{checkAndRefresh}} rethrows
the {{IOException}} as {{UncheckedIOException}}. A periodic task that throws is
never run again by the executor, and the exception stays in a
{{ScheduledFuture}} that nobody reads, so nothing is logged either. From then
on {{getCurrentSecretKey}} returns the last fetched key for the life of the
process, and {{ShortLivedTokenSecretManager.createPassword}} keeps signing with
it without looking at its expiry.
The class Javadoc says the client "periodically check and get the latest
current secret key from SCM", and the only comment at the throw site is a TODO
about failure metrics, so the cancellation does not look intended. HDDS-9020
added a retry for {{SECRET_KEY_NOT_INITIALIZED}} to the initial fetch only.
h3. Trigger
# Secure cluster. OM always runs this client. Datanodes run it when
{{hdds.block.token.enabled}} or {{hdds.container.token.enabled}} is set.
# The poller calls SCM once its key is older than
{{hdds.secret.key.rotate.duration}} (1d), and then at every
{{hdds.secret.key.rotate.check.duration}} (10m) until SCM returns a newer key.
Processes that hold the same key become due within one check interval of each
other.
# One of these calls fails. The poller of that process is gone.
Ways the call can fail at default settings:
* SCM cannot be reached, or has no leader, until the SCM failover proxy gives
up. With {{hdds.scmclient.max.retry.timeout}} 10m and
{{hdds.scmclient.failover.retry.interval}} 2s that is 300 failovers, about 10
minutes when the connections are refused. An SCM outage that covers the daily
rotation time by that much is enough, and it hits all OMs and datanodes
together. This is the case that was run, with the failure injected or with a
shortened retry budget (see Reproduction). The default 10 minute budget was not
run.
* The leader SCM is ready but has not initialized its secret keys yet (a
restarted SCM loads the keys from its key file only after it has become
leader). It answers {{SECRET_KEY_NOT_INITIALIZED}} as a response status, which
{{SecretKeyProtocolClientSideTranslatorPB.handleError}} turns into an exception
outside of the retry proxy, so it is not retried at all. Argued from the code,
not run. The window is normally one Ratis write.
* Any {{RuntimeException}} or {{Error}} from the call has the same effect, by
the contract of the executor. Not run as the first failure.
h3. Impact
* The process keeps issuing tokens signed with the stale key. Datanodes reject
them from the moment the key expires ({{hdds.secret.key.expiry.duration}}, 9d
after its creation, so up to 8 days after the failed poll), with "Can't find
the signing secret key" once SCM has dropped the key at the next rotation (this
is the message seen in the reproduction) and, by code reading, with "Token
can't be verified due to expired secret key" on a datanode that still has the
key cached. For the OM that serves clients this means every block token it
hands out is rejected. A datanode signs the block and container tokens it uses
toward other datanodes ({{TokenHelper}}, used by EC reconstruction and
container reconciliation, by code reading), so those requests are rejected in
the same way.
* Nothing in the process starts the poller again. The only recovery is a
restart of each affected OM and datanode. (By code reading there is one
exception: an OM that installs a checkpoint from the leader stops and starts
its secret key client as a side effect. Not run.)
* {{ozone admin om fetch-key}} does not help either, because it does not reach
the signer at the moment.
* The same signer key is used by OM for delegation tokens and STS tokens (code
reading, not run).
Fail closed: no token is accepted that should not be. The damage is
availability, it is silent, and it shows up days after the cause.
h3. Reproduction
PASS, deterministic, unmodified source, about 4 seconds.
[^TestBugMC4FailedPollStopsKeyRefresh.java] ({{hadoop-hdds/framework}}) uses
the real {{DefaultSecretKeyClient}} for the signer and for the verifier,
{{OzoneBlockTokenSecretManager}} and {{TokenVerifier}}, and a real
{{SecretKeyManager}} as SCM that is called in process instead of over RPC.
While SCM is "unreachable" its {{getCurrentSecretKey}} throws
{{ConnectException}}, the exception the failover proxy ends with. Rotation is
500 ms, the check interval 50 ms, key expiry 3 s. The test shows the signer
following a rotation, then one failed poll, then no poll at all in the next 20
check intervals while SCM rotates, and finally a freshly issued block token
rejected with "Can't find the signing secret key" once SCM has dropped the
stale key. A restarted signer is accepted. A passing test means the defect is
present. A real SCM, the RPC retry path and a datanode over the wire are not
exercised by it.
A run with a real SCM exists, made by the verification pipeline that found this
and not repeated for this report: a signer client with the real SCM RPC proxy
on a secure mini cluster, whose only SCM was stopped and started again, with
the client retry budget shortened to about one second. The poll that fell into
the outage failed with a {{ConnectException}}, no poll followed while SCM
rotated four more times, and after SCM had dropped the signer's key a fresh
token of that signer was rejected with "Can't find the signing secret key".
h3. Patch
[^MC-4-keep-secret-key-poller-running-after-failed-poll.patch], against
025266b52a6dcaf39508607cad736799c40907e8. It also applies to master at
4389803780f.
The scheduled task now catches whatever the poll throws (errors included, since
anything thrown ends the schedule), logs it at WARN with the cause and leaves
the next run to the executor, so the fetch is retried at the next check.
{{checkAndRefresh}} itself still throws, so {{refetchSecretKey}} keeps
reporting a failure to its caller. No new retry loop and no new configuration.
One visible consequence: during a long SCM outage the poller now keeps trying
for as long as its key is due, and the SCM failover proxy prints one line to
stderr per attempt (every 2s). Before, that stopped with the poller.
Covered by the new {{TestDefaultSecretKeySignerClient}} (there was no unit test
for this class): {{pollerKeepsRefreshingAfterFailedPolls}} fails three polls in
a row, with an {{IOException}}, a {{RuntimeException}} and an {{Error}}, and
expects the key of the following poll,
{{refetchSecretKeyReportsFailureAndKeepsKey}} pins the behaviour of the manual
refetch. Without the change the first one fails ("Wanted 5 times ... But was 2
times"). With it the secret key and token unit suites of
{{hadoop-hdds/framework}} (40 tests) and {{TestBlockTokens}} on a secure mini
cluster (5 tests) pass, checkstyle is clean. With the patch the reproduction
fails at its assertion that no poll follows the failed one.
Found by TLA+ model checking and code review of the SCM secret key rotation and
distribution paths under HDDS-15926, on commit
025266b52a6dcaf39508607cad736799c40907e8. 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
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
