diff --git a/datafusion-tracing/src/exec_instrument_macros.rs b/datafusion-tracing/src/exec_instrument_macros.rs index fc22bb5..7282fb4 100644 --- a/datafusion-tracing/src/exec_instrument_macros.rs +++ b/datafusion-tracing/src/exec_instrument_macros.rs @@ -112,6 +112,9 @@ macro_rules! instrument_with_spans { datafusion.boundedness = tracing::field::Empty, datafusion.preview = tracing::field::Empty, datafusion.preview_rows = tracing::field::Empty, + datafusion.metrics.aggregate_arguments_time = tracing::field::Empty, + datafusion.metrics.aggregation_time = tracing::field::Empty, + datafusion.metrics.batches_split = tracing::field::Empty, datafusion.metrics.bloom_filter_eval_time = tracing::field::Empty, datafusion.metrics.build_input_batches = tracing::field::Empty, datafusion.metrics.build_input_rows = tracing::field::Empty, @@ -119,6 +122,7 @@ macro_rules! instrument_with_spans { datafusion.metrics.build_time = tracing::field::Empty, datafusion.metrics.bytes_scanned = tracing::field::Empty, datafusion.metrics.elapsed_compute = tracing::field::Empty, + datafusion.metrics.emitting_time = tracing::field::Empty, datafusion.metrics.end_timestamp = tracing::field::Empty, datafusion.metrics.fetch_time = tracing::field::Empty, datafusion.metrics.file_open_errors = tracing::field::Empty, @@ -126,20 +130,29 @@ macro_rules! instrument_with_spans { datafusion.metrics.input_batches = tracing::field::Empty, datafusion.metrics.input_rows = tracing::field::Empty, datafusion.metrics.join_time = tracing::field::Empty, + datafusion.metrics.left_input_batches = tracing::field::Empty, + datafusion.metrics.left_input_rows = tracing::field::Empty, + datafusion.metrics.max_mem_used = tracing::field::Empty, + datafusion.metrics.max_queued = tracing::field::Empty, datafusion.metrics.mem_used = tracing::field::Empty, datafusion.metrics.metadata_load_time = tracing::field::Empty, datafusion.metrics.num_bytes = tracing::field::Empty, datafusion.metrics.num_predicate_creation_errors = tracing::field::Empty, datafusion.metrics.output_batches = tracing::field::Empty, + datafusion.metrics.output_bytes = tracing::field::Empty, datafusion.metrics.output_rows = tracing::field::Empty, datafusion.metrics.page_index_eval_time = tracing::field::Empty, datafusion.metrics.page_index_rows_matched = tracing::field::Empty, datafusion.metrics.page_index_rows_pruned = tracing::field::Empty, datafusion.metrics.peak_mem_used = tracing::field::Empty, + datafusion.metrics.predicate_cache_inner_records = tracing::field::Empty, + datafusion.metrics.predicate_cache_records = tracing::field::Empty, datafusion.metrics.predicate_evaluation_errors = tracing::field::Empty, datafusion.metrics.pushdown_rows_matched = tracing::field::Empty, datafusion.metrics.pushdown_rows_pruned = tracing::field::Empty, datafusion.metrics.repartition_time = tracing::field::Empty, + datafusion.metrics.right_input_batches = tracing::field::Empty, + datafusion.metrics.right_input_rows = tracing::field::Empty, datafusion.metrics.row_groups_matched_bloom_filter = tracing::field::Empty, datafusion.metrics.row_groups_matched_statistics = tracing::field::Empty, datafusion.metrics.row_groups_pruned_bloom_filter = tracing::field::Empty, @@ -154,6 +167,7 @@ macro_rules! instrument_with_spans { datafusion.metrics.start_timestamp = tracing::field::Empty, datafusion.metrics.statistics_eval_time = tracing::field::Empty, datafusion.metrics.stream_memory_usage = tracing::field::Empty, + datafusion.metrics.time_calculating_group_ids = tracing::field::Empty, datafusion.metrics.time_elapsed_opening = tracing::field::Empty, datafusion.metrics.time_elapsed_processing = tracing::field::Empty, datafusion.metrics.time_elapsed_scanning_total = tracing::field::Empty, diff --git a/tests/snapshots/02_basic_metrics_trace.snap b/tests/snapshots/02_basic_metrics_trace.snap index 7cdd03d..875fb4f 100644 --- a/tests/snapshots/02_basic_metrics_trace.snap +++ b/tests/snapshots/02_basic_metrics_trace.snap @@ -1,5 +1,6 @@ --- source: tests/integration_tests.rs +assertion_line: 250 expression: json_lines --- [ @@ -1452,6 +1453,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[1 as Int64(1)]", diff --git a/tests/snapshots/05_basic_all_options_trace.snap b/tests/snapshots/05_basic_all_options_trace.snap index 5f0814a..d1981fb 100644 --- a/tests/snapshots/05_basic_all_options_trace.snap +++ b/tests/snapshots/05_basic_all_options_trace.snap @@ -1,5 +1,6 @@ --- source: tests/integration_tests.rs +assertion_line: 250 expression: json_lines --- [ @@ -1453,6 +1454,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[1 as Int64(1)]", diff --git a/tests/snapshots/06_object_store_all_options_trace.snap b/tests/snapshots/06_object_store_all_options_trace.snap index f403767..85710d6 100644 --- a/tests/snapshots/06_object_store_all_options_trace.snap +++ b/tests/snapshots/06_object_store_all_options_trace.snap @@ -1,5 +1,6 @@ --- source: tests/integration_tests.rs +assertion_line: 250 expression: json_lines --- [ @@ -2165,6 +2166,7 @@ expression: json_lines "span": { "datafusion.boundedness": "Bounded", "datafusion.emission_type": "Incremental", + "datafusion.metrics.batches_split": "0", "datafusion.metrics.bloom_filter_eval_time": "0.00ms", "datafusion.metrics.bytes_scanned": "1.71 K", "datafusion.metrics.elapsed_compute": "0.00ms", @@ -2174,9 +2176,12 @@ expression: json_lines "datafusion.metrics.metadata_load_time": "0.00ms", "datafusion.metrics.num_predicate_creation_errors": "0", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "3.4 KB", "datafusion.metrics.output_rows": "25", "datafusion.metrics.page_index_eval_time": "0.00ms", "datafusion.metrics.page_index_rows_pruned": "0 total → 0 matched", + "datafusion.metrics.predicate_cache_inner_records": "0", + "datafusion.metrics.predicate_cache_records": "0", "datafusion.metrics.predicate_evaluation_errors": "0", "datafusion.metrics.pushdown_rows_matched": "0", "datafusion.metrics.pushdown_rows_pruned": "0", @@ -2220,6 +2225,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "0", + "datafusion.metrics.output_bytes": "0.0 B", "datafusion.metrics.output_rows": "25", "datafusion.metrics.spill_count": "0", "datafusion.metrics.spilled_bytes": "0.0 B", diff --git a/tests/snapshots/09_recursive_all_options_trace.snap b/tests/snapshots/09_recursive_all_options_trace.snap index 39f946c..7de4202 100644 --- a/tests/snapshots/09_recursive_all_options_trace.snap +++ b/tests/snapshots/09_recursive_all_options_trace.snap @@ -1,5 +1,6 @@ --- source: tests/integration_tests.rs +assertion_line: 250 expression: json_lines --- [ @@ -2135,6 +2136,7 @@ expression: json_lines "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.fetch_time": "0.00ms", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "64.0 KB", "datafusion.metrics.output_rows": "1", "datafusion.metrics.repartition_time": "0.00ms", "datafusion.metrics.send_time": "0.00ms", @@ -2182,6 +2184,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "64.0 KB", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "FilterExec: n@0 < 3", @@ -2224,6 +2227,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[n@0 + 1 as numbers.n + Int64(1)]", @@ -2266,6 +2270,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "CoalescePartitionsExec", @@ -2346,6 +2351,7 @@ expression: json_lines "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.fetch_time": "0.00ms", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "64.0 KB", "datafusion.metrics.output_rows": "1", "datafusion.metrics.repartition_time": "0.00ms", "datafusion.metrics.send_time": "0.00ms", @@ -2393,6 +2399,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "64.0 KB", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "FilterExec: n@0 < 3", @@ -2435,6 +2442,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[n@0 + 1 as numbers.n + Int64(1)]", @@ -2477,6 +2485,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "CoalescePartitionsExec", @@ -2557,6 +2566,7 @@ expression: json_lines "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.fetch_time": "0.00ms", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "64.0 KB", "datafusion.metrics.output_rows": "1", "datafusion.metrics.repartition_time": "0.00ms", "datafusion.metrics.send_time": "0.00ms", @@ -2604,6 +2614,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "0", + "datafusion.metrics.output_bytes": "0.0 B", "datafusion.metrics.output_rows": "0", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "FilterExec: n@0 < 3", @@ -2645,6 +2656,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "0", + "datafusion.metrics.output_bytes": "0.0 B", "datafusion.metrics.output_rows": "0", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[n@0 + 1 as numbers.n + Int64(1)]", @@ -2686,6 +2698,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "0", + "datafusion.metrics.output_bytes": "0.0 B", "datafusion.metrics.output_rows": "0", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "CoalescePartitionsExec", @@ -2755,6 +2768,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "1", + "datafusion.metrics.output_bytes": "8.0 B", "datafusion.metrics.output_rows": "1", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "ProjectionExec: expr=[1 as n]", @@ -2788,6 +2802,7 @@ expression: json_lines "datafusion.metrics.elapsed_compute": "0.00ms", "datafusion.metrics.end_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.metrics.output_batches": "3", + "datafusion.metrics.output_bytes": "24.0 B", "datafusion.metrics.output_rows": "3", "datafusion.metrics.start_timestamp": "1970-01-01 00:00:00 UTC", "datafusion.node": "RecursiveQueryExec: name=numbers, is_distinct=false",