重构日志与可观测性体系
新增单行文本编码器与结构化 GORM 日志,统一错误记录与请求日志策略,收紧日志文件权限并修复按天切分与压缩,支付回调参数脱敏,生产强制阿里云短信,RequestID 校验防注入,日志文案中文化。
This commit is contained in:
@@ -11,22 +11,15 @@ import (
|
||||
"go.uber.org/zap"
|
||||
)
|
||||
|
||||
func Recovery(logger *zap.Logger) gin.HandlerFunc {
|
||||
const contextPanicStack = "panic_stack"
|
||||
|
||||
func Recovery(_ *zap.Logger) gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
defer func() {
|
||||
if recovered := recover(); recovered != nil {
|
||||
err := fmt.Errorf("panic: %v", recovered)
|
||||
_ = c.Error(err)
|
||||
logger.Error("http panic recovered",
|
||||
zap.String("request_id", GetRequestID(c)),
|
||||
zap.String("method", c.Request.Method),
|
||||
zap.String("path", c.Request.URL.Path),
|
||||
zap.String("route", c.FullPath()),
|
||||
zap.String("client_ip", c.ClientIP()),
|
||||
zap.String("user_agent", c.GetHeader("User-Agent")),
|
||||
zap.String("panic", fmt.Sprint(recovered)),
|
||||
zap.ByteString("stack", debug.Stack()),
|
||||
)
|
||||
c.Set(contextPanicStack, string(debug.Stack()))
|
||||
if !c.Writer.Written() {
|
||||
response.Error(c, http.StatusInternalServerError, "internal_error", "服务暂时不可用")
|
||||
}
|
||||
|
||||
@@ -3,12 +3,18 @@ package middleware
|
||||
import (
|
||||
"crypto/rand"
|
||||
"encoding/hex"
|
||||
"fmt"
|
||||
"strings"
|
||||
"sync/atomic"
|
||||
"time"
|
||||
|
||||
"hfb_sys/backend/internal/logging"
|
||||
|
||||
"github.com/gin-gonic/gin"
|
||||
)
|
||||
|
||||
var requestIDFallbackCounter atomic.Uint64
|
||||
|
||||
const (
|
||||
RequestIDHeader = "X-Request-ID"
|
||||
ContextRequestID = "request_id"
|
||||
@@ -17,7 +23,7 @@ const (
|
||||
func RequestID() gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
requestID := c.GetHeader(RequestIDHeader)
|
||||
if requestID == "" {
|
||||
if !validRequestID(requestID) {
|
||||
requestID = newRequestID()
|
||||
}
|
||||
c.Set(ContextRequestID, requestID)
|
||||
@@ -42,7 +48,19 @@ func GetRequestID(c *gin.Context) string {
|
||||
func newRequestID() string {
|
||||
buf := make([]byte, 16)
|
||||
if _, err := rand.Read(buf); err != nil {
|
||||
return ""
|
||||
return fmt.Sprintf("%x-%x", time.Now().UnixNano(), requestIDFallbackCounter.Add(1))
|
||||
}
|
||||
return hex.EncodeToString(buf)
|
||||
}
|
||||
|
||||
func validRequestID(value string) bool {
|
||||
if value == "" || len(value) > 64 {
|
||||
return false
|
||||
}
|
||||
return strings.IndexFunc(value, func(char rune) bool {
|
||||
return !((char >= 'a' && char <= 'z') ||
|
||||
(char >= 'A' && char <= 'Z') ||
|
||||
(char >= '0' && char <= '9') ||
|
||||
char == '-' || char == '_' || char == '.')
|
||||
}) == -1
|
||||
}
|
||||
|
||||
@@ -0,0 +1,24 @@
|
||||
package middleware
|
||||
|
||||
import "testing"
|
||||
|
||||
func TestValidRequestID(t *testing.T) {
|
||||
tests := []struct {
|
||||
name string
|
||||
value string
|
||||
want bool
|
||||
}{
|
||||
{name: "标准 ID", value: "req-20260729_ab.cd", want: true},
|
||||
{name: "空值", value: "", want: false},
|
||||
{name: "包含空格", value: "bad id", want: false},
|
||||
{name: "包含换行", value: "bad\nid", want: false},
|
||||
{name: "超长", value: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa", want: false},
|
||||
}
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
if got := validRequestID(tt.value); got != tt.want {
|
||||
t.Fatalf("validRequestID() = %v, want %v", got, tt.want)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
@@ -1,15 +1,17 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"strings"
|
||||
"net/http"
|
||||
"time"
|
||||
|
||||
"hfb_sys/backend/pkg/response"
|
||||
|
||||
"github.com/gin-gonic/gin"
|
||||
"go.uber.org/zap"
|
||||
)
|
||||
|
||||
// 成功且延迟低于该阈值的热路径请求不再写访问日志(错误/慢请求仍全量记录)。
|
||||
const slowRequestThresholdMs = 200
|
||||
// 正常请求不记录访问日志;只有慢请求、服务端错误、限流和有诊断价值的认证失败会输出。
|
||||
const slowRequestThresholdMs = 500
|
||||
|
||||
func RequestLogger(logger *zap.Logger) gin.HandlerFunc {
|
||||
return func(c *gin.Context) {
|
||||
@@ -20,8 +22,9 @@ func RequestLogger(logger *zap.Logger) gin.HandlerFunc {
|
||||
status := c.Writer.Status()
|
||||
path := c.Request.URL.Path
|
||||
route := c.FullPath()
|
||||
authFailure := meaningfulAuthFailure(c)
|
||||
|
||||
if shouldSkipHTTPLog(path, route, status, latencyMs) {
|
||||
if shouldSkipHTTPLog(path, route, status, latencyMs) && !authFailure {
|
||||
return
|
||||
}
|
||||
|
||||
@@ -31,16 +34,9 @@ func RequestLogger(logger *zap.Logger) gin.HandlerFunc {
|
||||
zap.String("path", path),
|
||||
zap.String("route", route),
|
||||
zap.Int("status", status),
|
||||
zap.Float64("latency_ms", latencyMs),
|
||||
zap.String("code", response.CodeFromContext(c)),
|
||||
zap.Float64("duration_ms", latencyMs),
|
||||
zap.String("client_ip", c.ClientIP()),
|
||||
zap.Int("response_size", c.Writer.Size()),
|
||||
}
|
||||
// 成功响应省略 UA/referer,错误与 4xx/5xx 保留完整现场
|
||||
if status >= 400 {
|
||||
fields = append(fields,
|
||||
zap.String("user_agent", c.GetHeader("User-Agent")),
|
||||
zap.String("referer", c.GetHeader("Referer")),
|
||||
)
|
||||
}
|
||||
if userID, ok := c.Get(ContextUserID); ok {
|
||||
fields = append(fields, zap.Any("user_id", userID))
|
||||
@@ -64,47 +60,44 @@ func RequestLogger(logger *zap.Logger) gin.HandlerFunc {
|
||||
fields = append(fields, zap.Any("auth_current_token_version", currentVersion))
|
||||
}
|
||||
if len(c.Errors) > 0 {
|
||||
fields = append(fields, zap.String("errors", strings.TrimSpace(c.Errors.String())))
|
||||
fields = append(fields,
|
||||
zap.String("error", c.Errors.Last().Err.Error()),
|
||||
zap.Int("error_count", len(c.Errors)),
|
||||
)
|
||||
}
|
||||
if stack, ok := c.Get(contextPanicStack); ok {
|
||||
fields = append(fields, zap.Any("stack", stack))
|
||||
}
|
||||
|
||||
switch {
|
||||
case status >= 500:
|
||||
logger.Error("http request", fields...)
|
||||
case status >= 400:
|
||||
logger.Warn("http request", fields...)
|
||||
default:
|
||||
logger.Info("http request", fields...)
|
||||
logger.Error("HTTP 请求失败", fields...)
|
||||
case status == http.StatusTooManyRequests:
|
||||
logger.Warn("HTTP 请求被限流", fields...)
|
||||
case authFailure:
|
||||
logger.Warn("后台认证失败", fields...)
|
||||
case latencyMs >= slowRequestThresholdMs:
|
||||
logger.Warn("HTTP 慢请求", fields...)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// shouldSkipHTTPLog 判断是否跳过写入:仅跳过「成功 + 非慢请求」的高频热路径。
|
||||
func shouldSkipHTTPLog(path, route string, status int, latencyMs float64) bool {
|
||||
if status >= 400 {
|
||||
// shouldSkipHTTPLog 判断是否为无需记录的普通请求。
|
||||
func shouldSkipHTTPLog(_, _ string, status int, latencyMs float64) bool {
|
||||
if status >= 500 || status == http.StatusTooManyRequests {
|
||||
return false
|
||||
}
|
||||
if latencyMs >= slowRequestThresholdMs {
|
||||
return false
|
||||
}
|
||||
return isHotPath(path, route)
|
||||
return true
|
||||
}
|
||||
|
||||
func isHotPath(path, route string) bool {
|
||||
if strings.HasSuffix(path, "/unread-count") {
|
||||
return true
|
||||
func meaningfulAuthFailure(c *gin.Context) bool {
|
||||
value, ok := c.Get(ContextAuthFailureReason)
|
||||
if !ok {
|
||||
return false
|
||||
}
|
||||
if path == "/api/wallet/balance" {
|
||||
return true
|
||||
}
|
||||
if path == "/api/mobile-home-config" {
|
||||
return true
|
||||
}
|
||||
if strings.HasSuffix(path, "/cover") || route == "/api/listings/:id/cover" {
|
||||
return true
|
||||
}
|
||||
if path == "/api/files/object" || path == "/api/admin/files/object" ||
|
||||
route == "/api/files/object" || route == "/api/admin/files/object" {
|
||||
return true
|
||||
}
|
||||
return false
|
||||
reason, _ := value.(string)
|
||||
return reason != "" && reason != "missing"
|
||||
}
|
||||
|
||||
@@ -0,0 +1,52 @@
|
||||
package middleware
|
||||
|
||||
import (
|
||||
"errors"
|
||||
"net/http"
|
||||
"net/http/httptest"
|
||||
"testing"
|
||||
|
||||
"hfb_sys/backend/pkg/response"
|
||||
|
||||
"github.com/gin-gonic/gin"
|
||||
"go.uber.org/zap"
|
||||
"go.uber.org/zap/zaptest/observer"
|
||||
)
|
||||
|
||||
func TestRequestLoggerRecordsServerErrorCause(t *testing.T) {
|
||||
gin.SetMode(gin.TestMode)
|
||||
core, observed := observer.New(zap.DebugLevel)
|
||||
engine := gin.New()
|
||||
engine.Use(RequestID(), RequestLogger(zap.New(core)))
|
||||
engine.GET("/failed", func(c *gin.Context) {
|
||||
response.RecordError(c, errors.New("database unavailable"))
|
||||
response.Error(c, http.StatusInternalServerError, "internal_error", "服务暂时不可用")
|
||||
})
|
||||
|
||||
request := httptest.NewRequest(http.MethodGet, "/failed", nil)
|
||||
responseRecorder := httptest.NewRecorder()
|
||||
engine.ServeHTTP(responseRecorder, request)
|
||||
|
||||
entries := observed.FilterMessage("HTTP 请求失败").All()
|
||||
if len(entries) != 1 {
|
||||
t.Fatalf("server error logs = %d, want 1", len(entries))
|
||||
}
|
||||
fields := entries[0].ContextMap()
|
||||
if fields["error"] != "database unavailable" || fields["code"] != "internal_error" {
|
||||
t.Fatalf("unexpected fields: %v", fields)
|
||||
}
|
||||
}
|
||||
|
||||
func TestRequestLoggerSkipsOrdinaryNotFound(t *testing.T) {
|
||||
gin.SetMode(gin.TestMode)
|
||||
core, observed := observer.New(zap.DebugLevel)
|
||||
engine := gin.New()
|
||||
engine.Use(RequestID(), RequestLogger(zap.New(core)))
|
||||
|
||||
request := httptest.NewRequest(http.MethodGet, "/missing", nil)
|
||||
responseRecorder := httptest.NewRecorder()
|
||||
engine.ServeHTTP(responseRecorder, request)
|
||||
if observed.Len() != 0 {
|
||||
t.Fatalf("ordinary 404 should not produce logs: %v", observed.All())
|
||||
}
|
||||
}
|
||||
@@ -11,16 +11,14 @@ func TestShouldSkipHTTPLog(t *testing.T) {
|
||||
latencyMs float64
|
||||
wantSkip bool
|
||||
}{
|
||||
{name: "轮询未读成功跳过", path: "/api/chats/unread-count", status: 200, latencyMs: 1, wantSkip: true},
|
||||
{name: "钱包余额成功跳过", path: "/api/wallet/balance", status: 200, latencyMs: 2, wantSkip: true},
|
||||
{name: "封面成功跳过", path: "/api/listings/12/cover", route: "/api/listings/:id/cover", status: 200, latencyMs: 3, wantSkip: true},
|
||||
{name: "文件对象成功跳过", path: "/api/files/object", status: 200, latencyMs: 5, wantSkip: true},
|
||||
{name: "首页配置成功跳过", path: "/api/mobile-home-config", status: 200, latencyMs: 4, wantSkip: true},
|
||||
{name: "轮询 401 不跳过", path: "/api/chats/unread-count", status: 401, latencyMs: 1, wantSkip: false},
|
||||
{name: "普通成功请求跳过", path: "/api/orders", status: 200, latencyMs: 20, wantSkip: true},
|
||||
{name: "创建成功请求跳过", path: "/api/orders", status: 201, latencyMs: 30, wantSkip: true},
|
||||
{name: "普通 400 跳过", path: "/api/orders", status: 400, latencyMs: 2, wantSkip: true},
|
||||
{name: "普通 401 跳过", path: "/api/orders", status: 401, latencyMs: 2, wantSkip: true},
|
||||
{name: "普通 404 跳过", path: "/unknown", status: 404, latencyMs: 2, wantSkip: true},
|
||||
{name: "轮询 500 不跳过", path: "/api/wallet/balance", status: 500, latencyMs: 1, wantSkip: false},
|
||||
{name: "轮询慢请求不跳过", path: "/api/chats/unread-count", status: 200, latencyMs: 250, wantSkip: false},
|
||||
{name: "普通业务成功不跳过", path: "/api/orders", status: 200, latencyMs: 20, wantSkip: false},
|
||||
{name: "下单成功不跳过", path: "/api/orders", status: 201, latencyMs: 30, wantSkip: false},
|
||||
{name: "限流请求不跳过", path: "/api/auth/sms", status: 429, latencyMs: 1, wantSkip: false},
|
||||
{name: "慢请求不跳过", path: "/api/orders", status: 200, latencyMs: 500, wantSkip: false},
|
||||
}
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
|
||||
Reference in New Issue
Block a user