Improve `Debug` impl of `core::time::Duration`

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

diff --git a/src/libcore/tests/time.rs b/src/libcore/tests/time.rs
index 042c523f25f25badec26e7737654afeb65de94ee..bfb5369cf8f8c1d9f67f3340e2a6161df30715de 100644 (file)
--- 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 8e8b1691c657a3bc0edaa12e336332e82f55a3db..a0a48e8493ce3dff393e8878d666a6e8e7d44f63 100644 (file)
--- 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 @@
 /// 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 @@ fn sum<I: Iterator<Item=&'a Duration>>(iter: I) -> 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)
+        }
+    }
+}