Skip to content

Milliseconds treated as seconds in histogram stats #165

@michaelsproul

Description

@michaelsproul

In the request runner, the millisecond duration is inserted into the Report's duration field:

None => reports.push(Report {
name: self.name.to_owned(),
duration: duration_ms,
status: 520u16,
}),
Some(response) => {
let status = response.status().as_u16();
reports.push(Report {
name: self.name.to_owned(),
duration: duration_ms,
status,
});

Elsewhere it seems the code expects this value to be in seconds, e.g. it multiplies it by 1000 when inserting it into the histogram:

hist += (r.duration * 1_000.0) as u64;

The histogram is set with bounds such that its maximum is 60 * 60 * 1000, i.e. an hour in milliseconds. However due to the extra multiplication by 1000 the actual limit is just 60 * 60, i.e. 3.6 seconds. Any request taking longer than this causes a panic when its duration is added to the histogram:

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: ValueOutOfRangeResizeDisabled', /home/michael/.cargo/registry/src/github.com-1ecc6299db9ec823/hdrhistogram-7.5.2/src/lib.rs:1864:28
stack backtrace:
   0: rust_begin_unwind
             at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/std/src/panicking.rs:575:5
   1: core::panicking::panic_fmt
             at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/panicking.rs:64:14
   2: core::result::unwrap_failed
             at /rustc/fc594f15669680fa70d255faec3ca3fb507c3405/library/core/src/result.rs:1791:5
   3: <hdrhistogram::Histogram<T> as core::ops::arith::AddAssign<u64>>::add_assign
   4: drill::compute_stats
   5: drill::show_stats
   6: drill::main
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions