fix(proxy): improve usage logging and cache token parsing

- Log requests even when usage parsing fails (with default values)
- Add detailed debug logging for usage metrics
- Support cache_read_input_tokens field in Codex responses
- Fallback to input_tokens_details.cached_tokens if needed
- Add test case for cached_tokens in input_tokens_details
- Ensure all requests are tracked in database for analytics

This fixes missing request logs when API responses lack usage data
and improves cache token detection across different response formats.
This commit is contained in:
YoVinchen
2025-12-30 18:58:01 +08:00
parent fe08f69cac
commit 3a692c84fb
2 changed files with 103 additions and 7 deletions
+48
View File
@@ -112,6 +112,19 @@ pub async fn handle_non_streaming(
spawn_log_usage(state, ctx, usage, &model, status.as_u16(), false);
} else {
let model = json_value
.get("model")
.and_then(|m| m.as_str())
.unwrap_or(&ctx.request_model)
.to_string();
spawn_log_usage(
state,
ctx,
TokenUsage::default(),
&model,
status.as_u16(),
false,
);
log::debug!(
"[{}] 未能解析 usage 信息,跳过记录",
parser_config.app_type_str
@@ -123,6 +136,14 @@ pub async fn handle_non_streaming(
ctx.tag,
body_bytes.len()
);
spawn_log_usage(
state,
ctx,
TokenUsage::default(),
&ctx.request_model,
status.as_u16(),
false,
);
}
log::info!("[{}] ====== 请求结束 ======", ctx.tag);
@@ -267,6 +288,25 @@ fn create_usage_collector(
.await;
});
} else {
let model = model_extractor(&events, &request_model);
let latency_ms = start_time.elapsed().as_millis() as u64;
let state = state.clone();
let provider_id = provider_id.clone();
tokio::spawn(async move {
log_usage_internal(
&state,
&provider_id,
app_type_str,
&model,
TokenUsage::default(),
latency_ms,
first_token_ms,
true, // is_streaming
status_code,
)
.await;
});
log::debug!("[{tag}] 流式响应缺少 usage 统计,跳过消费记录");
}
})
@@ -338,6 +378,14 @@ async fn log_usage_internal(
let request_id = uuid::Uuid::new_v4().to_string();
log::debug!(
"[{app_type}] 记录请求日志: id={request_id}, provider={provider_id}, model={model}, streaming={is_streaming}, status={status_code}, latency_ms={latency_ms}, first_token_ms={first_token_ms:?}, input={}, output={}, cache_read={}, cache_creation={}",
usage.input_tokens,
usage.output_tokens,
usage.cache_read_tokens,
usage.cache_creation_tokens
);
if let Err(e) = logger.log_with_calculation(
request_id,
provider_id.to_string(),
+55 -7
View File
@@ -163,13 +163,21 @@ impl TokenUsage {
.and_then(|v| v.as_str())
.map(|s| s.to_string());
let cached_tokens = usage
.get("cache_read_input_tokens")
.and_then(|v| v.as_u64())
.or_else(|| {
usage
.get("input_tokens_details")
.and_then(|d| d.get("cached_tokens"))
.and_then(|v| v.as_u64())
})
.unwrap_or(0) as u32;
Some(Self {
input_tokens: input_tokens? as u32,
output_tokens: output_tokens? as u32,
cache_read_tokens: usage
.get("cache_read_input_tokens")
.and_then(|v| v.as_u64())
.unwrap_or(0) as u32,
cache_read_tokens: cached_tokens,
cache_creation_tokens: usage
.get("cache_creation_input_tokens")
.and_then(|v| v.as_u64())
@@ -188,11 +196,16 @@ impl TokenUsage {
let input_tokens = usage.get("input_tokens")?.as_u64()? as u32;
let output_tokens = usage.get("output_tokens")?.as_u64()? as u32;
// 获取 cached_tokens (可能在 input_tokens_details 中)
// 获取 cached_tokens (可能在 cache_read_input_tokens 或 input_tokens_details 中)
let cached_tokens = usage
.get("input_tokens_details")
.and_then(|d| d.get("cached_tokens"))
.get("cache_read_input_tokens")
.and_then(|v| v.as_u64())
.or_else(|| {
usage
.get("input_tokens_details")
.and_then(|d| d.get("cached_tokens"))
.and_then(|v| v.as_u64())
})
.unwrap_or(0) as u32;
// 调整 input_tokens: 减去 cached_tokens
@@ -499,6 +512,25 @@ mod tests {
assert_eq!(usage.model, None);
}
#[test]
fn test_codex_response_parsing_cached_tokens_in_details() {
let response = json!({
"usage": {
"input_tokens": 1000,
"output_tokens": 500,
"input_tokens_details": {
"cached_tokens": 300
}
}
});
let usage = TokenUsage::from_codex_response(&response).unwrap();
// 非调整模式:input_tokens 保持原值,但应记录缓存命中
assert_eq!(usage.input_tokens, 1000);
assert_eq!(usage.output_tokens, 500);
assert_eq!(usage.cache_read_tokens, 300);
}
#[test]
fn test_codex_response_adjusted() {
let response = json!({
@@ -534,6 +566,22 @@ mod tests {
assert_eq!(usage.cache_read_tokens, 0);
}
#[test]
fn test_codex_response_adjusted_cache_read_input_tokens() {
let response = json!({
"usage": {
"input_tokens": 1000,
"output_tokens": 500,
"cache_read_input_tokens": 200
}
});
let usage = TokenUsage::from_codex_response_adjusted(&response).unwrap();
assert_eq!(usage.input_tokens, 800);
assert_eq!(usage.output_tokens, 500);
assert_eq!(usage.cache_read_tokens, 200);
}
#[test]
fn test_codex_response_adjusted_saturating_sub() {
// 测试 cached_tokens > input_tokens 的边界情况