From 88d74aca7d776bd4a21c802e0d48e6ee976245cf Mon Sep 17 00:00:00 2001 From: yml2213 Date: Wed, 29 Jul 2026 16:19:35 +0800 Subject: [PATCH] =?UTF-8?q?=E9=87=8D=E6=9E=84=E6=97=A5=E5=BF=97=E4=B8=8E?= =?UTF-8?q?=E5=8F=AF=E8=A7=82=E6=B5=8B=E6=80=A7=E4=BD=93=E7=B3=BB?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 新增单行文本编码器与结构化 GORM 日志，统一错误记录与请求日志策略，收紧日志文件权限并修复按天切分与压缩，支付回调参数脱敏，生产强制阿里云短信，RequestID 校验防注入，日志文案中文化。 --- README.md | 4 +- backend/.env.example | 3 +- backend/.env.prod.example | 3 +- backend/cmd/api/main.go | 24 ++-- backend/internal/config/config.go | 9 +- backend/internal/database/gorm_logger.go | 106 ++++++++++++++ backend/internal/database/gorm_logger_test.go | 48 +++++++ backend/internal/database/mysql.go | 25 +--- backend/internal/integrations/sms/aliyun.go | 19 +-- backend/internal/integrations/sms/mock.go | 2 +- backend/internal/jobs/ordertimeout/job.go | 12 +- backend/internal/jobs/refundretry/job.go | 30 ++-- backend/internal/logging/context.go | 22 ++- backend/internal/logging/daily_writer.go | 131 ++++++++++++++---- backend/internal/logging/daily_writer_test.go | 31 ++++- backend/internal/logging/logger.go | 29 ++-- backend/internal/logging/text_encoder.go | 128 +++++++++++++++++ backend/internal/logging/text_encoder_test.go | 36 +++++ backend/internal/middleware/recovery.go | 15 +- backend/internal/middleware/request_id.go | 22 ++- .../internal/middleware/request_id_test.go | 24 ++++ backend/internal/middleware/request_logger.go | 73 +++++----- .../request_logger_integration_test.go | 52 +++++++ .../middleware/request_logger_test.go | 16 +-- .../internal/modules/adminaudit/handler.go | 1 + backend/internal/modules/adminauth/handler.go | 1 + .../modules/admindashboard/handler.go | 1 + .../internal/modules/adminfinance/handler.go | 1 + backend/internal/modules/adminmgr/handler.go | 1 + .../modules/adminnotification/handler.go | 1 + backend/internal/modules/adminpush/handler.go | 1 + backend/internal/modules/adminrole/handler.go | 1 + backend/internal/modules/adminuser/handler.go | 1 + .../internal/modules/announcement/handler.go | 8 ++ backend/internal/modules/auth/handler.go | 1 + backend/internal/modules/auth/service.go | 11 +- .../internal/modules/chat/handler_error.go | 1 + .../internal/modules/chat/handler_qrcode.go | 32 +++-- .../internal/modules/dispute/arbitration.go | 11 +- backend/internal/modules/dispute/handler.go | 1 + backend/internal/modules/file/handler.go | 2 +- .../internal/modules/listing/handler_error.go | 1 + .../modules/listing/handler_external.go | 3 +- backend/internal/modules/mohong/handler.go | 9 ++ .../internal/modules/notification/handler.go | 1 + .../internal/modules/order/handler_error.go | 1 + backend/internal/modules/order/refund.go | 12 +- backend/internal/modules/payment/handler.go | 16 +-- .../modules/payment/mohong_payment.go | 12 +- backend/internal/modules/payment/notify.go | 58 +++++--- .../internal/modules/payment/payment_start.go | 11 +- backend/internal/modules/payment/refund.go | 28 ++-- .../internal/modules/payment/repository.go | 2 +- .../modules/paymentaccount/handler.go | 1 + .../internal/modules/paymentconfig/handler.go | 10 ++ backend/internal/modules/pickup/handler.go | 1 + backend/internal/modules/realname/handler.go | 1 + backend/internal/modules/realname/service.go | 11 +- .../internal/modules/supportgroup/handler.go | 1 + .../internal/modules/systemconfig/handler.go | 1 + backend/internal/modules/wallet/handler.go | 1 + .../internal/modules/withdrawal/handler.go | 1 + backend/internal/router/router.go | 20 +-- backend/pkg/response/response.go | 31 +++++ 64 files changed, 896 insertions(+), 277 deletions(-) create mode 100644 backend/internal/database/gorm_logger.go create mode 100644 backend/internal/database/gorm_logger_test.go create mode 100644 backend/internal/logging/text_encoder.go create mode 100644 backend/internal/logging/text_encoder_test.go create mode 100644 backend/internal/middleware/request_id_test.go create mode 100644 backend/internal/middleware/request_logger_integration_test.go diff --git a/README.md b/README.md index d61f644..5aa3fc8 100644 --- a/README.md +++ b/README.md @@ -52,8 +52,8 @@ npm run dev ## 开发态短信与实名 -- 后端日志默认同时输出到控制台和 `backend/logs/app-YYYY-MM-DD.log`，按北京时间自动按天切分；可通过 `LOG_LEVEL=debug|info|warn|error` 调整级别。 -- 短信验证码默认使用 mock 适配器，验证码会打印在后端日志中；生产环境可通过 `SMS_PROVIDER=aliyun` 接入阿里云短信。 +- 后端日志使用单行可读文本。开发环境默认只输出控制台，生产示例只输出 `backend/logs/app-YYYY-MM-DD.log`，避免重复存储；可通过 `LOG_LEVEL=debug|info|warn|error` 调整级别。 +- 短信验证码默认使用 mock 适配器；需要查看调试验证码时将 `LOG_LEVEL` 临时设为 `debug`。生产环境强制使用 `SMS_PROVIDER=aliyun`。 - 阿里云短信需要配置 `ALIYUN_ACCESS_KEY_ID`、`ALIYUN_ACCESS_KEY_SECRET`、`ALIYUN_SMS_SIGN_NAME` 和 `ALIYUN_SMS_LOGIN_TEMPLATE_CODE`，模板变量名默认为 `code`。 - 实名认证使用 mock 适配器，登录后请求 `POST /api/realname/start`，提交合法姓名和 18 位身份证号会直接通过。 - 实名状态可通过 `GET /api/realname/status` 查询。 diff --git a/backend/.env.example b/backend/.env.example index e1d2a33..37d6f10 100644 --- a/backend/.env.example +++ b/backend/.env.example @@ -30,7 +30,8 @@ RATE_LIMIT_REQUESTS_PER_MINUTE=300 LOG_LEVEL=info LOG_DIR=logs LOG_ENABLE_CONSOLE=true -LOG_ENABLE_FILE=true +LOG_ENABLE_FILE=false +LOG_RETAIN_DAYS=14 # MinIO 容器初始化变量，同时供后端对象存储使用。 MINIO_ROOT_USER=minioadmin diff --git a/backend/.env.prod.example b/backend/.env.prod.example index 90fcb7d..aa16483 100644 --- a/backend/.env.prod.example +++ b/backend/.env.prod.example @@ -40,8 +40,9 @@ RATE_LIMIT_REQUESTS_PER_MINUTE=300 LOG_LEVEL=info LOG_DIR=/app/logs -LOG_ENABLE_CONSOLE=true +LOG_ENABLE_CONSOLE=false LOG_ENABLE_FILE=true +LOG_RETAIN_DAYS=14 # MinIO 容器初始化变量，同时供后端对象存储使用；使用内置 MinIO 时，STORAGE_* 密钥必须和 MINIO_ROOT_* 保持一致。 MINIO_ROOT_USER=change-minio-user diff --git a/backend/cmd/api/main.go b/backend/cmd/api/main.go index c34580b..2def695 100644 --- a/backend/cmd/api/main.go +++ b/backend/cmd/api/main.go @@ -53,14 +53,14 @@ func main() { _ = logger.Sync() }() if err := cfg.ValidateProductionSecurity(); err != nil { - logger.Fatal("production security config invalid", zap.Error(err)) + logger.Fatal("生产安全配置校验失败", zap.Error(err)) } logAuthRuntimeIdentity(logger, cfg) var deps router.Dependencies - db, err := database.OpenMySQL(cfg.MySQLDSN, cfg.Log.Level) + db, err := database.OpenMySQL(cfg.MySQLDSN, cfg.Log.Level, logger) if err != nil { - logger.Warn("mysql unavailable; database-backed APIs will return 503", zap.Error(err)) + logger.Warn("MySQL 不可用，数据库接口将返回 503", zap.Error(err)) } else { deps.DB = db if err := adminauth.BootstrapAdmin(context.Background(), db, adminauth.BootstrapConfig{ @@ -69,7 +69,7 @@ func main() { Password: cfg.BootstrapAdminPassword, Nickname: cfg.BootstrapAdminNickname, }); err != nil { - logger.Fatal("admin bootstrap failed", zap.Error(err)) + logger.Fatal("初始管理员创建失败", zap.Error(err)) } } redisClient, err := database.OpenRedis(context.Background(), database.RedisConfig{ @@ -78,7 +78,7 @@ func main() { DB: cfg.RedisDB, }) if err != nil { - logger.Warn("redis unavailable; redis-backed APIs will return 503", zap.Error(err)) + logger.Warn("Redis 不可用，相关接口将返回 503", zap.Error(err)) } else { deps.Redis = redisClient defer func() { @@ -103,9 +103,9 @@ func main() { } go func() { - logger.Info("api server starting", zap.String("addr", cfg.AppAddr)) + logger.Info("API 服务启动", zap.String("addr", cfg.AppAddr)) if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed { - logger.Fatal("api server failed", zap.Error(err)) + logger.Fatal("API 服务异常退出", zap.Error(err)) } }() @@ -117,9 +117,9 @@ func main() { ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() if err := server.Shutdown(ctx); err != nil { - logger.Fatal("api server shutdown failed", zap.Error(err)) + logger.Fatal("API 服务关闭失败", zap.Error(err)) } - logger.Info("api server stopped") + logger.Info("API 服务已停止") } // logAuthRuntimeIdentity 记录可用于排查多实例或部署配置漂移的非敏感身份信息。 @@ -129,7 +129,7 @@ func logAuthRuntimeIdentity(logger *zap.Logger, cfg config.Config) { instanceID = "unknown" } sum := sha256.Sum256([]byte(cfg.JWTSecret)) - logger.Info("auth runtime identity", + logger.Debug("认证运行实例", zap.String("instance_id", instanceID), zap.String("app_env", cfg.AppEnv), zap.String("jwt_secret_fingerprint", hex.EncodeToString(sum[:])[:12]), @@ -146,10 +146,10 @@ func newPaymentConfigRepositoryForJobs(cfg config.Config, db *gorm.DB, logger *z } if encryptor == nil { if config.IsProductionEnv(cfg.AppEnv) { - logger.Fatal("PAYMENT_CONFIG_ENCRYPTION_KEY not set or invalid") + logger.Fatal("支付配置加密密钥未设置或无效") } encryptor = &paymentconfig.MockEncryptor{} - logger.Warn("PAYMENT_CONFIG_ENCRYPTION_KEY not set or invalid, using MockEncryptor for jobs") + logger.Debug("定时任务使用模拟支付配置加密器") } return paymentconfig.NewRepository(db, encryptor) } diff --git a/backend/internal/config/config.go b/backend/internal/config/config.go index b3bc8fc..9061540 100644 --- a/backend/internal/config/config.go +++ b/backend/internal/config/config.go @@ -109,7 +109,7 @@ func Load() Config { Level: getEnv("LOG_LEVEL", "info"), Dir: getEnv("LOG_DIR", "logs"), EnableConsole: getEnvBool("LOG_ENABLE_CONSOLE", true), - EnableFile: getEnvBool("LOG_ENABLE_FILE", true), + EnableFile: getEnvBool("LOG_ENABLE_FILE", false), RetainDays: getEnvInt("LOG_RETAIN_DAYS", 14), }, RateLimit: RateLimitConfig{ @@ -123,6 +123,13 @@ func (c Config) ValidateProductionSecurity() error { if !IsProductionEnv(c.AppEnv) { return nil } + if !strings.EqualFold(strings.TrimSpace(c.SMS.Provider), "aliyun") { + return errors.New("SMS_PROVIDER must be aliyun in production") + } + if strings.TrimSpace(c.SMS.AliyunAccessKeyID) == "" || strings.TrimSpace(c.SMS.AliyunAccessKeySecret) == "" || + strings.TrimSpace(c.SMS.AliyunSignName) == "" || strings.TrimSpace(c.SMS.AliyunLoginTemplateCode) == "" { + return errors.New("aliyun SMS credentials, sign name, and template code are required in production") + } if strings.TrimSpace(c.JWTSecret) == "" || isPlaceholder(c.JWTSecret) || len([]byte(c.JWTSecret)) < 32 { return errors.New("JWT_SECRET must be a non-default random value of at least 32 bytes in production") } diff --git a/backend/internal/database/gorm_logger.go b/backend/internal/database/gorm_logger.go new file mode 100644 index 0000000..e5ca36f --- /dev/null +++ b/backend/internal/database/gorm_logger.go @@ -0,0 +1,106 @@ +package database + +import ( + "context" + "errors" + "fmt" + "strings" + "time" + + appLogging "hfb_sys/backend/internal/logging" + + "go.uber.org/zap" + "gorm.io/gorm" + gormLogger "gorm.io/gorm/logger" +) + +type structuredGormLogger struct { + logger *zap.Logger + level gormLogger.LogLevel + slowThreshold time.Duration +} + +func newGormLogger(logLevel string, logger *zap.Logger) gormLogger.Interface { + level := gormLogger.Warn + if strings.EqualFold(strings.TrimSpace(logLevel), "debug") { + level = gormLogger.Info + } + if logger == nil { + logger = zap.L() + } + return &structuredGormLogger{ + logger: logger.With(zap.String("module", "database")), + level: level, + slowThreshold: 500 * time.Millisecond, + } +} + +func (l *structuredGormLogger) LogMode(level gormLogger.LogLevel) gormLogger.Interface { + cloned := *l + cloned.level = level + return &cloned +} + +func (l *structuredGormLogger) Info(ctx context.Context, message string, args ...any) { + if l.level >= gormLogger.Info { + l.withContext(ctx).Debug("数据库信息", zap.String("detail", fmt.Sprintf(message, args...))) + } +} + +func (l *structuredGormLogger) Warn(ctx context.Context, message string, args ...any) { + if l.level >= gormLogger.Warn { + l.withContext(ctx).Warn("数据库警告", zap.String("detail", fmt.Sprintf(message, args...))) + } +} + +func (l *structuredGormLogger) Error(ctx context.Context, message string, args ...any) { + if l.level >= gormLogger.Error { + l.withContext(ctx).Error("数据库错误", zap.String("detail", fmt.Sprintf(message, args...))) + } +} + +func (l *structuredGormLogger) Trace(ctx context.Context, begin time.Time, query func() (string, int64), err error) { + if l.level == gormLogger.Silent { + return + } + elapsed := time.Since(begin) + switch { + case err != nil && !errors.Is(err, gorm.ErrRecordNotFound) && l.level >= gormLogger.Error: + sql, rows := query() + l.withContext(ctx).Error("数据库查询失败", queryFields(sql, rows, elapsed, err)...) + case elapsed >= l.slowThreshold && l.level >= gormLogger.Warn: + sql, rows := query() + l.withContext(ctx).Warn("数据库慢查询", queryFields(sql, rows, elapsed, nil)...) + case l.level == gormLogger.Info: + sql, rows := query() + l.withContext(ctx).Debug("数据库查询", queryFields(sql, rows, elapsed, nil)...) + } +} + +// ParamsFilter 让 GORM 保留 SQL 占位符，避免查询参数进入日志。 +func (l *structuredGormLogger) ParamsFilter(_ context.Context, sql string, _ ...any) (string, []any) { + return sql, nil +} + +func (l *structuredGormLogger) withContext(ctx context.Context) *zap.Logger { + fields := make([]zap.Field, 0, 2) + if requestID := appLogging.RequestIDFromContext(ctx); requestID != "" { + fields = append(fields, zap.String("request_id", requestID)) + } + if adminID := appLogging.AdminIDFromContext(ctx); adminID != 0 { + fields = append(fields, zap.Uint64("admin_id", adminID)) + } + return l.logger.With(fields...) +} + +func queryFields(sql string, rows int64, elapsed time.Duration, err error) []zap.Field { + fields := []zap.Field{ + zap.Float64("duration_ms", float64(elapsed.Microseconds())/1000), + zap.Int64("rows", rows), + zap.String("sql", sql), + } + if err != nil { + fields = append(fields, zap.Error(err)) + } + return fields +} diff --git a/backend/internal/database/gorm_logger_test.go b/backend/internal/database/gorm_logger_test.go new file mode 100644 index 0000000..343ce67 --- /dev/null +++ b/backend/internal/database/gorm_logger_test.go @@ -0,0 +1,48 @@ +package database + +import ( + "strings" + "testing" + + "go.uber.org/zap" + "go.uber.org/zap/zaptest/observer" + "gorm.io/driver/sqlite" + "gorm.io/gorm" +) + +func TestGormLoggerDoesNotLogQueryParameters(t *testing.T) { + core, observed := observer.New(zap.DebugLevel) + logger := zap.New(core) + db, err := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{ + Logger: newGormLogger("debug", logger), + }) + if err != nil { + t.Fatal(err) + } + type secretRecord struct { + ID uint64 + Phone string + } + if err := db.AutoMigrate(&secretRecord{}); err != nil { + t.Fatal(err) + } + const secretPhone = "13812345678" + if err := db.Create(&secretRecord{Phone: secretPhone}).Error; err != nil { + t.Fatal(err) + } + + for _, entry := range observed.All() { + for _, value := range entry.ContextMap() { + if strings.Contains(valueString(value), secretPhone) { + t.Fatalf("query parameter leaked into log: %v", entry.ContextMap()) + } + } + } +} + +func valueString(value any) string { + if text, ok := value.(string); ok { + return text + } + return "" +} diff --git a/backend/internal/database/mysql.go b/backend/internal/database/mysql.go index 966e461..3b62fad 100644 --- a/backend/internal/database/mysql.go +++ b/backend/internal/database/mysql.go @@ -1,19 +1,16 @@ package database import ( - "log" - "os" - "strings" "time" + "go.uber.org/zap" "gorm.io/driver/mysql" "gorm.io/gorm" - "gorm.io/gorm/logger" ) -func OpenMySQL(dsn string, logLevel string) (*gorm.DB, error) { +func OpenMySQL(dsn string, logLevel string, appLogger *zap.Logger) (*gorm.DB, error) { db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{ - Logger: newGormLogger(logLevel), + Logger: newGormLogger(logLevel, appLogger), }) if err != nil { return nil, err @@ -31,19 +28,3 @@ func OpenMySQL(dsn string, logLevel string) (*gorm.DB, error) { return db, nil } - -func newGormLogger(logLevel string) logger.Interface { - level := logger.Warn - if strings.EqualFold(strings.TrimSpace(logLevel), "debug") { - level = logger.Info - } - return logger.New( - log.New(os.Stdout, "\r\n", log.LstdFlags), - logger.Config{ - SlowThreshold: 500 * time.Millisecond, - LogLevel: level, - IgnoreRecordNotFoundError: true, - Colorful: false, - }, - ) -} diff --git a/backend/internal/integrations/sms/aliyun.go b/backend/internal/integrations/sms/aliyun.go index 8afe13d..f9d8503 100644 --- a/backend/internal/integrations/sms/aliyun.go +++ b/backend/internal/integrations/sms/aliyun.go @@ -70,9 +70,6 @@ func (p *AliyunProvider) SendLoginCode(ctx context.Context, phone string, code s resp, err := p.client.SendSmsWithContext(ctx, req, &dara.RuntimeOptions{}) if err != nil { - if p.log != nil { - p.log.Warn("aliyun sms send failed", zap.String("phone", maskPhone(phone)), zap.Error(err)) - } return fmt.Errorf("aliyun sms send failed: %w", err) } if resp == nil || resp.Body == nil { @@ -82,15 +79,6 @@ func (p *AliyunProvider) SendLoginCode(ctx context.Context, phone string, code s resultCode := dara.StringValue(resp.Body.Code) if resultCode != "OK" { resultMessage := dara.StringValue(resp.Body.Message) - if p.log != nil { - p.log.Warn( - "aliyun sms rejected", - zap.String("phone", maskPhone(phone)), - zap.String("request_id", dara.StringValue(resp.Body.RequestId)), - zap.String("code", resultCode), - zap.String("message", resultMessage), - ) - } providerErr := &ProviderError{Code: resultCode, Message: resultMessage} if resultCode == "isv.BUSINESS_LIMIT_CONTROL" { providerErr.Err = ErrProviderRateLimited @@ -99,11 +87,10 @@ func (p *AliyunProvider) SendLoginCode(ctx context.Context, phone string, code s } if p.log != nil { - p.log.Info( - "aliyun sms sent", + p.log.Debug( + "短信发送成功", zap.String("phone", maskPhone(phone)), - zap.String("request_id", dara.StringValue(resp.Body.RequestId)), - zap.String("biz_id", dara.StringValue(resp.Body.BizId)), + zap.String("provider_request_id", dara.StringValue(resp.Body.RequestId)), ) } return nil diff --git a/backend/internal/integrations/sms/mock.go b/backend/internal/integrations/sms/mock.go index 7af2e52..b95378d 100644 --- a/backend/internal/integrations/sms/mock.go +++ b/backend/internal/integrations/sms/mock.go @@ -19,7 +19,7 @@ func (p *MockProvider) SendLoginCode(ctx context.Context, phone string, code str return err } if p.log != nil { - p.log.Info("mock sms code generated", zap.String("phone", phone), zap.String("code", code)) + p.log.Debug("调试短信验证码", zap.String("phone", maskPhone(phone)), zap.String("code", code)) } return nil } diff --git a/backend/internal/jobs/ordertimeout/job.go b/backend/internal/jobs/ordertimeout/job.go index 5a698ea..93de1f3 100644 --- a/backend/internal/jobs/ordertimeout/job.go +++ b/backend/internal/jobs/ordertimeout/job.go @@ -83,7 +83,7 @@ func (j *Job) acquireLock(ctx context.Context) (func(), bool) { } ok, err := j.redis.SetNX(ctx, orderTimeoutLockKey, j.instanceID, j.lockTTL()).Result() if err != nil { - j.logger.Warn("order timeout job acquire lock failed, run without lock", zap.Error(err)) + j.logger.Warn("订单超时任务获取锁失败，将以单实例模式执行", zap.Error(err)) return func() {}, true } if !ok { @@ -101,7 +101,7 @@ func (j *Job) releaseLock() { defer cancel() script := redis.NewScript(`if redis.call("get", KEYS[1]) == ARGV[1] then return redis.call("del", KEYS[1]) else return 0 end`) if err := script.Run(relCtx, j.redis, []string{orderTimeoutLockKey}, j.instanceID).Err(); err != nil { - j.logger.Warn("order timeout job release lock failed", zap.Error(err)) + j.logger.Warn("订单超时任务释放锁失败", zap.Error(err)) } } @@ -131,7 +131,7 @@ func (j *Job) loop(ctx context.Context) { for { select { case <-ctx.Done(): - j.logger.Info("order timeout job stopped") + j.logger.Debug("订单超时任务已停止") return case <-ticker.C: j.run(ctx) @@ -148,7 +148,7 @@ func (j *Job) run(ctx context.Context) { cfg, err := j.loadThresholds(ctx) if err != nil { - j.logger.Warn("order timeout job config load failed", zap.Error(err)) + j.logger.Warn("订单超时任务加载配置失败", zap.Error(err)) return } now := time.Now() @@ -164,13 +164,13 @@ func (j *Job) run(ctx context.Context) { for _, handler := range handlers { count, err := handler(ctx, now, cfg) if err != nil { - j.logger.Warn("order timeout handler failed", zap.Error(err)) + j.logger.Warn("订单超时处理失败", zap.Error(err)) continue } total += count } if total > 0 { - j.logger.Info("order timeout job processed orders", zap.Int("count", total)) + j.logger.Info("订单超时处理完成", zap.Int("count", total)) } } diff --git a/backend/internal/jobs/refundretry/job.go b/backend/internal/jobs/refundretry/job.go index 7dfd2dd..1f8fe48 100644 --- a/backend/internal/jobs/refundretry/job.go +++ b/backend/internal/jobs/refundretry/job.go @@ -51,7 +51,7 @@ func (j *Job) acquireLock(ctx context.Context) (func(), bool) { } ok, err := j.redis.SetNX(ctx, refundRetryLockKey, j.instanceID, j.lockTTL()).Result() if err != nil { - j.logger.Warn("refund retry job acquire lock failed, run without lock", zap.Error(err)) + j.logger.Warn("退款重试任务获取锁失败，将以单实例模式执行", zap.Error(err)) return func() {}, true } if !ok { @@ -69,7 +69,7 @@ func (j *Job) releaseLock() { defer cancel() script := redis.NewScript(`if redis.call("get", KEYS[1]) == ARGV[1] then return redis.call("del", KEYS[1]) else return 0 end`) if err := script.Run(relCtx, j.redis, []string{refundRetryLockKey}, j.instanceID).Err(); err != nil { - j.logger.Warn("refund retry job release lock failed", zap.Error(err)) + j.logger.Warn("退款重试任务释放锁失败", zap.Error(err)) } } @@ -99,7 +99,7 @@ func (j *Job) loop(ctx context.Context) { for { select { case <-ctx.Done(): - j.logger.Info("refund retry job stopped") + j.logger.Debug("退款重试任务已停止") return case <-ticker.C: j.run(ctx) @@ -117,14 +117,14 @@ func (j *Job) run(ctx context.Context) { now := time.Now() processed, err := j.syncRefundPayments(ctx, now) if err != nil { - j.logger.Warn("refund retry job sync payments failed", zap.Error(err)) + j.logger.Warn("退款重试任务同步失败", zap.Error(err)) } missing, rebuilt, err := j.warnMissingRefundOrders(ctx, now) if err != nil { - j.logger.Warn("refund retry job scan missing refund orders failed", zap.Error(err)) + j.logger.Warn("退款重试任务扫描缺失退款单失败", zap.Error(err)) } if processed > 0 || missing > 0 { - j.logger.Info("refund retry job finished", + j.logger.Info("退款重试任务处理完成", zap.Int("processed", processed), zap.Int("missing_refund_orders", missing), zap.Int("rebuilt_arbitration_refunds", rebuilt), @@ -147,13 +147,13 @@ func (j *Job) syncRefundPayments(ctx context.Context, now time.Time) (int, error for _, row := range rows { if _, err := j.payments.SyncRefundStatusByPaymentID(ctx, row.ID); err != nil { if markErr := j.markRetryFailed(ctx, row, now); markErr != nil { - j.logger.Warn("refund retry mark failure failed", + j.logger.Warn("退款重试失败状态保存失败", zap.Uint64("payment_id", row.ID), zap.Uint64("order_id", row.OrderID), zap.Error(markErr), ) } - j.logger.Warn("refund retry sync failed", + j.logger.Warn("退款状态同步失败", zap.Uint64("payment_id", row.ID), zap.Uint64("order_id", row.OrderID), zap.String("biz_type", row.BizType), @@ -164,7 +164,7 @@ func (j *Job) syncRefundPayments(ctx context.Context, now time.Time) (int, error continue } if err := j.resetRetry(ctx, row.ID); err != nil { - j.logger.Warn("refund retry reset counter failed", + j.logger.Warn("退款重试计数重置失败", zap.Uint64("payment_id", row.ID), zap.Uint64("order_id", row.OrderID), zap.Error(err), @@ -222,7 +222,7 @@ func (j *Job) warnMaxRetryRefunds(ctx context.Context, now time.Time) { Limit(50). Find(&rows).Error if err != nil { - j.logger.Warn("refund retry max count scan failed", zap.Error(err)) + j.logger.Warn("退款最大重试次数扫描失败", zap.Error(err)) return } if len(rows) == 0 { @@ -235,7 +235,7 @@ func (j *Job) warnMaxRetryRefunds(ctx context.Context, now time.Time) { ids = append(ids, row.ID) orderIDs = append(orderIDs, row.OrderID) } - j.logger.Warn("refund retry reached max count, need manual check", + j.logger.Warn("退款已达最大重试次数，需要人工处理", zap.Int("count", len(rows)), zap.Uint64s("payment_ids", ids), zap.Uint64s("order_ids", orderIDs), @@ -243,7 +243,7 @@ func (j *Job) warnMaxRetryRefunds(ctx context.Context, now time.Time) { if err := j.db.WithContext(ctx).Model(&model.PaymentOrder{}). Where("id IN ?", ids). Update("last_retry_at", now).Error; err != nil { - j.logger.Warn("refund retry bump last_retry_at failed", zap.Error(err)) + j.logger.Warn("退款重试时间更新失败", zap.Error(err)) } } @@ -284,7 +284,7 @@ func (j *Job) warnMissingRefundOrders(ctx context.Context, now time.Time) (int, rebuildFailOrderIDs = append(rebuildFailOrderIDs, row.ID) } else { rebuilt++ - j.logger.Info("auto rebuild arbitration refund submitted", + j.logger.Info("仲裁退款单已自动补建", zap.Uint64("order_id", row.ID), zap.Int64("refund_amount_cent", row.RefundAmountCent), ) @@ -295,13 +295,13 @@ func (j *Job) warnMissingRefundOrders(ctx context.Context, now time.Time) (int, } // 汇总告警 + Redis 24h 去重，避免每轮扫描刷屏 if len(missingOrderIDs) > 0 && j.shouldWarn(ctx, "missing_payment", 0) { - j.logger.Warn("refund order missing payment record, need manual check", + j.logger.Warn("退款订单缺少支付记录，需要人工处理", zap.Int("count", len(missingOrderIDs)), zap.Uint64s("order_ids", missingOrderIDs), ) } if len(rebuildFailOrderIDs) > 0 && j.shouldWarn(ctx, "rebuild_fail", 0) { - j.logger.Warn("auto rebuild arbitration refund failed, need manual check", + j.logger.Warn("仲裁退款单自动补建失败，需要人工处理", zap.Int("count", len(rebuildFailOrderIDs)), zap.Uint64s("order_ids", rebuildFailOrderIDs), ) diff --git a/backend/internal/logging/context.go b/backend/internal/logging/context.go index 7580f16..acac4be 100644 --- a/backend/internal/logging/context.go +++ b/backend/internal/logging/context.go @@ -1,6 +1,10 @@ package logging -import "context" +import ( + "context" + + "go.uber.org/zap" +) type requestIDContextKey struct{} type adminIDContextKey struct{} @@ -41,3 +45,19 @@ func AdminIDFromContext(ctx context.Context) uint64 { adminID, _ := ctx.Value(adminIDContextKey{}).(uint64) return adminID } + +// FromContext 返回自动携带请求和管理员上下文的日志器。 +func FromContext(ctx context.Context) *zap.Logger { + logger := zap.L() + fields := make([]zap.Field, 0, 2) + if requestID := RequestIDFromContext(ctx); requestID != "" { + fields = append(fields, zap.String("request_id", requestID)) + } + if adminID := AdminIDFromContext(ctx); adminID != 0 { + fields = append(fields, zap.Uint64("admin_id", adminID)) + } + if len(fields) == 0 { + return logger + } + return logger.With(fields...) +} diff --git a/backend/internal/logging/daily_writer.go b/backend/internal/logging/daily_writer.go index e5dc6b7..ed7712c 100644 --- a/backend/internal/logging/daily_writer.go +++ b/backend/internal/logging/daily_writer.go @@ -2,6 +2,7 @@ package logging import ( "compress/gzip" + "errors" "fmt" "io" "os" @@ -21,6 +22,12 @@ type dailyWriter struct { file *os.File } +func (w *dailyWriter) Open() error { + w.mu.Lock() + defer w.mu.Unlock() + return w.rotateIfNeeded(time.Now().In(w.location)) +} + func newDailyWriter(dir string, prefix string, location *time.Location, retainDays int) *dailyWriter { if retainDays < 0 { retainDays = 0 @@ -59,51 +66,79 @@ func (w *dailyWriter) rotateIfNeeded(now time.Time) error { return nil } - if err := os.MkdirAll(w.dir, 0o755); err != nil { + if err := os.MkdirAll(w.dir, 0o700); err != nil { + return err + } + if err := os.Chmod(w.dir, 0o700); err != nil { return err } - prevDay := w.day if w.file != nil { - _ = w.file.Close() + if err := w.file.Close(); err != nil { + return err + } w.file = nil } path := filepath.Join(w.dir, fmt.Sprintf("%s-%s.log", w.prefix, day)) - file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o644) + file, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o600) if err != nil { return err } + if err := file.Chmod(0o600); err != nil { + _ = file.Close() + return err + } w.file = file w.day = day - // 异步压缩昨日日志并清理过期文件，避免阻塞业务写路径 - if prevDay != "" && prevDay != day { - go w.maintain(prevDay, now) - } else { - // 进程启动或首写：尝试压缩昨天 + 清理过期 - yesterday := now.AddDate(0, 0, -1).Format("2006-01-02") - go w.maintain(yesterday, now) - } + // 异步补压缩全部历史日志并清理过期文件，避免漏掉停机期间的日期。 + go w.maintain(now) return nil } -func (w *dailyWriter) maintain(prevDay string, now time.Time) { - if prevDay != "" { - _ = w.compressDay(prevDay) +func (w *dailyWriter) maintain(now time.Time) { + if err := w.compressHistorical(now); err != nil { + writeMaintenanceError(err) } if w.retainDays > 0 { - _ = w.purgeOlderThan(now) + if err := w.purgeOlderThan(now); err != nil { + writeMaintenanceError(err) + } } } +func (w *dailyWriter) compressHistorical(now time.Time) error { + entries, err := os.ReadDir(w.dir) + if err != nil { + return err + } + today := now.In(w.location).Format("2006-01-02") + for _, entry := range entries { + day, ok := w.dayFromFilename(entry.Name(), ".log") + if !ok || day >= today { + continue + } + if err := w.compressDay(day); err != nil { + return fmt.Errorf("压缩 %s 日志失败: %w", day, err) + } + } + return nil +} + func (w *dailyWriter) compressDay(day string) error { srcPath := filepath.Join(w.dir, fmt.Sprintf("%s-%s.log", w.prefix, day)) dstPath := srcPath + ".gz" if _, err := os.Stat(dstPath); err == nil { - // 已压缩则删除明文（若仍存在） - _ = os.Remove(srcPath) - return nil + if err := validateGzip(dstPath); err == nil { + if err := os.Remove(srcPath); err != nil && !os.IsNotExist(err) { + return err + } + return nil + } + if err := os.Remove(dstPath); err != nil { + return err + } } src, err := os.Open(srcPath) if err != nil { @@ -114,32 +149,58 @@ func (w *dailyWriter) compressDay(day string) error { } defer src.Close() - dst, err := os.OpenFile(dstPath, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o644) + dst, err := os.CreateTemp(w.dir, "."+filepath.Base(dstPath)+".tmp-*") if err != nil { return err } + tmpPath := dst.Name() + defer func() { _ = os.Remove(tmpPath) }() + if err := dst.Chmod(0o600); err != nil { + _ = dst.Close() + return err + } gz := gzip.NewWriter(dst) if _, err := io.Copy(gz, src); err != nil { _ = gz.Close() _ = dst.Close() - _ = os.Remove(dstPath) return err } if err := gz.Close(); err != nil { _ = dst.Close() - _ = os.Remove(dstPath) + return err + } + if err := dst.Sync(); err != nil { + _ = dst.Close() return err } if err := dst.Close(); err != nil { return err } + if err := os.Rename(tmpPath, dstPath); err != nil { + return err + } return os.Remove(srcPath) } +func validateGzip(path string) error { + file, err := os.Open(path) + if err != nil { + return err + } + defer file.Close() + reader, err := gzip.NewReader(file) + if err != nil { + return err + } + _, copyErr := io.Copy(io.Discard, reader) + closeErr := reader.Close() + return errors.Join(copyErr, closeErr) +} + func (w *dailyWriter) purgeOlderThan(now time.Time) error { // 按「日历天」比较：保留最近 retainDays 天（含当天），更早的 .log / .log.gz 删除。 today := time.Date(now.In(w.location).Year(), now.In(w.location).Month(), now.In(w.location).Day(), 0, 0, 0, 0, w.location) - cutoff := today.AddDate(0, 0, -w.retainDays) // day < cutoff 才删除；retainDays=2 且今天 12 号 → 删除 10 号之前 + cutoff := today.AddDate(0, 0, -(w.retainDays - 1)) entries, err := os.ReadDir(w.dir) if err != nil { return err @@ -150,10 +211,10 @@ func (w *dailyWriter) purgeOlderThan(now time.Time) error { continue } name := entry.Name() - if !strings.HasPrefix(name, prefix) { + if !strings.HasPrefix(name, prefix) || + (!strings.HasSuffix(name, ".log") && !strings.HasSuffix(name, ".log.gz")) { continue } - // app-2026-07-11.log 或 app-2026-07-11.log.gz rest := strings.TrimPrefix(name, prefix) rest = strings.TrimSuffix(rest, ".gz") rest = strings.TrimSuffix(rest, ".log") @@ -162,8 +223,26 @@ func (w *dailyWriter) purgeOlderThan(now time.Time) error { continue } if day.Before(cutoff) { - _ = os.Remove(filepath.Join(w.dir, name)) + if err := os.Remove(filepath.Join(w.dir, name)); err != nil && !os.IsNotExist(err) { + return err + } } } return nil } + +func (w *dailyWriter) dayFromFilename(name string, suffix string) (string, bool) { + prefix := w.prefix + "-" + if !strings.HasPrefix(name, prefix) || !strings.HasSuffix(name, suffix) { + return "", false + } + day := strings.TrimSuffix(strings.TrimPrefix(name, prefix), suffix) + if _, err := time.ParseInLocation("2006-01-02", day, w.location); err != nil { + return "", false + } + return day, true +} + +func writeMaintenanceError(err error) { + _, _ = fmt.Fprintf(os.Stderr, "%s | ERROR | 日志维护失败 | error=%q\n", time.Now().Format("2006-01-02 15:04:05.000"), err.Error()) +} diff --git a/backend/internal/logging/daily_writer_test.go b/backend/internal/logging/daily_writer_test.go index 423a0c9..b759af6 100644 --- a/backend/internal/logging/daily_writer_test.go +++ b/backend/internal/logging/daily_writer_test.go @@ -32,7 +32,7 @@ func TestCompressDayAndPurge(t *testing.T) { t.Fatalf("gzip missing: %v", err) } - // 以 7-12 为「现在」，保留 2 天 → cutoff=7-10，删除 7-10 之前（仅 7-01） + // 以 7-12 为「现在」，保留 2 天（7-11、7-12），删除 7-11 之前。 now := time.Date(2026, 7, 12, 12, 0, 0, 0, loc) if err := w.purgeOlderThan(now); err != nil { t.Fatalf("purgeOlderThan: %v", err) @@ -40,15 +40,38 @@ func TestCompressDayAndPurge(t *testing.T) { if _, err := os.Stat(filepath.Join(dir, "app-2026-07-01.log")); !os.IsNotExist(err) { t.Fatal("expired log should be purged") } - // 7-10 / 7-11 仍应存在（cutoff 当天起保留） - if _, err := os.Stat(filepath.Join(dir, "app-2026-07-10.log.gz")); err != nil { - t.Fatalf("recent gzip should remain: %v", err) + if _, err := os.Stat(filepath.Join(dir, "app-2026-07-10.log.gz")); !os.IsNotExist(err) { + t.Fatalf("expired gzip should be purged, err=%v", err) } + // 7-11 仍应存在（cutoff 当天起保留） if _, err := os.Stat(filepath.Join(dir, "app-2026-07-11.log")); err != nil { t.Fatalf("recent plain should remain: %v", err) } } +func TestCompressDayReplacesCorruptedGzip(t *testing.T) { + dir := t.TempDir() + w := newDailyWriter(dir, "app", time.UTC, 0) + sourcePath := filepath.Join(dir, "app-2026-07-11.log") + gzipPath := sourcePath + ".gz" + if err := os.WriteFile(sourcePath, []byte("important log\n"), 0o600); err != nil { + t.Fatal(err) + } + if err := os.WriteFile(gzipPath, []byte("broken"), 0o600); err != nil { + t.Fatal(err) + } + + if err := w.compressDay("2026-07-11"); err != nil { + t.Fatal(err) + } + if err := validateGzip(gzipPath); err != nil { + t.Fatalf("gzip should be valid: %v", err) + } + if _, err := os.Stat(sourcePath); !os.IsNotExist(err) { + t.Fatalf("source should be removed after successful compression, err=%v", err) + } +} + func TestCompressDayIdempotent(t *testing.T) { dir := t.TempDir() loc := time.UTC diff --git a/backend/internal/logging/logger.go b/backend/internal/logging/logger.go index 28dea8e..4d335e6 100644 --- a/backend/internal/logging/logger.go +++ b/backend/internal/logging/logger.go @@ -1,6 +1,7 @@ package logging import ( + "fmt" "os" "strings" "time" @@ -18,47 +19,41 @@ func New(cfg config.LogConfig) (*zap.Logger, error) { } level := zap.NewAtomicLevelAt(parseLevel(cfg.Level)) - encoderConfig := zap.NewProductionEncoderConfig() - encoderConfig.TimeKey = "time" - encoderConfig.LevelKey = "level" - encoderConfig.MessageKey = "message" - encoderConfig.CallerKey = "caller" - encoderConfig.EncodeTime = func(t time.Time, enc zapcore.PrimitiveArrayEncoder) { - enc.AppendString(t.In(location).Format("2006-01-02 15:04:05.000 -0700")) - } - encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder - encoderConfig.EncodeDuration = zapcore.StringDurationEncoder - encoderConfig.EncodeCaller = zapcore.ShortCallerEncoder - cores := make([]zapcore.Core, 0, 2) if cfg.EnableConsole { cores = append(cores, zapcore.NewCore( - zapcore.NewConsoleEncoder(encoderConfig), + newTextEncoder(location), zapcore.Lock(os.Stdout), level, )) } if cfg.EnableFile { writer := newDailyWriter(cfg.Dir, "app", location, cfg.RetainDays) + if err := writer.Open(); err != nil { + return nil, fmt.Errorf("初始化日志文件失败: %w", err) + } cores = append(cores, zapcore.NewCore( - zapcore.NewJSONEncoder(encoderConfig), + newTextEncoder(location), writer, level, )) } if len(cores) == 0 { cores = append(cores, zapcore.NewCore( - zapcore.NewConsoleEncoder(encoderConfig), + newTextEncoder(location), zapcore.Lock(os.Stdout), level, )) } - return zap.New( + logger := zap.New( zapcore.NewTee(cores...), zap.AddCaller(), zap.AddStacktrace(zapcore.PanicLevel), - ), nil + zap.ErrorOutput(zapcore.Lock(os.Stderr)), + ) + zap.ReplaceGlobals(logger) + return logger, nil } func parseLevel(value string) zapcore.Level { diff --git a/backend/internal/logging/text_encoder.go b/backend/internal/logging/text_encoder.go new file mode 100644 index 0000000..2e105c1 --- /dev/null +++ b/backend/internal/logging/text_encoder.go @@ -0,0 +1,128 @@ +package logging + +import ( + "fmt" + "sort" + "strconv" + "strings" + "time" + + "go.uber.org/zap/buffer" + "go.uber.org/zap/zapcore" +) + +var textBufferPool = buffer.NewPool() + +// textEncoder 把结构化字段输出为便于直接阅读和 grep 的单行文本。 +type textEncoder struct { + *zapcore.MapObjectEncoder + location *time.Location +} + +func newTextEncoder(location *time.Location) zapcore.Encoder { + return &textEncoder{ + MapObjectEncoder: zapcore.NewMapObjectEncoder(), + location: location, + } +} + +func (e *textEncoder) Clone() zapcore.Encoder { + cloned := &textEncoder{ + MapObjectEncoder: zapcore.NewMapObjectEncoder(), + location: e.location, + } + for key, value := range e.Fields { + cloned.Fields[key] = value + } + return cloned +} + +func (e *textEncoder) EncodeEntry(entry zapcore.Entry, fields []zapcore.Field) (*buffer.Buffer, error) { + ctx := e.Clone().(*textEncoder) + for i := range fields { + fields[i].AddTo(ctx) + } + + buf := textBufferPool.Get() + buf.AppendString(entry.Time.In(e.location).Format("2006-01-02 15:04:05.000")) + buf.AppendString(" | ") + buf.AppendString(fmt.Sprintf("%-5s", strings.ToUpper(entry.Level.String()))) + buf.AppendString(" | ") + buf.AppendString(cleanText(entry.Message)) + + if entry.Level >= zapcore.WarnLevel && entry.Caller.Defined { + buf.AppendString(" | caller=") + buf.AppendString(entry.Caller.TrimmedPath()) + } + + keys := orderedKeys(ctx.Fields) + for _, key := range keys { + value := ctx.Fields[key] + if isEmptyValue(value) { + continue + } + buf.AppendString(" | ") + buf.AppendString(key) + buf.AppendByte('=') + buf.AppendString(formatValue(value)) + } + if entry.Stack != "" { + buf.AppendString(" | stack=") + buf.AppendString(strconv.Quote(entry.Stack)) + } + buf.AppendByte('\n') + return buf, nil +} + +func orderedKeys(fields map[string]any) []string { + priority := []string{ + "module", "request_id", "method", "route", "path", "status", "code", + "duration_ms", "rows", "user_id", "admin_id", "client_ip", "error", + } + keys := make([]string, 0, len(fields)) + seen := make(map[string]bool, len(fields)) + for _, key := range priority { + if _, ok := fields[key]; ok { + keys = append(keys, key) + seen[key] = true + } + } + rest := make([]string, 0, len(fields)-len(keys)) + for key := range fields { + if !seen[key] { + rest = append(rest, key) + } + } + sort.Strings(rest) + return append(keys, rest...) +} + +func formatValue(value any) string { + switch typed := value.(type) { + case string: + if typed != "" && !strings.ContainsAny(typed, " \t\r\n|=\"") { + return typed + } + return strconv.Quote(typed) + case []byte: + return strconv.Quote(string(typed)) + case time.Time: + return typed.Format(time.RFC3339) + case time.Duration: + return typed.String() + default: + return cleanText(fmt.Sprint(typed)) + } +} + +func cleanText(value string) string { + return strings.NewReplacer("\r", `\r`, "\n", `\n`, "\t", `\t`).Replace(value) +} + +func isEmptyValue(value any) bool { + if value == nil { + return true + } + text, ok := value.(string) + return ok && strings.TrimSpace(text) == "" +} diff --git a/backend/internal/logging/text_encoder_test.go b/backend/internal/logging/text_encoder_test.go new file mode 100644 index 0000000..458c2f7 --- /dev/null +++ b/backend/internal/logging/text_encoder_test.go @@ -0,0 +1,36 @@ +package logging + +import ( + "bytes" + "strings" + "testing" + "time" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func TestTextEncoderProducesReadableSingleLine(t *testing.T) { + var output bytes.Buffer + core := zapcore.NewCore(newTextEncoder(time.UTC), zapcore.AddSync(&output), zapcore.DebugLevel) + logger := zap.New(core) + logger.Info("服务启动", + zap.String("request_id", "req-1"), + zap.String("empty", ""), + zap.String("detail", "line1\nline2"), + ) + + got := output.String() + if strings.ContainsAny(got, "{}") { + t.Fatalf("output should not use JSON object syntax: %s", got) + } + if !strings.Contains(got, "INFO | 服务启动 | request_id=req-1") { + t.Fatalf("unexpected text output: %s", got) + } + if strings.Contains(got, "empty=") { + t.Fatalf("empty fields should be omitted: %s", got) + } + if strings.Count(got, "\n") != 1 || !strings.Contains(got, `detail="line1\nline2"`) { + t.Fatalf("output should remain one physical line: %q", got) + } +} diff --git a/backend/internal/middleware/recovery.go b/backend/internal/middleware/recovery.go index e960742..f4c9b06 100644 --- a/backend/internal/middleware/recovery.go +++ b/backend/internal/middleware/recovery.go @@ -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", "服务暂时不可用") } diff --git a/backend/internal/middleware/request_id.go b/backend/internal/middleware/request_id.go index 3c6554a..6dea524 100644 --- a/backend/internal/middleware/request_id.go +++ b/backend/internal/middleware/request_id.go @@ -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 +} diff --git a/backend/internal/middleware/request_id_test.go b/backend/internal/middleware/request_id_test.go new file mode 100644 index 0000000..ed3b8e2 --- /dev/null +++ b/backend/internal/middleware/request_id_test.go @@ -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) + } + }) + } +} diff --git a/backend/internal/middleware/request_logger.go b/backend/internal/middleware/request_logger.go index 64b4678..56e9cf4 100644 --- a/backend/internal/middleware/request_logger.go +++ b/backend/internal/middleware/request_logger.go @@ -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" } diff --git a/backend/internal/middleware/request_logger_integration_test.go b/backend/internal/middleware/request_logger_integration_test.go new file mode 100644 index 0000000..51b8c1a --- /dev/null +++ b/backend/internal/middleware/request_logger_integration_test.go @@ -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()) + } +} diff --git a/backend/internal/middleware/request_logger_test.go b/backend/internal/middleware/request_logger_test.go index 71e8ba9..359b5ea 100644 --- a/backend/internal/middleware/request_logger_test.go +++ b/backend/internal/middleware/request_logger_test.go @@ -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) { diff --git a/backend/internal/modules/adminaudit/handler.go b/backend/internal/modules/adminaudit/handler.go index 933cf84..13a81c4 100644 --- a/backend/internal/modules/adminaudit/handler.go +++ b/backend/internal/modules/adminaudit/handler.go @@ -65,6 +65,7 @@ func parseQuery(c *gin.Context) (Query, bool) { } func writeAuditError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminauth/handler.go b/backend/internal/modules/adminauth/handler.go index 87597ee..90cc382 100644 --- a/backend/internal/modules/adminauth/handler.go +++ b/backend/internal/modules/adminauth/handler.go @@ -170,6 +170,7 @@ func isHTTPSRequest(c *gin.Context) bool { } func writeAdminAuthError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/admindashboard/handler.go b/backend/internal/modules/admindashboard/handler.go index f46d9b3..a739c96 100644 --- a/backend/internal/modules/admindashboard/handler.go +++ b/backend/internal/modules/admindashboard/handler.go @@ -27,6 +27,7 @@ func (h *Handler) Summary(c *gin.Context) { } func writeDashboardError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminfinance/handler.go b/backend/internal/modules/adminfinance/handler.go index 817a7a7..99ab947 100644 --- a/backend/internal/modules/adminfinance/handler.go +++ b/backend/internal/modules/adminfinance/handler.go @@ -228,6 +228,7 @@ func parseDateRange(c *gin.Context, defaultLookbackDays int) (time.Time, time.Ti } func writeFinanceError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminmgr/handler.go b/backend/internal/modules/adminmgr/handler.go index 8499952..4e32e8c 100644 --- a/backend/internal/modules/adminmgr/handler.go +++ b/backend/internal/modules/adminmgr/handler.go @@ -163,6 +163,7 @@ func parseID(c *gin.Context) (uint64, bool) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminnotification/handler.go b/backend/internal/modules/adminnotification/handler.go index a846e92..5b1ab50 100644 --- a/backend/internal/modules/adminnotification/handler.go +++ b/backend/internal/modules/adminnotification/handler.go @@ -110,6 +110,7 @@ func currentAdminID(c *gin.Context) (uint64, bool) { } func writeNotificationError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminpush/handler.go b/backend/internal/modules/adminpush/handler.go index fc8ce04..81ae6be 100644 --- a/backend/internal/modules/adminpush/handler.go +++ b/backend/internal/modules/adminpush/handler.go @@ -154,6 +154,7 @@ func currentAdminID(c *gin.Context) (uint64, bool) { } func writePushError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminrole/handler.go b/backend/internal/modules/adminrole/handler.go index f13edd1..efda6c2 100644 --- a/backend/internal/modules/adminrole/handler.go +++ b/backend/internal/modules/adminrole/handler.go @@ -120,6 +120,7 @@ func parseID(c *gin.Context) (uint64, bool) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/adminuser/handler.go b/backend/internal/modules/adminuser/handler.go index a0bc329..3ab00b7 100644 --- a/backend/internal/modules/adminuser/handler.go +++ b/backend/internal/modules/adminuser/handler.go @@ -236,6 +236,7 @@ func auditMeta(c *gin.Context) AuditMeta { } func writeAdminUserError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/announcement/handler.go b/backend/internal/modules/announcement/handler.go index 97b3f95..f349c44 100644 --- a/backend/internal/modules/announcement/handler.go +++ b/backend/internal/modules/announcement/handler.go @@ -29,6 +29,7 @@ func (h *Handler) List(c *gin.Context) { result, err := h.service.List(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取公告列表失败") return } @@ -67,6 +68,7 @@ func (h *Handler) AdminList(c *gin.Context) { result, err := h.service.AdminList(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取公告列表失败") return } @@ -111,6 +113,7 @@ func (h *Handler) Create(c *gin.Context) { announcement, err := h.service.Create(c.Request.Context(), req, adminID) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "创建公告失败") return } @@ -134,6 +137,7 @@ func (h *Handler) Update(c *gin.Context) { announcement, err := h.service.Update(c.Request.Context(), id, req) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "更新公告失败") return } @@ -150,6 +154,7 @@ func (h *Handler) Publish(c *gin.Context) { } if err := h.service.Publish(c.Request.Context(), id); err != nil { + response.RecordError(c, err) response.InternalServerError(c, "发布公告失败") return } @@ -166,6 +171,7 @@ func (h *Handler) Archive(c *gin.Context) { } if err := h.service.Archive(c.Request.Context(), id); err != nil { + response.RecordError(c, err) response.InternalServerError(c, "归档公告失败") return } @@ -182,6 +188,7 @@ func (h *Handler) Unarchive(c *gin.Context) { } if err := h.service.Unarchive(c.Request.Context(), id); err != nil { + response.RecordError(c, err) response.InternalServerError(c, "取消归档公告失败") return } @@ -198,6 +205,7 @@ func (h *Handler) Delete(c *gin.Context) { } if err := h.service.Delete(c.Request.Context(), id); err != nil { + response.RecordError(c, err) response.InternalServerError(c, "删除公告失败") return } diff --git a/backend/internal/modules/auth/handler.go b/backend/internal/modules/auth/handler.go index 2de27f1..2c2b908 100644 --- a/backend/internal/modules/auth/handler.go +++ b/backend/internal/modules/auth/handler.go @@ -212,6 +212,7 @@ func (h *Handler) ResetPassword(c *gin.Context) { } func writeAuthError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库或 Redis 未连接") diff --git a/backend/internal/modules/auth/service.go b/backend/internal/modules/auth/service.go index 7945c01..0d362c0 100644 --- a/backend/internal/modules/auth/service.go +++ b/backend/internal/modules/auth/service.go @@ -11,6 +11,7 @@ import ( "hfb_sys/backend/internal/captcha" smsprovider "hfb_sys/backend/internal/integrations/sms" + "hfb_sys/backend/internal/logging" "hfb_sys/backend/internal/model" "github.com/redis/go-redis/v9" @@ -120,7 +121,15 @@ func (s *Service) SendSMSCode(ctx context.Context, phone string, captchaID strin } if err := s.sms.SendLoginCode(ctx, phone, code); err != nil { if s.log != nil { - s.log.Warn("sms login code send failed", zap.String("phone", PublicPhone(phone)), zap.Error(err)) + fields := []zap.Field{ + zap.String("module", "auth"), + zap.String("phone", PublicPhone(phone)), + zap.Error(err), + } + if requestID := logging.RequestIDFromContext(ctx); requestID != "" { + fields = append(fields, zap.String("request_id", requestID)) + } + s.log.Warn("短信验证码发送失败", fields...) } if smsprovider.IsProviderRateLimited(err) { pipe := s.redis.TxPipeline() diff --git a/backend/internal/modules/chat/handler_error.go b/backend/internal/modules/chat/handler_error.go index 31f87dd..164562c 100644 --- a/backend/internal/modules/chat/handler_error.go +++ b/backend/internal/modules/chat/handler_error.go @@ -10,6 +10,7 @@ import ( ) func writeChatError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "聊天服务暂时不可用") diff --git a/backend/internal/modules/chat/handler_qrcode.go b/backend/internal/modules/chat/handler_qrcode.go index 91efb5d..262ed86 100644 --- a/backend/internal/modules/chat/handler_qrcode.go +++ b/backend/internal/modules/chat/handler_qrcode.go @@ -5,6 +5,8 @@ import ( "net/http" "strconv" + "hfb_sys/backend/pkg/response" + "github.com/gin-gonic/gin" ) @@ -19,7 +21,8 @@ func (h *Handler) CreateQrCodeHandler(c *gin.Context) { adminID := c.GetUint64("admin_id") qrcode, err := h.service.repo.CreateQrCode(c.Request.Context(), adminID, req) if err != nil { - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -37,7 +40,8 @@ func (h *Handler) BatchCreateQrCodeHandler(c *gin.Context) { adminID := c.GetUint64("admin_id") qrcodes, err := h.service.repo.BatchCreateQrCode(c.Request.Context(), adminID, req) if err != nil { - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -54,7 +58,8 @@ func (h *Handler) BatchDeleteQrCodeHandler(c *gin.Context) { deleted, err := h.service.repo.BatchDeleteQrCodes(c.Request.Context(), req.IDs) if err != nil { - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -71,7 +76,8 @@ func (h *Handler) ListQrCodesHandler(c *gin.Context) { qrcodes, total, err := h.service.repo.ListQrCodes(c.Request.Context(), req) if err != nil { - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -89,7 +95,8 @@ func (h *Handler) ListQrCodesHandler(c *gin.Context) { func (h *Handler) GetQrCodeStatsHandler(c *gin.Context) { stats, err := h.service.repo.GetQrCodeStats(c.Request.Context()) if err != nil { - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -124,7 +131,8 @@ func (h *Handler) RecognizeQrCodeGroupNameHandler(c *gin.Context) { c.JSON(http.StatusBadGateway, gin.H{"error": "PaddleOCR 服务暂时不可用"}) return } - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -167,7 +175,8 @@ func (h *Handler) SubmitOCRJobHandler(c *gin.Context) { c.JSON(http.StatusNotFound, gin.H{"error": "OCR 任务不存在或已过期"}) return } - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -188,7 +197,8 @@ func (h *Handler) GetOCRJobResultHandler(c *gin.Context) { c.JSON(http.StatusNotFound, gin.H{"error": "OCR 任务不存在或已过期"}) return } - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -218,7 +228,8 @@ func (h *Handler) UpdateQrCodeHandler(c *gin.Context) { c.JSON(http.StatusBadRequest, gin.H{"error": "已发放的二维码不能改回待用"}) return } - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } @@ -238,7 +249,8 @@ func (h *Handler) DeleteQrCodeHandler(c *gin.Context) { c.JSON(http.StatusNotFound, gin.H{"error": "二维码不存在"}) return } - c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()}) + response.RecordError(c, err) + response.InternalServerError(c, "聊天二维码服务暂时不可用") return } diff --git a/backend/internal/modules/dispute/arbitration.go b/backend/internal/modules/dispute/arbitration.go index 27d0c59..9248702 100644 --- a/backend/internal/modules/dispute/arbitration.go +++ b/backend/internal/modules/dispute/arbitration.go @@ -4,11 +4,11 @@ import ( "context" "errors" "fmt" - "log" "math" "time" "hfb_sys/backend/internal/listingstatus" + "hfb_sys/backend/internal/logging" "hfb_sys/backend/internal/model" "hfb_sys/backend/internal/modules/adminnotification" "hfb_sys/backend/internal/modules/notification" @@ -17,6 +17,7 @@ import ( "hfb_sys/backend/internal/modules/wallet" "hfb_sys/backend/pkg/money" + "go.uber.org/zap" "gorm.io/gorm" "gorm.io/gorm/clause" ) @@ -453,7 +454,13 @@ func (r *Repository) startRefundBestEffort(ctx context.Context, action *refundAc return } if _, err := r.refundStarter.StartRefund(ctx, action.OrderID, action.RefundAmountCent, action.BizType, action.Remark); err != nil { - log.Printf("[dispute] start refund failed order_id=%d biz_type=%s amount_cent=%d err=%v", action.OrderID, action.BizType, action.RefundAmountCent, err) + logging.FromContext(ctx).Error("争议退款提交失败", + zap.String("module", "dispute"), + zap.Uint64("order_id", action.OrderID), + zap.String("biz_type", action.BizType), + zap.Int64("amount_cent", action.RefundAmountCent), + zap.Error(err), + ) } } diff --git a/backend/internal/modules/dispute/handler.go b/backend/internal/modules/dispute/handler.go index dce7764..af1d1ee 100644 --- a/backend/internal/modules/dispute/handler.go +++ b/backend/internal/modules/dispute/handler.go @@ -226,6 +226,7 @@ func parsePagination(c *gin.Context) (int, int) { } func writeDisputeError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/file/handler.go b/backend/internal/modules/file/handler.go index 075be5d..a90a154 100644 --- a/backend/internal/modules/file/handler.go +++ b/backend/internal/modules/file/handler.go @@ -94,7 +94,7 @@ func (h *Handler) writeObject(c *gin.Context, publicOnly bool) { } func writeFileError(c *gin.Context, err error) { - _ = c.Error(err) + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "文件存储未连接") diff --git a/backend/internal/modules/listing/handler_error.go b/backend/internal/modules/listing/handler_error.go index 8f767d5..8d9f7dd 100644 --- a/backend/internal/modules/listing/handler_error.go +++ b/backend/internal/modules/listing/handler_error.go @@ -13,6 +13,7 @@ import ( ) func writeListingError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/listing/handler_external.go b/backend/internal/modules/listing/handler_external.go index a91655d..9aed7a5 100644 --- a/backend/internal/modules/listing/handler_external.go +++ b/backend/internal/modules/listing/handler_external.go @@ -1,9 +1,9 @@ package listing import ( - _ "embed" "crypto/hmac" "crypto/sha256" + _ "embed" "encoding/hex" "encoding/json" "errors" @@ -116,6 +116,7 @@ func externalUploadIPAllowed(clientIP string, allowed []string) bool { } func writeExternalUploadAuthError(c *gin.Context, err error) { + response.RecordError(c, err) switch err { case errExternalUploadForbiddenIP: response.Error(c, http.StatusForbidden, "forbidden", "来源 IP 不允许访问") diff --git a/backend/internal/modules/mohong/handler.go b/backend/internal/modules/mohong/handler.go index 9721917..6d2949b 100644 --- a/backend/internal/modules/mohong/handler.go +++ b/backend/internal/modules/mohong/handler.go @@ -22,6 +22,7 @@ func NewHandler(service *Service) *Handler { func (h *Handler) ListCategories(c *gin.Context) { items, err := h.service.ListPublicCategories(c.Request.Context()) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取分类失败") return } @@ -36,6 +37,7 @@ func (h *Handler) ListProducts(c *gin.Context) { query.Page, query.PageSize = parsePagination(c) result, err := h.service.ListPublicProducts(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取商品列表失败") return } @@ -84,6 +86,7 @@ func (h *Handler) ListMyOrders(c *gin.Context) { query.Page, query.PageSize = parsePagination(c) result, err := h.service.ListOrdersForUser(c.Request.Context(), userID, query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取订单列表失败") return } @@ -133,6 +136,7 @@ func (h *Handler) CancelMyOrder(c *gin.Context) { func (h *Handler) AdminListCategories(c *gin.Context) { items, err := h.service.AdminListCategories(c.Request.Context()) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取分类失败") return } @@ -194,6 +198,7 @@ func (h *Handler) AdminListProducts(c *gin.Context) { query.Page, query.PageSize = parsePagination(c) result, err := h.service.AdminListProducts(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取商品列表失败") return } @@ -273,6 +278,7 @@ func (h *Handler) AdminListOrders(c *gin.Context) { query.Page, query.PageSize = parsePagination(c) result, err := h.service.AdminListOrders(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取订单列表失败") return } @@ -340,6 +346,7 @@ func (h *Handler) AdminCancelOrder(c *gin.Context) { func (h *Handler) AdminGetConfig(c *gin.Context) { item, err := h.service.GetConfig(c.Request.Context()) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "获取配置失败") return } @@ -354,6 +361,7 @@ func (h *Handler) AdminUpdateConfig(c *gin.Context) { } item, err := h.service.UpdateConfig(c.Request.Context(), req) if err != nil { + response.RecordError(c, err) response.InternalServerError(c, "更新配置失败") return } @@ -361,6 +369,7 @@ func (h *Handler) AdminUpdateConfig(c *gin.Context) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrProductNotFound), errors.Is(err, ErrOrderNotFound): response.NotFound(c, err.Error()) diff --git a/backend/internal/modules/notification/handler.go b/backend/internal/modules/notification/handler.go index bdc00bd..d3c9be9 100644 --- a/backend/internal/modules/notification/handler.go +++ b/backend/internal/modules/notification/handler.go @@ -104,6 +104,7 @@ func currentUserID(c *gin.Context) (uint64, bool) { } func writeNotificationError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/order/handler_error.go b/backend/internal/modules/order/handler_error.go index 0e9bc3a..9eb45c2 100644 --- a/backend/internal/modules/order/handler_error.go +++ b/backend/internal/modules/order/handler_error.go @@ -10,6 +10,7 @@ import ( ) func writeOrderError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/order/refund.go b/backend/internal/modules/order/refund.go index 8a03c71..7f7c104 100644 --- a/backend/internal/modules/order/refund.go +++ b/backend/internal/modules/order/refund.go @@ -2,9 +2,11 @@ package order import ( "context" - "log" + "hfb_sys/backend/internal/logging" "hfb_sys/backend/internal/model" + + "go.uber.org/zap" ) func (r *Repository) prepareRefund(order *model.RentalOrder, amountCent int64, bizType string, remark string) (*refundAction, error) { @@ -30,6 +32,12 @@ func (r *Repository) startRefundBestEffort(ctx context.Context, action *refundAc return } if _, err := r.refundStarter.StartRefund(ctx, action.OrderID, action.RefundAmountCent, action.BizType, action.Remark); err != nil { - log.Printf("[order] start refund failed order_id=%d biz_type=%s amount_cent=%d err=%v", action.OrderID, action.BizType, action.RefundAmountCent, err) + logging.FromContext(ctx).Error("订单退款提交失败", + zap.String("module", "order"), + zap.Uint64("order_id", action.OrderID), + zap.String("biz_type", action.BizType), + zap.Int64("amount_cent", action.RefundAmountCent), + zap.Error(err), + ) } } diff --git a/backend/internal/modules/payment/handler.go b/backend/internal/modules/payment/handler.go index 192beca..29035a0 100644 --- a/backend/internal/modules/payment/handler.go +++ b/backend/internal/modules/payment/handler.go @@ -186,14 +186,13 @@ func (h *Handler) LeshuaNotify(c *gin.Context) { } rawPayload := string(body) contentType := c.GetHeader("Content-Type") - h.log().Info("payment notify received", notifyLogFields(c.Request.Context(), "leshua", params, contentType, len(body))...) result, err := h.service.HandleLeshuaNotify(c.Request.Context(), params, rawPayload, contentType) if err != nil || result == nil || !result.OK { - h.log().Warn("payment notify failed", notifyLogFields(c.Request.Context(), "leshua", params, contentType, len(body), zap.Error(err))...) + h.log().Warn("支付回调处理失败", notifyLogFields(c.Request.Context(), "leshua", params, contentType, len(body), zap.Error(err))...) c.String(http.StatusOK, "FAIL") return } - h.log().Info("payment notify processed", notifyLogFields(c.Request.Context(), "leshua", params, contentType, len(body))...) + h.log().Info("支付回调处理完成", notifyLogFields(c.Request.Context(), "leshua", params, contentType, len(body))...) c.String(http.StatusOK, result.Message) } @@ -211,14 +210,13 @@ func (h *Handler) LakalaNotify(c *gin.Context) { rawPayload := string(body) contentType := c.GetHeader("Content-Type") authorization := c.GetHeader("Authorization") - h.log().Info("payment notify received", notifyLogFields(c.Request.Context(), "lakala", params, contentType, len(body))...) result, err := h.service.HandleNotify(c.Request.Context(), "lakala", params, rawPayload, contentType, authorization) if err != nil || result == nil || !result.OK { - h.log().Warn("payment notify failed", notifyLogFields(c.Request.Context(), "lakala", params, contentType, len(body), zap.Error(err))...) + h.log().Warn("支付回调处理失败", notifyLogFields(c.Request.Context(), "lakala", params, contentType, len(body), zap.Error(err))...) c.JSON(http.StatusOK, gin.H{"code": "FAIL", "message": "失败"}) return } - h.log().Info("payment notify processed", notifyLogFields(c.Request.Context(), "lakala", params, contentType, len(body))...) + h.log().Info("支付回调处理完成", notifyLogFields(c.Request.Context(), "lakala", params, contentType, len(body))...) c.JSON(http.StatusOK, gin.H{"code": "SUCCESS", "message": "执行成功"}) } @@ -236,14 +234,13 @@ func (h *Handler) ShunchengNotify(c *gin.Context) { rawPayload := string(body) contentType := c.GetHeader("Content-Type") authorization := c.GetHeader("Authorization") - h.log().Info("payment notify received", notifyLogFields(c.Request.Context(), "shuncheng", params, contentType, len(body))...) result, err := h.service.HandleNotify(c.Request.Context(), "shuncheng", params, rawPayload, contentType, authorization) if err != nil || result == nil || !result.OK { - h.log().Warn("payment notify failed", notifyLogFields(c.Request.Context(), "shuncheng", params, contentType, len(body), zap.Error(err))...) + h.log().Warn("支付回调处理失败", notifyLogFields(c.Request.Context(), "shuncheng", params, contentType, len(body), zap.Error(err))...) c.String(http.StatusOK, "FAIL") return } - h.log().Info("payment notify processed", notifyLogFields(c.Request.Context(), "shuncheng", params, contentType, len(body))...) + h.log().Info("支付回调处理完成", notifyLogFields(c.Request.Context(), "shuncheng", params, contentType, len(body))...) c.String(http.StatusOK, result.Message) } @@ -295,6 +292,7 @@ func parseAdminPaymentQuery(c *gin.Context) (AdminPaymentQuery, bool) { } func writePaymentError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/payment/mohong_payment.go b/backend/internal/modules/payment/mohong_payment.go index a8609fe..8bc54ca 100644 --- a/backend/internal/modules/payment/mohong_payment.go +++ b/backend/internal/modules/payment/mohong_payment.go @@ -60,11 +60,6 @@ func (r *Repository) StartMohong(ctx context.Context, userID uint64, orderID uin return nil, ErrPaymentUnavailable } - r.log().Info("mohong payment start", paymentLogFields(ctx, appendFields( - paymentOrderFields(payment), - runtimeConfigFields(runtimeConfig), - )..., - )...) resp, err := runtimeConfig.Channel.CreatePayment(ctx, channelCreatePaymentRequest{ ThirdOrderID: payment.ThirdOrderID, AmountCent: payment.AmountCent, @@ -78,7 +73,7 @@ func (r *Repository) StartMohong(ctx context.Context, userID uint64, orderID uin }) if err != nil { _ = r.markPaymentFailed(ctx, payment.ID, nil, err.Error()) - r.log().Warn("mohong payment request failed", paymentLogFields(ctx, appendFields( + r.log().Warn("魔哄支付下单失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{zap.Error(err)}, @@ -107,6 +102,11 @@ func (r *Repository) StartMohong(ctx context.Context, userID uint64, orderID uin return nil, err } r.recordConfigUsage(ctx, runtimeConfig, latest) + r.log().Info("魔哄支付下单完成", paymentLogFields(ctx, appendFields( + paymentOrderFields(latest), + runtimeConfigFields(runtimeConfig), + )..., + )...) dto := toDTO(*latest) return &dto, nil } diff --git a/backend/internal/modules/payment/notify.go b/backend/internal/modules/payment/notify.go index 959de39..0e9117b 100644 --- a/backend/internal/modules/payment/notify.go +++ b/backend/internal/modules/payment/notify.go @@ -2,6 +2,10 @@ package payment import ( "context" + "crypto/sha256" + "encoding/hex" + "strconv" + "strings" "hfb_sys/backend/internal/model" @@ -33,7 +37,7 @@ func (r *Repository) HandleNotify(ctx context.Context, provider string, params m if amount := parseCent(params["amount"]); amount > 0 && amount != payment.AmountCent { if err := r.recordNotifyDiagnostic(ctx, payment.ID, params, rawPayload, contentType, verify, "amount_mismatch"); err != nil { - r.log().Warn("payment notify diagnostic save failed", paymentLogFields(ctx, appendFields( + r.log().Warn("支付回调诊断保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{ @@ -116,20 +120,18 @@ func (r *Repository) verifyNotify(ctx context.Context, payment *model.PaymentOrd } verify, err := runtimeConfig.Channel.VerifyNotify(params, rawPayload, contentType, authorization) if err != nil || !verify.OK { - r.log().Warn("payment notify verify failed", paymentLogFields(ctx, appendFields( + r.log().Warn("支付回调验签失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{ - zap.String("sign_got", verify.Got), - zap.String("sign_expected", firstNonEmpty(verify.Expected["notify_key"], verify.Expected["notify_cert"], verify.Expected["error"])), + zap.Bool("signature_present", verify.Got != ""), zap.Strings("param_keys", verify.ParamKeys), - zap.String("sign_base_string", firstNonEmpty(verify.BaseString["notify_key"], verify.BaseString["notify_cert"])), zap.Error(err), }, )..., )...) if err := r.recordNotifyDiagnostic(ctx, payment.ID, params, rawPayload, contentType, verify, "verify_failed"); err != nil { - r.log().Warn("payment notify diagnostic save failed", paymentLogFields(ctx, appendFields( + r.log().Warn("支付回调诊断保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{ @@ -141,12 +143,6 @@ func (r *Repository) verifyNotify(ctx context.Context, payment *model.PaymentOrd } return verify, ErrPaymentVerifyFailed } - r.log().Info("payment notify verified", paymentLogFields(ctx, appendFields( - paymentOrderFields(payment), - runtimeConfigFields(runtimeConfig), - []zap.Field{zap.String("matched_key", verify.MatchedKey)}, - )..., - )...) return verify, nil } func (r *Repository) recordNotifyDiagnostic(ctx context.Context, paymentID uint64, params map[string]string, rawPayload string, contentType string, verify channelVerifyNotifyResult, status string) error { @@ -159,13 +155,41 @@ func (r *Repository) recordNotifyDiagnostic(ctx context.Context, paymentID uint6 Update("raw_response", jsonMap(raw)).Error } func withNotifyDiagnostic(params map[string]string, rawPayload string, contentType string, verify channelVerifyNotifyResult, status string) map[string]string { - raw := withRawSource(params, channelSourceNotify) + raw := withRawSource(redactNotifyParams(params), channelSourceNotify) raw["_notify_diagnostic_status"] = status - raw["_raw_payload"] = rawPayload raw["_raw_content_type"] = contentType - raw["_sign_got"] = verify.Got + raw["_raw_payload_size"] = strconv.Itoa(len(rawPayload)) + raw["_raw_payload_sha256"] = shortDigest(rawPayload) + raw["_signature_present"] = strconv.FormatBool(verify.Got != "") raw["_sign_matched_key"] = verify.MatchedKey - raw["_sign_expected"] = jsonString(verify.Expected) - raw["_sign_base_strings"] = jsonString(verify.BaseString) + raw["_sign_param_keys"] = strings.Join(verify.ParamKeys, ",") return raw } + +func redactNotifyParams(params map[string]string) map[string]string { + allowed := map[string]bool{ + "service": true, "merchant_id": true, "third_order_id": true, + "provider_order_id": true, "leshua_order_id": true, "schc_order_id": true, + "merchant_refund_id": true, "provider_refund_id": true, + "leshua_refund_id": true, "schc_refund_id": true, + "status": true, "amount": true, "refund_amount": true, + "pay_time": true, "refund_time": true, + "code": true, "resp_code": true, "result_code": true, "error_code": true, + } + redacted := make(map[string]string, len(allowed)) + for key, value := range params { + lowerKey := strings.ToLower(key) + if allowed[lowerKey] { + redacted[key] = value + } + } + return redacted +} + +func shortDigest(value string) string { + if value == "" { + return "" + } + sum := sha256.Sum256([]byte(value)) + return hex.EncodeToString(sum[:8]) +} diff --git a/backend/internal/modules/payment/payment_start.go b/backend/internal/modules/payment/payment_start.go index 8702a1d..fe513f2 100644 --- a/backend/internal/modules/payment/payment_start.go +++ b/backend/internal/modules/payment/payment_start.go @@ -60,11 +60,6 @@ func (r *Repository) Start(ctx context.Context, userID uint64, orderID uint64, r return nil, ErrPaymentUnavailable } - r.log().Info("payment start", paymentLogFields(ctx, appendFields( - paymentOrderFields(payment), - runtimeConfigFields(runtimeConfig), - )..., - )...) resp, err := runtimeConfig.Channel.CreatePayment(ctx, channelCreatePaymentRequest{ ThirdOrderID: payment.ThirdOrderID, AmountCent: payment.AmountCent, @@ -78,7 +73,7 @@ func (r *Repository) Start(ctx context.Context, userID uint64, orderID uint64, r }) if err != nil { _ = r.markPaymentFailed(ctx, payment.ID, nil, err.Error()) - r.log().Warn("payment request failed", paymentLogFields(ctx, appendFields( + r.log().Warn("支付下单请求失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{zap.Error(err)}, @@ -88,7 +83,7 @@ func (r *Repository) Start(ctx context.Context, userID uint64, orderID uint64, r } if !resp.OK { _ = r.markPaymentFailed(ctx, payment.ID, resp.Raw, resp.ErrorMessage) - r.log().Warn("payment rejected", paymentLogFields(ctx, appendFields( + r.log().Warn("支付下单被渠道拒绝", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), runtimeConfigFields(runtimeConfig), []zap.Field{ @@ -117,7 +112,7 @@ func (r *Repository) Start(ctx context.Context, userID uint64, orderID uint64, r return nil, err } r.recordConfigUsage(ctx, runtimeConfig, latest) - r.log().Info("payment result", paymentLogFields(ctx, appendFields( + r.log().Info("支付下单完成", paymentLogFields(ctx, appendFields( paymentOrderFields(latest), runtimeConfigFields(runtimeConfig), )..., diff --git a/backend/internal/modules/payment/refund.go b/backend/internal/modules/payment/refund.go index dced72c..0432e90 100644 --- a/backend/internal/modules/payment/refund.go +++ b/backend/internal/modules/payment/refund.go @@ -31,7 +31,7 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou if existing { latest, syncErr := r.syncRefundPayment(ctx, refundOrder, refundOrder.Status != "refunded") if syncErr != nil { - r.log().Warn("payment existing refund sync failed", paymentLogFields(ctx, appendFields( + r.log().Warn("已有退款单同步失败", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), []zap.Field{zap.String("biz_type", bizType), zap.Error(syncErr)}, )..., @@ -65,19 +65,9 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou return &dto, nil } - r.log().Info("payment refund start", paymentLogFields(ctx, appendFields( - paymentOrderFields(refundOrder), - runtimeConfigFields(runtimeConfig), - []zap.Field{ - zap.String("merchant_refund_id", refundOrder.ThirdOrderID), - zap.String("origin_third_order_id", originalPayment.ThirdOrderID), - zap.String("origin_provider_order_id", refundOriginProviderOrderID(originalPayment)), - }, - )..., - )...) r.recordConfigUsage(ctx, runtimeConfig, refundOrder) if err := r.markOrderRefunding(ctx, orderID, refundAmountCent); err != nil { - r.log().Warn("payment mark order refunding failed", paymentLogFields(ctx, + r.log().Warn("订单退款状态更新失败", paymentLogFields(ctx, zap.Uint64("order_id", orderID), zap.Int64("refund_amount_cent", refundAmountCent), zap.Error(err), @@ -86,7 +76,7 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou if runtimeConfig.Channel == nil { if err := r.markRefundFailed(ctx, refundOrder.ID, orderID, refundAmountCent, map[string]string{"error": "payment channel unavailable"}, nil); err != nil { - r.log().Warn("payment mark refund failed status failed", paymentLogFields(ctx, appendFields( + r.log().Warn("退款失败状态保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), []zap.Field{zap.Error(err)}, )..., @@ -109,13 +99,13 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou rawRequest = resp.RawRequest } if markErr := r.markRefundFailed(ctx, refundOrder.ID, orderID, refundAmountCent, map[string]string{"error": err.Error()}, rawRequest); markErr != nil { - r.log().Warn("payment mark refund failed status failed", paymentLogFields(ctx, appendFields( + r.log().Warn("退款失败状态保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), []zap.Field{zap.Error(markErr)}, )..., )...) } - r.log().Warn("payment refund request failed", paymentLogFields(ctx, appendFields( + r.log().Warn("退款渠道请求失败", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), runtimeConfigFields(runtimeConfig), []zap.Field{zap.Error(err)}, @@ -125,13 +115,13 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou } if !resp.OK { if markErr := r.markRefundFailed(ctx, refundOrder.ID, orderID, refundAmountCent, resp.Raw, resp.RawRequest); markErr != nil { - r.log().Warn("payment mark refund rejected status failed", paymentLogFields(ctx, appendFields( + r.log().Warn("退款拒绝状态保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), []zap.Field{zap.Error(markErr)}, )..., )...) } - r.log().Warn("payment refund rejected", paymentLogFields(ctx, appendFields( + r.log().Warn("退款被渠道拒绝", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), runtimeConfigFields(runtimeConfig), []zap.Field{ @@ -153,7 +143,7 @@ func (r *Repository) StartRefund(ctx context.Context, orderID uint64, refundAmou }); err != nil { return nil, err } - r.log().Info("payment refund result", paymentLogFields(ctx, appendFields( + r.log().Info("退款提交完成", paymentLogFields(ctx, appendFields( paymentOrderFields(refundOrder), runtimeConfigFields(runtimeConfig), []zap.Field{ @@ -308,7 +298,7 @@ func (r *Repository) syncRefundPayment(ctx context.Context, payment *model.Payme if err != nil { if resp != nil && resp.RawRequest != nil { if updateErr := r.updateRefundRawRequest(ctx, payment.ID, resp.RawRequest); updateErr != nil { - r.log().Warn("payment refund query raw request update failed", paymentLogFields(ctx, appendFields( + r.log().Warn("退款查询诊断保存失败", paymentLogFields(ctx, appendFields( paymentOrderFields(payment), []zap.Field{zap.Error(updateErr)}, )..., diff --git a/backend/internal/modules/payment/repository.go b/backend/internal/modules/payment/repository.go index 3a9da8f..0ce14fc 100644 --- a/backend/internal/modules/payment/repository.go +++ b/backend/internal/modules/payment/repository.go @@ -255,7 +255,7 @@ func (r *Repository) recordConfigUsage(ctx context.Context, runtimeConfig *runti return } if err := r.configRepo.RecordUsage(ctx, runtimeConfig.ID, payment.ID, runtimeConfig.Provider, runtimeConfig.MerchantID, payment.AmountCent, payment.BizType); err != nil { - r.log().Warn("payment config usage record failed", paymentLogFields(ctx, + r.log().Warn("支付配置使用记录保存失败", paymentLogFields(ctx, zap.Uint64("payment_config_id", runtimeConfig.ID), zap.Uint64("payment_id", payment.ID), zap.Error(err), diff --git a/backend/internal/modules/paymentaccount/handler.go b/backend/internal/modules/paymentaccount/handler.go index e6ed4c9..586e279 100644 --- a/backend/internal/modules/paymentaccount/handler.go +++ b/backend/internal/modules/paymentaccount/handler.go @@ -165,6 +165,7 @@ func parseID(c *gin.Context) (uint64, bool) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch err { case ErrAccountNotFound: response.NotFound(c, "收款账号不存在") diff --git a/backend/internal/modules/paymentconfig/handler.go b/backend/internal/modules/paymentconfig/handler.go index fd48be5..ff0ab8d 100644 --- a/backend/internal/modules/paymentconfig/handler.go +++ b/backend/internal/modules/paymentconfig/handler.go @@ -40,6 +40,7 @@ func (h *Handler) List(c *gin.Context) { resp, err := h.service.List(c.Request.Context(), query) if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "查询失败") return } @@ -78,6 +79,7 @@ func (h *Handler) Get(c *gin.Context) { return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "查询失败") return } @@ -99,16 +101,19 @@ func (h *Handler) ExportBackup(c *gin.Context) { backup, err := h.service.ExportBackup(c.Request.Context(), adminID, auditMeta(c)) if err == ErrDecryptionFailed { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "decrypt_failed", "密钥解密失败") return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "导出失败") return } data, err := json.MarshalIndent(backup, "", " ") if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "导出失败") return } @@ -148,10 +153,12 @@ func (h *Handler) ImportBackup(c *gin.Context) { return } if err == ErrEncryptionFailed { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "encrypt_failed", "密钥加密失败") return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "导入失败") return } @@ -187,6 +194,7 @@ func (h *Handler) Create(c *gin.Context) { return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "创建失败") return } @@ -230,6 +238,7 @@ func (h *Handler) Update(c *gin.Context) { return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "更新失败") return } @@ -266,6 +275,7 @@ func (h *Handler) Delete(c *gin.Context) { return } if err != nil { + response.RecordError(c, err) response.Error(c, http.StatusInternalServerError, "internal_error", "删除失败") return } diff --git a/backend/internal/modules/pickup/handler.go b/backend/internal/modules/pickup/handler.go index aa6bcd5..ffd56e1 100644 --- a/backend/internal/modules/pickup/handler.go +++ b/backend/internal/modules/pickup/handler.go @@ -179,6 +179,7 @@ func (h *Handler) ListForSeller(c *gin.Context) { } func writePickupError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/realname/handler.go b/backend/internal/modules/realname/handler.go index d688119..6241597 100644 --- a/backend/internal/modules/realname/handler.go +++ b/backend/internal/modules/realname/handler.go @@ -69,6 +69,7 @@ func currentUserID(c *gin.Context) (uint64, bool) { } func writeRealnameError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/realname/service.go b/backend/internal/modules/realname/service.go index 4e2afad..ddcbeb1 100644 --- a/backend/internal/modules/realname/service.go +++ b/backend/internal/modules/realname/service.go @@ -6,6 +6,7 @@ import ( "regexp" "strings" + "hfb_sys/backend/internal/logging" "hfb_sys/backend/internal/model" "go.uber.org/zap" @@ -61,13 +62,17 @@ func (s *Service) Start(ctx context.Context, userID uint64, name string, idNo st }) if err != nil { if s.log != nil { - s.log.Warn( - "realname provider verify failed", + fields := []zap.Field{ + zap.String("module", "realname"), zap.String("provider", s.provider.Name()), zap.Uint64("user_id", userID), zap.String("masked_id_no", maskIDNo(idNo)), zap.Error(err), - ) + } + if requestID := logging.RequestIDFromContext(ctx); requestID != "" { + fields = append(fields, zap.String("request_id", requestID)) + } + s.log.Warn("实名认证服务调用失败", fields...) } return nil, err } diff --git a/backend/internal/modules/supportgroup/handler.go b/backend/internal/modules/supportgroup/handler.go index 643ccce..fbee04c 100644 --- a/backend/internal/modules/supportgroup/handler.go +++ b/backend/internal/modules/supportgroup/handler.go @@ -120,6 +120,7 @@ func parseID(c *gin.Context) (uint64, bool) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrInvalidGroup): response.BadRequest(c, "客服分组信息不正确") diff --git a/backend/internal/modules/systemconfig/handler.go b/backend/internal/modules/systemconfig/handler.go index 8b50d7b..fb476ee 100644 --- a/backend/internal/modules/systemconfig/handler.go +++ b/backend/internal/modules/systemconfig/handler.go @@ -128,6 +128,7 @@ func currentAdminID(c *gin.Context) (uint64, bool) { } func writeConfigError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/wallet/handler.go b/backend/internal/modules/wallet/handler.go index 01a6e5f..103b43c 100644 --- a/backend/internal/modules/wallet/handler.go +++ b/backend/internal/modules/wallet/handler.go @@ -129,6 +129,7 @@ func currentUserID(c *gin.Context) (uint64, bool) { } func writeWalletError(c *gin.Context, err error) { + response.RecordError(c, err) switch { case errors.Is(err, ErrDependencyUnavailable): response.ServiceUnavailable(c, "数据库未连接") diff --git a/backend/internal/modules/withdrawal/handler.go b/backend/internal/modules/withdrawal/handler.go index 97fff09..062c0fd 100644 --- a/backend/internal/modules/withdrawal/handler.go +++ b/backend/internal/modules/withdrawal/handler.go @@ -217,6 +217,7 @@ func parseID(c *gin.Context) (uint64, bool) { } func writeError(c *gin.Context, err error) { + response.RecordError(c, err) switch err { case ErrWithdrawalNotFound: response.NotFound(c, "提现申请不存在") diff --git a/backend/internal/router/router.go b/backend/internal/router/router.go index 487d58c..186d8cc 100644 --- a/backend/internal/router/router.go +++ b/backend/internal/router/router.go @@ -83,9 +83,9 @@ func New(cfg config.Config, deps Dependencies, logger *zap.Logger) *gin.Engine { encryptor, err := crypto.NewFieldEncryptor(primary, legacy) if err != nil { if config.IsProductionEnv(cfg.AppEnv) { - logger.Fatal("FIELD_ENCRYPTION_KEY invalid", zap.Error(err)) + logger.Fatal("业务字段加密密钥无效", zap.Error(err)) } - logger.Warn("FIELD_ENCRYPTION_KEY invalid, fallback to legacy-only", zap.Error(err)) + logger.Warn("业务字段加密密钥无效，已回退旧密钥", zap.Error(err)) // primary 非法时退回 legacy 单密钥（若有），否则 MockEncryptor if legacy != "" { if e, eErr := crypto.NewFieldEncryptor(legacy); eErr == nil { @@ -100,15 +100,15 @@ func New(cfg config.Config, deps Dependencies, logger *zap.Logger) *gin.Engine { encryptor, err := crypto.NewFieldEncryptor(legacy) if err == nil { fieldEncryptor = encryptor - logger.Warn("FIELD_ENCRYPTION_KEY not set, using legacy-only encryptor for dev compatibility") + logger.Debug("开发环境使用旧业务字段加密密钥") } } if fieldEncryptor == nil { if config.IsProductionEnv(cfg.AppEnv) { - logger.Fatal("FIELD_ENCRYPTION_KEY not set") + logger.Fatal("业务字段加密密钥未设置") } fieldEncryptor = &crypto.MockEncryptor{} - logger.Warn("FIELD_ENCRYPTION_KEY and legacy both unset, using MockEncryptor") + logger.Debug("开发环境使用模拟业务字段加密器") } jwtManager := auth.NewJWTManager(cfg.JWTSecret) @@ -245,10 +245,10 @@ func New(cfg config.Config, deps Dependencies, logger *zap.Logger) *gin.Engine { } if encryptor == nil { if config.IsProductionEnv(cfg.AppEnv) { - logger.Fatal("PAYMENT_CONFIG_ENCRYPTION_KEY not set or invalid") + logger.Fatal("支付配置加密密钥未设置或无效") } encryptor = &paymentconfig.MockEncryptor{} - logger.Warn("PAYMENT_CONFIG_ENCRYPTION_KEY not set or invalid, using MockEncryptor") + logger.Debug("开发环境使用模拟支付配置加密器") } paymentConfigRepo = paymentconfig.NewRepository(deps.DB, encryptor) paymentConfigService = paymentconfig.NewService(paymentConfigRepo) @@ -331,7 +331,7 @@ func New(cfg config.Config, deps Dependencies, logger *zap.Logger) *gin.Engine { var err error fileStorage, err = filemodule.NewStorage(cfg.Storage) if err != nil { - logger.Warn("file storage bucket is not ready; file APIs will retry on request", zap.Error(err)) + logger.Warn("文件存储桶尚未就绪，接口请求时将重试", zap.Error(err)) } } fileService := filemodule.NewService(fileStorage) @@ -766,7 +766,7 @@ func newSMSProvider(cfg config.Config, logger *zap.Logger) smsintegration.Provid LoginTemplateCode: cfg.SMS.AliyunLoginTemplateCode, }, logger) if err != nil { - logger.Warn("aliyun sms provider unavailable; sms send will fail", zap.Error(err)) + logger.Warn("阿里云短信服务初始化失败", zap.Error(err)) return smsintegration.NewUnavailableProvider(err) } return provider @@ -784,7 +784,7 @@ func newRealnameProvider(cfg config.Config, encryptor crypto.Encryptor, logger * Encryptor: encryptor, }) if err != nil { - logger.Warn("cloud market realname provider unavailable; realname verify will fail", zap.Error(err)) + logger.Warn("实名认证服务初始化失败", zap.Error(err)) return realname.NewUnavailableProvider(err) } return provider diff --git a/backend/pkg/response/response.go b/backend/pkg/response/response.go index 1112427..f173a2e 100644 --- a/backend/pkg/response/response.go +++ b/backend/pkg/response/response.go @@ -1,11 +1,15 @@ package response import ( + "errors" + "fmt" "net/http" "github.com/gin-gonic/gin" ) +const contextResponseCode = "response_code" + type Body struct { Code string `json:"code"` Message string `json:"message"` @@ -29,12 +33,39 @@ func Created(c *gin.Context, data any) { } func Error(c *gin.Context, status int, code, message string) { + if status >= http.StatusInternalServerError && len(c.Errors) == 0 { + RecordError(c, fmt.Errorf("未记录原始错误: %s", code)) + } + c.Set(contextResponseCode, code) c.JSON(status, Body{ Code: code, Message: message, }) } +// RecordError 保存原始错误，供统一请求日志记录服务端故障原因。 +func RecordError(c *gin.Context, err error) { + if c == nil || err == nil { + return + } + for _, item := range c.Errors { + if errors.Is(item.Err, err) { + return + } + } + _ = c.Error(err) +} + +// CodeFromContext 返回已经写入响应的稳定业务错误码。 +func CodeFromContext(c *gin.Context) string { + value, ok := c.Get(contextResponseCode) + if !ok { + return "" + } + code, _ := value.(string) + return code +} + func BadRequest(c *gin.Context, message string) { Error(c, http.StatusBadRequest, "bad_request", message) }