Files
CC-Switch/src-tauri/src/proxy/response_processor.rs
T
Dex Miller 67e074c0a7 refactor(proxy): transparent header forwarding via hyper client (#1714)
* style(frontend): reformat provider forms, constants and hooks

Apply prettier formatting across 5 frontend files. No logic changes.

Changed files:
- AddProviderDialog.tsx: reformat generic type annotation and callback
- ClaudeFormFields.tsx: consolidate multi-line useState and Collapsible props
- CodexConfigSections.tsx: expand single-line React imports to multi-line,
  collapse removeCodexTopLevelField() call
- constants.ts: merge TemplateType into single line
- useSkills.ts: expand single-line TanStack Query imports to multi-line,
  reformat uninstallSkill mutationFn chain

* deps(proxy): add hyper ecosystem crates and manual decompression libs

reqwest internally normalizes all header names to lowercase and does not
preserve insertion order, causing proxied requests to differ from the
original client requests. To achieve transparent header forwarding with
original casing and order, introduce lower-level hyper HTTP client libs.

New dependencies:
- hyper-util 0.1: TokioExecutor + legacy Client with
  preserve_header_case support for HTTP/1.1
- hyper-rustls 0.27: rustls-based TLS connector for hyper
- http 1 / http-body 1 / http-body-util 0.1: HTTP type crates for
  hyper 1.x request/response construction
- flate2 1: manual gzip/deflate decompression (replaces reqwest auto)
- brotli 7: manual brotli decompression

Changed dependencies:
- serde_json: enable preserve_order feature to keep JSON field order
- reqwest: drop gzip feature to prevent reqwest from overriding the
  client's original accept-encoding header

* refactor(proxy): use hyper client for header-case preserving forwarding

Previously the proxy used reqwest for all upstream requests. reqwest
normalizes header names to lowercase and reorders them internally,
making proxied requests distinguishable from direct CLI requests.
Some upstream providers are sensitive to these differences.

This commit replaces reqwest with a hyper-based HTTP client on the
default (non-proxy) path, achieving wire-level header fidelity:

Server layer (server.rs):
- Replace axum::serve with a manual hyper HTTP/1.1 accept loop
- Enable preserve_header_case(true) so incoming header casing is
  captured in a HeaderCaseMap extension on each request
- Bridge hyper requests to axum Router via tower::Service

New hyper client module (hyper_client.rs):
- Lazy-initialized hyper-util Client with preserve_header_case
- ProxyResponse enum wrapping both hyper::Response and reqwest::Response
  behind a unified interface (status, headers, bytes, bytes_stream)
- send_request() builds requests with ordered HeaderMap + case map

Request handlers (handlers.rs):
- Switch from (HeaderMap, Json<Value>) extractors to raw
  axum::extract::Request to preserve Extensions (containing the
  HeaderCaseMap from the accept loop)
- Pass extensions through the forwarding chain

Forwarder (forwarder.rs):
- Remove HEADER_BLACKLIST array; replace with ordered header iteration
  that preserves original header sequence and casing
- Build ordered_headers by iterating client headers, skipping only
  auth/host/content-length, and inserting auth headers at the original
  authorization position to maintain order
- Handle anthropic-beta (ensure claude-code-20250219 tag) and
  anthropic-version (passthrough or default) inline during iteration
- Remove should_force_identity_encoding() — accept-encoding is now
  transparently forwarded to upstream
- Use hyper client by default; fall back to reqwest only when an
  HTTP/SOCKS5 proxy tunnel is configured

Provider adapters (adapter.rs, claude.rs, codex.rs, gemini.rs):
- Replace add_auth_headers(RequestBuilder) -> RequestBuilder with
  get_auth_headers(AuthInfo) -> Vec<(HeaderName, HeaderValue)>
- Adapters now return header pairs instead of mutating a reqwest builder
- Claude adapter: merge Anthropic/ClaudeAuth/Bearer into single branch;
  move Copilot fingerprint headers into get_auth_headers

Response processing (response_processor.rs):
- Add manual decompression (gzip/deflate/brotli via flate2 + brotli)
  for non-streaming responses, since reqwest auto-decompression is now
  disabled to allow accept-encoding passthrough
- Add compressed-SSE warning log for streaming responses
- Accept ProxyResponse instead of reqwest::Response

HTTP client (http_client.rs):
- Disable reqwest auto-decompression (.no_gzip/.no_brotli/.no_deflate)
  on both global and per-provider clients

Streaming adapters (streaming.rs, streaming_responses.rs):
- Generalize stream error type from reqwest::Error to generic E: Error

Misc:
- log_codes.rs: add SRV-005 (ACCEPT_ERR) and SRV-006 (CONN_ERR)
- stream_check.rs: reformat copilot header lines
- transform.rs: fix trailing whitespace alignment

* fix(lint): resolve 35 clippy warnings across Rust codebase

Fix all clippy warnings reported by `cargo clippy --lib`:

- codex_config.rs: fix doc_overindented_list_items (3 spaces -> 2)
- commands/copilot.rs: inline format args in 2 log::error! calls
- commands/provider.rs: inline format args in 3 map_err closures
- proxy/hyper_client.rs: inline format arg in log::debug! call
- proxy/providers/copilot_auth.rs: inline format args in 16 locations
  (log macros, format! in headers, error constructors)
- proxy/thinking_optimizer.rs: inline format args in 2 log::info! calls
- services/skill.rs: inline format args in log::debug! call
- services/webdav_sync.rs: inline format args in 6 format! calls
  (version compat messages, download limit messages)
- services/webdav_sync/archive.rs: inline format args in 2 format! calls
- session_manager/providers/opencode.rs: inline format args in
  source_path format!

All fixes use the clippy::uninlined_format_args suggestion pattern:
  format!("msg: {}", var)  ->  format!("msg: {var}")

* deps(proxy): add raw HTTP write and native TLS cert dependencies

Add crates required for the raw TCP/TLS write path that bypasses
hyper's header encoder to preserve original header name casing:

- httparse: parse raw TCP peek bytes to capture header casings
- tokio-rustls + rustls: direct TLS connections for raw write path
- webpki-roots: Mozilla CA bundle baseline
- rustls-native-certs: load system keychain CAs (trusts proxy MITM
  certificates from Clash, mitmproxy, etc.)

* fix(proxy): address code review feedback on response handling

Fixes from PR #1714 code review:

- Extract `read_decoded_body()` and `strip_entity_headers_for_rebuilt_body()`
  in response_processor to properly clean content-encoding/content-length
  headers after decompression
- Reuse `read_decoded_body()` in handlers.rs for Claude transform path,
  ensuring compressed responses are decoded before format conversion
- Make `build_proxy_url_from_config()` public so forwarder can pass proxy
  URL to the hyper raw write path
- Add `has_system_proxy_env()` utility with test coverage
- Add 50ms backoff after accept() failures in server.rs to prevent
  tight-loop CPU spin on transient socket errors

* feat(proxy): implement raw TCP/TLS write with HTTP CONNECT tunnel

Rewrite hyper_client with a two-tier strategy for header case preservation:

Primary path (raw write):
- Peek raw TCP bytes in server.rs to capture OriginalHeaderCases before
  hyper lowercases them
- Build raw HTTP/1.1 request bytes with exact original header name casing
- Write directly to TLS stream, then use WriteFilter to let hyper parse
  the response while discarding its duplicate request writes
- Support HTTP CONNECT tunneling through upstream proxies, so header case
  is preserved even when a proxy (Clash, V2Ray) is configured

Fallback path (hyper-util Client):
- Used when OriginalHeaderCases is empty or raw write fails
- Configured with title_case_headers(true) for best-effort casing

TLS improvements:
- Load native system certificates alongside webpki roots so proxy MITM
  CAs (installed in system keychain) are trusted through CONNECT tunnels

Key types added:
- OriginalHeaderCases: maps lowercase name → original wire-casing bytes
- WriteFilter<S>: AsyncRead+AsyncWrite wrapper that discards writes
- connect_via_proxy(): HTTP CONNECT tunnel establishment
- ExtensionDebugMarker: diagnostic marker for extension chain debugging

* refactor(proxy): route requests through hyper with proxy-aware forwarding

Rework forwarder request dispatch to always prefer the hyper raw write
path (header case preservation) over reqwest:

Request routing:
- HTTP/HTTPS proxy: hyper raw write through CONNECT tunnel (case preserved)
- SOCKS5 proxy: reqwest fallback (CONNECT not supported for SOCKS5)
- No proxy: hyper raw write direct connection

Header handling improvements:
- Replace host header in-place at original position instead of
  skip-and-append, preserving client's header ordering
- Preserve client's original accept-encoding for transparent passthrough;
  only force identity encoding when transform path needs decompression
- Add should_force_identity_encoding() to centralize the decision
- Remove hardcoded 'br, gzip, deflate' override that masked client values

Proxy URL resolution (priority order):
1. Provider-specific proxy config (if enabled)
2. Global proxy URL configured in CC Switch
3. Direct connection (no proxy)

* chore(proxy): remove dead code, redundant tests and debug scaffolding

- Inline should_force_identity_encoding() (was just `needs_transform`)
  and delete its 5 test cases
- Remove ExtensionDebugMarker diagnostic type
- Remove unused has_system_proxy_env() and its test
- Remove strip_entity_headers test
- Simplify hyper path: remove redundant is_socks_proxy ternary
- Update hyper_client module doc to reflect CONNECT tunnel support

* fix(proxy): block direct-connect fallback and complete CONNECT tunnel support

* feat(hooks): improve proxy requirement warnings with specific reasons

- Remove redundant OpenAI format hint toast messages
- Add detailed reason detection for proxy requirements (OpenAI Chat, OpenAI Responses, full URL mode)
- Update i18n files with new reason-specific keys

* style(*): format code with prettier

- Remove extra whitespace in http_client.rs
- Fix formatting issues in useProviderActions.ts

* fix(proxy): post-merge fixes for forward return type and clippy warnings

- Restore forward() return type to (ProxyResponse, Option<String>)
  to pass claude_api_format through to callers
- Inline format args in log::warn! macro (clippy::uninlined_format_args)
- Suppress too_many_arguments for check_claude_stream

* refactor(proxy): preserve original header wire order and add non-streaming body timeout

- Rewrite build_raw_request to emit headers in original
  client-sent sequence instead of hash-map order
- Remove unused OriginalHeaderCases::get_all method
- Add body_timeout to read_decoded_body to prevent
  requests hanging when upstream stalls after headers
2026-03-29 20:26:15 +08:00

884 lines
29 KiB
Rust
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
//! 响应处理器模块
//!
//! 统一处理流式和非流式 API 响应
use super::{
handler_config::UsageParserConfig,
handler_context::{RequestContext, StreamingTimeoutConfig},
hyper_client::ProxyResponse,
server::ProxyState,
sse::strip_sse_field,
usage::parser::TokenUsage,
ProxyError,
};
use axum::http::header::HeaderMap;
use axum::response::{IntoResponse, Response};
use bytes::Bytes;
use futures::stream::{Stream, StreamExt};
use serde_json::Value;
use std::{
io::Read,
sync::{
atomic::{AtomicBool, Ordering},
Arc,
},
time::Duration,
};
use tokio::sync::Mutex;
// ============================================================================
// 响应解压
// ============================================================================
/// 根据 content-encoding 解压响应体字节
///
/// reqwest 自动解压已禁用(为了透传 accept-encoding),需要手动解压。
fn decompress_body(content_encoding: &str, body: &[u8]) -> Result<Vec<u8>, std::io::Error> {
match content_encoding {
"gzip" | "x-gzip" => {
let mut decoder = flate2::read::GzDecoder::new(body);
let mut decompressed = Vec::new();
decoder.read_to_end(&mut decompressed)?;
Ok(decompressed)
}
"deflate" => {
let mut decoder = flate2::read::DeflateDecoder::new(body);
let mut decompressed = Vec::new();
decoder.read_to_end(&mut decompressed)?;
Ok(decompressed)
}
"br" => {
let mut decompressed = Vec::new();
brotli::BrotliDecompress(&mut std::io::Cursor::new(body), &mut decompressed)?;
Ok(decompressed)
}
_ => {
log::warn!("未知的 content-encoding: {content_encoding},跳过解压");
Ok(body.to_vec())
}
}
}
/// 从响应头提取 content-encoding(忽略 identity 和 chunked
fn get_content_encoding(headers: &HeaderMap) -> Option<String> {
headers
.get("content-encoding")
.and_then(|v| v.to_str().ok())
.map(|s| s.trim().to_lowercase())
.filter(|s| !s.is_empty() && s != "identity")
}
/// 移除在重建响应体后会失真的实体头。
pub(crate) fn strip_entity_headers_for_rebuilt_body(headers: &mut HeaderMap) {
headers.remove(axum::http::header::CONTENT_ENCODING);
headers.remove(axum::http::header::CONTENT_LENGTH);
headers.remove(axum::http::header::TRANSFER_ENCODING);
}
/// 读取响应体并在需要时解压,确保 headers 与返回 body 一致。
///
/// `body_timeout`: 整包超时。当非零时用 `tokio::time::timeout` 包住 `.bytes()` 调用,
/// 防止上游发完响应头后卡住 body 导致请求永远挂住。
/// 传入 `Duration::ZERO` 表示不启用超时(故障转移关闭时)。
pub(crate) async fn read_decoded_body(
response: ProxyResponse,
tag: &str,
body_timeout: Duration,
) -> Result<(HeaderMap, http::StatusCode, Bytes), ProxyError> {
let mut headers = response.headers().clone();
let status = response.status();
let raw_bytes = if body_timeout.is_zero() {
response.bytes().await?
} else {
tokio::time::timeout(body_timeout, response.bytes())
.await
.map_err(|_| {
ProxyError::Timeout(format!(
"响应体读取超时: {}s(上游发完响应头后 body 未到达)",
body_timeout.as_secs()
))
})??
};
log::debug!(
"[{tag}] 已接收上游响应体: status={}, bytes={}, headers={}",
status.as_u16(),
raw_bytes.len(),
format_headers(&headers)
);
let mut body_bytes = raw_bytes.clone();
let mut decoded = false;
if let Some(encoding) = get_content_encoding(&headers) {
log::debug!("[{tag}] 解压非流式响应: content-encoding={encoding}");
match decompress_body(&encoding, &raw_bytes) {
Ok(decompressed) => {
body_bytes = Bytes::from(decompressed);
decoded = true;
}
Err(e) => {
log::warn!("[{tag}] 解压失败 ({encoding}): {e},使用原始数据");
}
}
}
if decoded {
strip_entity_headers_for_rebuilt_body(&mut headers);
}
Ok((headers, status, body_bytes))
}
// ============================================================================
// 公共接口
// ============================================================================
/// 检测响应是否为 SSE 流式响应
#[inline]
pub fn is_sse_response(response: &ProxyResponse) -> bool {
response.is_sse()
}
/// 处理流式响应
pub async fn handle_streaming(
response: ProxyResponse,
ctx: &RequestContext,
state: &ProxyState,
parser_config: &UsageParserConfig,
) -> Response {
let status = response.status();
log::debug!(
"[{}] 已接收上游流式响应: status={}, headers={}",
ctx.tag,
status.as_u16(),
format_headers(response.headers())
);
// 检查流式响应是否被压缩(SSE 通常不压缩,如果压缩则 SSE 解析会失败)
if let Some(encoding) = get_content_encoding(response.headers()) {
log::warn!(
"[{}] 流式响应含 content-encoding={encoding}SSE 解析可能失败。\
上游在 accept-encoding 透传后压缩了 SSE 流。",
ctx.tag
);
}
let mut builder = axum::response::Response::builder().status(status);
// 复制响应头
for (key, value) in response.headers() {
builder = builder.header(key, value);
}
// 创建字节流
let stream = response.bytes_stream();
// 创建使用量收集器
let usage_collector = create_usage_collector(ctx, state, status.as_u16(), parser_config);
// 获取流式超时配置
let timeout_config = ctx.streaming_timeout_config();
// 创建带日志和超时的透传流
let logged_stream =
create_logged_passthrough_stream(stream, ctx.tag, Some(usage_collector), timeout_config);
let body = axum::body::Body::from_stream(logged_stream);
match builder.body(body) {
Ok(resp) => resp,
Err(e) => {
log::error!("[{}] 构建流式响应失败: {e}", ctx.tag);
ProxyError::Internal(format!("Failed to build streaming response: {e}")).into_response()
}
}
}
/// 处理非流式响应
pub async fn handle_non_streaming(
response: ProxyResponse,
ctx: &RequestContext,
state: &ProxyState,
parser_config: &UsageParserConfig,
) -> Result<Response, ProxyError> {
// 整包超时:仅在故障转移开启且配置值非零时生效
let body_timeout =
if ctx.app_config.auto_failover_enabled && ctx.app_config.non_streaming_timeout > 0 {
Duration::from_secs(ctx.app_config.non_streaming_timeout as u64)
} else {
Duration::ZERO
};
let (response_headers, status, body_bytes) =
read_decoded_body(response, ctx.tag, body_timeout).await?;
log::debug!(
"[{}] 上游响应体内容: {}",
ctx.tag,
String::from_utf8_lossy(&body_bytes)
);
// 解析并记录使用量
if let Ok(json_value) = serde_json::from_slice::<Value>(&body_bytes) {
// 解析使用量
if let Some(usage) = (parser_config.response_parser)(&json_value) {
// 优先使用 usage 中解析出的模型名称,其次使用响应中的 model 字段,最后回退到请求模型
let model = if let Some(ref m) = usage.model {
m.clone()
} else if let Some(m) = json_value.get("model").and_then(|m| m.as_str()) {
m.to_string()
} else {
ctx.request_model.clone()
};
spawn_log_usage(
state,
ctx,
usage,
&model,
&ctx.request_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,
&ctx.request_model,
status.as_u16(),
false,
);
log::debug!(
"[{}] 未能解析 usage 信息,跳过记录",
parser_config.app_type_str
);
}
} else {
log::debug!(
"[{}] <<< 响应 (非 JSON): {} bytes",
ctx.tag,
body_bytes.len()
);
spawn_log_usage(
state,
ctx,
TokenUsage::default(),
&ctx.request_model,
&ctx.request_model,
status.as_u16(),
false,
);
}
// 构建响应
let mut builder = axum::response::Response::builder().status(status);
for (key, value) in response_headers.iter() {
builder = builder.header(key, value);
}
let body = axum::body::Body::from(body_bytes);
builder.body(body).map_err(|e| {
log::error!("[{}] 构建响应失败: {e}", ctx.tag);
ProxyError::Internal(format!("Failed to build response: {e}"))
})
}
/// 通用响应处理入口
///
/// 根据响应类型自动选择流式或非流式处理
pub async fn process_response(
response: ProxyResponse,
ctx: &RequestContext,
state: &ProxyState,
parser_config: &UsageParserConfig,
) -> Result<Response, ProxyError> {
if is_sse_response(&response) {
Ok(handle_streaming(response, ctx, state, parser_config).await)
} else {
handle_non_streaming(response, ctx, state, parser_config).await
}
}
// ============================================================================
// SSE 使用量收集器
// ============================================================================
type UsageCallbackWithTiming = Arc<dyn Fn(Vec<Value>, Option<u64>) + Send + Sync + 'static>;
/// SSE 使用量收集器
#[derive(Clone)]
pub struct SseUsageCollector {
inner: Arc<SseUsageCollectorInner>,
}
struct SseUsageCollectorInner {
events: Mutex<Vec<Value>>,
first_event_time: Mutex<Option<std::time::Instant>>,
start_time: std::time::Instant,
on_complete: UsageCallbackWithTiming,
finished: AtomicBool,
}
impl SseUsageCollector {
/// 创建新的使用量收集器
pub fn new(
start_time: std::time::Instant,
callback: impl Fn(Vec<Value>, Option<u64>) + Send + Sync + 'static,
) -> Self {
let on_complete: UsageCallbackWithTiming = Arc::new(callback);
Self {
inner: Arc::new(SseUsageCollectorInner {
events: Mutex::new(Vec::new()),
first_event_time: Mutex::new(None),
start_time,
on_complete,
finished: AtomicBool::new(false),
}),
}
}
/// 推送 SSE 事件
pub async fn push(&self, event: Value) {
// 记录首个事件时间
{
let mut first_time = self.inner.first_event_time.lock().await;
if first_time.is_none() {
*first_time = Some(std::time::Instant::now());
}
}
let mut events = self.inner.events.lock().await;
events.push(event);
}
/// 完成收集并触发回调
pub async fn finish(&self) {
if self.inner.finished.swap(true, Ordering::SeqCst) {
return;
}
let events = {
let mut guard = self.inner.events.lock().await;
std::mem::take(&mut *guard)
};
let first_token_ms = {
let first_time = self.inner.first_event_time.lock().await;
first_time.map(|t| (t - self.inner.start_time).as_millis() as u64)
};
(self.inner.on_complete)(events, first_token_ms);
}
}
// ============================================================================
// 内部辅助函数
// ============================================================================
/// 创建使用量收集器
fn create_usage_collector(
ctx: &RequestContext,
state: &ProxyState,
status_code: u16,
parser_config: &UsageParserConfig,
) -> SseUsageCollector {
let logging_enabled = state
.config
.try_read()
.map(|c| c.enable_logging)
.unwrap_or(true);
let state = state.clone();
let provider_id = ctx.provider.id.clone();
let request_model = ctx.request_model.clone();
let app_type_str = parser_config.app_type_str;
let tag = ctx.tag;
let start_time = ctx.start_time;
let stream_parser = parser_config.stream_parser;
let model_extractor = parser_config.model_extractor;
let session_id = ctx.session_id.clone();
SseUsageCollector::new(start_time, move |events, first_token_ms| {
if !logging_enabled {
return;
}
if let Some(usage) = stream_parser(&events) {
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();
let session_id = session_id.clone();
let request_model = request_model.clone();
tokio::spawn(async move {
log_usage_internal(
&state,
&provider_id,
app_type_str,
&model,
&request_model,
usage,
latency_ms,
first_token_ms,
true, // is_streaming
status_code,
Some(session_id),
)
.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();
let session_id = session_id.clone();
let request_model = request_model.clone();
tokio::spawn(async move {
log_usage_internal(
&state,
&provider_id,
app_type_str,
&model,
&request_model,
TokenUsage::default(),
latency_ms,
first_token_ms,
true, // is_streaming
status_code,
Some(session_id),
)
.await;
});
log::debug!("[{tag}] 流式响应缺少 usage 统计,跳过消费记录");
}
})
}
/// 异步记录使用量
fn spawn_log_usage(
state: &ProxyState,
ctx: &RequestContext,
usage: TokenUsage,
model: &str,
request_model: &str,
status_code: u16,
is_streaming: bool,
) {
// Check enable_logging before spawning the log task
if let Ok(config) = state.config.try_read() {
if !config.enable_logging {
return;
}
}
let state = state.clone();
let provider_id = ctx.provider.id.clone();
let app_type_str = ctx.app_type_str.to_string();
let model = model.to_string();
let request_model = request_model.to_string();
let latency_ms = ctx.latency_ms();
let session_id = ctx.session_id.clone();
tokio::spawn(async move {
log_usage_internal(
&state,
&provider_id,
&app_type_str,
&model,
&request_model,
usage,
latency_ms,
None,
is_streaming,
status_code,
Some(session_id),
)
.await;
});
}
/// 内部使用量记录函数
#[allow(clippy::too_many_arguments)]
async fn log_usage_internal(
state: &ProxyState,
provider_id: &str,
app_type: &str,
model: &str,
request_model: &str,
usage: TokenUsage,
latency_ms: u64,
first_token_ms: Option<u64>,
is_streaming: bool,
status_code: u16,
session_id: Option<String>,
) {
use super::usage::logger::UsageLogger;
let logger = UsageLogger::new(&state.db);
let (multiplier, pricing_model_source) =
logger.resolve_pricing_config(provider_id, app_type).await;
let pricing_model = if pricing_model_source == "request" {
request_model
} else {
model
};
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:?}, session={}, input={}, output={}, cache_read={}, cache_creation={}",
session_id.as_deref().unwrap_or("none"),
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(),
app_type.to_string(),
model.to_string(),
request_model.to_string(),
pricing_model.to_string(),
usage,
multiplier,
latency_ms,
first_token_ms,
status_code,
session_id,
None, // provider_type
is_streaming,
) {
log::warn!("[USG-001] 记录使用量失败: {e}");
}
}
/// 创建带日志记录和超时控制的透传流
pub fn create_logged_passthrough_stream(
stream: impl Stream<Item = Result<Bytes, std::io::Error>> + Send + 'static,
tag: &'static str,
usage_collector: Option<SseUsageCollector>,
timeout_config: StreamingTimeoutConfig,
) -> impl Stream<Item = Result<Bytes, std::io::Error>> + Send {
async_stream::stream! {
let mut buffer = String::new();
let mut collector = usage_collector;
let mut is_first_chunk = true;
// 超时配置
let first_byte_timeout = if timeout_config.first_byte_timeout > 0 {
Some(Duration::from_secs(timeout_config.first_byte_timeout))
} else {
None
};
let idle_timeout = if timeout_config.idle_timeout > 0 {
Some(Duration::from_secs(timeout_config.idle_timeout))
} else {
None
};
tokio::pin!(stream);
loop {
// 选择超时时间:首字节超时或静默期超时
let timeout_duration = if is_first_chunk {
first_byte_timeout
} else {
idle_timeout
};
let chunk_result = match timeout_duration {
Some(duration) => {
match tokio::time::timeout(duration, stream.next()).await {
Ok(Some(chunk)) => Some(chunk),
Ok(None) => None, // 流结束
Err(_) => {
// 超时
let timeout_type = if is_first_chunk { "首字节" } else { "静默期" };
log::error!("[{tag}] 流式响应{}超时 ({}秒)", timeout_type, duration.as_secs());
yield Err(std::io::Error::other(format!("流式响应{timeout_type}超时")));
break;
}
}
}
None => stream.next().await, // 无超时限制
};
match chunk_result {
Some(Ok(bytes)) => {
if is_first_chunk {
log::debug!(
"[{tag}] 已接收上游流式首包: bytes={}",
bytes.len()
);
}
is_first_chunk = false;
let text = String::from_utf8_lossy(&bytes);
buffer.push_str(&text);
// 尝试解析并记录完整的 SSE 事件
while let Some(pos) = buffer.find("\n\n") {
let event_text = buffer[..pos].to_string();
buffer = buffer[pos + 2..].to_string();
if !event_text.trim().is_empty() {
// 提取 data 部分并尝试解析为 JSON
for line in event_text.lines() {
if let Some(data) = strip_sse_field(line, "data") {
if data.trim() != "[DONE]" {
if let Ok(json_value) = serde_json::from_str::<Value>(data) {
if let Some(c) = &collector {
c.push(json_value.clone()).await;
}
log::debug!("[{tag}] <<< SSE 事件: {data}");
} else {
log::debug!("[{tag}] <<< SSE 数据: {data}");
}
} else {
log::debug!("[{tag}] <<< SSE: [DONE]");
}
}
}
}
}
yield Ok(bytes);
}
Some(Err(e)) => {
log::error!("[{tag}] 流错误: {e}");
yield Err(std::io::Error::other(e.to_string()));
break;
}
None => {
// 流正常结束
break;
}
}
}
if let Some(c) = collector.take() {
c.finish().await;
}
}
}
fn format_headers(headers: &HeaderMap) -> String {
headers
.iter()
.map(|(key, value)| {
let value_str = value.to_str().unwrap_or("<non-utf8>");
format!("{key}={value_str}")
})
.collect::<Vec<_>>()
.join(", ")
}
#[cfg(test)]
mod tests {
use super::*;
use crate::database::Database;
use crate::error::AppError;
use crate::provider::ProviderMeta;
use crate::proxy::failover_switch::FailoverSwitchManager;
use crate::proxy::provider_router::ProviderRouter;
use crate::proxy::types::{ProxyConfig, ProxyStatus};
use rust_decimal::Decimal;
use std::collections::HashMap;
use std::str::FromStr;
use std::sync::Arc;
use tokio::sync::RwLock;
#[test]
fn test_strip_sse_field_accepts_optional_space() {
assert_eq!(
super::strip_sse_field("data: {\"ok\":true}", "data"),
Some("{\"ok\":true}")
);
assert_eq!(
super::strip_sse_field("data:{\"ok\":true}", "data"),
Some("{\"ok\":true}")
);
assert_eq!(
super::strip_sse_field("event: message_start", "event"),
Some("message_start")
);
assert_eq!(
super::strip_sse_field("event:message_start", "event"),
Some("message_start")
);
assert_eq!(super::strip_sse_field("id:1", "data"), None);
}
fn build_state(db: Arc<Database>) -> ProxyState {
ProxyState {
db: db.clone(),
config: Arc::new(RwLock::new(ProxyConfig::default())),
status: Arc::new(RwLock::new(ProxyStatus::default())),
start_time: Arc::new(RwLock::new(None)),
current_providers: Arc::new(RwLock::new(HashMap::new())),
provider_router: Arc::new(ProviderRouter::new(db.clone())),
app_handle: None,
failover_manager: Arc::new(FailoverSwitchManager::new(db)),
}
}
fn seed_pricing(db: &Database) -> Result<(), AppError> {
let conn = crate::database::lock_conn!(db.conn);
conn.execute(
"INSERT OR REPLACE INTO model_pricing (model_id, display_name, input_cost_per_million, output_cost_per_million)
VALUES (?1, ?2, ?3, ?4)",
rusqlite::params!["resp-model", "Resp Model", "1.0", "0"],
)
.map_err(|e| AppError::Database(e.to_string()))?;
conn.execute(
"INSERT OR REPLACE INTO model_pricing (model_id, display_name, input_cost_per_million, output_cost_per_million)
VALUES (?1, ?2, ?3, ?4)",
rusqlite::params!["req-model", "Req Model", "2.0", "0"],
)
.map_err(|e| AppError::Database(e.to_string()))?;
Ok(())
}
fn insert_provider(
db: &Database,
id: &str,
app_type: &str,
meta: ProviderMeta,
) -> Result<(), AppError> {
let meta_json =
serde_json::to_string(&meta).map_err(|e| AppError::Database(e.to_string()))?;
let conn = crate::database::lock_conn!(db.conn);
conn.execute(
"INSERT INTO providers (id, app_type, name, settings_config, meta)
VALUES (?1, ?2, ?3, ?4, ?5)",
rusqlite::params![id, app_type, "Test Provider", "{}", meta_json],
)
.map_err(|e| AppError::Database(e.to_string()))?;
Ok(())
}
#[tokio::test]
async fn test_log_usage_uses_provider_override_config() -> Result<(), AppError> {
let db = Arc::new(Database::memory()?);
let app_type = "claude";
db.set_default_cost_multiplier(app_type, "1.5").await?;
db.set_pricing_model_source(app_type, "response").await?;
seed_pricing(&db)?;
let mut meta = ProviderMeta::default();
meta.cost_multiplier = Some("2".to_string());
meta.pricing_model_source = Some("request".to_string());
insert_provider(&db, "provider-1", app_type, meta)?;
let state = build_state(db.clone());
let usage = TokenUsage {
input_tokens: 1_000_000,
output_tokens: 0,
cache_read_tokens: 0,
cache_creation_tokens: 0,
model: None,
};
log_usage_internal(
&state,
"provider-1",
app_type,
"resp-model",
"req-model",
usage,
10,
None,
false,
200,
None,
)
.await;
let conn = crate::database::lock_conn!(db.conn);
let (model, request_model, total_cost, cost_multiplier): (String, String, String, String) =
conn.query_row(
"SELECT model, request_model, total_cost_usd, cost_multiplier
FROM proxy_request_logs WHERE provider_id = ?1",
["provider-1"],
|row| Ok((row.get(0)?, row.get(1)?, row.get(2)?, row.get(3)?)),
)
.map_err(|e| AppError::Database(e.to_string()))?;
assert_eq!(model, "resp-model");
assert_eq!(request_model, "req-model");
assert_eq!(
Decimal::from_str(&cost_multiplier).unwrap(),
Decimal::from_str("2").unwrap()
);
assert_eq!(
Decimal::from_str(&total_cost).unwrap(),
Decimal::from_str("4").unwrap()
);
Ok(())
}
#[tokio::test]
async fn test_log_usage_falls_back_to_global_defaults() -> Result<(), AppError> {
let db = Arc::new(Database::memory()?);
let app_type = "claude";
db.set_default_cost_multiplier(app_type, "1.5").await?;
db.set_pricing_model_source(app_type, "response").await?;
seed_pricing(&db)?;
let meta = ProviderMeta::default();
insert_provider(&db, "provider-2", app_type, meta)?;
let state = build_state(db.clone());
let usage = TokenUsage {
input_tokens: 1_000_000,
output_tokens: 0,
cache_read_tokens: 0,
cache_creation_tokens: 0,
model: None,
};
log_usage_internal(
&state,
"provider-2",
app_type,
"resp-model",
"req-model",
usage,
10,
None,
false,
200,
None,
)
.await;
let conn = crate::database::lock_conn!(db.conn);
let (total_cost, cost_multiplier): (String, String) = conn
.query_row(
"SELECT total_cost_usd, cost_multiplier
FROM proxy_request_logs WHERE provider_id = ?1",
["provider-2"],
|row| Ok((row.get(0)?, row.get(1)?)),
)
.map_err(|e| AppError::Database(e.to_string()))?;
assert_eq!(
Decimal::from_str(&cost_multiplier).unwrap(),
Decimal::from_str("1.5").unwrap()
);
assert_eq!(
Decimal::from_str(&total_cost).unwrap(),
Decimal::from_str("1.5").unwrap()
);
Ok(())
}
}