refactor(middleware): 精简请求日志 — 采用社区标准分层策略

- 移除 Request Body 记录（交由 Controller 层以结构化参数形式记录） - 移除正常响应 Body 的 DEBUG 记录（减少日志量） - 保留 HTTP 元信息：method/path/handler/status/latency/ip/query - 保留错误响应(4xx/5xx)的 Response Body 记录 - 导出 IsSensitivePath 供 Controller 层调用 - 重写架构文档 8.6 节：分层日志架构表、字段说明、分级策略 - 更新 phase1 实施计划中间件描述 Made-with: Cursor
2026-02-28 16:10:07 +08:00
parent a6ef49a3e0
commit 4d3d486902
3 changed files with 93 additions and 139 deletions
--- a/backend/go-service/pkg/middleware/logger.go
+++ b/backend/go-service/pkg/middleware/logger.go
@@ -2,7 +2,6 @@ package middleware

 import (
 	"bytes"
-	"io"
 	"strings"
 	"time"

@@ -12,19 +11,10 @@ import (
 )

 const (
-	maxBodyLogSize     = 4096 // 请求/响应 Body 记录的最大字节数
-	maxResponseLogSize = 2048 // 响应 Body 记录的最大字节数
+	maxResponseLogSize = 2048 // 错误响应 Body 记录的最大字节数
 )

-// 敏感路径：这些路径的请求 Body 中密码字段需要脱敏
-var sensitivePathPrefixes = []string{
-	"/api/v1/auth/login",
-	"/api/v1/auth/register",
-	"/api/v1/admin/auth/login",
-	"/api/v1/auth/password",
-}
-
-// responseBodyWriter 包装 gin.ResponseWriter 以捕获响应 Body
+// responseBodyWriter 包装 gin.ResponseWriter 以捕获响应 Body（仅用于错误响应记录）
 type responseBodyWriter struct {
 	gin.ResponseWriter
 	body *bytes.Buffer
@@ -42,20 +32,22 @@ func (w *responseBodyWriter) Write(b []byte) (int, error) {
 	return w.ResponseWriter.Write(b)
 }

-// Logger 请求日志中间件
-// 记录每个请求的完整信息：方法、路径、请求参数、状态码、耗时、IP、User-Agent
-// 请求参数（Query + Body）在 INFO 级别记录（所有环境生效）
-// 响应 Body 在 DEBUG 级别记录，错误响应(4xx/5xx)在 INFO 级别也记录
-// 自动携带 trace_id，慢请求（>500ms）记录 WARN
+// Logger 请求日志中间件（Access Log 层）
+//
+// 职责：记录 HTTP 请求级元信息，不记录请求 Body（由 Controller 层以结构化参数形式记录）
+// 记录字段：method / path / handler / status / latency / ip / user_agent / query
+// 错误响应（4xx/5xx）额外记录响应 Body，便于排查接口返回内容
+//
+// 分层日志策略（符合社区最佳实践）：
+//   - 中间件层：HTTP 元信息 + 错误响应
+//   - Controller 层：结构化请求参数（ShouldBindJSON 后，caller 准确指向业务代码）
+//   - Service/DAO 层：业务逻辑关键节点和异常
+//   - 通过 trace_id 串联同一请求的所有层级日志
 func Logger() gin.HandlerFunc {
 	return func(c *gin.Context) {
 		start := time.Now()
-
-		// --- 请求阶段：捕获请求参数 ---
 		query := c.Request.URL.RawQuery
-		reqBody := readRequestBody(c)

-		// 包装 ResponseWriter 以捕获响应
 		rbw := &responseBodyWriter{
 			ResponseWriter: c.Writer,
 			body:           bytes.NewBufferString(""),
@@ -64,53 +56,34 @@ func Logger() gin.HandlerFunc {

 		c.Next()

-		// --- 响应阶段：记录日志 ---
 		latency := time.Since(start)
 		ctx := c.Request.Context()
 		funcName := "middleware.Logger"
 		status := rbw.Status()
 		path := c.Request.URL.Path

-		// handler 名称：如 "main.main.func1" 或 "controller.auth_controller.Login"
-		handler := c.HandlerName()
-
 		fields := []zap.Field{
 			zap.String("method", c.Request.Method),
 			zap.String("path", path),
-			zap.String("handler", handler),
+			zap.String("handler", c.HandlerName()),
 			zap.Int("status", status),
 			zap.Duration("latency", latency),
 			zap.String("ip", c.ClientIP()),
 			zap.String("user_agent", c.Request.UserAgent()),
 		}

-		// Query 参数（始终记录）
 		if query != "" {
 			fields = append(fields, zap.String("query", query))
 		}

-		// Request Body（始终记录，敏感路径脱敏）
-		if reqBody != "" {
-			if isSensitivePath(path) {
-				reqBody = maskSensitiveBody(reqBody)
-			}
-			fields = append(fields, zap.String("req_body", reqBody))
-		}
-
-		// Response Body：错误响应(4xx/5xx)始终记录，正常响应仅 DEBUG
+		// 错误响应(4xx/5xx)：额外记录响应 Body
+		if status >= 400 {
 			respBody := rbw.body.String()
 			if respBody != "" {
-			if status >= 400 {
 				fields = append(fields, zap.String("resp_body", truncate(respBody, maxResponseLogSize)))
-			} else {
-				logs.Debug(ctx, funcName, "响应数据",
-					zap.String("path", path),
-					zap.String("resp_body", truncate(respBody, maxResponseLogSize)),
-				)
 			}
 		}

-		// 按状态分级输出
 		if len(c.Errors) > 0 {
 			fields = append(fields, zap.String("error", c.Errors.String()))
 			logs.Error(ctx, funcName, "请求处理异常", fields...)
@@ -136,33 +109,19 @@ func Logger() gin.HandlerFunc {
 	}
 }

-// readRequestBody 读取请求 Body（读完后重新填回，不影响后续 Handler）
-func readRequestBody(c *gin.Context) string {
-	if c.Request.Body == nil {
-		return ""
+// truncate 截断字符串到指定长度
+func truncate(s string, maxLen int) string {
+	if len(s) <= maxLen {
+		return s
+	}
+	return s[:maxLen] + "...[truncated]"
 }

-	// 文件上传不记录 Body
-	contentType := c.GetHeader("Content-Type")
-	if strings.Contains(contentType, "multipart/form-data") {
-		return "[file upload]"
-	}
+// --- 以下工具函数保留供 Controller 层使用 ---

-	body, err := io.ReadAll(io.LimitReader(c.Request.Body, maxBodyLogSize+1))
-	if err != nil {
-		return "[read error]"
-	}
-	// 将 Body 重新填回，供后续 Handler 使用
-	c.Request.Body = io.NopCloser(bytes.NewBuffer(body))
-
-	if len(body) > maxBodyLogSize {
-		return string(body[:maxBodyLogSize]) + "...[truncated]"
-	}
-	return string(body)
-}
-
-// isSensitivePath 判断是否为敏感路径（包含密码等字段的接口）
-func isSensitivePath(path string) bool {
+// IsSensitivePath 判断是否为敏感路径（包含密码等字段的接口）
+// Controller 层记录参数前可调用此函数决定是否脱敏
+func IsSensitivePath(path string) bool {
 	for _, prefix := range sensitivePathPrefixes {
 		if strings.HasPrefix(path, prefix) {
 			return true
@@ -171,32 +130,9 @@ func isSensitivePath(path string) bool {
 	return false
 }

-// maskSensitiveBody 对敏感 Body 中的密码字段进行脱敏
-// 简单策略：将 "password":"xxx" 替换为 "password":"***"
-func maskSensitiveBody(body string) string {
-	// 处理 JSON 中的 password 字段
-	for _, field := range []string{"password", "old_password", "new_password", "confirm_password"} {
-		for {
-			key := `"` + field + `":"`
-			idx := strings.Index(body, key)
-			if idx < 0 {
-				break
-			}
-			start := idx + len(key)
-			end := strings.Index(body[start:], `"`)
-			if end < 0 {
-				break
-			}
-			body = body[:start] + "***" + body[start+end:]
-		}
-	}
-	return body
-}
-
-// truncate 截断字符串到指定长度
-func truncate(s string, maxLen int) string {
-	if len(s) <= maxLen {
-		return s
-	}
-	return s[:maxLen] + "...[truncated]"
+var sensitivePathPrefixes = []string{
+	"/api/v1/auth/login",
+	"/api/v1/auth/register",
+	"/api/v1/admin/auth/login",
+	"/api/v1/auth/password",
 }
--- a/docs/architecture/system-architecture.md
+++ b/docs/architecture/system-architecture.md
@@ -429,26 +429,35 @@ func (s *AuthService) Login(ctx context.Context, req *dto.LoginRequest) (*dto.Lo
 }
 ```

-### 8.6 请求日志中间件
+### 8.6 请求日志中间件（Access Log 层）

-HTTP 请求日志中间件自动记录每个请求的完整信息，包含请求参数和响应数据。
+HTTP 请求日志中间件采用社区标准的「分层不重复」策略，只记录 HTTP 请求级元信息，不记录请求 Body。

-#### 请求参数记录策略（INFO 级别，所有环境生效）
+#### 分层日志架构

-| 内容 | 记录时机 | 限制 |
-|------|---------|------|
-| **Query 参数** (`?key=val`) | GET/POST/PUT 等所有请求方式 | 无限制 |
-| **Request Body** | POST/PUT/PATCH 等有 Body 的请求 | 最大 4KB，超出自动截断并标记 `[truncated]` |
-| 文件上传 Body | 自动跳过（Content-Type 为 multipart/form-data） | 仅标记 `[file upload]` |
-| 敏感路径密码 | 登录/注册/改密码接口的 Body | `password` 等字段自动替换为 `***` |
+| 层级 | 职责 | caller 指向 | 记录内容 |
+|------|------|------------|---------|
+| **中间件层（Access Log）** | HTTP 请求元信息 | 中间件源码 | method / path / handler / status / latency / ip / query |
+| **Controller 层** | 结构化请求参数 | Controller 代码行号 | ShouldBindJSON 后的业务参数（可精准脱敏） |
+| **Service 层** | 业务逻辑关键节点 | Service 代码行号 | 业务状态变更、外部调用等 |
+| **DAO 层** | 数据操作 | DAO 代码行号 | SQL 操作、缓存操作等 |

-#### 响应数据记录策略
+> 同一请求的各层日志通过 `trace_id` 串联，可完整追踪请求的处理链路。

-| 状态码 | 日志级别 | 记录内容 |
-|--------|---------|---------|
-| 200-399（正常） | DEBUG | 响应 Body（最大 2KB） |
-| 400-499（客户端错误） | WARN | 请求信息 + 响应 Body |
-| 500+（服务器错误） | ERROR | 请求信息 + 响应 Body |
+#### 中间件记录字段
+
+| 字段 | 说明 | 记录时机 |
+|------|------|---------|
+| `method` | HTTP 方法 | 始终记录 |
+| `path` | 请求路径 | 始终记录 |
+| `handler` | 处理函数名（如 `controller.auth_controller.Login`） | 始终记录 |
+| `status` | HTTP 状态码 | 始终记录 |
+| `latency` | 请求耗时 | 始终记录 |
+| `ip` | 客户端 IP | 始终记录 |
+| `user_agent` | 客户端 User-Agent | 始终记录 |
+| `query` | URL Query 参数 | 有 Query 时记录 |
+| `resp_body` | 响应 Body（最大 2KB） | 仅 4xx/5xx 错误响应 |
+| `error` | Gin 错误信息 | 有 c.Errors 时记录 |

 #### 状态码分级输出

@@ -461,34 +470,34 @@ HTTP 请求日志中间件自动记录每个请求的完整信息，包含请求

 #### 日志输出示例

-**GET 请求（带 Query 参数）：**
+**正常 GET 请求（带 Query 参数）：**

 ```json
 {
    "level": "INFO",
-    "ts": "2026-02-28 15:55:48",
-    "caller": "middleware/logger.go:135",
-    "trace_id": "a6f0a744-eb14-4ac8-9e7a-5162ce7be842",
+    "ts": "2026-02-28 16:08:40",
+    "caller": "middleware/logger.go:108",
+    "trace_id": "b94a08f8-3c1e-4567-96ab-7bfe1057239a",
    "func": "middleware.Logger",
    "msg": "请求完成",
    "method": "GET",
    "path": "/health",
    "handler": "main.main.func1",
    "status": 200,
-    "latency": 0.000422,
+    "latency": 0.000530,
    "ip": "192.168.1.100",
-    "user_agent": "Mozilla/5.0",
+    "user_agent": "curl/8.7.1",
    "query": "foo=bar&debug=true"
 }
 ```

-**POST 登录请求（密码已脱敏）：**
+**POST 请求（中间件只记录元信息，参数由 Controller 层记录）：**

 ```json
 {
    "level": "INFO",
-    "ts": "2026-02-28 15:48:00",
-    "caller": "middleware/logger.go:135",
+    "ts": "2026-02-28 16:08:41",
+    "caller": "middleware/logger.go:108",
    "trace_id": "abc-123-def-456",
    "func": "middleware.Logger",
    "msg": "请求完成",
@@ -496,32 +505,43 @@ HTTP 请求日志中间件自动记录每个请求的完整信息，包含请求
    "path": "/api/v1/auth/login",
    "handler": "controller.auth_controller.Login",
    "status": 200,
-    "latency": 0.025,
-    "ip": "192.168.1.100",
-    "req_body": "{\"account\":\"testuser\",\"password\":\"***\"}"
+    "latency": 0.025
 }
 ```

-**错误响应（4xx/5xx 自动记录响应 Body）：**
+**错误响应（4xx/5xx 额外记录响应 Body）：**

 ```json
 {
    "level": "WARN",
-    "ts": "2026-02-28 15:48:01",
-    "caller": "middleware/logger.go:125",
-    "trace_id": "def-456-ghi-789",
+    "ts": "2026-02-28 16:08:42",
+    "caller": "middleware/logger.go:99",
+    "trace_id": "79f3f6fb-6997-4645-9c33-23f832dc6af2",
    "func": "middleware.Logger",
    "msg": "客户端错误",
    "method": "POST",
    "path": "/api/v1/auth/register",
    "handler": "controller.auth_controller.Register",
    "status": 400,
-    "req_body": "{\"username\":\"a\",\"email\":\"bad\",\"password\":\"***\"}",
    "resp_body": "{\"code\":400,\"message\":\"邮箱格式不正确\"}"
 }
 ```

-> **关于 `caller` 和 `handler` 字段**：`caller` 字段固定指向中间件源码行号（因为请求日志由中间件发出），`handler` 字段则显示实际处理请求的 Controller 函数名（如 `controller.auth_controller.Login`），通过 `handler` + `trace_id` 可快速定位到具体的业务处理代码。
+**Controller 层日志（caller 精确指向业务代码行号）：**
+
+```json
+{
+    "level": "INFO",
+    "ts": "2026-02-28 16:08:41",
+    "caller": "controller/auth_controller.go:35",
+    "trace_id": "abc-123-def-456",
+    "func": "controller.auth_controller.Login",
+    "msg": "开始处理登录",
+    "account": "testuser"
+}
+```
+
+> **设计理念**：中间件层关注"哪个接口被调用、结果如何"，业务层关注"具体做了什么、哪里出错"。两者通过 `trace_id` 串联，既避免日志重复，又能完整追踪请求链路。

 ### 8.7 WebSocket 日志

--- a/docs/plans/2026-02-27-phase1-foundation-and-auth.md
+++ b/docs/plans/2026-02-27-phase1-foundation-and-auth.md
@@ -251,15 +251,13 @@ type Response struct {
  - 注入 context，后续所有日志自动携带 trace_id
  - 在响应头中返回 `X-Request-ID`

-创建 `pkg/middleware/logger.go` — **请求日志中间件**：
-  - 记录每个请求的完整信息：方法、路径、状态码、耗时、IP、User-Agent
-  - **请求参数记录**：Query 参数 + Request Body 在 INFO 级别始终记录（所有环境生效）
-    - 文件上传自动跳过，仅标记 `[file upload]`
-    - 敏感路径（登录/注册/改密码）自动脱敏 password 字段
-    - Body 超过 4KB 自动截断
-  - **响应数据记录**：正常响应 DEBUG 级别记录，错误响应(4xx/5xx)在 WARN/ERROR 也记录
-    - 响应 Body 最大记录 2KB
-  - 自动携带 trace_id
+创建 `pkg/middleware/logger.go` — **请求日志中间件（Access Log 层）**：
+  - 采用社区标准「分层不重复」策略，只记录 HTTP 请求级元信息
+  - 记录字段：method / path / handler / status / latency / ip / user_agent / query
+  - **不记录 Request Body**（由 Controller 层在 ShouldBindJSON 后以结构化参数形式记录，caller 可精确指向业务代码行号）
+  - 错误响应(4xx/5xx)额外记录 Response Body（最大 2KB），便于排查接口返回内容
+  - handler 字段通过 `c.HandlerName()` 获取，显示实际处理请求的函数名
+  - 自动携带 trace_id，通过 trace_id 串联同一请求的各层日志
  - 状态码分级：5xx→ERROR / 4xx→WARN / 慢请求(>500ms)→WARN / 正常→INFO

 创建 `pkg/middleware/cors.go` — CORS 跨域中间件。