Skip to content

Commit 444a9c3

Browse files
committed
Auto merge of #50364 - LukasKalbertodt:improve-duration-debug-impl, r=KodrAus
Improve `Debug` impl of `time::Duration` Hi there! For a long time now, I was getting annoyed by the derived `Debug` impl of `Duration`. Usually, I use `Duration` to either do quick'n'dirty benchmarking or measuring the time of some operation in general. The output of the derived Debug impl is hard to parse for humans: is { secs: 0, nanos: 968360102 } or { secs: 0, nanos 98507324 } longer? So after running into the annoyance several times (sometimes building my own function to print the Duration properly), I decided to tackle this. Now the output looks like this: ``` Duration::new(1, 0) => 1s Duration::new(1, 1) => 1.000000001s Duration::new(1, 300) => 1.0000003s Duration::new(1, 4000) => 1.000004s Duration::new(1, 600000) => 1.0006s Duration::new(1, 7000000) => 1.007s Duration::new(0, 0) => 0ns Duration::new(0, 1) => 1ns Duration::new(0, 300) => 300ns Duration::new(0, 4001) => 4.001µs Duration::new(0, 600300) => 600.3µs Duration::new(0, 7000000) => 7ms ``` Note that I implemented the formatting manually and didn't use floats. No information is "lost" when printing. So `Duration::new(123_456_789_000, 900_000_001)` prints as `123456789000.900000001s`. ~~This is not yet finished~~, but I wanted to open the PR now already in order to get some feedback (maybe everyone likes the derived impl). ### Still ToDo: - [x] Respect precision ~~and width~~ parameter of the formatter (see [this comment](#50364 (comment))) ### Alternatives/Decisions - Should large durations displayed in minutes, hours, days, ...? For now, I decided not to because the current formatting is close the how a `Duration` is stored. From this new `Debug` output, you can still easily see what the values of `secs` and `nanos` are. A formatting like `3h 27m 12s 9ms` might be more appropriate for a `Display` impl? - Should this rather be a `Display` impl and should `Debug` be derived? Maybe this formatting is too fancy for `Debug`? In my opinion it's not and, as already mentioned, from the current format one can still very easily determine the values for `secs` and `nanos`. - Whitespace between the number and the unit? ### Notes for reviewers - ~~The combined diff sucks. Rather review both commits individually.~~ - ~~In the unit test, I am building my own type implementing `fmt::Write` to test the output. Maybe there is already something like that which I can use?~~ - My `Debug` impl block is marked as `#[stable(...)]`... but that's fine since the derived Debug impl was stable already, right? --- ~~Apart from the main change, I moved all `time` unit tests into the `tests` directory. All other `libcore` tests are there, so I guess it was simply an oversight. Prior to this change, the `time` tests weren't run, so I guess this is kind of a bug fix. If my `Debug` impl is rejected, I can of course just send the fix as PR.~~ (this was already merged in #50466)
2 parents 67d99d9 + 59e7114 commit 444a9c3

File tree

2 files changed

+246
-1
lines changed

2 files changed

+246
-1
lines changed

src/libcore/tests/time.rs

