tdm_server_rust/middleware/
debug_log.rs

1//! 开发环境 HTTP 请求/响应日志中间件
2//!
3//! 提供彩色终端输出、请求/响应 body 详情和调用栈耗时树。
4//! 仅在 dev/dev-h2 profile 下挂载。
5//!
6//! ## 功能
7//!
8//! - **摘要行**: 方法 + 路径 + 状态码 + 耗时
9//! - **Body 详情**: 请求体和响应体内容（超 64KB 截断）
10//! - **调用栈树**: 每个 `#[tracing::instrument]` 的 self/inclusive 耗时
11//! - **Server-Timing**: 生成响应头供前端联调
12//! - **热点高亮**: 标记耗时最长的 span
13//!
14//! ## 终端着色
15//!
16//! 使用 ANSI 转义序列着色，支持 Windows VT100 和 Unix 终端。
17//! 可通过 `NO_COLOR` 环境变量关闭着色。
18
19use super::http_log_fmt::HttpLogStyle;
20use crate::profile::{
21    append_jsonl_report, http_request_span, min_show_duration, scope, RequestProfile,
22};
23use axum::{
24    body::Body,
25    http::{header, HeaderMap, Request},
26    middleware::Next,
27    response::Response,
28};
29use bytes::Bytes;
30use http_body_util::BodyExt;
31use std::sync::{Arc, Mutex};
32use std::time::Instant;
33use tracing::Instrument;
34
35/// 单条日志最大 body 字节数（超此截断）
36const MAX_LOG_BODY: usize = 64 * 1024;
37
38/// dev 环境调试日志中间件（终端 profile 树 + body 摘要）
39#[tracing::instrument(skip_all, level = "info")]
40pub async fn debug_log_middleware(req: Request<Body>, next: Next) -> Response {
41    HttpLogStyle::enable_ansi_support();
42    let style = HttpLogStyle::detect();
43    let method = req.method().clone();
44    let uri = req.uri().clone();
45    let started = Instant::now();
46
47    let (parts, body) = req.into_parts();
48    let req_headers = parts.headers.clone();
49    let body_bytes = body
50        .collect()
51        .await
52        .map(|b| b.to_bytes())
53        .unwrap_or_default();
54
55    let req = Request::from_parts(parts, Body::from(body_bytes.clone()));
56    let profile = Arc::new(Mutex::new(RequestProfile::new()));
57    let profile_for_print = profile.clone();
58    let span = http_request_span(&method, &uri);
59
60    let response = scope(profile, async { next.run(req).instrument(span).await }).await;
61
62    let (mut resp_parts, resp_body) = response.into_parts();
63    let resp_bytes = resp_body
64        .collect()
65        .await
66        .map(|b| b.to_bytes())
67        .unwrap_or_default();
68    let elapsed = started.elapsed();
69
70    let mut lines = Vec::new();
71    lines.push(style.divider());
72    lines.push(style.summary(&method, &uri, resp_parts.status, elapsed));
73    let (_prof_lines, server_timing) = {
74        let guard = profile_for_print.lock().unwrap_or_else(|e| e.into_inner());
75        let min_show = min_show_duration();
76        if let Some(report) =
77            guard.build_report(&method, &uri, resp_parts.status, elapsed, min_show)
78        {
79            append_jsonl_report(&report);
80        }
81        let prof = guard.format_report(&method, &uri, elapsed, min_show);
82        lines.extend(prof.clone());
83        ((), guard.format_server_timing(elapsed, min_show))
84    };
85    if let Some(value) = server_timing.and_then(|v| header::HeaderValue::from_str(&v).ok()) {
86        resp_parts
87            .headers
88            .insert(header::HeaderName::from_static("server-timing"), value);
89        resp_parts.headers.insert(
90            header::HeaderName::from_static("timing-allow-origin"),
91            header::HeaderValue::from_static("*"),
92        );
93    }
94    let quiet = should_quiet_log(uri.path(), &resp_parts.headers);
95    if !body_bytes.is_empty()
96        && !quiet
97        && should_log_body_text(uri.path(), &body_bytes, &req_headers)
98    {
99        lines.push(format!(
100            "{} {}",
101            style.label("req │"),
102            log_bytes(&body_bytes)
103        ));
104    } else if !body_bytes.is_empty() && !quiet {
105        lines.push(format!(
106            "{} {} bytes ({})",
107            style.label("req │"),
108            body_bytes.len(),
109            content_type_label(&req_headers)
110        ));
111    }
112    if !resp_bytes.is_empty() && !quiet && !is_html_response(&resp_parts.headers) {
113        if should_log_body_text(uri.path(), &resp_bytes, &resp_parts.headers) {
114            lines.push(format!(
115                "{} {}",
116                style.label("res │"),
117                log_bytes(&resp_bytes)
118            ));
119        } else {
120            lines.push(format!(
121                "{} {} bytes ({})",
122                style.label("res │"),
123                resp_bytes.len(),
124                content_type_label(&resp_parts.headers)
125            ));
126        }
127    } else if !resp_bytes.is_empty() && !quiet {
128        lines.push(format!(
129            "{} {} bytes",
130            style.label("res │"),
131            resp_bytes.len()
132        ));
133    }
134    lines.push(style.divider());
135    HttpLogStyle::print_lines(&lines);
136
137    crate::telemetry::log_http_summary(
138        method.as_str(),
139        uri.path(),
140        resp_parts.status.as_u16(),
141        elapsed.as_millis(),
142    );
143
144    Response::from_parts(resp_parts, Body::from(resp_bytes))
145}
146
147/// 将 body 转为可日志字符串，超长截断；换行压平为单行避免 app.log 多行 JSON 污染
148fn log_bytes(bytes: &Bytes) -> String {
149    if bytes.is_empty() {
150        return String::new();
151    }
152    let raw = if bytes.len() > MAX_LOG_BODY {
153        format!(
154            "{}...(truncated, total {} bytes)",
155            String::from_utf8_lossy(&bytes[..MAX_LOG_BODY]),
156            bytes.len()
157        )
158    } else {
159        String::from_utf8_lossy(bytes).into_owned()
160    };
161    raw.replace('\r', " ").replace('\n', " ")
162}
163
164/// dev 控制台轮询路由、OpenAPI 文档不输出 body，避免污染 app.log
165fn should_quiet_log(path: &str, _headers: &HeaderMap) -> bool {
166    path.starts_with("/dev/")
167        || path.starts_with("/doc/")
168        || path.starts_with("/swagger-ui")
169        || path.contains("openapi")
170}
171
172/// 大 JSON / OpenAPI 响应只记字节数，不写入 app.log 全文
173fn should_log_body_text(path: &str, bytes: &Bytes, headers: &HeaderMap) -> bool {
174    if should_quiet_log(path, headers) {
175        return false;
176    }
177    if bytes.len() > 1024 && (is_json_content(headers) || looks_like_json_bytes(bytes)) {
178        return false;
179    }
180    true
181}
182
183fn is_json_content(headers: &HeaderMap) -> bool {
184    headers
185        .get(header::CONTENT_TYPE)
186        .and_then(|v| v.to_str().ok())
187        .is_some_and(|ct| ct.contains("json"))
188}
189
190fn looks_like_json_bytes(bytes: &Bytes) -> bool {
191    bytes
192        .iter()
193        .find(|b| !b.is_ascii_whitespace())
194        .is_some_and(|b| *b == b'{' || *b == b'[')
195}
196
197fn content_type_label(headers: &HeaderMap) -> &str {
198    headers
199        .get(header::CONTENT_TYPE)
200        .and_then(|v| v.to_str().ok())
201        .and_then(|ct| ct.split(';').next())
202        .unwrap_or("binary")
203}
204
205/// 响应是否为 HTML（不输出 body 全文，仅显示字节数）
206fn is_html_response(headers: &HeaderMap) -> bool {
207    headers
208        .get(header::CONTENT_TYPE)
209        .and_then(|v| v.to_str().ok())
210        .is_some_and(|ct| ct.contains("text/html"))
211}
tdm_server_rust/middleware/debug_log.rs

tdm_server_rust/middleware/
debug_log.rs
