otel: add second-based duration histograms

This commit is contained in:
Richard Lee
2026-06-08 14:17:20 -07:00
parent 4cbbdef615
commit a848c7528e
3 changed files with 169 additions and 13 deletions
+80 -13
View File
@@ -43,8 +43,16 @@ use tracing::debug;
const ENV_ATTRIBUTE: &str = "env";
const METER_NAME: &str = "codex";
const DURATION_UNIT: &str = "ms";
const DURATION_DESCRIPTION: &str = "Duration in milliseconds.";
const MILLISECOND_DURATION_UNIT: &str = "ms";
const MILLISECOND_DURATION_DESCRIPTION: &str = "Duration in milliseconds.";
const MILLISECOND_DURATION_BOUNDARIES: &[f64] = &[
0.0, 5.0, 10.0, 25.0, 50.0, 75.0, 100.0, 250.0, 500.0, 750.0, 1000.0, 2500.0, 5000.0, 7500.0,
10000.0,
];
const SECOND_DURATION_UNIT: &str = "s";
const SECOND_DURATION_BOUNDARIES: &[f64] = &[
0.0, 0.005, 0.01, 0.025, 0.05, 0.075, 0.1, 0.25, 0.5, 0.75, 1.0, 2.5, 5.0, 7.5, 10.0,
];
#[derive(Debug, Eq, Hash, PartialEq)]
struct InstrumentKey {
@@ -85,6 +93,13 @@ impl MetricReader for SharedManualReader {
}
}
#[derive(Debug)]
struct CachedDurationHistogram {
unit: &'static str,
description: String,
histogram: Histogram<f64>,
}
#[derive(Debug)]
struct MetricsClientInner {
meter_provider: SdkMeterProvider,
@@ -92,7 +107,7 @@ struct MetricsClientInner {
counters: Mutex<HashMap<InstrumentKey, Counter<u64>>>,
gauges: Mutex<HashMap<InstrumentKey, Gauge<i64>>>,
histograms: Mutex<HashMap<String, Histogram<f64>>>,
duration_histograms: Mutex<HashMap<String, Histogram<f64>>>,
duration_histograms: Mutex<HashMap<String, CachedDurationHistogram>>,
runtime_reader: Option<Arc<ManualReader>>,
default_tags: BTreeMap<String, String>,
}
@@ -177,7 +192,15 @@ impl MetricsClientInner {
Ok(())
}
fn duration_histogram(&self, name: &str, value: i64, tags: &[(&str, &str)]) -> Result<()> {
fn duration_histogram(
&self,
name: &str,
value: f64,
unit: &'static str,
description: &str,
boundaries: &'static [f64],
tags: &[(&str, &str)],
) -> Result<()> {
validate_metric_name(name)?;
let attributes = self.attributes(tags)?;
@@ -185,14 +208,37 @@ impl MetricsClientInner {
.duration_histograms
.lock()
.unwrap_or_else(std::sync::PoisonError::into_inner);
let histogram = histograms.entry(name.to_string()).or_insert_with(|| {
self.meter
.f64_histogram(name.to_string())
.with_unit(DURATION_UNIT)
.with_description(DURATION_DESCRIPTION)
.build()
});
histogram.record(value as f64, &attributes);
let histogram = match histograms.entry(name.to_string()) {
std::collections::hash_map::Entry::Occupied(entry) => {
let cached = entry.into_mut();
if cached.unit != unit || cached.description != description {
return Err(MetricsError::ConflictingDurationHistogram {
name: name.to_string(),
existing_unit: cached.unit.to_string(),
existing_description: cached.description.clone(),
requested_unit: unit.to_string(),
requested_description: description.to_string(),
});
}
&cached.histogram
}
std::collections::hash_map::Entry::Vacant(entry) => {
&entry
.insert(CachedDurationHistogram {
unit,
description: description.to_string(),
histogram: self
.meter
.f64_histogram(name.to_string())
.with_unit(unit)
.with_description(description.to_string())
.with_boundaries(boundaries.to_vec())
.build(),
})
.histogram
}
};
histogram.record(value, &attributes);
Ok(())
}
@@ -338,7 +384,28 @@ impl MetricsClient {
) -> Result<()> {
self.0.duration_histogram(
name,
duration.as_millis().min(i64::MAX as u128) as i64,
duration.as_millis().min(i64::MAX as u128) as f64,
MILLISECOND_DURATION_UNIT,
MILLISECOND_DURATION_DESCRIPTION,
MILLISECOND_DURATION_BOUNDARIES,
tags,
)
}
/// Record a duration in seconds using a histogram with an instrument description.
pub fn record_duration_seconds_with_description(
&self,
name: &str,
description: &str,
duration: Duration,
tags: &[(&str, &str)],
) -> Result<()> {
self.0.duration_histogram(
name,
duration.as_secs_f64(),
SECOND_DURATION_UNIT,
description,
SECOND_DURATION_BOUNDARIES,
tags,
)
}
+11
View File
@@ -20,6 +20,17 @@ pub enum MetricsError {
#[error("counter increment must be non-negative for {name}: {inc}")]
NegativeCounterIncrement { name: String, inc: i64 },
#[error(
"duration histogram {name} is already registered with unit {existing_unit} and description {existing_description:?}; requested unit {requested_unit} and description {requested_description:?}"
)]
ConflictingDurationHistogram {
name: String,
existing_unit: String,
existing_description: String,
requested_unit: String,
requested_description: String,
},
#[error("failed to build OTLP metrics exporter")]
ExporterBuild {
#[source]
+78
View File
@@ -2,6 +2,7 @@ use crate::harness::attributes_to_map;
use crate::harness::build_metrics_with_defaults;
use crate::harness::histogram_data;
use crate::harness::latest_metrics;
use codex_otel::MetricsError;
use codex_otel::Result;
use pretty_assertions::assert_eq;
use std::time::Duration;
@@ -33,6 +34,83 @@ fn record_duration_records_histogram() -> Result<()> {
Ok(())
}
#[test]
fn record_duration_seconds_uses_fractional_seconds_and_scaled_buckets() -> Result<()> {
let (metrics, exporter) = build_metrics_with_defaults(&[])?;
for duration in [
Duration::from_millis(200),
Duration::from_secs(1),
Duration::from_millis(4900),
] {
metrics.record_duration_seconds_with_description(
"codex.request_duration_seconds",
"Duration of Codex requests in seconds.",
duration,
&[("method", "initialize")],
)?;
}
metrics.shutdown()?;
let resource_metrics = latest_metrics(&exporter);
let (bounds, bucket_counts, sum, count) =
histogram_data(&resource_metrics, "codex.request_duration_seconds");
assert_eq!(
bounds,
vec![
0.0, 0.005, 0.01, 0.025, 0.05, 0.075, 0.1, 0.25, 0.5, 0.75, 1.0, 2.5, 5.0, 7.5, 10.0,
]
);
assert_eq!(
bucket_counts,
vec![0, 0, 0, 0, 0, 0, 0, 1, 0, 0, 1, 0, 1, 0, 0, 0]
);
assert!((sum - 6.1).abs() < f64::EPSILON * 8.0);
assert_eq!(count, 3);
let metric = crate::harness::find_metric(&resource_metrics, "codex.request_duration_seconds")
.unwrap_or_else(|| panic!("metric codex.request_duration_seconds missing"));
assert_eq!(metric.unit(), "s");
assert_eq!(
metric.description(),
"Duration of Codex requests in seconds."
);
Ok(())
}
#[test]
fn duration_histograms_reject_conflicting_instrument_metadata() -> Result<()> {
let (metrics, _exporter) = build_metrics_with_defaults(&[])?;
metrics.record_duration("codex.request_duration", Duration::from_millis(15), &[])?;
let error = metrics
.record_duration_seconds_with_description(
"codex.request_duration",
"Duration of Codex requests in seconds.",
Duration::from_millis(15),
&[],
)
.expect_err("conflicting metadata should fail");
metrics.shutdown()?;
assert!(matches!(
error,
MetricsError::ConflictingDurationHistogram {
name,
existing_unit,
existing_description,
requested_unit,
requested_description,
} if name == "codex.request_duration"
&& existing_unit == "ms"
&& existing_description == "Duration in milliseconds."
&& requested_unit == "s"
&& requested_description == "Duration of Codex requests in seconds."
));
Ok(())
}
// Ensures time_result returns the closure output and records timing.
#[test]
fn timer_result_records_success() -> Result<()> {