+128
Original file line numberDiff line numberDiff line change
@@ -160,3 +160,131 @@ fn checked_div() {
160160
assert_eq!(Duration::new(1, 0).checked_div(2), Some(Duration::new(0, 500_000_000)));
161161
assert_eq!(Duration::new(2, 0).checked_div(0), None);
162162
}
163+
164+
#[test]
165+
fn debug_formatting_extreme_values() {
166+
assert_eq!(
167+
format!("{:?}", Duration::new(18_446_744_073_709_551_615, 123_456_789)),
168+
"18446744073709551615.123456789s"
169+
);
170+
}
171+
172+
#[test]
173+
fn debug_formatting_secs() {
174+
assert_eq!(format!("{:?}", Duration::new(7, 000_000_000)), "7s");
175+
assert_eq!(format!("{:?}", Duration::new(7, 100_000_000)), "7.1s");
176+
assert_eq!(format!("{:?}", Duration::new(7, 000_010_000)), "7.00001s");
177+
assert_eq!(format!("{:?}", Duration::new(7, 000_000_001)), "7.000000001s");
178+
assert_eq!(format!("{:?}", Duration::new(7, 123_456_789)), "7.123456789s");
179+
180+
assert_eq!(format!("{:?}", Duration::new(88, 000_000_000)), "88s");
181+
assert_eq!(format!("{:?}", Duration::new(88, 100_000_000)), "88.1s");
182+
assert_eq!(format!("{:?}", Duration::new(88, 000_010_000)), "88.00001s");
183+
assert_eq!(format!("{:?}", Duration::new(88, 000_000_001)), "88.000000001s");
184+
assert_eq!(format!("{:?}", Duration::new(88, 123_456_789)), "88.123456789s");
185+
186+
assert_eq!(format!("{:?}", Duration::new(999, 000_000_000)), "999s");
187+
assert_eq!(format!("{:?}", Duration::new(999, 100_000_000)), "999.1s");
188+
assert_eq!(format!("{:?}", Duration::new(999, 000_010_000)), "999.00001s");
189+
assert_eq!(format!("{:?}", Duration::new(999, 000_000_001)), "999.000000001s");
190+
assert_eq!(format!("{:?}", Duration::new(999, 123_456_789)), "999.123456789s");
191+
}
192+
193+
#[test]
194+
fn debug_formatting_millis() {
195+
assert_eq!(format!("{:?}", Duration::new(0, 7_000_000)), "7ms");
196+
assert_eq!(format!("{:?}", Duration::new(0, 7_100_000)), "7.1ms");
197+
assert_eq!(format!("{:?}", Duration::new(0, 7_000_001)), "7.000001ms");
198+
assert_eq!(format!("{:?}", Duration::new(0, 7_123_456)), "7.123456ms");
199+
200+
assert_eq!(format!("{:?}", Duration::new(0, 88_000_000)), "88ms");
201+
assert_eq!(format!("{:?}", Duration::new(0, 88_100_000)), "88.1ms");
202+
assert_eq!(format!("{:?}", Duration::new(0, 88_000_001)), "88.000001ms");
203+
assert_eq!(format!("{:?}", Duration::new(0, 88_123_456)), "88.123456ms");
204+
205+
assert_eq!(format!("{:?}", Duration::new(0, 999_000_000)), "999ms");
206+
assert_eq!(format!("{:?}", Duration::new(0, 999_100_000)), "999.1ms");
207+
assert_eq!(format!("{:?}", Duration::new(0, 999_000_001)), "999.000001ms");
208+
assert_eq!(format!("{:?}", Duration::new(0, 999_123_456)), "999.123456ms");
209+
}
210+
211+
#[test]
212+
fn debug_formatting_micros() {
213+
assert_eq!(format!("{:?}", Duration::new(0, 7_000)), "7µs");
214+
assert_eq!(format!("{:?}", Duration::new(0, 7_100)), "7.1µs");
215+
assert_eq!(format!("{:?}", Duration::new(0, 7_001)), "7.001µs");
216+
assert_eq!(format!("{:?}", Duration::new(0, 7_123)), "7.123µs");
217+
218+
assert_eq!(format!("{:?}", Duration::new(0, 88_000)), "88µs");
219+
assert_eq!(format!("{:?}", Duration::new(0, 88_100)), "88.1µs");
220+
assert_eq!(format!("{:?}", Duration::new(0, 88_001)), "88.001µs");
221+
assert_eq!(format!("{:?}", Duration::new(0, 88_123)), "88.123µs");
222+
223+
assert_eq!(format!("{:?}", Duration::new(0, 999_000)), "999µs");
224+
assert_eq!(format!("{:?}", Duration::new(0, 999_100)), "999.1µs");
225+
assert_eq!(format!("{:?}", Duration::new(0, 999_001)), "999.001µs");
226+
assert_eq!(format!("{:?}", Duration::new(0, 999_123)), "999.123µs");
227+
}
228+
229+
#[test]
230+
fn debug_formatting_nanos() {
231+
assert_eq!(format!("{:?}", Duration::new(0, 0)), "0ns");
232+
assert_eq!(format!("{:?}", Duration::new(0, 1)), "1ns");
233+
assert_eq!(format!("{:?}", Duration::new(0, 88)), "88ns");
234+
assert_eq!(format!("{:?}", Duration::new(0, 999)), "999ns");
235+
}
236+
237+
#[test]
238+
fn debug_formatting_precision_zero() {
239+
assert_eq!(format!("{:.0?}", Duration::new(0, 0)), "0ns");
240+
assert_eq!(format!("{:.0?}", Duration::new(0, 123)), "123ns");
241+
242+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_001)), "1µs");
243+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_499)), "1µs");
244+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_500)), "2µs");
245+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_999)), "2µs");
246+
247+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_000_001)), "1ms");
248+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_499_999)), "1ms");
249+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_500_000)), "2ms");
250+
assert_eq!(format!("{:.0?}", Duration::new(0, 1_999_999)), "2ms");
251+
252+
assert_eq!(format!("{:.0?}", Duration::new(1, 000_000_001)), "1s");
253+
assert_eq!(format!("{:.0?}", Duration::new(1, 499_999_999)), "1s");
254+
assert_eq!(format!("{:.0?}", Duration::new(1, 500_000_000)), "2s");
255+
assert_eq!(format!("{:.0?}", Duration::new(1, 999_999_999)), "2s");
256+
}
257+
258+
#[test]
259+
fn debug_formatting_precision_two() {
260+
assert_eq!(format!("{:.2?}", Duration::new(0, 0)), "0.00ns");
261+
assert_eq!(format!("{:.2?}", Duration::new(0, 123)), "123.00ns");
262+
263+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_000)), "1.00µs");
264+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_001)), "7.00µs");
265+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_100)), "7.10µs");
266+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_109)), "7.11µs");
267+
assert_eq!(format!("{:.2?}", Duration::new(0, 7_199)), "7.20µs");
268+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_999)), "2.00µs");
269+
270+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_000_000)), "1.00ms");
271+
assert_eq!(format!("{:.2?}", Duration::new(0, 3_001_000)), "3.00ms");
272+
assert_eq!(format!("{:.2?}", Duration::new(0, 3_100_000)), "3.10ms");
273+
assert_eq!(format!("{:.2?}", Duration::new(0, 1_999_999)), "2.00ms");
274+
275+
assert_eq!(format!("{:.2?}", Duration::new(1, 000_000_000)), "1.00s");
276+
assert_eq!(format!("{:.2?}", Duration::new(4, 001_000_000)), "4.00s");
277+
assert_eq!(format!("{:.2?}", Duration::new(2, 100_000_000)), "2.10s");
278+
assert_eq!(format!("{:.2?}", Duration::new(2, 104_990_000)), "2.10s");
279+
assert_eq!(format!("{:.2?}", Duration::new(2, 105_000_000)), "2.11s");
280+
assert_eq!(format!("{:.2?}", Duration::new(8, 999_999_999)), "9.00s");
281+
}
282+
283+
#[test]
284+
fn debug_formatting_precision_high() {
285+
assert_eq!(format!("{:.5?}", Duration::new(0, 23_678)), "23.67800µs");
286+
287+
assert_eq!(format!("{:.9?}", Duration::new(1, 000_000_000)), "1.000000000s");
288+
assert_eq!(format!("{:.10?}", Duration::new(4, 001_000_000)), "4.0010000000s");
289+
assert_eq!(format!("{:.20?}", Duration::new(4, 001_000_000)), "4.00100000000000000000s");
290+
}

