fix: langfuse startTime uses ms precision for sub-second requests

This commit is contained in:
whit3rabbit
2026-03-27 22:21:09 -05:00
parent dbd63437b0
commit c9ce57ebb1
2 changed files with 50 additions and 4 deletions
+20
View File
@@ -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();
+30 -4
View File
@@ -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}");
}
}