From c9ce57ebb1ca061df93fc76a451505b72b41cd4f Mon Sep 17 00:00:00 2001 From: whit3rabbit Date: Fri, 27 Mar 2026 22:21:09 -0500 Subject: [PATCH] fix: langfuse startTime uses ms precision for sub-second requests --- crates/proxy/src/admin/db.rs | 20 +++++++++++++ crates/proxy/src/integrations/langfuse.rs | 34 ++++++++++++++++++++--- 2 files changed, 50 insertions(+), 4 deletions(-) diff --git a/crates/proxy/src/admin/db.rs b/crates/proxy/src/admin/db.rs index 097fa08..111f8e6 100644 --- a/crates/proxy/src/admin/db.rs +++ b/crates/proxy/src/admin/db.rs @@ -482,6 +482,17 @@ pub(crate) fn epoch_to_iso8601(epoch: u64) -> String { ) } +/// Convert unix epoch milliseconds to ISO 8601 string with millisecond precision. +/// Format: "2026-03-27T10:15:30.500Z" +pub(crate) fn epoch_to_iso8601_ms(epoch_ms: u64) -> String { + let secs = epoch_ms / 1000; + let ms = epoch_ms % 1000; + let base = epoch_to_iso8601(secs); + // epoch_to_iso8601 returns "YYYY-MM-DDTHH:MM:SSZ"; strip the Z, append .mmmZ + let without_z = base.trim_end_matches('Z'); + format!("{}.{:03}Z", without_z, ms) +} + /// Convert days since 1970-01-01 to (year, month, day). pub(crate) fn days_to_ymd(days: u64) -> (u64, u64, u64) { // Algorithm from http://howardhinnant.github.io/date_algorithms.html @@ -866,6 +877,15 @@ mod tests { assert_eq!(result, "1970-01-01T00:00:00Z"); } + #[test] + fn epoch_to_iso8601_ms_formats_fractional_seconds() { + assert_eq!(epoch_to_iso8601_ms(500), "1970-01-01T00:00:00.500Z"); + assert_eq!(epoch_to_iso8601_ms(1000), "1970-01-01T00:00:01.000Z"); + assert_eq!(epoch_to_iso8601_ms(1001), "1970-01-01T00:00:01.001Z"); + let result = epoch_to_iso8601_ms(1774070400000); + assert!(result.ends_with(".000Z"), "got: {result}"); + } + #[test] fn init_db_idempotent() { let conn = Connection::open_in_memory().unwrap(); diff --git a/crates/proxy/src/integrations/langfuse.rs b/crates/proxy/src/integrations/langfuse.rs index a4b03a5..5e1a291 100644 --- a/crates/proxy/src/integrations/langfuse.rs +++ b/crates/proxy/src/integrations/langfuse.rs @@ -79,10 +79,11 @@ impl LangfuseClient { pub(crate) fn build_generation_payload(entry: &RequestLogEntry) -> serde_json::Value { let end_time = &entry.timestamp; let start_time = iso8601_to_epoch(end_time) - .map(|epoch| { - // Integer truncation: sub-second requests produce start_time == end_time. - // Langfuse accepts this; use latency_ms in metadata for precise duration. - crate::admin::db::epoch_to_iso8601(epoch.saturating_sub(entry.latency_ms / 1000)) + .map(|epoch_secs| { + // Compute start in milliseconds for sub-second precision. + let end_ms = epoch_secs.saturating_mul(1000); + let start_ms = end_ms.saturating_sub(entry.latency_ms); + crate::admin::db::epoch_to_iso8601_ms(start_ms) }) .unwrap_or_else(|| end_time.clone()); @@ -356,4 +357,29 @@ mod tests { assert_eq!(body["level"], "ERROR"); assert_eq!(body["metadata"]["error"], "internal error"); } + + #[test] + fn build_payload_starttime_has_ms_precision_for_subsecond_latency() { + let entry = RequestLogEntry { + request_id: "req-ms".to_string(), + timestamp: "2026-03-27T10:00:01Z".to_string(), + backend: "openai".to_string(), + model_requested: Some("gpt-4o".to_string()), + model_mapped: None, + status_code: 200, + latency_ms: 500, + input_tokens: None, + output_tokens: None, + is_streaming: false, + error_message: None, + key_id: None, + cost_usd: None, + }; + let payload = build_generation_payload(&entry); + let body = &payload["batch"][0]["body"]; + let start = body["startTime"].as_str().unwrap(); + let end = body["endTime"].as_str().unwrap(); + assert_ne!(start, end, "sub-second latency should produce different start/end times"); + assert!(start.contains('.'), "startTime should have ms precision: {start}"); + } }