Skip to content

Commit 9eeb13f

Browse files
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
1 parent 6f721f5 commit 9eeb13f

File tree

2 files changed

+189
-1
lines changed

2 files changed

+189
-1
lines changed

src/libcore/tests/time.rs

+112
Original file line numberDiff line numberDiff line change
@@ -122,3 +122,115 @@ fn checked_div() {
122122
assert_eq!(Duration::new(1, 0).checked_div(2), Some(Duration::new(0, 500_000_000)));
123123
assert_eq!(Duration::new(2, 0).checked_div(0), None);
124124
}
125+
126+
#[test]
127+
fn debug_formatting_extreme_values() {
128+
assert_eq!(
129+
format!("{:?}", Duration::new(18_446_744_073_709_551_615, 123_456_789)),
130+
"18446744073709551615.123456789s"
131+
);
132+
}
133+
134+
#[test]
135+
fn debug_formatting_secs() {
136+
assert_eq!(format!("{:?}", Duration::new(7, 000_000_000)), "7s");
137+
assert_eq!(format!("{:?}", Duration::new(7, 100_000_000)), "7.1s");
138+
assert_eq!(format!("{:?}", Duration::new(7, 000_010_000)), "7.00001s");
139+
assert_eq!(format!("{:?}", Duration::new(7, 000_000_001)), "7.000000001s");
140+
assert_eq!(format!("{:?}", Duration::new(7, 123_456_789)), "7.123456789s");
141+
142+
assert_eq!(format!("{:?}", Duration::new(88, 000_000_000)), "88s");
143+
assert_eq!(format!("{:?}", Duration::new(88, 100_000_000)), "88.1s");
144+
assert_eq!(format!("{:?}", Duration::new(88, 000_010_000)), "88.00001s");
145+
assert_eq!(format!("{:?}", Duration::new(88, 000_000_001)), "88.000000001s");
146+
assert_eq!(format!("{:?}", Duration::new(88, 123_456_789)), "88.123456789s");
147+
148+
assert_eq!(format!("{:?}", Duration::new(999, 000_000_000)), "999s");
149+
assert_eq!(format!("{:?}", Duration::new(999, 100_000_000)), "999.1s");
150+
assert_eq!(format!("{:?}", Duration::new(999, 000_010_000)), "999.00001s");
151+
assert_eq!(format!("{:?}", Duration::new(999, 000_000_001)), "999.000000001s");
152+
assert_eq!(format!("{:?}", Duration::new(999, 123_456_789)), "999.123456789s");
153+
}
154+
155+
#[test]
156+
fn debug_formatting_millis() {
157+
assert_eq!(format!("{:?}", Duration::new(0, 7_000_000)), "7ms");
158+
assert_eq!(format!("{:?}", Duration::new(0, 7_100_000)), "7.1ms");
159+
assert_eq!(format!("{:?}", Duration::new(0, 7_000_001)), "7.000001ms");
160+
assert_eq!(format!("{:?}", Duration::new(0, 7_123_456)), "7.123456ms");
161+
162+
assert_eq!(format!("{:?}", Duration::new(0, 88_000_000)), "88ms");
163+
assert_eq!(format!("{:?}", Duration::new(0, 88_100_000)), "88.1ms");
164+
assert_eq!(format!("{:?}", Duration::new(0, 88_000_001)), "88.000001ms");
165+
assert_eq!(format!("{:?}", Duration::new(0, 88_123_456)), "88.123456ms");
166+
167+
assert_eq!(format!("{:?}", Duration::new(0, 999_000_000)), "999ms");
168+
assert_eq!(format!("{:?}", Duration::new(0, 999_100_000)), "999.1ms");
169+
assert_eq!(format!("{:?}", Duration::new(0, 999_000_001)), "999.000001ms");
170+
assert_eq!(format!("{:?}", Duration::new(0, 999_123_456)), "999.123456ms");
171+
}
172+
173+
#[test]
174+
fn debug_formatting_micros() {
175+
assert_eq!(format!("{:?}", Duration::new(0, 7_000)), "7µs");
176+
assert_eq!(format!("{:?}", Duration::new(0, 7_100)), "7.1µs");
177+
assert_eq!(format!("{:?}", Duration::new(0, 7_001)), "7.001µs");
178+
assert_eq!(format!("{:?}", Duration::new(0, 7_123)), "7.123µs");
179+
180+
assert_eq!(format!("{:?}", Duration::new(0, 88_000)), "88µs");
181+
assert_eq!(format!("{:?}", Duration::new(0, 88_100)), "88.1µs");
182+
assert_eq!(format!("{:?}", Duration::new(0, 88_001)), "88.001µs");
183+
assert_eq!(format!("{:?}", Duration::new(0, 88_123)), "88.123µs");
184+
185+
assert_eq!(format!("{:?}", Duration::new(0, 999_000)), "999µs");
186+
assert_eq!(format!("{:?}", Duration::new(0, 999_100)), "999.1µs");
187+
assert_eq!(format!("{:?}", Duration::new(0, 999_001)), "999.001µs");
188+
assert_eq!(format!("{:?}", Duration::new(0, 999_123)), "999.123µs");
189+
}
190+
191+
#[test]
192+
fn debug_formatting_nanos() {
193+
assert_eq!(format!("{:?}", Duration::new(0, 0)), "0ns");
194+
assert_eq!(format!("{:?}", Duration::new(0, 1)), "1ns");
195+
assert_eq!(format!("{:?}", Duration::new(0, 88)), "88ns");
196+
assert_eq!(format!("{:?}", Duration::new(0, 999)), "999ns");
197+
}
198+
199+
#[test]
200+
fn debug_formatting_precision_zero() {
201+
assert_eq!(format!("{:.0?}", Duration::new(0, 0)), "0ns");
202+
assert_eq!(format!("{:.0?}", Duration::new(0, 123)), "123ns");
203+
204+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_001)), "1µs");
205+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_999)), "1µs");
206+
207+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_000_001)), "1ms");
208+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_999_999)), "1ms");
209+
210+
assert_eq!(format!("{:.0?}", Duration::new(1, 000_000_001)), "1s");
211+
assert_eq!(format!("{:.0?}", Duration::new(1, 999_999_999)), "1s");
212+
}
213+
214+
#[test]
215+
fn debug_formatting_precision_two() {
216+
// This might seem inconsistent with the other units, but printing
217+
// fractional digits for nano seconds would imply more precision than is
218+
// actually stored.
219+
assert_eq!(format!("{:.2?}", Duration::new(0, 0)), "0ns");
220+
assert_eq!(format!("{:.2?}", Duration::new(0, 123)), "123ns");
221+
222+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_000)), "1.00µs");
223+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_001)), "7.00µs");
224+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_100)), "7.10µs");
225+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_999)), "1.99µs");
226+
227+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_000_000)), "1.00ms");
228+
assert_eq!(format!("{:.2?}", Duration::new(0, 3_001_000)), "3.00ms");
229+
assert_eq!(format!("{:.2?}", Duration::new(0, 3_100_000)), "3.10ms");
230+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_999_999)), "1.99ms");
231+
232+
assert_eq!(format!("{:.2?}", Duration::new(1, 000_000_000)), "1.00s");
233+
assert_eq!(format!("{:.2?}", Duration::new(4, 001_000_000)), "4.00s");
234+
assert_eq!(format!("{:.2?}", Duration::new(2, 100_000_000)), "2.10s");
235+
assert_eq!(format!("{:.2?}", Duration::new(8, 999_999_999)), "8.99s");
236+
}

