2026-06-23 11:53:00 +08:00

648 lines
17 KiB
Go
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

// Package logx provides structured runtime logging for service boundaries and workers.
// Services emit JSON/text to stdout only; deployment collects stdout into CLS or local logs.
package logx
import (
"bytes"
"context"
"encoding/json"
"errors"
"fmt"
"io"
"log"
"log/slog"
"mime"
"net/http"
"os"
"strings"
"sync"
"time"
"hyapp/pkg/appcode"
"hyapp/pkg/xerr"
"google.golang.org/grpc"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/status"
"google.golang.org/protobuf/encoding/protojson"
"google.golang.org/protobuf/proto"
)
const (
defaultLevel = "info"
defaultFormat = "json"
defaultEnv = "local"
defaultMaxPayloadBytes = 2048
redactedValue = "***REDACTED***"
)
// Config controls process-wide structured logging. Service code must not write to CLS directly.
type Config struct {
Service string `yaml:"service"`
Env string `yaml:"env"`
Version string `yaml:"version"`
NodeID string `yaml:"node_id"`
Level string `yaml:"level"`
Format string `yaml:"format"`
IncludeRequestBody bool `yaml:"include_request_body"`
IncludeResponseBody bool `yaml:"include_response_body"`
MaxPayloadBytes int `yaml:"max_payload_bytes"`
Output io.Writer `yaml:"-"`
}
// WithRuntimeFields fills process identity fields from service config without duplicating YAML.
func (cfg Config) WithRuntimeFields(service string, env string, nodeID string) Config {
if strings.TrimSpace(cfg.Service) == "" {
cfg.Service = service
}
if strings.TrimSpace(cfg.Env) == "" {
cfg.Env = env
}
if strings.TrimSpace(cfg.NodeID) == "" {
cfg.NodeID = nodeID
}
return cfg
}
type contextAttrsKey struct{}
var (
globalMu sync.RWMutex
globalLogger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo, ReplaceAttr: replaceAttr}))
globalConfig = Config{Env: defaultEnv, Level: defaultLevel, Format: defaultFormat, MaxPayloadBytes: defaultMaxPayloadBytes}
)
// Init installs the process logger and redirects the standard library log package into JSON/text logs.
func Init(cfg Config) error {
normalized, err := NormalizeConfig(cfg)
if err != nil {
return err
}
level, err := parseLevel(normalized.Level)
if err != nil {
return err
}
output := normalized.Output
if output == nil {
output = os.Stdout
}
handlerOptions := &slog.HandlerOptions{Level: level, ReplaceAttr: replaceAttr}
var handler slog.Handler
switch normalized.Format {
case "json":
handler = slog.NewJSONHandler(output, handlerOptions)
case "text":
handler = slog.NewTextHandler(output, handlerOptions)
default:
return fmt.Errorf("unsupported log format %q", normalized.Format)
}
baseAttrs := make([]any, 0, 8)
baseAttrs = appendNonEmpty(baseAttrs, "env", normalized.Env)
baseAttrs = appendNonEmpty(baseAttrs, "service", normalized.Service)
baseAttrs = appendNonEmpty(baseAttrs, "version", normalized.Version)
baseAttrs = appendNonEmpty(baseAttrs, "node_id", normalized.NodeID)
logger := slog.New(handler).With(baseAttrs...)
globalMu.Lock()
globalLogger = logger
globalConfig = normalized
globalMu.Unlock()
slog.SetDefault(logger)
log.SetFlags(0)
log.SetOutput(stdLogWriter{})
return nil
}
// NormalizeConfig applies safe defaults and validates static logging knobs.
func NormalizeConfig(cfg Config) (Config, error) {
cfg.Service = strings.TrimSpace(cfg.Service)
cfg.Env = strings.ToLower(strings.TrimSpace(cfg.Env))
if cfg.Env == "" {
cfg.Env = defaultEnv
}
cfg.Version = strings.TrimSpace(cfg.Version)
cfg.NodeID = strings.TrimSpace(cfg.NodeID)
cfg.Level = strings.ToLower(strings.TrimSpace(cfg.Level))
if cfg.Level == "" {
cfg.Level = defaultLevel
}
cfg.Format = strings.ToLower(strings.TrimSpace(cfg.Format))
if cfg.Format == "" {
cfg.Format = defaultFormat
}
if cfg.MaxPayloadBytes <= 0 {
cfg.MaxPayloadBytes = defaultMaxPayloadBytes
}
if _, err := parseLevel(cfg.Level); err != nil {
return Config{}, err
}
if cfg.Format != "json" && cfg.Format != "text" {
return Config{}, fmt.Errorf("unsupported log format %q", cfg.Format)
}
return cfg, nil
}
// Logger returns a logger enriched with attributes attached to ctx through With.
func Logger(ctx context.Context) *slog.Logger {
globalMu.RLock()
logger := globalLogger
globalMu.RUnlock()
attrs := attrsFromContext(ctx)
if len(attrs) == 0 {
return logger
}
args := make([]any, 0, len(attrs))
for _, attr := range attrs {
args = append(args, attr)
}
return logger.With(args...)
}
// With attaches structured fields to ctx for subsequent Logger/Info/Warn/Error calls.
func With(ctx context.Context, attrs ...slog.Attr) context.Context {
if ctx == nil {
ctx = context.Background()
}
if len(attrs) == 0 {
return ctx
}
existing := attrsFromContext(ctx)
merged := make([]slog.Attr, 0, len(existing)+len(attrs))
merged = append(merged, existing...)
merged = append(merged, attrs...)
return context.WithValue(ctx, contextAttrsKey{}, merged)
}
// Info records a normal runtime event.
func Info(ctx context.Context, msg string, attrs ...slog.Attr) {
Logger(ctx).LogAttrs(ctx, slog.LevelInfo, msg, attrs...)
}
// Warn records a recoverable runtime failure or degraded path.
func Warn(ctx context.Context, msg string, attrs ...slog.Attr) {
Logger(ctx).LogAttrs(ctx, slog.LevelWarn, msg, attrs...)
}
// Error records a request, transaction, worker, or external dependency failure.
func Error(ctx context.Context, msg string, err error, attrs ...slog.Attr) {
if err != nil {
attrs = append(attrs, slog.String("error", err.Error()))
}
Logger(ctx).LogAttrs(ctx, slog.LevelError, msg, attrs...)
}
// HTTPMiddleware records gateway HTTP access logs. Health checks are intentionally excluded by callers.
func HTTPMiddleware(service string, requestIDFromContext func(context.Context) string, next http.Handler) http.Handler {
return http.HandlerFunc(func(writer http.ResponseWriter, request *http.Request) {
startedAt := time.Now()
cfg := configSnapshot()
requestBody := readAndRestoreBody(request, cfg)
capture := newHTTPResponseCapture(writer, cfg.IncludeResponseBody, cfg.MaxPayloadBytes)
next.ServeHTTP(capture, request)
requestID := strings.TrimSpace(requestIDFromContext(request.Context()))
ctx := With(request.Context(), slog.String("request_id", requestID), slog.String("app_code", appcode.FromContext(request.Context())))
attrs := []slog.Attr{
slog.String("method", request.Method),
slog.String("path", request.URL.Path),
slog.String("query", request.URL.RawQuery),
slog.Int("status", capture.statusCode),
slog.Int64("duration_ms", time.Since(startedAt).Milliseconds()),
slog.String("client_ip", clientIP(request)),
}
attrs = appendServiceAttr(attrs, service)
if cfg.IncludeRequestBody {
attrs = append(attrs, slog.Any("request", safePayload(requestBody, cfg.MaxPayloadBytes, len(requestBody) > cfg.MaxPayloadBytes)))
}
if cfg.IncludeResponseBody {
attrs = append(attrs, slog.Any("response", safePayload(capture.body.Bytes(), cfg.MaxPayloadBytes, capture.truncated)))
}
switch levelForHTTPStatus(capture.statusCode) {
case slog.LevelError:
Error(ctx, "http_access", nil, attrs...)
case slog.LevelWarn:
Warn(ctx, "http_access", attrs...)
default:
Info(ctx, "http_access", attrs...)
}
})
}
// UnaryServerInterceptor records internal gRPC access logs without coupling business services to a logger.
func UnaryServerInterceptor(service string) grpc.UnaryServerInterceptor {
return func(ctx context.Context, request any, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (any, error) {
if strings.Contains(info.FullMethod, "/grpc.health.v1.Health/") {
return handler(ctx, request)
}
startedAt := time.Now()
cfg := configSnapshot()
response, err := handler(ctx, request)
code := codes.OK
if err != nil {
code = status.Code(err)
}
meta := requestMetaFromPayload(request)
ctx = With(ctx, slog.String("request_id", meta.RequestID), slog.String("app_code", appcode.Normalize(meta.AppCode)))
attrs := []slog.Attr{
slog.String("grpc_method", info.FullMethod),
slog.String("grpc_code", code.String()),
slog.String("reason", string(xerr.ReasonFromGRPC(err))),
slog.Int64("duration_ms", time.Since(startedAt).Milliseconds()),
}
if err != nil {
// gRPC access 日志是跨服务排障入口reason 只给稳定错误码message 保留服务端校验分支,便于定位 400/409 的真实拒绝原因。
attrs = append(attrs, slog.String("error_message", grpcErrorMessage(err)))
}
attrs = appendServiceAttr(attrs, service)
attrs = append(attrs, commonAttrsFromPayload(request)...)
if cfg.IncludeRequestBody {
attrs = append(attrs, slog.Any("request", safePayloadFromValue(request, cfg.MaxPayloadBytes)))
}
if cfg.IncludeResponseBody {
attrs = append(attrs, slog.Any("response", safePayloadFromValue(response, cfg.MaxPayloadBytes)))
}
switch levelForGRPCCode(code) {
case slog.LevelError:
Error(ctx, "grpc_access", err, attrs...)
case slog.LevelWarn:
Warn(ctx, "grpc_access", attrs...)
default:
Info(ctx, "grpc_access", attrs...)
}
return response, err
}
}
func grpcErrorMessage(err error) string {
if err == nil {
return ""
}
if st, ok := status.FromError(err); ok {
return st.Message()
}
return err.Error()
}
type stdLogWriter struct{}
func (stdLogWriter) Write(data []byte) (int, error) {
line := strings.TrimSpace(string(data))
if line != "" {
Info(context.Background(), "stdlog", slog.String("message", redactLogLine(line)))
}
return len(data), nil
}
type requestMeta struct {
RequestID string
AppCode string
}
type httpResponseCapture struct {
http.ResponseWriter
statusCode int
capture bool
maxBytes int
truncated bool
body bytes.Buffer
}
func newHTTPResponseCapture(writer http.ResponseWriter, capture bool, maxBytes int) *httpResponseCapture {
return &httpResponseCapture{ResponseWriter: writer, statusCode: http.StatusOK, capture: capture, maxBytes: maxBytes}
}
func (c *httpResponseCapture) WriteHeader(statusCode int) {
c.statusCode = statusCode
c.ResponseWriter.WriteHeader(statusCode)
}
func (c *httpResponseCapture) Write(data []byte) (int, error) {
if c.capture && c.body.Len() < c.maxBytes {
remaining := c.maxBytes - c.body.Len()
if len(data) > remaining {
c.body.Write(data[:remaining])
c.truncated = true
} else {
c.body.Write(data)
}
} else if c.capture && len(data) > 0 {
c.truncated = true
}
return c.ResponseWriter.Write(data)
}
func readAndRestoreBody(request *http.Request, cfg Config) []byte {
if !cfg.IncludeRequestBody || request.Body == nil {
return nil
}
mediaType, _, _ := mime.ParseMediaType(request.Header.Get("Content-Type"))
if strings.HasPrefix(mediaType, "multipart/") {
return []byte("<multipart body omitted>")
}
body, err := io.ReadAll(request.Body)
if err != nil {
request.Body = io.NopCloser(bytes.NewReader(nil))
return nil
}
_ = request.Body.Close()
request.Body = io.NopCloser(bytes.NewReader(body))
return body
}
func safePayloadFromValue(value any, maxBytes int) any {
if value == nil {
return nil
}
raw, err := marshalPayload(value)
if err != nil {
return "<payload_marshal_failed>"
}
return safePayload(raw, maxBytes, len(raw) > maxBytes)
}
func requestMetaFromPayload(value any) requestMeta {
raw, err := marshalPayload(value)
if err != nil || len(raw) == 0 {
return requestMeta{}
}
var payload map[string]any
if err := json.Unmarshal(raw, &payload); err != nil {
return requestMeta{}
}
result := requestMeta{RequestID: stringFromMap(payload, "request_id"), AppCode: stringFromMap(payload, "app_code")}
meta, ok := payload["meta"].(map[string]any)
if !ok {
return result
}
if result.RequestID == "" {
result.RequestID = stringFromMap(meta, "request_id")
}
if result.AppCode == "" {
result.AppCode = stringFromMap(meta, "app_code")
}
return result
}
func marshalPayload(value any) ([]byte, error) {
if value == nil {
return nil, nil
}
if message, ok := value.(proto.Message); ok {
return protojson.MarshalOptions{UseProtoNames: true}.Marshal(message)
}
return json.Marshal(value)
}
func safePayload(raw []byte, maxBytes int, truncated bool) any {
raw = bytes.TrimSpace(raw)
if len(raw) == 0 {
return nil
}
if maxBytes <= 0 {
maxBytes = defaultMaxPayloadBytes
}
if truncated || len(raw) > maxBytes {
return map[string]any{"truncated": true, "bytes": len(raw)}
}
var payload any
if err := json.Unmarshal(raw, &payload); err != nil {
return redactLogLine(string(raw))
}
return redactValue(payload)
}
func redactValue(value any) any {
switch typed := value.(type) {
case map[string]any:
redacted := make(map[string]any, len(typed))
for key, field := range typed {
if isSensitiveKey(key) {
redacted[key] = redactedValue
continue
}
redacted[key] = redactValue(field)
}
return redacted
case []any:
redacted := make([]any, len(typed))
for index, item := range typed {
redacted[index] = redactValue(item)
}
return redacted
default:
return value
}
}
func replaceAttr(_ []string, attr slog.Attr) slog.Attr {
if isSensitiveKey(attr.Key) {
return slog.String(attr.Key, redactedValue)
}
return attr
}
func isSensitiveKey(key string) bool {
normalized := strings.ToLower(strings.ReplaceAll(key, "-", "_"))
sensitiveParts := []string{
"password",
"credential",
"secret",
"token",
"access_token",
"refresh_token",
"id_token",
"user_sig",
"usersig",
"authorization",
"signature",
"private_key",
"callback_auth",
"receipt",
}
for _, part := range sensitiveParts {
if strings.Contains(normalized, part) {
return true
}
}
return false
}
func redactLogLine(line string) string {
fields := strings.Fields(line)
if len(fields) == 0 {
return line
}
changed := false
for index, field := range fields {
separator := strings.IndexAny(field, "=:")
if separator <= 0 {
continue
}
key := strings.Trim(field[:separator], "\"'")
if isSensitiveKey(key) {
fields[index] = field[:separator+1] + redactedValue
changed = true
}
}
if !changed {
return line
}
return strings.Join(fields, " ")
}
func attrsFromContext(ctx context.Context) []slog.Attr {
if ctx == nil {
return nil
}
attrs, _ := ctx.Value(contextAttrsKey{}).([]slog.Attr)
return attrs
}
func configSnapshot() Config {
globalMu.RLock()
cfg := globalConfig
globalMu.RUnlock()
if cfg.MaxPayloadBytes <= 0 {
cfg.MaxPayloadBytes = defaultMaxPayloadBytes
}
return cfg
}
func parseLevel(value string) (slog.Level, error) {
switch strings.ToLower(strings.TrimSpace(value)) {
case "debug":
return slog.LevelDebug, nil
case "", "info":
return slog.LevelInfo, nil
case "warn", "warning":
return slog.LevelWarn, nil
case "error":
return slog.LevelError, nil
default:
return slog.LevelInfo, fmt.Errorf("%w %q", ErrUnsupportedLevel, value)
}
}
func levelForHTTPStatus(statusCode int) slog.Level {
switch {
case statusCode >= http.StatusInternalServerError:
return slog.LevelError
case statusCode >= http.StatusBadRequest:
return slog.LevelWarn
default:
return slog.LevelInfo
}
}
func levelForGRPCCode(code codes.Code) slog.Level {
switch code {
case codes.OK:
return slog.LevelInfo
case codes.Internal, codes.Unavailable, codes.DeadlineExceeded, codes.DataLoss, codes.Unknown:
return slog.LevelError
default:
return slog.LevelWarn
}
}
func appendServiceAttr(attrs []slog.Attr, service string) []slog.Attr {
if strings.TrimSpace(service) == "" {
return attrs
}
cfg := configSnapshot()
if cfg.Service != "" {
return attrs
}
return append(attrs, slog.String("service", service))
}
func appendNonEmpty(attrs []any, key string, value string) []any {
if strings.TrimSpace(value) == "" {
return attrs
}
return append(attrs, key, value)
}
func stringFromMap(values map[string]any, key string) string {
value, ok := values[key]
if !ok {
return ""
}
switch typed := value.(type) {
case string:
return typed
case fmt.Stringer:
return typed.String()
default:
return fmt.Sprint(typed)
}
}
func clientIP(request *http.Request) string {
if request == nil {
return ""
}
for _, header := range []string{"X-Forwarded-For", "X-Real-IP"} {
value := strings.TrimSpace(request.Header.Get(header))
if value == "" {
continue
}
if before, _, ok := strings.Cut(value, ","); ok {
return strings.TrimSpace(before)
}
return value
}
return request.RemoteAddr
}
func commonAttrsFromPayload(value any) []slog.Attr {
raw, err := marshalPayload(value)
if err != nil || len(raw) == 0 {
return nil
}
var payload map[string]any
if err := json.Unmarshal(raw, &payload); err != nil {
return nil
}
keys := []string{
"command_id",
"user_id",
"room_id",
"room_version",
"transaction_id",
"biz_type",
"asset_type",
"sender_user_id",
"target_user_id",
"seller_user_id",
"gift_id",
"gift_count",
"event_id",
"event_type",
}
attrs := make([]slog.Attr, 0, len(keys))
for _, key := range keys {
value, ok := payload[key]
if !ok || value == nil {
continue
}
attrs = append(attrs, slog.Any(key, value))
}
return attrs
}
// ErrUnsupportedLevel is kept as a stable sentinel for configuration tests.
var ErrUnsupportedLevel = errors.New("unsupported log level")