feat: 提前记录 pending 用量、优化流遥测时序与前端活跃请求发现机制

- 将 record_pending 调用移至执行开始前(sync/stream 两路),确保请求在执行前即有 pending 记录
- stream_pump 在收到第一个数据块前优先 yield 遥测帧,保证 ttfb 早于 data 帧到达
- stream execution 增加 should_refresh_stream_usage_telemetry,在遥测帧携带新 ttfb/elapsed 时及时更新 record_stream_started
- access_log 对高频轮询路径(usage/active、usage/records 等)降级为 TRACE 日志,减少日志噪音
- 前端新增 reconcileActiveRequestDiscovery 工具函数及 discoverActiveRequests 逻辑,活跃请求发现与全局自动刷新解耦,空闲时降频为 5 秒扫描
- RequestDetailDrawer 调整:进行中请求不再自动开启轮询,由用户手动触发;刷新按钮 title 动态适配状态
This commit is contained in:
fawney19
2026-04-10 20:58:01 +08:00
parent d5b8583d6b
commit 46f1507d44
13 changed files with 846 additions and 52 deletions

View File

@@ -3,9 +3,10 @@ use std::time::Instant;
use axum::body::Body;
use axum::extract::Request;
use axum::http::header::{HeaderName, HeaderValue};
use axum::http::Method;
use axum::middleware::Next;
use axum::response::Response;
use tracing::{info, warn};
use tracing::{info, trace, warn};
use crate::constants::{
CONTROL_REQUEST_ID_HEADER, CONTROL_ROUTE_CLASS_HEADER, EXECUTION_PATH_HEADER, TRACE_ID_HEADER,
@@ -16,6 +17,41 @@ use crate::log_ids::short_request_id;
#[derive(Debug, Clone, Copy)]
pub(crate) struct RequestLogEmitted;
fn is_usage_detail_path(path: &str) -> bool {
let Some(detail_id) = path.strip_prefix("/api/admin/usage/") else {
return false;
};
!detail_id.is_empty()
&& !detail_id.contains('/')
&& !matches!(detail_id, "active" | "records" | "stats" | "heatmap")
}
pub(crate) fn should_downgrade_access_log(method: &Method, path: &str) -> bool {
if method != Method::GET {
return false;
}
let normalized_path = path.split('?').next().unwrap_or(path);
matches!(
normalized_path,
"/api/admin/usage/active"
| "/api/users/me/usage/active"
| "/api/admin/usage/records"
| "/api/admin/usage/stats"
| "/api/admin/usage/aggregation/stats"
| "/api/admin/usage/heatmap"
| "/api/admin/usage/cache-affinity/interval-timeline"
| "/api/admin/usage/cache-affinity/ttl-analysis"
| "/api/admin/usage/cache-affinity/hit-analysis"
| "/api/admin/users"
| "/api/admin/monitoring/cache/stats"
| "/api/admin/monitoring/cache/model-mapping/stats"
| "/api/admin/monitoring/cache/config"
| "/api/admin/monitoring/cache/redis-keys"
| "/api/admin/monitoring/cache/affinities"
) || is_usage_detail_path(normalized_path)
|| normalized_path.starts_with("/api/admin/monitoring/trace/")
}
pub(crate) async fn access_log_middleware(request: Request<Body>, next: Next) -> Response {
let started_at = Instant::now();
let method = request.method().clone();
@@ -25,18 +61,33 @@ pub(crate) async fn access_log_middleware(request: Request<Body>, next: Next) ->
.map(|value| value.as_str().to_string())
.unwrap_or_else(|| "/".to_string());
let trace_id = extract_or_generate_trace_id(request.headers());
info!(
event_name = "http_request_started",
log_type = "access",
status = "started",
trace_id = %trace_id,
request_id = "-",
method = %method,
path = %path,
route_class = "pending",
execution_path = "pending",
"gateway request started"
);
if should_downgrade_access_log(&method, &path) {
trace!(
event_name = "http_request_started",
log_type = "access",
status = "started",
trace_id = %trace_id,
request_id = "-",
method = %method,
path = %path,
route_class = "pending",
execution_path = "pending",
"gateway request started"
);
} else {
info!(
event_name = "http_request_started",
log_type = "access",
status = "started",
trace_id = %trace_id,
request_id = "-",
method = %method,
path = %path,
route_class = "pending",
execution_path = "pending",
"gateway request started"
);
}
let mut response = next.run(request).await;
if !response.headers().contains_key(TRACE_ID_HEADER) {
response.headers_mut().insert(
@@ -79,6 +130,21 @@ pub(crate) async fn access_log_middleware(request: Request<Body>, next: Next) ->
elapsed_ms,
"gateway request failed"
);
} else if should_downgrade_access_log(&method, &path) {
trace!(
event_name = "http_request_completed",
log_type = "access",
status = "completed",
status_code,
trace_id = %trace_id,
request_id,
method = %method,
path = %path,
route_class,
execution_path,
elapsed_ms,
"gateway completed request"
);
} else {
info!(
event_name = "http_request_completed",
@@ -101,19 +167,20 @@ pub(crate) async fn access_log_middleware(request: Request<Body>, next: Next) ->
#[cfg(test)]
mod tests {
use super::access_log_middleware;
use super::{access_log_middleware, should_downgrade_access_log};
use crate::constants::{
CONTROL_REQUEST_ID_HEADER, CONTROL_ROUTE_CLASS_HEADER, EXECUTION_PATH_HEADER,
TRACE_ID_HEADER,
};
use axum::body::Body;
use axum::http::{Request, Response, StatusCode};
use axum::http::{Method, Request, Response, StatusCode};
use axum::routing::get;
use axum::Router;
use bytes::Bytes;
use futures_util::stream;
use std::sync::{Arc, Mutex};
use tower::ServiceExt;
use tracing_subscriber::filter::LevelFilter;
use tracing_subscriber::prelude::*;
#[derive(Clone, Default)]
@@ -416,4 +483,88 @@ mod tests {
assert_eq!(logs[1]["route_class"], "ai_public");
assert_eq!(logs[1]["execution_path"], "execution_runtime_stream");
}
#[tokio::test]
async fn access_log_downgrades_usage_active_polling_to_trace() {
let writer = SharedBuffer::default();
let subscriber = tracing_subscriber::registry().with(
tracing_subscriber::fmt::layer()
.json()
.flatten_event(true)
.with_current_span(false)
.with_span_list(false)
.with_writer(writer.clone())
.with_filter(LevelFilter::TRACE),
);
let dispatch = tracing::Dispatch::new(subscriber);
let _guard = tracing::dispatcher::set_default(&dispatch);
let app = Router::new()
.route(
"/api/admin/usage/active",
get(|| async {
Response::builder()
.status(StatusCode::OK)
.header(CONTROL_ROUTE_CLASS_HEADER, "admin_proxy")
.header(EXECUTION_PATH_HEADER, "public_proxy_passthrough")
.body(Body::empty())
.expect("response should build")
}),
)
.layer(axum::middleware::from_fn(access_log_middleware));
let _response = app
.oneshot(
Request::builder()
.uri("/api/admin/usage/active?ids=req-1")
.body(Body::empty())
.expect("request should build"),
)
.await
.expect("request should succeed");
let logs = writer.lines();
assert_eq!(logs.len(), 2);
assert_eq!(logs[0]["level"], "TRACE");
assert_eq!(logs[0]["event_name"], "http_request_started");
assert_eq!(logs[1]["level"], "TRACE");
assert_eq!(logs[1]["event_name"], "http_request_completed");
}
#[test]
fn access_log_marks_usage_active_paths_as_high_frequency() {
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/usage/active"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/usage/active?ids=req-1"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/users/me/usage/active"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/usage/records?limit=20"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/usage/123e4567-e89b-12d3-a456-426614174000?include_bodies=false"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/monitoring/trace/req-123?attempted_only=false"
));
assert!(should_downgrade_access_log(
&Method::GET,
"/api/admin/monitoring/cache/stats"
));
assert!(!should_downgrade_access_log(
&Method::DELETE,
"/api/admin/monitoring/cache/affinity/provider/key/model/openai:cli"
));
assert!(!should_downgrade_access_log(&Method::GET, "/v1/responses"));
}
}

View File

@@ -2,6 +2,8 @@ mod access_log;
mod frontdoor_cors;
mod strip_cf_headers;
pub(crate) use access_log::{access_log_middleware, RequestLogEmitted};
pub(crate) use access_log::{
access_log_middleware, should_downgrade_access_log, RequestLogEmitted,
};
pub(crate) use frontdoor_cors::frontdoor_cors_middleware;
pub use strip_cf_headers::strip_cf_headers_middleware;