You are viewing a plain text version of this content. The canonical link for it is here.
Posted to github@datafusion.apache.org by "progval (via GitHub)" <gi...@apache.org> on 2024/09/23 08:37:31 UTC
[PR] parquet: Add metrics on operations covered by `time_elapsed_opening` [datafusion]
progval opened a new pull request, #12585:
URL: https://github.com/apache/datafusion/pull/12585
## Which issue does this PR close?
Closes #12584.
## Rationale for this change
This allows both Datafusion developers and users to better measure the impact of their optimizations. For example, I am working on #12547 (caching the page index), and my patch makes these metrics go from:
> statistics_eval_time=775.283531ms, row_pushdown_eval_time=191ns, time_elapsed_scanning_until_data=16.463873ms, time_elapsed_processing=401.16043928s, **time_elapsed_opening=473.912060225s**, page_index_eval_time=24.19564ms, **metadata_load_time=410.282903954s**, bloom_filter_eval_time=62.038167937s, time_elapsed_scanning_total=16.516948ms
to
> row_pushdown_eval_time=191ns, time_elapsed_scanning_until_data=1.143893882s, time_elapsed_processing=34.501308377s, **time_elapsed_opening=67.214927741s**, page_index_eval_time=32.002383ms, **metadata_load_time=3.411246ms**, bloom_filter_eval_time=66.495163165s, statistics_eval_time=1.255058963s, time_elapsed_scanning_total=1.143978104s
## What changes are included in this PR?
1. Add `metadata_load_time`
2. Add`statistics_eval_time` and `bloom_filter_eval_time`
3. Rename `pushdown_eval_time` to `row_pushdown_eval_time`, because statistics and eval time are pushdown filters too
## Are these changes tested?
Not really. There is no unit tests, but it works in datafusion-cli and as a library
## Are there any user-facing changes?
Renamed a metric, and added two others, visible in `EXPLAIN ANALYZE`.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] parquet: Add finer metrics on operations covered by `time_elapsed_opening` [datafusion]
Posted by "alamb (via GitHub)" <gi...@apache.org>.
alamb commented on PR #12585:
URL: https://github.com/apache/datafusion/pull/12585#issuecomment-2373687122
Thanks again @progval
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] parquet: Add finer metrics on operations covered by `time_elapsed_opening` [datafusion]
Posted by "alamb (via GitHub)" <gi...@apache.org>.
alamb merged PR #12585:
URL: https://github.com/apache/datafusion/pull/12585
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] parquet: Add finer metrics on operations covered by `time_elapsed_opening` [datafusion]
Posted by "progval (via GitHub)" <gi...@apache.org>.
progval commented on code in PR #12585:
URL: https://github.com/apache/datafusion/pull/12585#discussion_r1773675575
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
if enable_bloom_filter && !row_groups.is_empty() {
+ let mut timer = file_metrics.bloom_filter_eval_time.timer();
Review Comment:
Good point I did the latter, because it's probably closer to what users expect.
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
Review Comment:
Doesn't matter anymore, as I moved both calls to the callees.
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
if enable_bloom_filter && !row_groups.is_empty() {
+ let mut timer = file_metrics.bloom_filter_eval_time.timer();
Review Comment:
Good point. I did the latter, because it's probably closer to what users expect.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] parquet: Add finer metrics on operations covered by `time_elapsed_opening` [datafusion]
Posted by "progval (via GitHub)" <gi...@apache.org>.
progval commented on code in PR #12585:
URL: https://github.com/apache/datafusion/pull/12585#discussion_r1773667286
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
Review Comment:
This one is needed, because it only goes out of scope after the Bloom Filter evaluation. The next `timer.stop()` is indeed redundant, but I kept it for consistency.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org
Re: [PR] parquet: Add finer metrics on operations covered by `time_elapsed_opening` [datafusion]
Posted by "alamb (via GitHub)" <gi...@apache.org>.
alamb commented on code in PR #12585:
URL: https://github.com/apache/datafusion/pull/12585#discussion_r1773544179
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
if enable_bloom_filter && !row_groups.is_empty() {
+ let mut timer = file_metrics.bloom_filter_eval_time.timer();
Review Comment:
I note that the time calculation for `page_index_eval_time` below seems to be in the call to
```rust
access_plan = p.prune_plan_with_page_index(
access_plan,
&file_schema,
builder.parquet_schema(),
file_metadata.as_ref(),
&file_metrics,
);
```
I wonder if we should move the timer into this function for consistency (or alternatively push the timer calculation into `prune_by_bloom_filters` and `prune_by_statistics`)
##########
datafusion/core/src/datasource/physical_plan/parquet/metrics.rs:
##########
@@ -43,14 +43,20 @@ pub struct ParquetFileMetrics {
pub pushdown_rows_pruned: Count,
/// Total rows passed predicates pushed into parquet scan
pub pushdown_rows_matched: Count,
- /// Total time spent evaluating pushdown filters
- pub pushdown_eval_time: Time,
+ /// Total time spent evaluating row-level pushdown filters
Review Comment:
As an aside while I am reviewing this code, the description of what the metrics mean would be more useful if we could attach them to the Metric itself somehow 🤔
Something like:
```rust
let row_pushdown_eval_time = MetricBuilder::new(metrics)
.with_description("Total time spent evaluating row-level pushdown filters")
.with_new_label("filename", filename.to_string())
.subset_time("row_pushdown_eval_time", partition);
```
Though then we would have to figure out how to expose that information in an explain plan 🤔
##########
datafusion/core/src/datasource/physical_plan/parquet/opener.rs:
##########
@@ -187,15 +190,18 @@ impl FileOpener for ParquetOpener {
}
// If there is a predicate that can be evaluated against the metadata
if let Some(predicate) = predicate.as_ref() {
+ let mut timer = file_metrics.statistics_eval_time.timer();
row_groups.prune_by_statistics(
&file_schema,
builder.parquet_schema(),
rg_metadata,
predicate,
&file_metrics,
);
+ timer.stop();
Review Comment:
I don't think it is a problem, but technically speaking the `stop()` is unecessary (it happens automatically when `timer` goes out of scope and is `Drop`ed
https://github.com/alamb/datafusion/blob/544e49bb0acac7130a873a92b44e1c902e41ac8f/datafusion/physical-plan/src/metrics/value.rs#L335-L339
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: github-unsubscribe@datafusion.apache.org
For additional commands, e-mail: github-help@datafusion.apache.org