Inter-event timing metrics on top of [tracing
].
This crate provides a tracing::Subscriber
that keeps statistics on
inter-event timing information. More concretely, given code like this:
rust
use tracing::*;
use tracing_timing::{Builder, Histogram};
let subscriber = Builder::from(|| Histogram::new_with_max(1_000_000, 2).unwrap()).build();
let dispatcher = Dispatch::new(subscriber);
dispatcher::with_default(&dispatcher, || {
trace_span!("request").in_scope(|| {
// do a little bit of work
trace!("fast");
// do a lot of work
trace!("slow");
})
});
You can produce something like this:
```text fast: mean: 173.2µs, p50: 172µs, p90: 262µs, p99: 327µs, p999: 450µs, max: 778µs 25µs | * | 2.2th %-ile 50µs | * | 2.2th %-ile 75µs | * | 4.7th %-ile 100µs | * | 11.5th %-ile 125µs | * | 24.0th %-ile 150µs | * | 41.1th %-ile 175µs | * | 59.2th %-ile 200µs | * | 75.4th %-ile 225µs | * | 80.1th %-ile 250µs | * | 87.3th %-ile 275µs | | 94.4th %-ile 300µs | * | 97.8th %-ile
slow: mean: 623.3µs, p50: 630µs, p90: 696µs, p99: 770µs, p999: 851µs, max: 950µs 500µs | * | 1.6th %-ile 525µs | * | 4.8th %-ile 550µs | | 10.9th %-ile 575µs | * | 22.2th %-ile 600µs | * | 37.9th %-ile 625µs | * | 55.9th %-ile 650µs | * | 72.9th %-ile 675µs | | 85.6th %-ile 700µs | ** | 93.5th %-ile 725µs | * | 97.1th %-ile ```
When TimingSubscriber
is used as the tracing::Dispatch
, the time
between each event in a span is measured using [quanta
], and is
recorded in "[high dynamic range histograms]" using [hdrhistogram
]'s
multi-threaded recording facilities. The recorded timing information is
grouped using the SpanGroup
and EventGroup
traits, allowing you to
combine recorded statistics across spans and events.