From 9e33e570afe3f1235a08537c6054ea10e50cdf3b Mon Sep 17 00:00:00 2001 From: lanyuanxiaoyao Date: Tue, 5 May 2026 01:54:53 +0800 Subject: [PATCH] =?UTF-8?q?fix:=20=E9=99=8D=E4=BD=8E=E8=AF=B7=E6=B1=82?= =?UTF-8?q?=E7=94=9F=E5=91=BD=E5=91=A8=E6=9C=9F=E6=97=A5=E5=BF=97=E7=BA=A7?= =?UTF-8?q?=E5=88=AB?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- backend/README.md | 2 +- .../internal/handler/middleware/logging.go | 4 +- .../handler/middleware/middleware_test.go | 57 +++++++++++++++++++ openspec/specs/middleware-system/spec.md | 10 +++- openspec/specs/structured-logging/spec.md | 10 +++- 5 files changed, 77 insertions(+), 6 deletions(-) diff --git a/backend/README.md b/backend/README.md index 9168aff..77c5d1b 100644 --- a/backend/README.md +++ b/backend/README.md @@ -54,7 +54,7 @@ func NewProxyHandler(..., logger *zap.Logger) *ProxyHandler { 使用 `pkg/logger/field.go` 中定义的字段构造函数： ```go -logger.Info("请求开始", +logger.Debug("请求开始", pkglogger.Method("POST"), pkglogger.Path("/v1/chat"), pkglogger.RequestID("xxx"), diff --git a/backend/internal/handler/middleware/logging.go b/backend/internal/handler/middleware/logging.go index 9ab84e2..93f5663 100644 --- a/backend/internal/handler/middleware/logging.go +++ b/backend/internal/handler/middleware/logging.go @@ -20,7 +20,7 @@ func Logging(logger *zap.Logger) gin.HandlerFunc { if id, ok := requestID.(string); ok { requestIDStr = id } - logger.Info("请求开始", + logger.Debug("请求开始", pkglogger.Method(c.Request.Method), pkglogger.Path(path), pkglogger.Query(query), @@ -33,7 +33,7 @@ func Logging(logger *zap.Logger) gin.HandlerFunc { latency := time.Since(start) statusCode := c.Writer.Status() - logger.Info("请求结束", + logger.Debug("请求结束", pkglogger.StatusCode(statusCode), pkglogger.Method(c.Request.Method), pkglogger.Path(path), diff --git a/backend/internal/handler/middleware/middleware_test.go b/backend/internal/handler/middleware/middleware_test.go index 74bbace..62f2a0f 100644 --- a/backend/internal/handler/middleware/middleware_test.go +++ b/backend/internal/handler/middleware/middleware_test.go @@ -7,6 +7,8 @@ import ( "github.com/gin-gonic/gin" "github.com/stretchr/testify/assert" "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" ) func init() { @@ -65,6 +67,61 @@ func TestLogging(t *testing.T) { assert.Equal(t, 200, w.Code) } +func TestLogging_DoesNotLogLifecycleAtInfoLevel(t *testing.T) { + core, logs := observer.New(zapcore.InfoLevel) + logger := zap.New(core) + + w := serveLoggingRequest(logger) + + assert.Equal(t, 200, w.Code) + assert.Empty(t, logs.FilterMessage("请求开始").All()) + assert.Empty(t, logs.FilterMessage("请求结束").All()) +} + +func TestLogging_LogsLifecycleAtDebugLevel(t *testing.T) { + core, logs := observer.New(zapcore.DebugLevel) + logger := zap.New(core) + + w := serveLoggingRequest(logger) + + assert.Equal(t, 200, w.Code) + startLogs := logs.FilterMessage("请求开始").All() + endLogs := logs.FilterMessage("请求结束").All() + if assert.Len(t, startLogs, 1) { + fields := startLogs[0].ContextMap() + assert.Equal(t, "GET", fields["method"]) + assert.Equal(t, "/test", fields["path"]) + assert.Equal(t, "key=value", fields["query"]) + assert.Equal(t, "existing-id-123", fields["request_id"]) + assert.NotEmpty(t, fields["client_ip"]) + } + if assert.Len(t, endLogs, 1) { + fields := endLogs[0].ContextMap() + assert.Equal(t, int64(200), fields["status"]) + assert.Equal(t, "GET", fields["method"]) + assert.Equal(t, "/test", fields["path"]) + assert.Equal(t, int64(2), fields["body_size"]) + assert.Equal(t, "existing-id-123", fields["request_id"]) + assert.Contains(t, fields, "latency") + } +} + +func serveLoggingRequest(logger *zap.Logger) *httptest.ResponseRecorder { + r := gin.New() + r.Use(RequestID()) + r.Use(Logging(logger)) + r.GET("/test", func(c *gin.Context) { + c.String(200, "ok") + }) + + w := httptest.NewRecorder() + req := httptest.NewRequest("GET", "/test?key=value", nil) + req.Header.Set("X-Request-ID", "existing-id-123") + r.ServeHTTP(w, req) + + return w +} + func TestRecovery_NoPanic(t *testing.T) { logger := zap.NewNop() diff --git a/openspec/specs/middleware-system/spec.md b/openspec/specs/middleware-system/spec.md index b8b5591..d1b6bcc 100644 --- a/openspec/specs/middleware-system/spec.md +++ b/openspec/specs/middleware-system/spec.md @@ -29,13 +29,13 @@ #### Scenario: 记录请求开始 - **WHEN** 收到 HTTP 请求 -- **THEN** SHALL 记录请求开始日志 +- **THEN** SHALL 以 debug 级别记录请求开始日志 - **THEN** SHALL 包含请求方法、路径、客户端 IP、请求 ID #### Scenario: 记录请求结束 - **WHEN** HTTP 请求处理完成 -- **THEN** SHALL 记录请求结束日志 +- **THEN** SHALL 以 debug 级别记录请求结束日志 - **THEN** SHALL 包含响应状态码、响应大小、请求耗时、请求 ID #### Scenario: 记录错误 @@ -44,6 +44,12 @@ - **THEN** SHALL 记录错误日志 - **THEN** SHALL 包含错误详情和请求 ID +#### Scenario: Info 级别过滤请求生命周期日志 + +- **WHEN** 日志中间件使用 info 级别 logger +- **THEN** SHALL NOT 输出“请求开始”日志 +- **THEN** SHALL NOT 输出“请求结束”日志 + ### Requirement: 实现错误恢复中间件 系统 SHALL 实现错误恢复中间件。 diff --git a/openspec/specs/structured-logging/spec.md b/openspec/specs/structured-logging/spec.md index 1a0546a..ca112d5 100644 --- a/openspec/specs/structured-logging/spec.md +++ b/openspec/specs/structured-logging/spec.md @@ -82,21 +82,29 @@ ### Requirement: 记录请求日志 -系统 SHALL 记录 HTTP 请求日志。 +系统 SHALL 记录 HTTP 请求日志，其中请求开始和请求结束生命周期日志 SHALL 使用 debug 级别记录。 #### Scenario: 请求开始日志 - **WHEN** 收到 HTTP 请求 +- **THEN** SHALL 以 debug 级别记录请求开始日志 - **THEN** SHALL 记录请求方法、路径、客户端 IP - **THEN** SHALL 包含请求 ID #### Scenario: 请求结束日志 - **WHEN** HTTP 请求处理完成 +- **THEN** SHALL 以 debug 级别记录请求结束日志 - **THEN** SHALL 记录响应状态码、响应大小 - **THEN** SHALL 记录请求耗时 - **THEN** SHALL 包含请求 ID +#### Scenario: Info 级别过滤请求生命周期日志 + +- **WHEN** 日志级别配置为 info +- **THEN** SHALL NOT 输出“请求开始”日志 +- **THEN** SHALL NOT 输出“请求结束”日志 + ### Requirement: 支持日志级别 系统 SHALL 支持日志级别控制。