Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perf: Add metric for time spent casting in native scan #919

Merged
merged 5 commits into from
Sep 10, 2024

Conversation

andygrove
Copy link
Member

@andygrove andygrove commented Sep 6, 2024

Which issue does this PR close?

N/A

Rationale for this change

Make it easy to see how much of the native ScanExec time is spent casting columns to different types (this usually means unpacking dictionaries).

Example from TPC-DS q9:

Screenshot from 2024-09-06 11-57-48

DataFusion metrics in native explain output:

metrics=[
  output_rows=2097152, 
  elapsed_compute=21.847892ms, 
  cast_time=21.631731ms]

Full plan:

AggregateExec: mode=Partial, gby=[], aggr=[count, avg, avg], metrics=[output_rows=1, elapsed_compute=9.481194ms]
  ProjectionExec: expr=[col_1@1 as col_0, col_2@2 as col_1], metrics=[output_rows=400519, elapsed_compute=50.596µs]
    FilterExec: col_0@0 IS NOT NULL AND col_0@0 >= 81 AND col_0@0 <= 100, metrics=[output_rows=400519, elapsed_compute=4.753725ms]
      ScanExec: source=[CometScan parquet  (unknown)], schema=[col_0: Int32, col_1: Decimal128(7, 2), col_2: Decimal128(7, 2)], metrics=[output_rows=2097152, elapsed_compute=21.847892ms, cast_time=21.631731ms]

What changes are included in this PR?

How are these changes tested?

@andygrove andygrove marked this pull request as draft September 6, 2024 16:58
@andygrove andygrove marked this pull request as ready for review September 9, 2024 20:54
@andygrove andygrove requested review from comphead and viirya September 9, 2024 22:29
def scanMetrics(sc: SparkContext): Map[String, SQLMetric] = {
Map(
"cast_time" ->
SQLMetrics.createNanoTimingMetric(sc, "Total time for casting arrays"))
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

"arrays" in "casting arrays" may be confused with Spark array type and considered as time spent on casting (Spark) "arrays".

Maybe "casting columns"?

@@ -345,16 +347,20 @@ struct ScanStream<'a> {
baseline_metrics: BaselineMetrics,
/// Cast options
cast_options: CastOptions<'a>,
/// Timer for cast operations
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

is this elapsed time?

@@ -198,9 +198,12 @@ case class CometScanExec(
// Tracking scan time has overhead, we can't afford to do it for each row, and can only do
// it for each batch.
if (supportsColumnar) {
Some("scanTime" -> SQLMetrics.createNanoTimingMetric(sparkContext, "scan time"))
Seq(
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should be it a Map instead of Seq?

@andygrove
Copy link
Member Author

@viirya @comphead I have addressed feedback. Thanks.

@andygrove andygrove changed the title perf: Add native metric for time spent casting in native scan perf: Ad metric for time spent casting in native scan Sep 10, 2024
@andygrove andygrove changed the title perf: Ad metric for time spent casting in native scan perf: Add metric for time spent casting in native scan Sep 10, 2024
Copy link
Contributor

@comphead comphead left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lgtm thanks @andygrove

@andygrove andygrove merged commit c0ec49b into apache:main Sep 10, 2024
76 checks passed
@andygrove andygrove deleted the scan-cast-timer branch September 10, 2024 23:22
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants