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 4 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:
|
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 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-1are guarded so they never decrement the byte 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,testReadTailTracksMetricsTestADLSInputStream—testReadFullyTracksMetrics,testReadTailTracksMetricsTestGCSInputStream—testRangeReadMetrics,testReadTailEmptyObjectDoesNotDecrementMetricsTestAnalyticsCoreUtil—readVectoredCountsOnlyCompletedRanges(no eager counting; successful ranges counted; failed ranges not counted)TestAnalyticsAcceleratorInputStreamWrapper—testReadTracksMetricsScope 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.