src/libcore/time.rs

+118-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
@@ -485,3 +486,119 @@ impl<'a> Sum<&'a Duration> for Duration {
485486
iter.fold(Duration::new(0, 0), |a, b| a + *b)
486487
}
487488
}
489+
490+
#[stable(feature = "duration_debug_impl", since = "1.27.0")]
491+
impl fmt::Debug for Duration {
492+
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
493+
/// Formats a floating point number in decimal notation.
494+
///
495+
/// The number is given as the `integer_part` and a fractional part.
496+
/// The value of the fractional part is `fractional_part / divisor`. So
497+
/// `integer_part` = 3, `fractional_part` = 12 and `divisor` = 100
498+
/// represents the number `3.012`. Trailing zeros are omitted.
499+
///
500+
/// `divisor` must not be above 100_000_000. It also should be a power
501+
/// of 10, everything else doesn't make sense. `fractional_part` has
502+
/// to be less than `10 * divisor`!
503+
fn fmt_decimal(
504+
f: &mut fmt::Formatter,
505+
mut integer_part: u64,
506+
mut fractional_part: u32,
507+
mut divisor: u32,
508+
) -> fmt::Result {
509+
// Encode the fractional part into a temporary buffer. The buffer
510+
// only need to hold 9 elements, because `fractional_part` has to
511+
// be smaller than 10^9. The buffer is prefilled with '0' digits
512+
// to simplify the code below.
513+
let mut buf = [b'0'; 9];
514+
515+
// The next digit is written at this position
516+
let mut pos = 0;
517+
518+
// We keep writing digits into the buffer while there are non-zero
519+
// digits left and we haven't written enough digits yet.
520+
while fractional_part > 0 && pos < f.precision().unwrap_or(9) {
521+
// Write new digit into the buffer
522+
buf[pos] = b'0' + (fractional_part / divisor) as u8;
523+
524+
fractional_part %= divisor;
525+
divisor /= 10;
526+
pos += 1;
527+
}
528+
529+
// If a precision < 9 was specified, there may be some non-zero
530+
// digits left that weren't written into the buffer. In that case we
531+
// need to perform rounding to match the semantics of printing
532+
// normal floating point numbers. However, we only need to do work
533+
// when rounding up. This happens if the first digit of the
534+
// remaining ones is >= 5.
535+
if fractional_part > 0 && fractional_part >= divisor * 5 {
536+
// Round up the number contained in the buffer. We go through
537+
// the buffer backwards and keep track of the carry.
538+
let mut rev_pos = pos;
539+
let mut carry = true;
540+
while carry && rev_pos > 0 {
541+
rev_pos -= 1;
542+
543+
// If the digit in the buffer is not '9', we just need to
544+
// increment it and can stop then (since we don't have a
545+
// carry anymore). Otherwise, we set it to '0' (overflow)
546+
// and continue.
547+
if buf[rev_pos] < b'9' {
548+
buf[rev_pos] += 1;
549+
carry = false;
550+
} else {
551+
buf[rev_pos] = b'0';
552+
}
553+
}
554+
555+
// If we still have the carry bit set, that means that we set
556+
// the whole buffer to '0's and need to increment the integer
557+
// part.
558+
if carry {
559+
integer_part += 1;
560+
}
561+
}
562+
563+
// Determine the end of the buffer: if precision is set, we just
564+
// use as many digits from the buffer (capped to 9). If it isn't
565+
// set, we only use all digits up to the last non-zero one.
566+
let end = f.precision().map(|p| ::cmp::min(p, 9)).unwrap_or(pos);
567+
568+
// If we haven't emitted a single fractional digit and the precision
569+
// wasn't set to a non-zero value, we don't print the decimal point.
570+
if end == 0 {
571+
write!(f, "{}", integer_part)
572+
} else {
573+
// We are only writing ASCII digits into the buffer and it was
574+
// initialized with '0's, so it contains valid UTF8.
575+
let s = unsafe {
576+
::str::from_utf8_unchecked(&buf[..end])
577+
};
578+
579+
// If the user request a precision > 9, we pad '0's at the end.
580+
let w = f.precision().unwrap_or(pos);
581+
write!(f, "{}.{:0<width$}", integer_part, s, width = w)
582+
}
583+
}
584+
585+
// Print leading '+' sign if requested
586+
if f.sign_plus() {
587+
write!(f, "+")?;
588+
}
589+
590+
if self.secs > 0 {
591+
fmt_decimal(f, self.secs, self.nanos, 100_000_000)?;
592+
f.write_str("s")
593+
} else if self.nanos >= 1_000_000 {
594+
fmt_decimal(f, self.nanos as u64 / 1_000_000, self.nanos % 1_000_000, 100_000)?;
595+
f.write_str("ms")
596+
} else if self.nanos >= 1_000 {
597+
fmt_decimal(f, self.nanos as u64 / 1_000, self.nanos % 1_000, 100)?;
598+
f.write_str("µs")
599+
} else {
600+
fmt_decimal(f, self.nanos as u64, 0, 1)?;
601+
f.write_str("ns")
602+
}
603+
}
604+
}

0 commit comments

Comments
 (0)