From b6aaee01cef64f94e7a26bf6ec2161f1abc97356 Mon Sep 17 00:00:00 2001 From: yangjianbo Date: Thu, 12 Feb 2026 19:19:11 +0800 Subject: [PATCH] =?UTF-8?q?fix(logging):=20=E4=BF=AE=E5=A4=8D=20warn=20?= =?UTF-8?q?=E7=BA=A7=E5=88=AB=E4=B8=8B=E7=B3=BB=E7=BB=9F=E6=97=A5=E5=BF=97?= =?UTF-8?q?=E7=A9=BA=E7=99=BD=E9=97=AE=E9=A2=98?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - 新增 logger.WriteSinkEvent，支持旁路写入 sink，不受全局级别门控影响\n- 在 http.access 中间件中，当 info 被门控时补写 sink，保障 Ops 系统日志可索引\n- 增加 level=warn 场景回归测试，验证访问日志仍可入库 --- backend/internal/pkg/logger/logger.go | 40 +++++++++++++ backend/internal/server/middleware/logger.go | 30 ++++++++++ .../middleware/request_access_logger_test.go | 58 ++++++++++++++++++- 3 files changed, 127 insertions(+), 1 deletion(-) diff --git a/backend/internal/pkg/logger/logger.go b/backend/internal/pkg/logger/logger.go index 86ef4ed7..5cc50696 100644 --- a/backend/internal/pkg/logger/logger.go +++ b/backend/internal/pkg/logger/logger.go @@ -127,6 +127,46 @@ func SetSink(sink Sink) { currentSink = sink } +// WriteSinkEvent 直接写入日志 sink，不经过全局日志级别门控。 +// 用于需要“可观测性入库”与“业务输出级别”解耦的场景（例如 ops 系统日志索引）。 +func WriteSinkEvent(level, component, message string, fields map[string]any) { + mu.RLock() + sink := currentSink + mu.RUnlock() + if sink == nil { + return + } + + level = strings.ToLower(strings.TrimSpace(level)) + if level == "" { + level = "info" + } + component = strings.TrimSpace(component) + message = strings.TrimSpace(message) + if message == "" { + return + } + + eventFields := make(map[string]any, len(fields)+1) + for k, v := range fields { + eventFields[k] = v + } + if component != "" { + if _, ok := eventFields["component"]; !ok { + eventFields["component"] = component + } + } + + sink.WriteLogEvent(&LogEvent{ + Time: time.Now(), + Level: level, + Component: component, + Message: message, + LoggerName: component, + Fields: eventFields, + }) +} + func L() *zap.Logger { mu.RLock() defer mu.RUnlock() diff --git a/backend/internal/server/middleware/logger.go b/backend/internal/server/middleware/logger.go index b14a3a21..3cf1acf5 100644 --- a/backend/internal/server/middleware/logger.go +++ b/backend/internal/server/middleware/logger.go @@ -58,6 +58,36 @@ func Logger() gin.HandlerFunc { l := logger.FromContext(c.Request.Context()).With(fields...) l.Info("http request completed", zap.Time("completed_at", endTime)) + // 当全局日志级别高于 info（如 warn/error）时，access info 不会进入 zap core， + // 这里补写一次 sink，保证 ops 系统日志仍可索引关键访问轨迹。 + if !logger.L().Core().Enabled(logger.LevelInfo) { + sinkFields := map[string]any{ + "component": "http.access", + "status_code": statusCode, + "latency_ms": latency.Milliseconds(), + "client_ip": clientIP, + "protocol": protocol, + "method": method, + "path": path, + "completed_at": endTime, + } + if requestID, ok := c.Request.Context().Value(ctxkey.RequestID).(string); ok && requestID != "" { + sinkFields["request_id"] = requestID + } + if clientRequestID, ok := c.Request.Context().Value(ctxkey.ClientRequestID).(string); ok && clientRequestID != "" { + sinkFields["client_request_id"] = clientRequestID + } + if hasAccountID && accountID > 0 { + sinkFields["account_id"] = accountID + } + if platform != "" { + sinkFields["platform"] = platform + } + if model != "" { + sinkFields["model"] = model + } + logger.WriteSinkEvent("info", "http.access", "http request completed", sinkFields) + } if len(c.Errors) > 0 { l.Warn("http request contains gin errors", zap.String("errors", c.Errors.String())) diff --git a/backend/internal/server/middleware/request_access_logger_test.go b/backend/internal/server/middleware/request_access_logger_test.go index 07faa32f..a135bf3a 100644 --- a/backend/internal/server/middleware/request_access_logger_test.go +++ b/backend/internal/server/middleware/request_access_logger_test.go @@ -4,6 +4,7 @@ import ( "context" "net/http" "net/http/httptest" + "strings" "sync" "testing" @@ -32,9 +33,17 @@ func (s *testLogSink) list() []*logger.LogEvent { } func initMiddlewareTestLogger(t *testing.T) *testLogSink { + return initMiddlewareTestLoggerWithLevel(t, "debug") +} + +func initMiddlewareTestLoggerWithLevel(t *testing.T, level string) *testLogSink { t.Helper() + level = strings.TrimSpace(level) + if level == "" { + level = "debug" + } if err := logger.Init(logger.InitOptions{ - Level: "debug", + Level: level, Format: "json", ServiceName: "sub2api", Environment: "test", @@ -191,3 +200,50 @@ func TestLogger_HealthPathSkipped(t *testing.T) { t.Fatalf("health endpoint should not write access log") } } + +func TestLogger_AccessLogStillIndexedWhenLevelWarn(t *testing.T) { + gin.SetMode(gin.TestMode) + sink := initMiddlewareTestLoggerWithLevel(t, "warn") + + r := gin.New() + r.Use(RequestLogger()) + r.Use(Logger()) + r.GET("/api/test", func(c *gin.Context) { + c.Status(http.StatusCreated) + }) + + w := httptest.NewRecorder() + req := httptest.NewRequest(http.MethodGet, "/api/test", nil) + r.ServeHTTP(w, req) + if w.Code != http.StatusCreated { + t.Fatalf("status=%d", w.Code) + } + + events := sink.list() + if len(events) == 0 { + t.Fatalf("expected access log event to be indexed when level=warn") + } + + found := false + for _, event := range events { + if event == nil || event.Message != "http request completed" { + continue + } + found = true + if event.Level != "info" { + t.Fatalf("event level=%q, want info", event.Level) + } + if event.Component != "http.access" && event.Fields["component"] != "http.access" { + t.Fatalf("event component mismatch: component=%q fields=%v", event.Component, event.Fields["component"]) + } + if _, ok := event.Fields["status_code"]; !ok { + t.Fatalf("status_code field missing: %+v", event.Fields) + } + if _, ok := event.Fields["request_id"]; !ok { + t.Fatalf("request_id field missing: %+v", event.Fields) + } + } + if !found { + t.Fatalf("access log event not found") + } +}