hyapp-server/pkg/logx/logx.go

// 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()),
		}
		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
	}
}

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")