perf(vindex): split build timing logs by phase - #723
Conversation
jerry-024
changed the title
The default_training_vector_count call was only used to populate a timing log field, but it ran unconditionally and propagated errors, introducing a new build failure path even when timing diagnostics were disabled. Compute it only when timing is enabled and fall back to 0 on error instead of failing the build. Co-Authored-By: Claude <noreply@anthropic.com>
shyjsarah
left a comment
shyjsarah
left a comment
There was a problem hiding this comment.
Reviewed the phase-level timing changes. The build path itself looks sound and CI is green, but I found four issues in the diagnostic semantics/implementation that are worth addressing so the emitted data remains actionable. Details are inline.
| async fn read(&self, range: Range<u64>) -> crate::Result<bytes::Bytes> { | ||
| let start = Instant::now(); | ||
| let result = self.inner.read(range).await; | ||
| self.timing.add_file_read(start.elapsed()); |
There was a problem hiding this comment.
file_read_nanos sums the elapsed time of every FileRead::read, but Parquet range fetching can run multiple reads concurrently (up to RANGE_FETCH_CONCURRENCY). Overlapping waits are therefore double-counted, so the emitted oss_read_ms is cumulative request wait rather than storage-I/O wall time and may exceed the enclosing phase/total. Could we either measure the wall-clock I/O span, or rename this to something like oss_read_wait_sum_ms and report the actual concurrency? The current hard-coded data_file_read_concurrency=1 is misleading for the same reason.
| if let Some(commit_start) = commit_start { | ||
| let commit = commit_start.elapsed(); | ||
| for timing in timings { | ||
| timing.log(&self.index_type, commit); |
There was a problem hiding this comment.
This applies the single operation-level commit duration to every shard-level timing event. For a multi-shard build, summing events counts commit N times; an early shard's total_ms also excludes time spent building later shards, so it is neither shard wall time nor operation wall time. Suggest keeping shard events limited to shard phases and emitting one operation-level event for all-shard build time, the single commit, and end-to-end total (ideally linked by a build ID).
| ); | ||
| let shard_count = shards.len(); | ||
| let mut messages = Vec::with_capacity(shard_count); | ||
| let mut timings = Vec::with_capacity(shard_count); |
There was a problem hiding this comment.
This reserves one VectorIndexBuildTiming slot per shard even when PAIMON_LOG_VECTOR_INDEX_BUILD_TIMING is disabled, leaving the default-off path with O(shard_count) diagnostic memory. Could we read the enable flag once and allocate/push only when enabled (or aggregate bounded operation-level stats instead)?
| .saturating_add(self.serialize_upload) | ||
| .saturating_add(commit); | ||
| let unattributed = total.saturating_sub(accounted); | ||
| eprintln!( |
There was a problem hiding this comment.
Could this use the logging facade instead of eprintln!? Direct stderr bypasses the embedding application's filtering, targets, sinks, structured handlers, and test logger, and performs synchronous output in this async path. Nearby vector diagnostics already use log::debug!; a stable target such as paimon::vector_index_build would keep this routable while the env flag can still avoid timing overhead when disabled.
* main: perf: vectorize raw vector search (apache#734) feat(file_index): add predicate evaluation foundation (apache#721) feat(go): add postpone fixed-bucket write bindings (apache#722) perf(vindex): split build timing logs by phase (apache#723) fix(avro): read TIME, BLOB, MULTISET and non-string-key map columns (apache#724) fix(datafusion): surface tag create-time and retention in $tags (apache#728) [core] Support multivalue global index (apache#731) feat: add Java-compatible array predicate pushdown (apache#732) fix: serialize unbounded varchar as string (apache#730) perf(vindex): decouple vector read threads and remove chunk barrier (apache#720) feat(vindex): add DiskANN and IVF-SQ/RQ support (apache#726) # Conflicts: # crates/paimon/src/table/data_file_reader.rs # crates/paimon/src/table/vindex_index_build_builder.rs
3 participants
Purpose
Vector index build diagnostics currently do not distinguish storage I/O, Parquet decoding, index training, and index population costs. This change adds opt-in phase-level timing logs so build bottlenecks can be identified without adding log noise when diagnostics are not enabled.
Enable the logs with:
PAIMON_LOG_VECTOR_INDEX_BUILD_TIMING=1Brief change log
Tests
cargo test -p paimoncargo fmt --all -- --checkgit diff --checkAPI and Format
No public API or storage format changes.
Documentation
No documentation changes. The environment variable is intended for opt-in build diagnostics.