From 9eeb13fdd1c10de7f489e7fc910686c6d492398e Mon Sep 17 00:00:00 2001 From: Lukas Kalbertodt Date: Sun, 6 May 2018 13:46:20 +0200 Subject: [PATCH] Improve `Debug` impl of `core::time::Duration` MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Prior to this, Duration simply derived Debug. Since Duration doesn't implement `Display`, the only way to inspect its value is to use `Debug`. Unfortunately, the derived `Debug` impl is far from optimal for humans. In many cases, Durations are used for some quick'n'dirty benchmarking (or in general: measuring the time of some code). Correctly understanding the output of Duration's Debug impl is not easy (e.g. is "{ secs: 0, nanos: 968360102 }" or "{ secs: 0, nanos 98507324 }" shorter?). This commit replaces the derived impl with a manual one. It prints the duration as seconds (i.e. "3.1803s") if the duration is longer than a second, otherwise it prints it in either ms, µs or ns (depending on the duration's length). This already helps readability a lot and it never omits information that is stored. This `Debug` impl does *not* respect the following formatting parameters: - fill/align/padding: difficult to implement, probably not worth it - alternate # flag: not clear what this should do --- src/libcore/tests/time.rs | 112 ++++++++++++++++++++++++++++++++++++++ src/libcore/time.rs | 78 +++++++++++++++++++++++++- 2 files changed, 189 insertions(+), 1 deletion(-) diff --git a/src/libcore/tests/time.rs b/src/libcore/tests/time.rs index 042c523f25f..bfb5369cf8f 100644 --- a/src/libcore/tests/time.rs +++ b/src/libcore/tests/time.rs @@ -122,3 +122,115 @@ fn checked_div() { assert_eq!(Duration::new(1, 0).checked_div(2), Some(Duration::new(0, 500_000_000))); assert_eq!(Duration::new(2, 0).checked_div(0), None); } + +#[test] +fn debug_formatting_extreme_values() { + assert_eq!( + format!("{:?}", Duration::new(18_446_744_073_709_551_615, 123_456_789)), + "18446744073709551615.123456789s" + ); +} + +#[test] +fn debug_formatting_secs() { + assert_eq!(format!("{:?}", Duration::new(7, 000_000_000)), "7s"); + assert_eq!(format!("{:?}", Duration::new(7, 100_000_000)), "7.1s"); + assert_eq!(format!("{:?}", Duration::new(7, 000_010_000)), "7.00001s"); + assert_eq!(format!("{:?}", Duration::new(7, 000_000_001)), "7.000000001s"); + assert_eq!(format!("{:?}", Duration::new(7, 123_456_789)), "7.123456789s"); + + assert_eq!(format!("{:?}", Duration::new(88, 000_000_000)), "88s"); + assert_eq!(format!("{:?}", Duration::new(88, 100_000_000)), "88.1s"); + assert_eq!(format!("{:?}", Duration::new(88, 000_010_000)), "88.00001s"); + assert_eq!(format!("{:?}", Duration::new(88, 000_000_001)), "88.000000001s"); + assert_eq!(format!("{:?}", Duration::new(88, 123_456_789)), "88.123456789s"); + + assert_eq!(format!("{:?}", Duration::new(999, 000_000_000)), "999s"); + assert_eq!(format!("{:?}", Duration::new(999, 100_000_000)), "999.1s"); + assert_eq!(format!("{:?}", Duration::new(999, 000_010_000)), "999.00001s"); + assert_eq!(format!("{:?}", Duration::new(999, 000_000_001)), "999.000000001s"); + assert_eq!(format!("{:?}", Duration::new(999, 123_456_789)), "999.123456789s"); +} + +#[test] +fn debug_formatting_millis() { + assert_eq!(format!("{:?}", Duration::new(0, 7_000_000)), "7ms"); + assert_eq!(format!("{:?}", Duration::new(0, 7_100_000)), "7.1ms"); + assert_eq!(format!("{:?}", Duration::new(0, 7_000_001)), "7.000001ms"); + assert_eq!(format!("{:?}", Duration::new(0, 7_123_456)), "7.123456ms"); + + assert_eq!(format!("{:?}", Duration::new(0, 88_000_000)), "88ms"); + assert_eq!(format!("{:?}", Duration::new(0, 88_100_000)), "88.1ms"); + assert_eq!(format!("{:?}", Duration::new(0, 88_000_001)), "88.000001ms"); + assert_eq!(format!("{:?}", Duration::new(0, 88_123_456)), "88.123456ms"); + + assert_eq!(format!("{:?}", Duration::new(0, 999_000_000)), "999ms"); + assert_eq!(format!("{:?}", Duration::new(0, 999_100_000)), "999.1ms"); + assert_eq!(format!("{:?}", Duration::new(0, 999_000_001)), "999.000001ms"); + assert_eq!(format!("{:?}", Duration::new(0, 999_123_456)), "999.123456ms"); +} + +#[test] +fn debug_formatting_micros() { + assert_eq!(format!("{:?}", Duration::new(0, 7_000)), "7µs"); + assert_eq!(format!("{:?}", Duration::new(0, 7_100)), "7.1µs"); + assert_eq!(format!("{:?}", Duration::new(0, 7_001)), "7.001µs"); + assert_eq!(format!("{:?}", Duration::new(0, 7_123)), "7.123µs"); + + assert_eq!(format!("{:?}", Duration::new(0, 88_000)), "88µs"); + assert_eq!(format!("{:?}", Duration::new(0, 88_100)), "88.1µs"); + assert_eq!(format!("{:?}", Duration::new(0, 88_001)), "88.001µs"); + assert_eq!(format!("{:?}", Duration::new(0, 88_123)), "88.123µs"); + + assert_eq!(format!("{:?}", Duration::new(0, 999_000)), "999µs"); + assert_eq!(format!("{:?}", Duration::new(0, 999_100)), "999.1µs"); + assert_eq!(format!("{:?}", Duration::new(0, 999_001)), "999.001µs"); + assert_eq!(format!("{:?}", Duration::new(0, 999_123)), "999.123µs"); +} + +#[test] +fn debug_formatting_nanos() { + assert_eq!(format!("{:?}", Duration::new(0, 0)), "0ns"); + assert_eq!(format!("{:?}", Duration::new(0, 1)), "1ns"); + assert_eq!(format!("{:?}", Duration::new(0, 88)), "88ns"); + assert_eq!(format!("{:?}", Duration::new(0, 999)), "999ns"); +} + +#[test] +fn debug_formatting_precision_zero() { + assert_eq!(format!("{:.0?}", Duration::new(0, 0)), "0ns"); + assert_eq!(format!("{:.0?}", Duration::new(0, 123)), "123ns"); + + assert_eq!(format!("{:.0?}", Duration::new(0, 1_001)), "1µs"); + assert_eq!(format!("{:.0?}", Duration::new(0, 1_999)), "1µs"); + + assert_eq!(format!("{:.0?}", Duration::new(0, 1_000_001)), "1ms"); + assert_eq!(format!("{:.0?}", Duration::new(0, 1_999_999)), "1ms"); + + assert_eq!(format!("{:.0?}", Duration::new(1, 000_000_001)), "1s"); + assert_eq!(format!("{:.0?}", Duration::new(1, 999_999_999)), "1s"); +} + +#[test] +fn debug_formatting_precision_two() { + // This might seem inconsistent with the other units, but printing + // fractional digits for nano seconds would imply more precision than is + // actually stored. + assert_eq!(format!("{:.2?}", Duration::new(0, 0)), "0ns"); + assert_eq!(format!("{:.2?}", Duration::new(0, 123)), "123ns"); + + assert_eq!(format!("{:.2?}", Duration::new(0, 1_000)), "1.00µs"); + assert_eq!(format!("{:.2?}", Duration::new(0, 7_001)), "7.00µs"); + assert_eq!(format!("{:.2?}", Duration::new(0, 7_100)), "7.10µs"); + assert_eq!(format!("{:.2?}", Duration::new(0, 1_999)), "1.99µs"); + + assert_eq!(format!("{:.2?}", Duration::new(0, 1_000_000)), "1.00ms"); + assert_eq!(format!("{:.2?}", Duration::new(0, 3_001_000)), "3.00ms"); + assert_eq!(format!("{:.2?}", Duration::new(0, 3_100_000)), "3.10ms"); + assert_eq!(format!("{:.2?}", Duration::new(0, 1_999_999)), "1.99ms"); + + assert_eq!(format!("{:.2?}", Duration::new(1, 000_000_000)), "1.00s"); + assert_eq!(format!("{:.2?}", Duration::new(4, 001_000_000)), "4.00s"); + assert_eq!(format!("{:.2?}", Duration::new(2, 100_000_000)), "2.10s"); + assert_eq!(format!("{:.2?}", Duration::new(8, 999_999_999)), "8.99s"); +} diff --git a/src/libcore/time.rs b/src/libcore/time.rs index 8e8b1691c65..a0a48e8493c 100644 --- a/src/libcore/time.rs +++ b/src/libcore/time.rs @@ -21,6 +21,7 @@ //! assert_eq!(Duration::new(5, 0), Duration::from_secs(5)); //! ``` +use fmt; use iter::Sum; use ops::{Add, Sub, Mul, Div, AddAssign, SubAssign, MulAssign, DivAssign}; @@ -59,7 +60,7 @@ const MICROS_PER_SEC: u64 = 1_000_000; /// let ten_millis = Duration::from_millis(10); /// ``` #[stable(feature = "duration", since = "1.3.0")] -#[derive(Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Debug, Hash, Default)] +#[derive(Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash, Default)] pub struct Duration { secs: u64, nanos: u32, // Always 0 <= nanos < NANOS_PER_SEC @@ -481,3 +482,78 @@ impl<'a> Sum<&'a Duration> for Duration { iter.fold(Duration::new(0, 0), |a, b| a + *b) } } + +#[stable(feature = "duration_debug_impl", since = "1.27.0")] +impl fmt::Debug for Duration { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + /// Formats a floating point number in decimal notation. + /// + /// The number is given as the `integer_part` and a fractional part. + /// The value of the fractional part is `fractional_part / divisor`. So + /// `integer_part` = 3, `fractional_part` = 12 and `divisor` = 100 + /// represents the number `3.012`. Trailing zeros are omitted. + /// + /// `divisor` must not be above 100_000_000. It also should be a power + /// of 10, everything else doesn't make sense. `fractional_part` has + /// to be less than `10 * divisor`! + fn fmt_decimal( + f: &mut fmt::Formatter, + integer_part: u64, + mut fractional_part: u32, + mut divisor: u32, + ) -> fmt::Result { + // Encode the fractional part into a temporary buffer. The buffer + // only need to hold 9 elements, because `fractional_part` has to + // be smaller than 10^9. The buffer is prefilled with '0' digits + // to simplify the code below. + let mut buf = [b'0'; 9]; + + // The next digit is written at this position + let mut pos = 0; + + // We can stop when there are no non-zero digits left or (when a + // precision was set and we already emitted that many digits). + while fractional_part > 0 && f.precision().map(|p| p > pos).unwrap_or(true) { + // Write new digit into the buffer + buf[pos] = b'0' + (fractional_part / divisor) as u8; + + fractional_part %= divisor; + divisor /= 10; + pos += 1; + } + + // If we haven't emitted a single fractional digit and the precision + // wasn't set to a non-zero value, we don't print the decimal point. + let end = f.precision().unwrap_or(pos); + if end == 0 { + write!(f, "{}", integer_part) + } else { + // We are only writing ASCII digits into the buffer and it was + // initialized with '0's, so it contains valid UTF8. + let s = unsafe { + ::str::from_utf8_unchecked(&buf[..end]) + }; + + write!(f, "{}.{}", integer_part, s) + } + } + + // Print leading '+' sign if requested + if f.sign_plus() { + write!(f, "+")?; + } + + if self.secs > 0 { + fmt_decimal(f, self.secs, self.nanos, 100_000_000)?; + f.write_str("s") + } else if self.nanos >= 1_000_000 { + fmt_decimal(f, self.nanos as u64 / 1_000_000, self.nanos % 1_000_000, 100_000)?; + f.write_str("ms") + } else if self.nanos >= 1_000 { + fmt_decimal(f, self.nanos as u64 / 1_000, self.nanos % 1_000, 100)?; + f.write_str("µs") + } else { + write!(f, "{}ns", self.nanos) + } + } +}