src/libcore/time.rs

+77-1
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@
2121
//! assert_eq!(Duration::new(5, 0), Duration::from_secs(5));
2222
//! ```
2323
24+
use fmt;
2425
use iter::Sum;
2526
use ops::{Add, Sub, Mul, Div, AddAssign, SubAssign, MulAssign, DivAssign};
2627

@@ -59,7 +60,7 @@ const MICROS_PER_SEC: u64 = 1_000_000;
5960
/// let ten_millis = Duration::from_millis(10);
6061
/// ```
6162
#[stable(feature = "duration", since = "1.3.0")]
62-
#[derive(Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Debug, Hash, Default)]
63+
#[derive(Clone, Copy, PartialEq, Eq, PartialOrd, Ord, Hash, Default)]
6364
pub struct Duration {
6465
secs: u64,
6566
nanos: u32, // Always 0 <= nanos < NANOS_PER_SEC
@@ -481,3 +482,78 @@ impl<'a> Sum<&'a Duration> for Duration {
481482
iter.fold(Duration::new(0, 0), |a, b| a + *b)
482483
}
483484
}
485+
486+
#[stable(feature = "duration_debug_impl", since = "1.27.0")]
487+
impl fmt::Debug for Duration {
488+
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
489+
/// Formats a floating point number in decimal notation.
490+
///
491+
/// The number is given as the `integer_part` and a fractional part.
492+
/// The value of the fractional part is `fractional_part / divisor`. So
493+
/// `integer_part` = 3, `fractional_part` = 12 and `divisor` = 100
494+
/// represents the number `3.012`. Trailing zeros are omitted.
495+
///
496+
/// `divisor` must not be above 100_000_000. It also should be a power
497+
/// of 10, everything else doesn't make sense. `fractional_part` has
498+
/// to be less than `10 * divisor`!
499+
fn fmt_decimal(
500+
f: &mut fmt::Formatter,
501+
integer_part: u64,
502+
mut fractional_part: u32,
503+
mut divisor: u32,
504+
) -> fmt::Result {
505+
// Encode the fractional part into a temporary buffer. The buffer
506+
// only need to hold 9 elements, because `fractional_part` has to
507+
// be smaller than 10^9. The buffer is prefilled with '0' digits
508+
// to simplify the code below.
509+
let mut buf = [b'0'; 9];
510+
511+
// The next digit is written at this position
512+
let mut pos = 0;
513+
514+
// We can stop when there are no non-zero digits left or (when a
515+
// precision was set and we already emitted that many digits).
516+
while fractional_part > 0 && f.precision().map(|p| p > pos).unwrap_or(true) {
517+
// Write new digit into the buffer
518+
buf[pos] = b'0' + (fractional_part / divisor) as u8;
519+
520+
fractional_part %= divisor;
521+
divisor /= 10;
522+
pos += 1;
523+
}
524+
525+
// If we haven't emitted a single fractional digit and the precision
526+
// wasn't set to a non-zero value, we don't print the decimal point.
527+
let end = f.precision().unwrap_or(pos);
528+
if end == 0 {
529+
write!(f, "{}", integer_part)
530+
} else {
531+
// We are only writing ASCII digits into the buffer and it was
532+
// initialized with '0's, so it contains valid UTF8.
533+
let s = unsafe {
534+
::str::from_utf8_unchecked(&buf[..end])
535+
};
536+
537+
write!(f, "{}.{}", integer_part, s)
538+
}
539+
}
540+
541+
// Print leading '+' sign if requested
542+
if f.sign_plus() {
543+
write!(f, "+")?;
544+
}
545+
546+
if self.secs > 0 {
547+
fmt_decimal(f, self.secs, self.nanos, 100_000_000)?;
548+
f.write_str("s")
549+
} else if self.nanos >= 1_000_000 {
550+
fmt_decimal(f, self.nanos as u64 / 1_000_000, self.nanos % 1_000_000, 100_000)?;
551+
f.write_str("ms")
552+
} else if self.nanos >= 1_000 {
553+
fmt_decimal(f, self.nanos as u64 / 1_000, self.nanos % 1_000, 100)?;
554+
f.write_str("µs")
555+
} else {
556+
write!(f, "{}ns", self.nanos)
557+
}
558+
}
559+
}

0 commit comments

Comments
 (0)