优化

internal/server/middleware/access_log.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"io"
 	"log/slog"
+	"net/http"
 	"strings"
 	"time"
 
@@ -14,38 +15,42 @@ import (
 
 // AccessLog is the single global request/response capture point, matching
 // the reference middleware ordering and making every HTTP request observable.
-func AccessLog(runtime *conf.Runtime, logger *slog.Logger) gin.HandlerFunc {
+func AccessLog(runtime *conf.Runtime, logger *slog.Logger, version string) gin.HandlerFunc {
 	return func(c *gin.Context) {
+		started := time.Now()
 		var requestBody []byte
 		multipart := strings.Contains(c.GetHeader("Content-Type"), "multipart/form-data")
+		bytesIn := c.Request.ContentLength
 		if c.Request.Body != nil && !multipart {
 			requestBody, _ = io.ReadAll(c.Request.Body)
 			c.Request.Body = io.NopCloser(bytes.NewReader(requestBody))
+			bytesIn = int64(len(requestBody))
+		}
+		if bytesIn < 0 {
+			bytesIn = 0
 		}
 		maxBytes := 1 << 20
 		writer := &captureWriter{ResponseWriter: c.Writer, maxBytes: maxBytes}
 		c.Writer = writer
-		started := time.Now()
+		c.Header("X-Kra-Version", version)
+		config := runtime.Admin()
+		logLimit := 1024
+		if config != nil && config.Zap != nil && config.Zap.AccessLogMaxBytes > 0 {
+			logLimit = int(config.Zap.AccessLogMaxBytes)
+		}
+		requestText := ""
+		if multipart {
+			requestText = "[文件]"
+		} else {
+			requestText = redactJSON(requestBody, c.GetHeader("Content-Type"), logLimit)
+		}
+		c.Set(ctxReqBodyKey, requestText)
+		c.Set(ctxRespBufferKey, &writer.body)
 		c.Next()
 		if logger == nil {
 			return
 		}
-		requestText, responseText := "", ""
-		config := runtime.Admin()
-		logLimit := 32768
-		if config != nil && config.Zap != nil && config.Zap.AccessLogMaxBytes > 0 {
-			logLimit = int(config.Zap.AccessLogMaxBytes)
-		}
-		if config == nil || config.Zap == nil || config.Zap.AccessReqBody {
-			if multipart {
-				requestText = "[文件]"
-			} else {
-				requestText = redactJSONLimit(requestBody, logLimit)
-			}
-		}
-		if config == nil || config.Zap == nil || config.Zap.AccessRespData {
-			responseText = redactJSONLimit(writer.body.Bytes(), logLimit)
-		}
+		responseText := redactJSON(writer.body.Bytes(), c.Writer.Header().Get("Content-Type"), logLimit)
 		userID, authorityID := uint(0), uint(0)
 		if claims := Claims(c); claims != nil {
 			userID, authorityID = claims.ID, claims.AuthorityID
@@ -54,27 +59,41 @@ func AccessLog(runtime *conf.Runtime, logger *slog.Logger) gin.HandlerFunc {
 		if route == "" {
 			route = "unmatched"
 		}
-		attributes := []any{
-			"ip", c.ClientIP(), "method", c.Request.Method, "path", c.Request.URL.Path, "http_route", route,
-			"status", c.Writer.Status(), "latency_ms", time.Since(started).Milliseconds(),
-			"request_id", stringValueFromContext(c, "request_id"), "trace_id", stringValueFromContext(c, "trace_id"),
-			"bytes_in", len(requestBody), "bytes_out", c.Writer.Size(), "user_id", userID, "authority_id", authorityID,
-			"ua", c.Request.UserAgent(), "query", c.Request.URL.RawQuery, "request", requestText, "response", responseText}
-		if config != nil && config.Zap != nil && config.Zap.AccessReqHeaders {
-			attributes = append(attributes, "headers", redactHeaders(c.Request.Header))
+		bytesOut := int64(c.Writer.Size())
+		if bytesOut < 0 {
+			bytesOut = 0
 		}
-		logger.InfoContext(c.Request.Context(), "http access", attributes...)
+		privateErrors := strings.TrimRight(c.Errors.ByType(gin.ErrorTypePrivate).String(), "\n")
+		attributes := []any{
+			"mod", "http", "ip", c.ClientIP(), "method", c.Request.Method, "http_path", c.Request.URL.Path, "http_route", route,
+			"http_status", c.Writer.Status(), "latency_ms", time.Since(started).Milliseconds(),
+			"request_id", stringValueFromContext(c, "request_id"), "trace_id", stringValueFromContext(c, "trace_id"),
+			"bytes_in", bytesIn, "bytes_out", bytesOut, "user_id", userID, "authority_id", authorityID,
+			"error", c.Writer.Status() >= http.StatusInternalServerError || privateErrors != "", "ua", c.Request.UserAgent(), "req_query", c.Request.URL.RawQuery}
+		if config != nil && config.Zap != nil && config.Zap.AccessReqHeaders {
+			attributes = append(attributes, "req_headers", redactHeaders(c.Request.Header))
+		}
+		if config != nil && config.Zap != nil && config.Zap.AccessReqBody {
+			attributes = append(attributes, "req_body", requestText)
+		}
+		if config != nil && config.Zap != nil && config.Zap.AccessRespData {
+			attributes = append(attributes, "resp_data", responseText)
+		}
+		if privateErrors != "" {
+			attributes = append(attributes, "error_msg", privateErrors)
+		}
+		logger.InfoContext(c.Request.Context(), "请求完成", attributes...)
 	}
 }
 
-func redactHeaders(headers map[string][]string) map[string][]string {
-	out := make(map[string][]string, len(headers))
+func redactHeaders(headers map[string][]string) map[string]string {
+	out := make(map[string]string, len(headers))
 	for key, values := range headers {
 		lower := strings.ToLower(key)
-		if strings.Contains(lower, "token") || lower == "authorization" || lower == "cookie" {
-			out[key] = []string{"******"}
+		if lower == "authorization" || lower == "cookie" || lower == "set-cookie" || lower == "x-token" {
+			out[key] = "***"
 		} else {
-			out[key] = values
+			out[key] = strings.Join(values, ",")
 		}
 	}
 	return out