fix(logging): 修复 warn 级别下系统日志空白问题

- 新增 logger.WriteSinkEvent,支持旁路写入 sink,不受全局级别门控影响\n- 在 http.access 中间件中,当 info 被门控时补写 sink,保障 Ops 系统日志可索引\n- 增加 level=warn 场景回归测试,验证访问日志仍可入库
This commit is contained in:
yangjianbo
2026-02-12 19:19:11 +08:00
parent 3511376c2c
commit b6aaee01ce
3 changed files with 127 additions and 1 deletions

View File

@@ -127,6 +127,46 @@ func SetSink(sink Sink) {
currentSink = 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 { func L() *zap.Logger {
mu.RLock() mu.RLock()
defer mu.RUnlock() defer mu.RUnlock()

View File

@@ -58,6 +58,36 @@ func Logger() gin.HandlerFunc {
l := logger.FromContext(c.Request.Context()).With(fields...) l := logger.FromContext(c.Request.Context()).With(fields...)
l.Info("http request completed", zap.Time("completed_at", endTime)) l.Info("http request completed", zap.Time("completed_at", endTime))
// 当全局日志级别高于 info如 warn/erroraccess 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 { if len(c.Errors) > 0 {
l.Warn("http request contains gin errors", zap.String("errors", c.Errors.String())) l.Warn("http request contains gin errors", zap.String("errors", c.Errors.String()))

View File

@@ -4,6 +4,7 @@ import (
"context" "context"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
"strings"
"sync" "sync"
"testing" "testing"
@@ -32,9 +33,17 @@ func (s *testLogSink) list() []*logger.LogEvent {
} }
func initMiddlewareTestLogger(t *testing.T) *testLogSink { func initMiddlewareTestLogger(t *testing.T) *testLogSink {
return initMiddlewareTestLoggerWithLevel(t, "debug")
}
func initMiddlewareTestLoggerWithLevel(t *testing.T, level string) *testLogSink {
t.Helper() t.Helper()
level = strings.TrimSpace(level)
if level == "" {
level = "debug"
}
if err := logger.Init(logger.InitOptions{ if err := logger.Init(logger.InitOptions{
Level: "debug", Level: level,
Format: "json", Format: "json",
ServiceName: "sub2api", ServiceName: "sub2api",
Environment: "test", Environment: "test",
@@ -191,3 +200,50 @@ func TestLogger_HealthPathSkipped(t *testing.T) {
t.Fatalf("health endpoint should not write access log") 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")
}
}