Skip to content

Commit aa67ff6

Browse files
Dmitrii BugakovDmitrii Bugakov
authored andcommitted
feat: add human-readable formatting to EXPLAIN ANALYZE metrics
1 parent 1dddf03 commit aa67ff6

File tree

4 files changed

+163
-42
lines changed

4 files changed

+163
-42
lines changed

Cargo.lock

Lines changed: 30 additions & 30 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

datafusion/core/tests/physical_optimizer/filter_pushdown/mod.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1824,7 +1824,7 @@ STORED AS PARQUET;
18241824
assert!(explain.contains("output_rows=128")); // Read 1 row group
18251825
assert!(explain.contains("t@0 < 1372708809")); // Dynamic filter was applied
18261826
assert!(
1827-
explain.contains("pushdown_rows_matched=128, pushdown_rows_pruned=99872"),
1827+
explain.contains("pushdown_rows_matched=128, pushdown_rows_pruned=99.87 K"),
18281828
"{explain}"
18291829
);
18301830
// Pushdown pruned most rows

datafusion/execution/src/memory_pool/mod.rs

Lines changed: 103 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -503,6 +503,56 @@ pub fn human_readable_size(size: usize) -> String {
503503
format!("{value:.1} {unit}")
504504
}
505505

506+
/// Present count in human-readable form with K, M, B, T suffixes
507+
pub fn human_readable_count(count: usize) -> String {
508+
let count = count as u64;
509+
let (value, unit) = {
510+
if count >= 1_000_000_000_000 {
511+
(count as f64 / 1_000_000_000_000.0, " T")
512+
} else if count >= 1_000_000_000 {
513+
(count as f64 / 1_000_000_000.0, " B")
514+
} else if count >= 1_000_000 {
515+
(count as f64 / 1_000_000.0, " M")
516+
} else if count >= 1_000 {
517+
(count as f64 / 1_000.0, " K")
518+
} else {
519+
return count.to_string();
520+
}
521+
};
522+
523+
// Format with appropriate precision
524+
// For values >= 100, show 1 decimal place (e.g., 123.4 K)
525+
// For values < 100, show 2 decimal places (e.g., 10.12 K)
526+
if value >= 100.0 {
527+
format!("{value:.1}{unit}")
528+
} else {
529+
format!("{value:.2}{unit}")
530+
}
531+
}
532+
533+
/// Present duration in human-readable form with 2 decimal places
534+
pub fn human_readable_duration(nanos: u64) -> String {
535+
const NANOS_PER_SEC: f64 = 1_000_000_000.0;
536+
const NANOS_PER_MILLI: f64 = 1_000_000.0;
537+
const NANOS_PER_MICRO: f64 = 1_000.0;
538+
539+
let nanos_f64 = nanos as f64;
540+
541+
if nanos >= 1_000_000_000 {
542+
// >= 1 second: show in seconds
543+
format!("{:.2}s", nanos_f64 / NANOS_PER_SEC)
544+
} else if nanos >= 1_000_000 {
545+
// >= 1 millisecond: show in milliseconds
546+
format!("{:.2}ms", nanos_f64 / NANOS_PER_MILLI)
547+
} else if nanos >= 1_000 {
548+
// >= 1 microsecond: show in microseconds
549+
format!("{:.2}µs", nanos_f64 / NANOS_PER_MICRO)
550+
} else {
551+
// < 1 microsecond: show in nanoseconds
552+
format!("{nanos}ns")
553+
}
554+
}
555+
506556
#[cfg(test)]
507557
mod tests {
508558
use super::*;
@@ -599,4 +649,57 @@ mod tests {
599649
assert_eq!(r2.size(), 25);
600650
assert_eq!(pool.reserved(), 28);
601651
}
652+
653+
#[test]
654+
fn test_human_readable_count() {
655+
// Test small numbers (< 1000) - should display as-is
656+
assert_eq!(human_readable_count(0), "0");
657+
assert_eq!(human_readable_count(1), "1");
658+
assert_eq!(human_readable_count(999), "999");
659+
660+
// Test thousands (K)
661+
assert_eq!(human_readable_count(1_000), "1.00 K");
662+
assert_eq!(human_readable_count(10_100), "10.10 K");
663+
assert_eq!(human_readable_count(1_532), "1.53 K");
664+
assert_eq!(human_readable_count(99_999), "100.00 K");
665+
666+
// Test millions (M)
667+
assert_eq!(human_readable_count(1_000_000), "1.00 M");
668+
assert_eq!(human_readable_count(1_532_000), "1.53 M");
669+
assert_eq!(human_readable_count(99_000_000), "99.00 M");
670+
assert_eq!(human_readable_count(123_456_789), "123.5 M");
671+
672+
// Test billions (B)
673+
assert_eq!(human_readable_count(1_000_000_000), "1.00 B");
674+
assert_eq!(human_readable_count(1_532_000_000), "1.53 B");
675+
assert_eq!(human_readable_count(999_999_999_999), "1000.0 B");
676+
677+
// Test trillions (T)
678+
assert_eq!(human_readable_count(1_000_000_000_000), "1.00 T");
679+
assert_eq!(human_readable_count(42_000_000_000_000), "42.00 T");
680+
}
681+
682+
#[test]
683+
fn test_human_readable_duration() {
684+
// Test nanoseconds (< 1µs)
685+
assert_eq!(human_readable_duration(0), "0ns");
686+
assert_eq!(human_readable_duration(1), "1ns");
687+
assert_eq!(human_readable_duration(999), "999ns");
688+
689+
// Test microseconds (1µs to < 1ms)
690+
assert_eq!(human_readable_duration(1_000), "1.00µs");
691+
assert_eq!(human_readable_duration(1_234), "1.23µs");
692+
assert_eq!(human_readable_duration(999_999), "1000.00µs");
693+
694+
// Test milliseconds (1ms to < 1s)
695+
assert_eq!(human_readable_duration(1_000_000), "1.00ms");
696+
assert_eq!(human_readable_duration(11_295_377), "11.30ms");
697+
assert_eq!(human_readable_duration(1_234_567), "1.23ms");
698+
assert_eq!(human_readable_duration(999_999_999), "1000.00ms");
699+
700+
// Test seconds (>= 1s)
701+
assert_eq!(human_readable_duration(1_000_000_000), "1.00s");
702+
assert_eq!(human_readable_duration(1_234_567_890), "1.23s");
703+
assert_eq!(human_readable_duration(42_000_000_000), "42.00s");
704+
}
602705
}

