Repository navigation
HDDS-16241. gRPC deadline kills long-lived block streams after 30 seconds and the client never recovers - #11080
Conversation
|
One note. The change grew beyond removing the deadline: cross-review of the initial fix by several AI models (Claude Fable 5, GPT-5.6 Terra) revealed additional latent defects in the streaming read path: permanent stream poisoning, broken retry classification, half-closed failed calls, a stale prefetch offset after unbuffer, and request-permit exhaustion by long-lived streams. Each was confirmed with a reproducing unit test before its fix was included. |
|
@ss77892 why stream is getting closed after 30 seconds with DEADLINE_EXCEEDED? |
That's in the jira description: XceiverClientGrpc.initStreamRead sets a gRPC deadline of ozone.client.read.timeout (30 seconds). A gRPC deadline bounds the whole call, and since HDDS-13974 one stream stays open per block for the lifetime of the input stream, so every stream is cancelled with DEADLINE_EXCEEDED 30 seconds after it opens, even when healthy. |
chihsuan
left a comment
There was a problem hiding this comment.
Thanks for putting this together! @ss77892 I was able to reproduce the failure end to end by shortening ozone.client.read.timeout, and the new tests
are indeed red without the production changes.
Since this PR fixes multiple reproducible issues, would it be worth considering separate Jira/PRs?I think that could make each behavior change easier to understand and review. I’ve also left two inline questions for your consideration. Thanks!
| protected boolean isConnectivityIssue(IOException ex) { | ||
| return Status.fromThrowable(ex).getCode() == Status.UNAVAILABLE.getCode(); | ||
| final Status.Code code = Status.fromThrowable(ex).getCode(); | ||
| return code == Status.UNAVAILABLE.getCode() || code == Status.DEADLINE_EXCEEDED.getCode(); |
There was a problem hiding this comment.
This also changes the classic BlockInputStream. DEADLINE_EXCEEDED now triggers an OM block-location refresh instead of a simple retry. Is this intentional?
There was a problem hiding this comment.
No, it's not intentional. The changes belong to StreamBlockInputStream. Thank you for noticing it! It will be in the next update.
| LOG.debug("initStreamRead {} on datanode {}", blockID.getContainerBlockID(), dn); | ||
| // No deadline: it would bound the entire long-lived streaming call. Per-request timeliness is | ||
| // enforced by streamReadTimeout in streamRead() and StreamingReader.poll(). | ||
| StreamObserver<ContainerCommandRequestProto> requestObserver = stub.send(streamObserver); |
There was a problem hiding this comment.
I may be missing an existing safeguard, but could long-lived streams keep server-side files open for an extended period? The current limits don’t seem to apply across the whole datanode. Is there another server-side limit or cleanup mechanism?
There was a problem hiding this comment.
I may be missing an existing safeguard, but could long-lived streams keep server-side files open for an extended period? The current limits don’t seem to apply across the whole datanode. Is there another server-side limit or cleanup mechanism?
There was no safeguard: with the deadline gone, an idle stream would keep its block file open until the client closed the stream or the connection dropped. maxConnectionIdle(15m) doesn't help, because it only applies to connections with no active calls.
The update adds hdds.datanode.stream.read.file.idle.timeout (default 1m). GrpcXceiverService closes the block file of any stream that has been idle longer than that. The gRPC stream stays open and the next ReadBlock reopens the file. A lock around each request keeps the file from being closed under an in-flight read. This bounds descriptors held by idle streams, which is the case the deadline removal creates. Tests are in TestGrpcXceiverService.
There is still no datanode-wide cap on concurrent streaming reads, but that is not new: before this change, active streams were limited only by the client's 30s deadline, which killed healthy streams too. I'd like to track a datanode-wide limit on concurrent streams separately, so this PR stays focused on the deadline regression.
…onds Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@chihsuan Thanks for the review and for reproducing it. Agreed, I split it. The PR now does only the minimum needed to fix HDDS-16241:
|
yandrey321
left a comment
There was a problem hiding this comment.
Please check comments below
| if (root instanceof StorageContainerException || isConnectivityIssue(root) || | ||
| root instanceof TimeoutIOException) { | ||
| if (shouldRetryRead(root, retryPolicy, retries++)) { | ||
| recordFailedStreamingDatanode(); |
There was a problem hiding this comment.
DEADLINE_EXCEEDED now routes into handleExceptions, which calls recordFailedStreamingDatanode() before failing over — so the datanode is added to failedStreamingDatanodes (line 101), and that set is never cleared for the life of the stream (it's only ever added to at 521 and read at 213/441).
But a deadline is a property of the call configuration, not of the datanode. In the scenario the description gives as the motivation for this half of the patch — a proxy or interceptor imposing its own deadline — every replica will exceed it identically. So a long-lived reader burns one replica per failover and after ~replication-factor attempts initStreamRead runs out of candidates and throws IOException("Failed to start streaming read to any available DataNodes"), which is not retryable. The patch converts "hangs forever" into "works for 3 deadlines, then fails hard" rather than into recovery.
Suggest either not recording the exclusion for DEADLINE_EXCEEDED specifically (it isn't evidence against the peer), or giving the exclusion a TTL / clearing it when the candidate set is exhausted. Worth also handling here that an exhausted-candidates failure could fall back to re-including previously failed datanodes instead of surfacing a hard error.
TestStreamBlockInputStream.java:492 can't catch this: the mock makes initStreamRead succeed unconditionally on the retry, so the exclusion side effect is invisible. A version that fails the second datanode would show the behavior.
There was a problem hiding this comment.
Once the deadline is removed, nothing in Ozone produces DEADLINE_EXCEEDED on the streaming call. I dropped the override. Running out of candidates after exclusions also happens today with UNAVAILABLE, so it's separate from this regression.
| BLOCK_DELETE_COMMAND_WORKER_INTERVAL_DEFAULT; | ||
| } | ||
|
|
||
| if (streamReadFileIdleTimeout.isNegative() || streamReadFileIdleTimeout.isZero()) { |
There was a problem hiding this comment.
Zero or negative silently resets to the 1m default, so there's no way to turn the new idle-close off. For a new always-on behavior on the read path, an operator hitting an unforeseen interaction has no lever except a rebuild. Suggest treating 0 as disabled (keep the reset for negatives) so pre-patch behavior is reachable from config.
There was a problem hiding this comment.
What is "pre-patch behavior" ???? Before this patch the 30s deadline killed every stream, so files were held for at most 30s. The 1m idle close is already looser than that. If someone needs it off, a very large value does that.
| } | ||
| } | ||
|
|
||
| private void closeFileIfIdle() { |
There was a problem hiding this comment.
New failure mode worth acknowledging explicitly, even if it's accepted: holding the descriptor open gave the stream POSIX unlink immunity — a block file deleted or replaced underneath an in-progress read kept working. Closing it on idle gives that up, so a block deletion or container move/replication landing in the idle window turns the reopen in readBlockImpl into a FileNotFoundException, surfaced as an IO_EXCEPTION StorageContainerException. The client treats that as retryable and fails over, which is survivable, but with finding #1 above each such event also costs a replica. A short comment here stating that the reopen may legitimately find the file gone, and ideally mapping a missing file to the same clean error rejectReadBlock produces rather than a generic internal error, would make the tradeoff deliberate.
There was a problem hiding this comment.
An open handle never kept reads of deleted data working: each request first looks up the container (CONTAINER_NOT_FOUND after delete or move) and the block metadata (NO_SUCH_BLOCK after block deletion), whether or not the file is open. The reopen isn't new either, because before this patch every stream was recreated every 30s by the deadline. A missing file comes back as a StorageContainerException, and the client retries it on another replica, which is correct when the replica is gone. rejectReadBlock would end the whole stream with a bare gRPC status, which is worse for the client.
| try { | ||
| server.shutdown(); | ||
| server.awaitTermination(5, TimeUnit.SECONDS); | ||
| xceiverService.shutdown(); |
There was a problem hiding this comment.
xceiverService.shutdown() is inside the try after server.awaitTermination(...), so an InterruptedException from awaitTermination skips it and leaks the ReadBlockIdleFileCloser thread; it's also skipped entirely on the isStarted == false path. The placement after awaitTermination is right (in-flight calls may still touch the timer) — just move the call into a finally. Most visible in MiniOzoneCluster suites that restart datanodes repeatedly.
There was a problem hiding this comment.
This movement wouldn't change anything. The timer thread only starts when the first idle check is scheduled, which happens only after the datanode has served a streaming read. If stop() runs while isStarted == false, the server never served anything, so there is no thread to leak.
| if (context != null) { | ||
| context.release(); | ||
| } | ||
| lastRequestNanos = System.nanoTime(); |
There was a problem hiding this comment.
lastRequestNanos and the reschedule check run in the finally for every command type, not just Type.ReadBlock. Two consequences: non-ReadBlock traffic on the same observer refreshes the idle clock of a block file nothing is reading, and the legacy ReadChunk path now pays a lock acquire plus a volatile write per request. Scoping the bookkeeping to the ReadBlock branch keeps the hot classic path byte-for-byte as it was and makes the invariant ("the clock tracks reads of this block file") true by construction.
There was a problem hiding this comment.
The Ozone client never mixes request types on one stream. StreamBlockInputStream sends only ReadBlock on its stream, and the classic path opens a new stream for each request (sendCommandAsync: one onNext, then onCompleted). So other request types can't refresh a block file's idle clock. On classic streams the block file is never opened, so the idle check is never scheduled and the lock is never contended.
sodonnel
left a comment
There was a problem hiding this comment.
LGTM - thanks for fixing this, as I think I originally used the withDeadline option which was clearly wrong for long slow reads.
* master: (64 commits) HDDS-16716. Add description for ozone.scm.ec.pipeline.per.volume.factor (#11415) HDDS-16008. PutBlocks from Flushes also go without Raft (#11356) HDDS-16666. Flush SCM transaction in memory during apply transaction (#11409) HDDS-15749. Run specific JUnit tests if possible (#10671) HDDS-16362. GetObjectAttributes ObjectParts should return Part entries for FSO buckets (#11242). HDDS-16643. Remove CleanupTableInfo mechanism (#11365) HDDS-16721. StreamBlockInputStream.read() returns a negative value for bytes 0x80 to 0xFF (#11411) HDDS-16241. gRPC deadline kills long-lived block streams after 30 seconds and the client never recovers (#11080) HDDS-15991. Speed up deleted table scans in quota repair (#11386) HDDS-16674. Bump awssdk to 2.55.6 (#11407) HDDS-16673. Avoid redundant ListBuckets RPCs when S3 bucket listing reaches the end (#11397) HDDS-16708. Let dependabot ignore iceberg minor version upgrades (#11398) HDDS-16713. Bump develocity-maven-extension to 2.6.0 (#11405) HDDS-16300. Allow OM to dynamically reconfigure its SCM node list without a restart (#11218) HDDS-15089. Support S3 per request read consistency (#11252) HDDS-16704. ReadBlock fails with IllegalStateException when a response is shorter than responseDataSize (#11402) HDDS-16631. Fix chooseRandom for rack names with common prefixes (#11401) HDDS-16654. Replace usage of deprecated finalize() in OM (#11376) HDDS-16658. Reuse source key details when opening input stream in S3 CopyObject (#11396) HDDS-16711. Bump moment to 2.31.0 (#11373) ... Conflicts: hadoop-hdds/server-scm/src/main/java/org/apache/hadoop/hdds/scm/node/HealthyReadOnlyNodeHandler.java hadoop-hdds/server-scm/src/main/java/org/apache/hadoop/hdds/scm/node/NodeStateManager.java hadoop-hdds/server-scm/src/main/java/org/apache/hadoop/hdds/scm/node/SCMNodeManager.java hadoop-hdds/server-scm/src/test/java/org/apache/hadoop/hdds/scm/ha/TestSCMStateMachine.java hadoop-hdds/server-scm/src/test/java/org/apache/hadoop/hdds/scm/node/TestDeadNodeHandler.java hadoop-hdds/server-scm/src/test/java/org/apache/hadoop/hdds/scm/node/TestNodeStateManager.java hadoop-ozone/client/src/test/java/org/apache/hadoop/ozone/client/rpc/TestRpcClient.java hadoop-ozone/common/src/main/java/org/apache/hadoop/ozone/OmUtils.java hadoop-ozone/common/src/test/java/org/apache/hadoop/ozone/om/ha/TestHadoopRpcOMFollowerReadFailoverProxyProvider.java hadoop-ozone/integration-test/src/test/java/org/apache/hadoop/ozone/shell/TestOzoneShellHA.java hadoop-ozone/interface-client/src/main/proto/OmClientProtocol.proto hadoop-ozone/ozone-manager/src/main/java/org/apache/hadoop/ozone/om/ratis/OzoneManagerStateMachine.java hadoop-ozone/ozone-manager/src/main/java/org/apache/hadoop/ozone/om/response/upgrade/OMCancelPrepareResponse.java hadoop-ozone/ozone-manager/src/main/java/org/apache/hadoop/ozone/om/response/upgrade/OMCompleteFinalizeUpgradeResponse.java hadoop-ozone/ozone-manager/src/main/java/org/apache/hadoop/ozone/om/response/upgrade/OMPrepareResponse.java hadoop-ozone/ozone-manager/src/main/java/org/apache/hadoop/ozone/protocolPB/OzoneManagerRequestHandler.java hadoop-ozone/ozone-manager/src/test/java/org/apache/hadoop/ozone/om/ratis/TestOzoneManagerStateMachine.java
What changes were proposed in this pull request?
HDDS-16241. gRPC deadline kills long-lived block streams after 30 seconds and the client never recovers
XceiverClientGrpc.initStreamRead arms a gRPC deadline (withDeadlineAfter, ozone.client.read.timeout, default 30 seconds) on the long-lived streaming ReadBlock call introduced by HDDS-13974. A gRPC deadline bounds the entire call, not a single request, so every block stream is cancelled with DEADLINE_EXCEEDED 30 seconds after it opens, even when it is perfectly healthy. The client then never recovers: StreamBlockInputStream.isConnectivityIssue only accepts UNAVAILABLE, so handleExceptions treats DEADLINE_EXCEEDED as non-retryable and surfaces it to the caller instead of failing over to another datanode.
Long-lived readers hit this hard. On an HBase-on-Ozone cluster, RegionServers keep store file input streams open indefinitely; after each stream's first 30 seconds, every pread through it fails. Short-lived readers (CLI, file copies) close before the deadline fires.
Removing the deadline raises a server-side question: an idle stream would keep its block file open on the datanode until the client closes the stream or the connection drops. This patch adds a bound for that.
What fix does:
A datanode-wide limit on concurrent streaming reads and the other robustness fixes found during the investigation will be addressed in separate jiras.
What is the link to the Apache JIRA
https://issues.apache.org/jira/browse/HDDS-16241
How was this patch tested?
UT has been added.
Basic freon/cli workloads to confirm that basic functionality hasn't been broken
HBase on Ozone cluster with YCSB workloads. The rate of failures dropped from ~60% to less than 1%. This 1% would be addressed as a separate jira because it has different root cause.