Measure Guardian review latency once with a monotonic clock (#55846)

## Why

Guardian review metrics derived duration from wall-clock timestamps, while analytics measured elapsed time when tracking the result. Clock changes and delayed tracking could produce inconsistent latencies.

## What changed

Capture one monotonic duration at review completion and pass it to both metrics and analytics. Preserve wall-clock timestamps for event ordering, and saturate analytics latency conversion at `u64::MAX`.

## Testing

Add a regression test covering skewed wall-clock timestamps and delayed tracking, verifying that the duration metric uses the captured interval and completion timestamps are preserved.

GitOrigin-RevId: 19eafb8e1f1a3d13a751bdc72c218e4cafeae410

codex-rs/analytics/src/client.rs

@@ -472,9 +472,10 @@ impl AnalyticsEventsClient {
         tracking: &GuardianReviewTrackContext,
         result: GuardianReviewAnalyticsResult,
         completed_at_ms: u64,
+        elapsed: Duration,
     ) {
         self.record_fact(AnalyticsFact::Custom(CustomAnalyticsFact::GuardianReview(
-            Box::new(tracking.event_params(result, completed_at_ms)),
+            Box::new(tracking.event_params(result, completed_at_ms, elapsed)),
         )));
     }
 

codex-rs/analytics/src/events.rs

@@ -1,5 +1,5 @@
 use std::sync::LazyLock;
-use std::time::Instant;
+use std::time::Duration;
 
 use crate::facts::AppInvocation;
 use crate::facts::ArtifactOperation;
@@ -448,7 +448,6 @@ pub struct GuardianReviewTrackContext {
     reviewed_action: GuardianReviewedAction,
     review_timeout_ms: u64,
     pub started_at_ms: u64,
-    started_instant: Instant,
 }
 
 impl GuardianReviewTrackContext {
@@ -470,7 +469,6 @@ impl GuardianReviewTrackContext {
             reviewed_action,
             review_timeout_ms,
             started_at_ms: now_unix_millis(),
-            started_instant: Instant::now(),
         }
     }
 
@@ -478,7 +476,9 @@ impl GuardianReviewTrackContext {
         &self,
         result: GuardianReviewAnalyticsResult,
         completed_at_ms: u64,
+        elapsed: Duration,
     ) -> GuardianReviewEventParams {
+        let completion_latency_ms = u64::try_from(elapsed.as_millis()).unwrap_or(u64::MAX);
         GuardianReviewEventParams {
             guardian_context_mode: result.guardian_context_mode,
             thread_id: self.thread_id.clone(),
@@ -509,7 +509,7 @@ impl GuardianReviewTrackContext {
             // TODO(rhan-oai): plumb nested Guardian review session tool-call counts.
             tool_call_count: None,
             time_to_first_token_ms: result.time_to_first_token_ms,
-            completion_latency_ms: Some(self.started_instant.elapsed().as_millis() as u64),
+            completion_latency_ms: Some(completion_latency_ms),
             started_at: self.started_at_ms / 1_000,
             completed_at: Some(completed_at_ms / 1_000),
             input_tokens: result.token_usage.as_ref().map(|usage| usage.input_tokens),

codex-rs/ext/guardian-reviewer/src/metrics.rs

@@ -26,7 +26,7 @@ pub(crate) fn emit_guardian_review_metrics(
     result: &GuardianReviewAnalyticsResult,
     approval_request_source: GuardianApprovalRequestSource,
     reviewed_action: &GuardianReviewedAction,
-    completion_latency_ms: u64,
+    elapsed: Duration,
 ) {
     let tags = guardian_review_metric_tags(result, approval_request_source, reviewed_action);
     let tag_refs: Vec<(&str, &str)> = tags
@@ -52,11 +52,7 @@ pub(crate) fn emit_guardian_review_metrics(
         /*inc*/ 1,
         &counter_tag_refs,
     );
-    session_telemetry.record_duration(
-        GUARDIAN_REVIEW_DURATION_METRIC,
-        Duration::from_millis(completion_latency_ms),
-        &tag_refs,
-    );
+    session_telemetry.record_duration(GUARDIAN_REVIEW_DURATION_METRIC, elapsed, &tag_refs);
 
     // Cached approvals may cancel an in-flight review: retain its attempt count,
     // but use the final review status to distinguish recovery from async release.
@@ -452,7 +448,7 @@ mod tests {
             &result,
             GuardianApprovalRequestSource::DelegatedSubagent,
             &reviewed_action,
-            /*completion_latency_ms*/ 456,
+            Duration::from_millis(456),
         );
 
         let snapshot = session_telemetry

codex-rs/ext/guardian-reviewer/src/reporting.rs

@@ -1,7 +1,11 @@
 //! Owns review reporting and the per-thread denial window. The host publishes
-//! events and enforces interruption only on the still-active owning turn.
+//! events and enforces interruption only on the still-active owning turn. Review
+//! completion captures one monotonic duration for latency reporting while retaining
+//! the actual wall-clock completion timestamp for event ordering.
 
 use std::sync::Arc;
+use std::time::Duration;
+use std::time::Instant;
 
 use codex_analytics::AnalyticsEventsClient;
 use codex_analytics::GuardianApprovalRequestSource;
@@ -42,6 +46,7 @@ pub struct ReviewMetadata {
 
 pub struct ReviewReport {
     started: GuardianAssessmentEvent,
+    started_instant: Instant,
     tracking: GuardianReviewTrackContext,
     approval_request_source: GuardianApprovalRequestSource,
     reviewed_action: GuardianReviewedAction,
@@ -49,6 +54,7 @@ pub struct ReviewReport {
 
 impl ReviewReport {
     pub fn new(metadata: ReviewMetadata) -> Self {
+        let started_instant = Instant::now();
         let tracking = GuardianReviewTrackContext::new(
             metadata.thread_id,
             metadata.turn_id.clone(),
@@ -77,6 +83,7 @@ impl ReviewReport {
         };
         Self {
             started,
+            started_instant,
             tracking,
             approval_request_source: metadata.approval_request_source,
             reviewed_action: metadata.reviewed_action,
@@ -91,6 +98,7 @@ impl ReviewReport {
         self.started.clone()
     }
 
+    /// Completes the report and captures the elapsed duration to use when tracking it.
     pub fn complete(
         &self,
         outcome: GuardianReviewOutcome,
@@ -98,11 +106,15 @@ impl ReviewReport {
         require_guardian: bool,
         analytics: GuardianReviewAnalyticsResult,
         completed_at_ms: i64,
-    ) -> ReviewCompletion {
+    ) -> (ReviewCompletion, Duration) {
+        let elapsed = self.started_instant.elapsed();
         let mut event = self.started.clone();
         event.completed_at_ms = Some(completed_at_ms);
         event.decision_source = Some(GuardianAssessmentDecisionSource::Agent);
-        crate::complete_review(outcome, model, require_guardian, event, analytics)
+        (
+            crate::complete_review(outcome, model, require_guardian, event, analytics),
+            elapsed,
+        )
     }
 
     pub fn track(
@@ -111,15 +123,16 @@ impl ReviewReport {
         analytics: &AnalyticsEventsClient,
         result: GuardianReviewAnalyticsResult,
         completed_at_ms: u64,
+        elapsed: Duration,
     ) {
         crate::metrics::emit_guardian_review_metrics(
             telemetry,
             &result,
             self.approval_request_source,
             &self.reviewed_action,
-            completed_at_ms.saturating_sub(self.tracking.started_at_ms),
+            elapsed,
         );
-        analytics.track_guardian_review(&self.tracking, result, completed_at_ms);
+        analytics.track_guardian_review(&self.tracking, result, completed_at_ms, elapsed);
     }
 }
 
@@ -163,3 +176,7 @@ impl ReviewDenials {
         }
     }
 }
+
+#[cfg(test)]
+#[path = "reporting_tests.rs"]
+mod tests;

codex-rs/ext/guardian-reviewer/src/reporting_tests.rs

@@ -0,0 +1,122 @@
+//! Regression coverage for capturing one review interval despite wall-clock skew.
+
+use super::*;
+use codex_otel::GUARDIAN_REVIEW_DURATION_METRIC;
+use codex_otel::MetricsClient;
+use codex_otel::MetricsConfig;
+use codex_protocol::ThreadId;
+use codex_protocol::approvals::NetworkApprovalProtocol;
+use codex_protocol::protocol::SessionSource;
+use opentelemetry_sdk::metrics::InMemoryMetricExporter;
+use opentelemetry_sdk::metrics::data::AggregatedMetrics;
+use opentelemetry_sdk::metrics::data::MetricData;
+use opentelemetry_sdk::metrics::data::ScopeMetrics;
+use pretty_assertions::assert_eq;
+use serde_json::json;
+use std::time::Duration;
+
+#[test]
+fn review_completion_uses_one_monotonic_duration() {
+    let exporter = InMemoryMetricExporter::default();
+    let metrics = MetricsClient::new(
+        MetricsConfig::in_memory("test", "codex-core", env!("CARGO_PKG_VERSION"), exporter)
+            .with_runtime_reader(),
+    )
+    .expect("in-memory metrics client");
+    let telemetry = SessionTelemetry::new(
+        ThreadId::new(),
+        "test-model",
+        "test-model",
+        /*account_id*/ None,
+        /*account_email*/ None,
+        /*auth_mode*/ None,
+        "test_originator".to_string(),
+        /*log_user_prompts*/ false,
+        "tty".to_string(),
+        SessionSource::Cli,
+    )
+    .with_metrics_without_metadata_tags(metrics);
+    let mut report = ReviewReport::new(ReviewMetadata {
+        thread_id: "thread".to_string(),
+        turn_id: "turn".to_string(),
+        review_id: "review".to_string(),
+        target_item_id: None,
+        plugin_id: None,
+        script_path: None,
+        approval_request_source: GuardianApprovalRequestSource::MainTurn,
+        reviewed_action: GuardianReviewedAction::NetworkAccess {
+            protocol: NetworkApprovalProtocol::Https,
+            port: 443,
+        },
+        action: GuardianAssessmentAction::NetworkAccess {
+            target: "example.com".to_string(),
+            host: "example.com".to_string(),
+            protocol: NetworkApprovalProtocol::Https,
+            port: 443,
+        },
+        review_reason: GuardianReviewReason::Policy,
+        model_context: ModelInvocationContext {
+            model_slug: "test-model".to_string(),
+            reasoning_effort: None,
+        },
+    });
+    report.tracking.started_at_ms = 1_654_073_807_000;
+    report.started.started_at_ms =
+        i64::try_from(report.tracking.started_at_ms).expect("start timestamp");
+    report.started_instant = Instant::now() - Duration::from_millis(456);
+    let model: ModelInfo = serde_json::from_value(json!({
+        "slug": "test-model",
+        "display_name": "Test model",
+        "supported_reasoning_levels": [],
+        "shell_type": "disabled",
+        "visibility": "none",
+        "supported_in_api": false,
+        "priority": 0,
+        "support_verbosity": false,
+        "truncation_policy": {"mode": "tokens", "limit": 1000},
+        "experimental_supported_tools": []
+    }))
+    .expect("test model");
+
+    let before = report.started_instant.elapsed();
+    let (completed, elapsed) = report.complete(
+        GuardianReviewOutcome::CachedApproval,
+        &model,
+        /*require_guardian*/ true,
+        GuardianReviewAnalyticsResult::without_session(),
+        /*completed_at_ms*/ 1_792_141_011_000,
+    );
+    let after = report.started_instant.elapsed();
+    assert!((before..=after).contains(&elapsed));
+    let elapsed_ms = u64::try_from(elapsed.as_millis()).expect("elapsed milliseconds");
+    assert_eq!(
+        (
+            completed.event.started_at_ms,
+            completed.event.completed_at_ms
+        ),
+        (1_654_073_807_000, Some(1_792_141_011_000),)
+    );
+
+    // Simulate tracking later: the captured interval must not be measured again.
+    report.started_instant -= Duration::from_secs(1);
+    report.track(
+        &telemetry,
+        &AnalyticsEventsClient::disabled(),
+        completed.analytics,
+        /*completed_at_ms*/ 1_792_141_011_000,
+        elapsed,
+    );
+
+    let snapshot = telemetry.snapshot_metrics().expect("metrics snapshot");
+    let metric = snapshot
+        .scope_metrics()
+        .flat_map(ScopeMetrics::metrics)
+        .find(|metric| metric.name() == GUARDIAN_REVIEW_DURATION_METRIC)
+        .expect("review duration metric");
+    let AggregatedMetrics::F64(MetricData::Histogram(histogram)) = metric.data() else {
+        panic!("expected a duration histogram");
+    };
+    let points: Vec<_> = histogram.data_points().collect();
+    assert_eq!(points.len(), 1);
+    assert_eq!((points[0].count(), points[0].sum() as u64), (1, elapsed_ms));
+}

codex-rs/ext/guardian-reviewer/src/review.rs

@@ -179,7 +179,7 @@ impl<H: ReviewHost> SynchronousApprovalReviewer for ReviewRequest<'_, H> {
             };
             let completed_at_ms = codex_analytics::now_unix_millis();
             let cached_approval = matches!(outcome, GuardianReviewOutcome::CachedApproval);
-            let completed = report.complete(
+            let (completed, elapsed) = report.complete(
                 outcome,
                 self.model,
                 self.require_guardian,
@@ -195,6 +195,7 @@ impl<H: ReviewHost> SynchronousApprovalReviewer for ReviewRequest<'_, H> {
                 self.analytics,
                 completed.analytics,
                 completed_at_ms,
+                elapsed,
             );
             if let Some(message) = completed.warning {
                 self.host