You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ozone.apache.org by "Tsz-wo Sze (Jira)" <ji...@apache.org> on 2026/05/31 16:08:01 UTC
[jira] [Commented] (HDDS-15422) Stream read with `seek` close stream during reverse scan may cause performance bottleneck
[ https://issues.apache.org/jira/browse/HDDS-15422?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18084998#comment-18084998 ]
Tsz-wo Sze commented on HDDS-15422:
-----------------------------------
bq. ... we found the input stream are closing immediately after seeking from end/middle of the file back to 0. the next seek that tried to seek from 0 to middle hangs and wait till timeout. ...
{code}
2026-05-29 12:50:06,171 DEBUG StreamBlockInputStream: stream119-reader3831: return response positon 179405298, length 4095502 (block offset 179306496, length 4194304)
2026-05-29 12:50:06,171 DEBUG StreamBlockInputStream: stream119: seek 179471034 -> 0
2026-05-29 12:50:06,172 DEBUG StreamBlockInputStream: Closing stream119-reader3831
2026-05-29 12:50:06,172 DEBUG StreamBlockInputStream: stream119-reader3831 setCompleted success
2026-05-29 12:50:06,172 DEBUG StreamBlockInputStream: stream120: seek 0 -> 133955559
{code}
[~taklwu], thanks for filing this bug!
From the log above, it seems the call is:
# read position is 179471034
# seek to 0
# seek to 133955559
Somehow the stream is closed between two seeks. Let me see how to fix it.
> Stream read with `seek` close stream during reverse scan may cause performance bottleneck
> ------------------------------------------------------------------------------------------
>
> Key: HDDS-15422
> URL: https://issues.apache.org/jira/browse/HDDS-15422
> Project: Apache Ozone
> Issue Type: Sub-task
> Components: Ozone Client
> Affects Versions: 2.2.0
> Reporter: Tak-Lon (Stephen) Wu
> Priority: Critical
> Attachments: hbase-rpc-handler-are-all-parked.png, hbase-rs-read-stream-60-1.txt, hbase-rs-read-stream-60-2.txt, hbase-rs-read-stream-60-3.txt, hbase-rs-read-stream-60-4.html, ozone-datanode-1.txt, ozone-datanode-2.txt
>
>
> While testing HBase read only with Ozone by using YCSB workload C (L1 blockcache / no bucketcache /), We are experiencing degraded read throughput and hanging handler threads on our HBase RegionServers. Despite a healthy BlockCache hit rate (~87.5%), active read threads are becoming blocked, creating a bottleneck.
> Profiling reveals that handler threads are hanging IdLock.getLockEntry while waiting for a single thread to fetch an HFile block from Apache Ozone.
> and while tuning on TRACE/DEBUG log , we found the input stream are closing immediately after seeking from end/middle of the file back to 0. the next seek that tried to seek from 0 to middle hangs and wait till timeout. this indicates that read amplification issue triggered by Reverse Scans over the Ozone gRPC client cannot reuse the stream.
> {code}
> 2026-05-29 12:50:06,171 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream119-reader3831: return response positon 179405298, length 4095502 (block offset 179306496, length 4194304)
> 2026-05-29 12:50:06,171 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream119: seek 179471034 -> 0
> 2026-05-29 12:50:06,172 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: Closing stream119-reader3831
> 2026-05-29 12:50:06,172 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream119-reader3831 setCompleted success
> 2026-05-29 12:50:06,172 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream120: seek 0 -> 133955559
> 2026-05-29 12:50:06,172 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [grpc-default-executor-11]: stream119-reader3831 Failed to setCompleted: Already completed
> 2026-05-29 12:50:06,985 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream493: seek 217274129 -> 0
> 2026-05-29 12:50:06,985 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream492: seek 0 -> 102738300
> 2026-05-29 12:50:06,985 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: position 102738300, length 65686, requested 102738300, diff 65686, readLength 65686, preReadSize=0
> 2026-05-29 12:50:07,008 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [grpc-default-executor-24]: stream492-reader3832: enqueue response offset 101711872, length 4194304, numChecksums 4, bytesPerChecksum=1048576
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream492-reader3832: return response positon 102738300, length 3167876 (block offset 101711872, length 4194304)
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream492: seek 102803986 -> 0
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: Closing stream492-reader3832
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream492-reader3832 setCompleted success
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: stream493: seek 0 -> 217274129
> 2026-05-29 12:50:07,009 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [grpc-default-executor-24]: stream492-reader3832 Failed to setCompleted: Already completed
> {code}
> please check [this snippet of code |https://github.com/apache/ozone/blob/master/hadoop-hdds/client/src/main/java/org/apache/hadoop/hdds/scm/storage/StreamBlockInputStream.java#L212] in StreamBlockInputStream.java.
> one thought is to reduce the read chunk size from e.g. 4MB or 1MB to 64KB to match the hbase block, but this size reduction does not help the fact of Reverse Scan for HFile reading cases.
> {code}
> 2026-05-29 12:50:06,985 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [RpcServer.default.FPBQ.Fifo.handler=42,queue=6,port=22101]: position 102738300, length 65686, requested 102738300, diff 65686, readLength 65686, preReadSize=0
> 2026-05-29 12:50:07,008 DEBUG org.apache.hadoop.hdds.scm.storage.StreamBlockInputStream: [grpc-default-executor-24]: stream492-reader3832: enqueue response offset 101711872, length 4194304, numChecksums 4, bytesPerChecksum=1048576
> {code}
> Setup configuration
> {code}
> ozone.fs.datastream.enabled = true
> ozone.client.stream.readblock.enable = true
> hdds.container.ratis.datastream.enabled = true
> ozone.client.verify.checksum = false (was true and turned to false when checksum failed)
> hdds.grpc.tls.enabled = false (final)
> ozone.client.stream.read.timeout = 120s
> scm.container.client.idle.threshold = 120s
> {code}
--
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