datafusion/physical-plan/src/metrics/value.rs

Lines changed: 29 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,9 @@
2020
use super::CustomMetricValue;
2121
use chrono::{DateTime, Utc};
2222
use datafusion_common::instant::Instant;
23-
use datafusion_execution::memory_pool::human_readable_size;
23+
use datafusion_execution::memory_pool::{
24+
human_readable_count, human_readable_duration, human_readable_size,
25+
};
2426
use parking_lot::Mutex;
2527
use std::{
2628
borrow::{Borrow, Cow},
@@ -49,7 +51,7 @@ impl PartialEq for Count {
4951

5052
impl Display for Count {
5153
fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
52-
write!(f, "{}", self.value())
54+
write!(f, "{}", human_readable_count(self.value()))
5355
}
5456
}
5557

@@ -169,8 +171,7 @@ impl PartialEq for Time {
169171

170172
impl Display for Time {
171173
fn fmt(&self, f: &mut std::fmt::Formatter) -> std::fmt::Result {
172-
let duration = Duration::from_nanos(self.value() as u64);
173-
write!(f, "{duration:?}")
174+
write!(f, "{}", human_readable_duration(self.value() as u64))
174175
}
175176
}
176177

@@ -379,7 +380,12 @@ impl Display for PruningMetrics {
379380
let matched = self.matched.load(Ordering::Relaxed);
380381
let total = self.pruned.load(Ordering::Relaxed) + matched;
381382

382-
write!(f, "{total} total → {matched} matched")
383+
write!(
384+
f,
385+
"{} total → {} matched",
386+
human_readable_count(total),
387+
human_readable_count(matched)
388+
)
383389
}
384390
}
385391

@@ -506,12 +512,18 @@ impl Display for RatioMetrics {
506512
if part == 0 {
507513
write!(f, "N/A (0/0)")
508514
} else {
509-
write!(f, "N/A ({part}/0)")
515+
write!(f, "N/A ({}/0)", human_readable_count(part))
510516
}
511517
} else {
512518
let percentage = (part as f64 / total as f64) * 100.0;
513519

514-
write!(f, "{}% ({part}/{total})", fmt_significant(percentage, 2))
520+
write!(
521+
f,
522+
"{}% ({}/{})",
523+
fmt_significant(percentage, 2),
524+
human_readable_count(part),
525+
human_readable_count(total)
526+
)
515527
}
516528
}
517529
}
@@ -939,8 +951,14 @@ impl Display for MetricValue {
939951
let readable_count = human_readable_size(count.value());
940952
write!(f, "{readable_count}")
941953
}
942-
Self::CurrentMemoryUsage(gauge) | Self::Gauge { gauge, .. } => {
943-
write!(f, "{gauge}")
954+
Self::CurrentMemoryUsage(gauge) => {
955+
// CurrentMemoryUsage is in bytes, format like SpilledBytes
956+
let readable_size = human_readable_size(gauge.value());
957+
write!(f, "{readable_size}")
958+
}
959+
Self::Gauge { gauge, .. } => {
960+
// Generic gauge metrics - format with human-readable count
961+
write!(f, "{}", human_readable_count(gauge.value()))
944962
}
945963
Self::ElapsedCompute(time) | Self::Time { time, .. } => {
946964
// distinguish between no time recorded and very small
@@ -1110,7 +1128,7 @@ mod tests {
11101128

11111129
time.add_duration(Duration::from_nanos(1042));
11121130
for value in &values {
1113-
assert_eq!("1.042µs", value.to_string(), "value {value:?}");
1131+
assert_eq!("1.04µs", value.to_string(), "value {value:?}");
11141132
}
11151133
}
11161134

@@ -1137,7 +1155,7 @@ mod tests {
11371155
};
11381156
tiny_ratio_metrics.add_part(1);
11391157
tiny_ratio_metrics.add_total(3000);
1140-
assert_eq!("0.033% (1/3000)", tiny_ratio.to_string());
1158+
assert_eq!("0.033% (1/3.00 K)", tiny_ratio.to_string());
11411159
}
11421160

11431161
#[test]

0 commit comments

Comments
 (0)