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(
73        &method,
74        &uri,
75        resp_parts.status,
76        elapsed,
77    ));
78    let (_prof_lines, server_timing) = {
79        let guard = profile_for_print.lock().unwrap_or_else(|e| e.into_inner());
80        let min_show = min_show_duration();
81        if let Some(report) = guard.build_report(&method, &uri, resp_parts.status, elapsed, min_show)
82        {
83            append_jsonl_report(&report);
84        }
85        let prof = guard.format_report(&method, &uri, elapsed, min_show);
86        lines.extend(prof.clone());
87        ((), guard.format_server_timing(elapsed, min_show))
88    };
89    if let Some(value) = server_timing.and_then(|v| header::HeaderValue::from_str(&v).ok()) {
90        resp_parts
91            .headers
92            .insert(header::HeaderName::from_static("server-timing"), value);
93        resp_parts.headers.insert(
94            header::HeaderName::from_static("timing-allow-origin"),
95            header::HeaderValue::from_static("*"),
96        );
97    }
98    let quiet = should_quiet_log(uri.path(), &resp_parts.headers);
99    if !body_bytes.is_empty() && !quiet && should_log_body_text(uri.path(), &body_bytes, &req_headers) {
100        lines.push(format!(
101            "{} {}",
102            style.label("req │"),
103            log_bytes(&body_bytes)
104        ));
105    } else if !body_bytes.is_empty() && !quiet {
106        lines.push(format!(
107            "{} {} bytes ({})",
108            style.label("req │"),
109            body_bytes.len(),
110            content_type_label(&req_headers)
111        ));
112    }
113    if !resp_bytes.is_empty() && !quiet && !is_html_response(&resp_parts.headers) {
114        if should_log_body_text(uri.path(), &resp_bytes, &resp_parts.headers) {
115            lines.push(format!(
116                "{} {}",
117                style.label("res │"),
118                log_bytes(&resp_bytes)
119            ));
120        } else {
121            lines.push(format!(
122                "{} {} bytes ({})",
123                style.label("res │"),
124                resp_bytes.len(),
125                content_type_label(&resp_parts.headers)
126            ));
127        }
128    } else if !resp_bytes.is_empty() && !quiet {
129        lines.push(format!(
130            "{} {} bytes",
131            style.label("res │"),
132            resp_bytes.len()
133        ));
134    }
135    lines.push(style.divider());
136    HttpLogStyle::print_lines(&lines);
137
138    crate::telemetry::log_http_summary(
139        method.as_str(),
140        uri.path(),
141        resp_parts.status.as_u16(),
142        elapsed.as_millis(),
143    );
144
145    Response::from_parts(resp_parts, Body::from(resp_bytes))
146}
147
148/// 将 body 转为可日志字符串，超长截断；换行压平为单行避免 app.log 多行 JSON 污染
149fn log_bytes(bytes: &Bytes) -> String {
150    if bytes.is_empty() {
151        return String::new();
152    }
153    let raw = if bytes.len() > MAX_LOG_BODY {
154        format!(
155            "{}...(truncated, total {} bytes)",
156            String::from_utf8_lossy(&bytes[..MAX_LOG_BODY]),
157            bytes.len()
158        )
159    } else {
160        String::from_utf8_lossy(bytes).into_owned()
161    };
162    raw.replace('\r', " ").replace('\n', " ")
163}
164
165/// dev 控制台轮询路由、OpenAPI 文档不输出 body，避免污染 app.log
166fn should_quiet_log(path: &str, _headers: &HeaderMap) -> bool {
167    path.starts_with("/dev/")
168        || path.starts_with("/doc/")
169        || path.starts_with("/swagger-ui")
170        || path.contains("openapi")
171}
172
173/// 大 JSON / OpenAPI 响应只记字节数，不写入 app.log 全文
174fn should_log_body_text(path: &str, bytes: &Bytes, headers: &HeaderMap) -> bool {
175    if should_quiet_log(path, headers) {
176        return false;
177    }
178    if bytes.len() > 1024 && (is_json_content(headers) || looks_like_json_bytes(bytes)) {
179        return false;
180    }
181    true
182}
183
184fn is_json_content(headers: &HeaderMap) -> bool {
185    headers
186        .get(header::CONTENT_TYPE)
187        .and_then(|v| v.to_str().ok())
188        .is_some_and(|ct| ct.contains("json"))
189}
190
191fn looks_like_json_bytes(bytes: &Bytes) -> bool {
192    bytes
193        .iter()
194        .find(|b| !b.is_ascii_whitespace())
195        .is_some_and(|b| *b == b'{' || *b == b'[')
196}
197
198fn content_type_label(headers: &HeaderMap) -> &str {
199    headers
200        .get(header::CONTENT_TYPE)
201        .and_then(|v| v.to_str().ok())
202        .and_then(|ct| ct.split(';').next())
203        .unwrap_or("binary")
204}
205
206/// 响应是否为 HTML（不输出 body 全文，仅显示字节数）
207fn is_html_response(headers: &HeaderMap) -> bool {
208    headers
209        .get(header::CONTENT_TYPE)
210        .and_then(|v| v.to_str().ok())
211        .is_some_and(|ct| ct.contains("text/html"))
212}
tdm_server_rust/middleware/debug_log.rs

tdm_server_rust/middleware/
debug_log.rs
