AWS, GCP, Azure: Track read metrics for positioned, vectored, and accelerated reads - #17236
AWS, GCP, Azure: Track read metrics for positioned, vectored, and accelerated reads#17236dbtsai wants to merge 8 commits into
Conversation
f08cf17 to
1bd2d42
Compare
1bd2d42 to
019fdec
Compare
…tore reads FileIO input streams (S3InputStream, GCSInputStream, ADLSInputStream, and the GCS analytics-core wrapper) only incremented READ_BYTES/READ_OPERATIONS in the sequential read() paths. The positioned-read methods readFully()/readTail() — and the vectored path Parquet layers on top of them since 1.11.0 via ParquetRangeReadableInputStreamAdapter — bypassed instrumentation entirely. Because RangeReadable.readVectored()'s default implementation loops over readFully(), and Parquet routes most column-chunk data through vectored reads, nearly all Parquet data bytes disappeared from the read metrics Spark consumes for task input metrics. Instrument readFully()/readTail() in all three object-store streams. The default RangeReadable.readVectored() loops over readFully(), so the vectored Parquet path is covered automatically for S3/ADLS/GCS. The GCS analytics-core wrapper overrides readVectored() and delegates to the analytics-core stream, so it is instrumented explicitly — recording bytes per range as each range future completes successfully (failed ranges are not counted). Empty-tail reads that return -1 are guarded so they never decrement the byte counter. Additionally, the S3 analytics-accelerator path (AnalyticsAcceleratorInputStreamWrapper, used when s3.analytics-accelerator is enabled) previously tracked no read metrics at all. Thread the MetricsContext already available on S3InputFile into the wrapper and increment the counters from its read() methods; it is not RangeReadable, so Parquet reads flow through read(byte[], int, int) and counting there captures all data bytes. Fixes apache#17208
019fdec to
8e65627
Compare
| .thenAccept( | ||
| buffer -> { | ||
| if (buffer != null && buffer.remaining() > 0) { | ||
| readBytes.increment(buffer.remaining()); |
There was a problem hiding this comment.
This counts inside a thenAccept callback that runs on whichever thread completes the future — an analytics-core background thread, not the caller. Every other counting site in this PR increments synchronously on the caller (task) thread.
That matters for the stated goal: under HadoopMetricsContext, READ_BYTES → FileSystem.Statistics.incrementBytesRead, and Hadoop's Statistics accumulates per-thread, with Spark attributing task input bytes from the task thread's statistics. If these futures complete on a background thread, the bytes land on the wrong thread's Statistics and may never reach Spark's task metrics — so the fix could silently no-op on this specific analytics-core path, which is the scenario #17208 is about.
TestAnalyticsCoreUtil uses DefaultMetricsContext (a plain LongAdder), so it can't surface a thread-attribution issue. Could you confirm the behavior against a real HadoopMetricsContext? If the async attribution is inherent to analytics-core, counting range.length() synchronously before delegating (accepting the failed-range imprecision this code deliberately avoids), or documenting it as a known limitation, would be worth weighing.
There was a problem hiding this comment.
Good catch — you're right, and I couldn't refute it. HadoopMetricsContext maps READ_BYTES to FileSystem.Statistics.incrementBytesRead, and Hadoop's Statistics accumulates in a ThreadLocal<StatisticsData>; Spark attributes task input bytes from the task thread's slot. My thenAccept callback runs on whichever thread completes the future (an analytics-core background thread), so on this path the bytes would land on the wrong thread's Statistics and never reach Spark's task metrics — a silent no-op for exactly the scenario #17208 targets. And as you note, the DefaultMetricsContext/LongAdder test can't surface thread attribution, so it stayed green.
I'll switch this path to count synchronously on the caller thread before delegating to stream.readVectored(...), matching every other counting site in the PR. The tradeoff is that, unlike the completion-callback approach, synchronous counting can only use the requested range.length() (the delivered size isn't known until the async read finishes), so it loses the failed-range / short-read precision this code was trying to get. Given the goal is that the bytes reach Spark at all, correct-thread attribution is the more important property; I'll count range.length() synchronously and add a comment documenting the imprecision. I'll also drop the now-misleading short-read test assertion for this path.
Does counting requested length synchronously (with a comment on the imprecision) sound right to you, or would you prefer I document the async attribution as a known limitation instead and leave counting in the callback? Happy to go either way.
There was a problem hiding this comment.
Synchronous counting of range.length() is the right call. The whole point of this metric is to reach Spark's per-thread task input statistics via HadoopMetricsContext; if it accumulates on the wrong thread it never arrives, so the number is effectively zero on this path. Over-counting a short read or a failed batch by a bounded amount is a precision issue — the magnitude is right and it lands where Spark can see it. Correct-thread attribution wins over precision here, so I wouldn't keep the callback and just document it — that would knowingly ship a broken metric on this path.
Two things to fold in when you switch it:
- Since you'll increment
range.length()up front, a batch wherestream.readVectored(...)throws will have already counted those bytes. That's acceptable for a metric (bounded over-count on a failure path), but please say so in the comment so the imprecision is on the record — both the short-read and the failed-range cases. - Agreed on dropping the short-read assertion. Worth being explicit in the test/PR that the remaining
DefaultMetricsContexttest can't verify thread attribution at all (it's a plainLongAdder); the correctness argument here is the per-threadStatisticsreasoning, not the unit test. No need to fake a thread-attribution test — just don't let the green test imply coverage it doesn't have.
Thanks for the quick turnaround on this and the EOF fix.
There was a problem hiding this comment.
+1 on synchronous range.length() counting — agreed it's the right correct-thread-vs-precision tradeoff.
Related convention point: the same "don't count on a no-data read" rule from #16055 isn't applied in readTail on the three streams — readBytes is guarded but readOperations still increments when the tail read returns -1/0 (empty object). I left inline comments; worth folding a bytesRead > 0 guard into this PR while we're here.
There was a problem hiding this comment.
Done — switched this path to count synchronously on the caller thread before delegating to stream.readVectored(...), using the requested range.length(), matching every other counting site in the PR. Added a comment documenting the bounded over-count on short reads / failed ranges, and flipped the test to readVectoredCountsRequestedLengthSynchronously (asserts both counters move up front, before the futures complete). Also noted in the test that DefaultMetricsContext (a plain LongAdder) cannot verify per-thread Statistics attribution, so the correctness argument rests on the HadoopMetricsContext reasoning rather than the unit test. Thanks for catching this.
There was a problem hiding this comment.
Good point — folded the bytesRead > 0 guard into readTail on all three streams in this PR.
| if (bytesRead > 0) { | ||
| readBytes.increment(bytesRead); | ||
| } | ||
| readOperations.increment(); |
There was a problem hiding this comment.
So this is incrementing readOperations on EOF (and you have a test for it). This is contradictory to your own implementation of read() above, and also to a recent bug fix we recently merged. I recommend aligning with that convention.
There was a problem hiding this comment.
Good catch. Fixed. Thanks.
| int bytesRead = this.delegate.read(b, off, len); | ||
| if (bytesRead > 0) { | ||
| readBytes.increment(bytesRead); | ||
| } | ||
| readOperations.increment(); | ||
| return bytesRead; |
There was a problem hiding this comment.
| int bytesRead = this.delegate.read(b, off, len); | |
| if (bytesRead > 0) { | |
| readBytes.increment(bytesRead); | |
| } | |
| readOperations.increment(); | |
| return bytesRead; | |
| int bytesRead = delegate.read(b, off, len); | |
| if (bytesRead != -1) { | |
| readBytes.increment(bytesRead); | |
| readOperations.increment(); | |
| } | |
| return bytesRead; |
…tStreamWrapper In read(byte[], int, int), readOperations was incremented unconditionally, including on EOF (bytesRead == -1), contradicting the read() method above it and the EOF-handling convention from apache#16055. Guard both counters on != -1 so an EOF read counts neither bytes nor an operation. Co-authored-by: Isaac
| if (bytesRead > 0) { | ||
| readBytes.increment(bytesRead); | ||
| } | ||
| readOperations.increment(); |
There was a problem hiding this comment.
readOperations is incremented even when bytesRead == -1 (empty/EOF tail), while readBytes is guarded. That's the same EOF-counting addressed in #16055, and it's inconsistent with read()/read(byte[]) above. Suggest guarding both together:
if (bytesRead > 0) {
readBytes.increment(bytesRead);
readOperations.increment();
}and flipping testReadTailEmptyObjectDoesNotDecrementMetrics to assert readOperations == 0.
There was a problem hiding this comment.
Done — guarded both counters on bytesRead > 0 and flipped the empty-object test to assert readOperations == 0.
| try (InputStream rangeStream = readRange(range)) { | ||
| int bytesRead = IOUtil.readRemaining(rangeStream, buffer, offset, length); | ||
| readBytes.increment(bytesRead); | ||
| readOperations.increment(); |
There was a problem hiding this comment.
Same convention nit: IOUtil.readRemaining returns 0 at EOF, so an empty tail read still ticks readOperations (and readBytes.increment(0)). Guard both on bytesRead > 0 to stay consistent with read() and #16055.
There was a problem hiding this comment.
Done, guarded both on bytesRead > 0.
| return IOUtil.readRemaining(inputStream, buffer, offset, length); | ||
| int bytesRead = IOUtil.readRemaining(inputStream, buffer, offset, length); | ||
| readBytes.increment(bytesRead); | ||
| readOperations.increment(); |
There was a problem hiding this comment.
Same as S3/GCS — an empty tail read counts an operation. Guard readBytes/readOperations on bytesRead > 0 so a no-data read doesn't increment (#16055 convention).
| void before() { | ||
| when(s3Client.getObject(any(GetObjectRequest.class), any(ResponseTransformer.class))) | ||
| // lenient: the metrics tests re-stub getObject with their own data streams | ||
| lenient() |
There was a problem hiding this comment.
The two new metrics tests re-stub getObject with their own data, so this shared stub goes unused there and would trip UnnecessaryStubbingException — hence lenient(). Reasonable, but since only testReadTailClosesTheStream needs the default stub, a cleaner option is to drop it from @BeforeEach and stub getObject inline in that one test, keeping strict stubbing everywhere. Non-blocking.
There was a problem hiding this comment.
Dropped the shared stub from @BeforeEach and stubbed inline in the two tests that need it, so strict stubbing everywhere. Thanks.
There was a problem hiding this comment.
Pre-existing issue, but maybe worth fixing: these increments are unconditional, which is inconsistent with the other conditional fixes in this PR.
There was a problem hiding this comment.
Similar comment here; we should re-review this for consistency with the guarded increments in the rest of the PR / code.
Review feedback on the read-metrics instrumentation: - AnalyticsCoreUtil.readVectored: count range.length() synchronously on the caller thread instead of in the range-future completion callback. The futures complete on analytics-core background threads; under HadoopMetricsContext, READ_BYTES accumulates per-thread and Spark reads task input from the task thread, so callback counting would land the bytes on the wrong thread and never reach Spark's task metrics (viirya). - readTail on S3/GCS/ADLS: guard readOperations together with readBytes on bytesRead > 0 so an empty-tail read counts neither (szehon-ho). - AnalyticsCoreUtil.read()/read(byte[],int,int): guard both counters on bytesRead != -1 for consistency with the rest of the PR and apache#16055 (JoshRosen). - TestS3InputStream: drop the shared lenient() getObject stub and stub inline in the two tests that need it, restoring strict stubbing (szehon-ho). A codebase-wide scan for the same pattern found two more streams with the same bug (both pre-existing): Aliyun OSSInputStream and Dell EcsSeekableInputStream incremented read metrics unconditionally, so an EOF read over-counted an operation and, in the buffered path, readBytes.increment(-1) decremented the byte counter and corrupted pos. Both now read first and return early on EOF before touching pos/counters. Co-authored-by: Isaac
Follow-up to review: the read(byte[], off, len) sites guarded on != -1 still counted an operation (and readBytes.increment(0)) on a zero-length read, since read returns 0 (not -1) when len == 0. Likewise the newly instrumented readFully(..., length) sites incremented READ_OPERATIONS unconditionally, so a zero-length readFully counted a phantom operation. Guard every count-by-length / count-by-bytesRead site on > 0: - AnalyticsAcceleratorInputStreamWrapper, AnalyticsCoreUtil, OSSInputStream, EcsSeekableInputStream read(byte[], off, len) - S3/ADLS/GCS/AnalyticsCoreUtil readFully The single-byte read() sites keep the != -1 guard: their return is a byte value 0-255, where 0 is legitimate data that > 0 would wrongly drop. Tests: accelerator wrapper now asserts a zero-length read counts nothing, and a new TestS3InputStream case asserts a zero-length readFully counts nothing. Co-authored-by: Isaac
Discussion:
|
|
This pull request has been marked as stale due to 30 days of inactivity. It will be closed in 1 week if no further activity occurs. If you think that’s incorrect or this pull request requires a review, please simply write any comment. If closed, you can revive the PR at any time and @mention a reviewer or discuss it on the dev@iceberg.apache.org list. Thank you for your contributions. |
|
This pull request has been closed due to lack of activity. This is not a judgement on the merit of the PR in any way. It is just a way of keeping the PR queue manageable. If you think that is incorrect, or the pull request requires review, you can revive the PR at any time. |
|
Hi, @dbtsai are you still working on this? We need to move forward with this, and hope to get the issue fixed. |
|
I found three issues in the current head:
After applying only the two test-helper type qualifications in a disposable worktree, all seven affected test classes passed. |
Drop the Aliyun (OSS) and Dell (ECS) changes to keep this PR focused on the AWS, GCP, and Azure object-store input streams. Co-authored-by: Isaac <no-reply@databricks.com>
…ored ranges - readTail no longer counts a read operation at EOF / empty tail (bytesRead <= 0); move readOperations.increment() inside the bytesRead > 0 guard, consistent with the other read paths. - readVectored skips zero-length ranges so they count neither bytes nor an operation, consistent with the new readFully handling. Add analytics-core regression tests for both cases. Co-authored-by: Isaac <no-reply@databricks.com>
|
Hi @liurenjie1024, apologies for the delay — I've been swamped and let this go stale. I've reopened it and will drive it to merge. Thanks for the careful review and for pushing to move it forward! On your three points:
|
readTail over an empty object returns 0 bytes; the > 0 guard must count neither bytes nor an operation. Add S3 and ADLS coverage to match the existing GCS/analytics-core empty-tail tests. Co-authored-by: Isaac <no-reply@databricks.com>
| 0L, | ||
| mock(), | ||
| metrics)) { | ||
| int bytesRead = in.readTail(new byte[8], 0, 8); |
There was a problem hiding this comment.
Clamp the tail start in ADLSInputStream with Math.max(0, fileSize - length). This test currently fails before reaching these assertions because an empty file produces offset -8, which Azure rejects; core-tests is red on this method.
There was a problem hiding this comment.
Good catch, thanks — fixed in 1884fb8. readTail now clamps the start with Math.max(0, fileSize - length), matching GCSInputStream, so an empty/small file no longer produces a negative offset that the Azure SDK FileRange rejects. testReadTailEmptyObjectDoesNotCountMetrics exercises exactly this path (empty file, tail of 8) and passes only with the clamp.
| */ | ||
| private static class CachingMetricsContext extends DefaultMetricsContext { | ||
| private final Map<String, org.apache.iceberg.metrics.Counter> counters = | ||
| Maps.newConcurrentMap(); |
There was a problem hiding this comment.
Please use JDK ConcurrentHashMap here and in the other new CachingMetricsContext helpers. These tests do not need Guava, and project convention is to avoid expanding Guava usage when a JDK equivalent exists.
There was a problem hiding this comment.
Done in 1884fb8. Dropped Guava here — and while at it, hoisted the duplicated helper into a single shared CachingMetricsContext under iceberg-api test artifacts (already on the aws/azure/gcp test classpath), backed by JDK ConcurrentHashMap. That also removes the four other copies. If you'd rather keep the change minimal I'm happy to revert to separate per-module helpers that each just use ConcurrentHashMap.
- ADLSInputStream.readTail: clamp the tail start with Math.max(0, fileSize - length) so an empty/small file no longer computes a negative offset that the Azure SDK FileRange rejects, matching GCSInputStream (szehon-ho). - Hoist the duplicated CachingMetricsContext test helper into one shared class under iceberg-api test artifacts (consumed by aws/azure/gcp tests) and back it with JDK ConcurrentHashMap instead of Guava Maps, per project convention (szehon-ho). Co-authored-by: Isaac <no-reply@databricks.com>
| private final Map<String, Counter> counters = new ConcurrentHashMap<>(); | ||
|
|
||
| @Override | ||
| public Counter counter(String name, Unit unit) { |
There was a problem hiding this comment.
Please fully qualify org.apache.iceberg.metrics.Counter in both the map value type and this method return type. The inherited deprecated MetricsContext.Counter shadows the top-level type, causing compileTestJava to fail across CI.
Problem
FileIO input streams (
S3InputStream,GCSInputStream,ADLSInputStream, and the GCS analytics-core wrapper) only incrementedREAD_BYTES/READ_OPERATIONSin the sequentialread()paths. The positioned-read methodsreadFully()/readTail()— and the vectored path that Parquet layers on top of them since 1.11.0 viaParquetRangeReadableInputStreamAdapter— bypassed instrumentation entirely.Because
RangeReadable.readVectored()'s default implementation loops overreadFully(), and Parquet now routes most column-chunk data through vectored reads, nearly all Parquet data bytes disappeared from the read metrics that Spark consumes for task input metrics. This under-reports Hadoop read metrics significantly.Closes #17208
Fix
Instrument
readFully()/readTail()in all three object-store streams (S3InputStream,ADLSInputStream,GCSInputStream). The defaultRangeReadable.readVectored()loops overreadFully(), so the vectored Parquet path is covered automatically for S3/ADLS/GCS.The GCS analytics-core wrapper (
AnalyticsCoreUtil) overridesreadVectored()and delegates to the native analytics-core vectored API, whose ranges complete asynchronously on analytics-core background threads. It counts each range's requested length synchronously on the caller (task) thread before delegating, rather than in the range-future completion callbacks. This is required for correct thread attribution: underHadoopMetricsContext,READ_BYTESmaps toFileSystem.Statistics.incrementBytesRead, which accumulates per-thread, and Spark reads task input bytes from the task thread — bytes recorded on a background thread would never reach Spark's task metrics. The tradeoff is a bounded over-count on short reads near EOF and on ranges whose read later fails; correct-thread attribution is worth more than precision for this metric. Zero-length ranges are skipped so they count neither bytes nor an operation.The counting convention across the changed paths: single-byte
read()guards on!= -1(a0-255return is real data), while the length/bytes-read-based paths (read(byte[], off, len),readFully,readTail, vectored ranges) guard on> 0so a zero-length read counts neither bytes nor an operation. In every caseREAD_BYTESandREAD_OPERATIONSare incremented together under the same guard, and empty/EOF reads that return-1/0can never decrement a counter.Additionally, the S3 analytics-accelerator path (
AnalyticsAcceleratorInputStreamWrapper, used whens3.analytics-acceleratoris enabled) previously tracked no read metrics at all. It is now threaded theMetricsContextalready available onS3InputFileand increments the counters from itsread()methods; it is notRangeReadable, so Parquet reads flow throughread(byte[], int, int)and counting there captures all data bytes.Tests
TestS3InputStream—testReadFullyTracksMetrics,testReadTailTracksMetrics,testZeroLengthReadFullyDoesNotCountMetrics,testReadTailEmptyObjectDoesNotCountMetricsTestADLSInputStream—testReadFullyTracksMetrics,testReadTailTracksMetrics,testReadTailEmptyObjectDoesNotCountMetricsTestGCSInputStream—testRangeReadMetrics,testReadTailEmptyObjectDoesNotDecrementMetricsTestAnalyticsCoreUtil—readVectoredCountsRequestedLengthSynchronously(bytes counted synchronously on the caller thread; completing or failing the futures afterward does not change the recorded metrics),readVectoredSkipsZeroLengthRanges,readDoesNotCountAtEof,readTailDoesNotCountAtEofTestAnalyticsAcceleratorInputStreamWrapper—testReadTracksMetrics(asserts single-byte, buffered, zero-length, and EOF reads all count correctly)Scope notes
OSSInputStream(Aliyun) is unaffected today because it does not implementRangeReadable; it would need the same treatment ifRangeReadablesupport is added there.Performance impact
None on the data path. This is a metrics-correctness change: the same reads happen as before, and the added work is a
Counter.increment(...)(backed byLongAdder) per read call — no locks, no allocation, no extra I/O. The fix corrects the measurement (READ_BYTES/READ_OPERATIONSthat Spark surfaces as task input metrics), not the reads being measured.