drill icon indicating copy to clipboard operation
drill copied to clipboard

Milliseconds treated as seconds in histogram stats

Open michaelsproul opened this issue 1 year ago • 0 comments

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

https://github.com/fcsonline/drill/blob/f7627bfd005a599638fe6c77963df2c45c00b5dc/src/actions/request.rs#L273-L285

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:

https://github.com/fcsonline/drill/blob/f7627bfd005a599638fe6c77963df2c45c00b5dc/src/main.rs#L116

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.

michaelsproul avatar Feb 01 '23 06:02 michaelsproul