Skip to content

Commit

Permalink
Fix incorrect seconds_per_step calculation
Browse files Browse the repository at this point in the history
seconds_per_step looks at a ring buffer with samples taken each
tick. Each sample is

    <duration of the tick> / <number of progress steps>

This results in an incorrect seconds_per_step, when this is
calculated as a raw average of the buffer values. This is because
we have no reason to assume any tick is a more representative sample
than any other tick, but this will treat ticks with very few steps
as *more* representative than steps with many ticks, because the
value of the denominator is lost.

The result is a very poor ETA / bitrate estimation when step
production follows a burst-wait pattern, since ticks with few or
no steps are to be expected.

A better estimate could be achieved by averaging over the step-rate
of each tick, but this would still not be ideal since it would
treat short ticks as equally representative as long ticks in the
average.

Instead, we make two changes:

First, we change the buffer to store the total number of steps
rather than the difference between steps. This necessitates changing
the new / reset code to set the first buffer item to zero.

Second, we create a second ring buffer to store the timestamp of
each tick. As a result, we can calculate the `seconds_per_step`
rate by simply looking at the earliest values in the buffer, and
returning `(now() - first_time) / (last_steps - first_steps)`.

By using `now()` instead of `last_time` in the above equation, we
also fix an additional issue. Since we only add items to the buffer
when new steps occur, the progress bar freezes and the ETA does not
update when progress stalls. By always using the latest time, we get
a more accurate seconds_per_step estimate with no additional
overhead.
  • Loading branch information
afontenot committed Apr 26, 2023
1 parent 4987fc5 commit 193a51c
Showing 1 changed file with 37 additions and 23 deletions.
60 changes: 37 additions & 23 deletions src/state.rs
Original file line number Diff line number Diff line change
Expand Up @@ -370,7 +370,8 @@ impl TabExpandedString {
/// Ring buffer with constant capacity. Used by `ProgressBar`s to display `{eta}`,
/// `{eta_precise}`, and `{*_per_sec}`.
pub(crate) struct Estimator {
steps: [f64; 16],
steps: [u64; 16],
step_instants: [Instant; 16],
pos: u8,
full: bool,
prev: (u64, Instant),
Expand All @@ -379,16 +380,16 @@ pub(crate) struct Estimator {
impl Estimator {
fn new(now: Instant) -> Self {
Self {
steps: [0.0; 16],
pos: 0,
steps: [0; 16],
step_instants: [now; 16],
pos: 1,
full: false,
prev: (0, now),
}
}

fn record(&mut self, new: u64, now: Instant) {
let delta = new.saturating_sub(self.prev.0);
if delta == 0 || now < self.prev.1 {
if new <= self.prev.0 || now < self.prev.1 {
// Reset on backwards seek to prevent breakage from seeking to the end for length determination
// See https://github.com/console-rs/indicatif/issues/480
if new < self.prev.0 {
Expand All @@ -397,14 +398,9 @@ impl Estimator {
return;
}

let elapsed = now - self.prev.1;
let divisor = delta as f64;
let mut batch = 0.0;
if divisor != 0.0 {
batch = duration_to_secs(elapsed) / divisor;
};
self.steps[self.pos as usize] = new;
self.step_instants[self.pos as usize] = now;

self.steps[self.pos as usize] = batch;
self.pos = (self.pos + 1) % 16;
if !self.full && self.pos == 0 {
self.full = true;
Expand All @@ -414,15 +410,23 @@ impl Estimator {
}

pub(crate) fn reset(&mut self, now: Instant) {
self.pos = 0;
self.pos = 1;
self.full = false;
self.prev = (0, now);
self.steps[0] = 0;
self.step_instants[0] = now;
}

/// Average time per step in seconds, using rolling buffer of last 15 steps
fn seconds_per_step(&self) -> f64 {
let len = self.len();
self.steps[0..len].iter().sum::<f64>() / len as f64
let now = Instant::now();
let first_pos = (self.pos as usize) % self.len();
let steps = self.prev.0 - self.steps[first_pos];
let mut duration: f64 = 0.0;
if steps != 0 {
duration = duration_to_secs(now - self.step_instants[first_pos]);
}
duration / steps as f64
}

fn len(&self) -> usize {
Expand Down Expand Up @@ -582,25 +586,35 @@ mod tests {
let mut now = Instant::now();
let mut est = Estimator::new(now);
let mut pos = 0;
let buffer_size = est.steps.len() as u64;

for _ in 0..est.steps.len() {
now -= Duration::from_secs(buffer_size);
let start_time = now;
est.reset(now);

for _ in 0..buffer_size {
pos += items_per_second;
now += Duration::from_secs(1);
est.record(pos, now);
}
let before = Instant::now();
let avg_seconds_per_step = est.seconds_per_step();
let after = Instant::now();

assert!(avg_seconds_per_step > 0.0);
assert!(avg_seconds_per_step.is_finite());

let expected_rate = 1.0 / items_per_second as f64;
let absolute_error = (avg_seconds_per_step - expected_rate).abs();
let expected_rate_upper =
expected_rate * duration_to_secs(after - start_time) / buffer_size as f64;
let expected_rate_lower =
expected_rate * duration_to_secs(before - start_time) / buffer_size as f64;
assert!(
absolute_error < f64::EPSILON,
"Expected rate: {}, actual: {}, absolute error: {}",
expected_rate,
avg_seconds_per_step > expected_rate_lower && expected_rate < expected_rate_upper,
"Expected rate (min): {}, actual: {}, Expected rate (max): {}",
expected_rate_lower,
avg_seconds_per_step,
absolute_error
expected_rate_upper
);
};

Expand Down Expand Up @@ -628,11 +642,11 @@ mod tests {
let mut est = Estimator::new(now);
est.record(0, now);
est.record(1, now);
assert_eq!(est.len(), 1);
assert_eq!(est.len(), 2);
// Should not panic.
est.record(0, now);
// Assert that the state of the estimator reset on rewind
assert_eq!(est.len(), 0);
assert_eq!(est.len(), 1);

let pb = ProgressBar::hidden();
pb.set_length(10);
Expand Down

0 comments on commit 193a51c

Please sign in to comment.