Files
user-system/internal/api/middleware/logger.go
long-agent 7b047e2f11 perf: Sprint 19 P0/P1 性能优化落地
P0(高优先级):
- P0-1: 确认数据库复合索引已存在(GORM tag),composite_index_test 验证通过
- P0-2: 连接池调优 MaxIdleConns 5→10, ConnMaxLifetime 30min→5min
- P0-3: Redis 智能探测(ProbeRedis),无 Redis 自动降级到纯内存模式

P1(中优先级):
- P1-1: GZIP 压缩中间件(compress/gzip 标准库,零新依赖)
- P1-2: 权限缓存 TTL 30min→5min
- P1-3: Argon2id 启动自适应校准(CalibrateArgon2id)

历史优化(含本次提交):
- L1Cache O(n)→O(1) LRU 重构
- Auth 中间件 DB 查询合并 + 5s L1 缓存
- Logger 异步化(4096 缓冲通道)

验证: go build/vet/test 41/41 PASS, govulncheck 无漏洞
2026-04-18 22:57:44 +08:00

142 lines
3.2 KiB
Go

package middleware
import (
"fmt"
"log"
"net/url"
"strings"
"time"
"github.com/gin-gonic/gin"
)
var sensitiveQueryKeys = map[string]struct{}{
"token": {},
"access_token": {},
"refresh_token": {},
"code": {},
"secret": {},
}
// logEntry is a single access-log line sent to the async writer.
type logEntry struct {
ts time.Time
method string
path string
rawQuery string
status int
latency time.Duration
ip string
userAgent string
userID interface{}
traceID string
errors []string
}
// asyncLogger holds a channel-based write queue so that access log I/O is
// decoupled from the HTTP request handling goroutine.
//
// Buffer depth of 4096 means we can absorb ~4 k outstanding log lines before
// back-pressure is applied. Under normal load (< 500 req/s) this buffer never
// fills; under load-test peaks it prevents log writes from inflating p99.
var asyncLogCh = func() chan logEntry {
ch := make(chan logEntry, 4096)
go func() {
for e := range ch {
writeLogEntry(e)
}
}()
return ch
}()
func writeLogEntry(e logEntry) {
log.Printf("[API] %s %s %s | status: %d | latency: %v | ip: %s | user_id: %v | trace_id: %s | ua: %s",
e.ts.Format("2006-01-02 15:04:05"),
e.method,
e.path,
e.status,
e.latency,
e.ip,
e.userID,
e.traceID,
e.userAgent,
)
for _, errMsg := range e.errors {
log.Printf("[Error] trace_id: %s | %s", e.traceID, errMsg)
}
if e.rawQuery != "" {
log.Printf("[Query] %s?%s", e.path, e.rawQuery)
}
}
// Logger returns a gin middleware that records each HTTP request.
// Log writes are offloaded to a background goroutine via a buffered channel,
// so they never block the handler goroutine or inflate response latency.
func Logger() gin.HandlerFunc {
return func(c *gin.Context) {
start := time.Now()
path := c.Request.URL.Path
raw := sanitizeQuery(c.Request.URL.RawQuery)
c.Next()
latency := time.Since(start)
userID, _ := c.Get("user_id")
traceID := GetTraceID(c)
var errStrings []string
for _, err := range c.Errors {
errStrings = append(errStrings, fmt.Sprintf("%v", err))
}
entry := logEntry{
ts: time.Now(),
method: c.Request.Method,
path: path,
rawQuery: raw,
status: c.Writer.Status(),
latency: latency,
ip: c.ClientIP(),
userAgent: c.Request.UserAgent(),
userID: userID,
traceID: traceID,
errors: errStrings,
}
// Non-blocking send: if the channel is full (extreme overload), drop the log
// line rather than stall the HTTP response.
select {
case asyncLogCh <- entry:
default:
// Channel full — log drop is preferable to adding latency.
}
}
}
func sanitizeQuery(raw string) string {
if raw == "" {
return ""
}
values, err := url.ParseQuery(raw)
if err != nil {
return ""
}
for key := range values {
if isSensitiveQueryKey(key) {
values.Set(key, "***")
}
}
return values.Encode()
}
func isSensitiveQueryKey(key string) bool {
normalized := strings.ToLower(strings.TrimSpace(key))
if _, ok := sensitiveQueryKeys[normalized]; ok {
return true
}
return strings.Contains(normalized, "token") || strings.Contains(normalized, "secret")
}