From f7a21ee45523e5224b60e28fc58e192fcbacd0f2 Mon Sep 17 00:00:00 2001 From: dailz Date: Fri, 10 Apr 2026 08:39:21 +0800 Subject: [PATCH] =?UTF-8?q?feat:=20=E6=B7=BB=E5=8A=A0=20zap=20=E6=97=A5?= =?UTF-8?q?=E5=BF=97=E5=B7=A5=E5=8E=82=E5=92=8C=20GORM=20=E6=97=A5?= =?UTF-8?q?=E5=BF=97=E6=A1=A5=E6=8E=A5?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - NewLogger 工厂函数：支持 JSON/Console 编码、stdout/文件/多输出、lumberjack 轮转 - NewGormLogger 实现 gorm.Interface：Trace 区分错误/慢查询/正常查询 - output_stdout 用 *bool 三态处理（nil=true, true, false） - 默认值：level=info, encoding=json, max_size=100, max_backups=5, max_age=30 - 慢查询阈值 200ms，ErrRecordNotFound 不视为错误 - 编译时接口检查: var _ gormlogger.Interface = (*GormLogger)(nil) - 完整 TDD 测试覆盖 Ultraworked with [Sisyphus](https://github.com/code-yeongyu/oh-my-openagent) Co-authored-by: Sisyphus --- internal/logger/gorm.go | 148 ++++++++++ internal/logger/gorm_test.go | 509 +++++++++++++++++++++++++++++++++ internal/logger/logger.go | 93 ++++++ internal/logger/logger_test.go | 286 ++++++++++++++++++ 4 files changed, 1036 insertions(+) create mode 100644 internal/logger/gorm.go create mode 100644 internal/logger/gorm_test.go create mode 100644 internal/logger/logger.go create mode 100644 internal/logger/logger_test.go diff --git a/internal/logger/gorm.go b/internal/logger/gorm.go new file mode 100644 index 0000000..63cf2b0 --- /dev/null +++ b/internal/logger/gorm.go @@ -0,0 +1,148 @@ +package logger + +import ( + "context" + "errors" + "time" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "gorm.io/gorm" + gormlogger "gorm.io/gorm/logger" +) + +const slowQueryThreshold = 200 * time.Millisecond + +// GormLogger implements gorm's logger.Interface backed by zap. +type GormLogger struct { + logger *zap.Logger + level zapcore.Level + silent bool +} + +// Compile-time interface check. +var _ gormlogger.Interface = (*GormLogger)(nil) + +// NewGormLogger creates a new GormLogger wrapping the given zap logger. +// The level string maps to zap levels; empty defaults to "warn". +// The special value "silent" suppresses all output. +func NewGormLogger(zapLogger *zap.Logger, level string) gormlogger.Interface { + lvl := parseGormLevel(level) + silent := level == "silent" + return &GormLogger{ + logger: zapLogger, + level: lvl, + silent: silent, + } +} + +// LogMode returns a new GormLogger with the given gorm log level. +// It does NOT mutate the receiver. +func (l *GormLogger) LogMode(level gormlogger.LogLevel) gormlogger.Interface { + newLogger := &GormLogger{ + logger: l.logger, + level: l.level, + silent: l.silent, + } + + switch level { + case gormlogger.Silent: + newLogger.silent = true + case gormlogger.Error: + newLogger.level = zapcore.ErrorLevel + newLogger.silent = false + case gormlogger.Warn: + newLogger.level = zapcore.WarnLevel + newLogger.silent = false + case gormlogger.Info: + newLogger.level = zapcore.InfoLevel + newLogger.silent = false + } + + return newLogger +} + +// Info logs at zap.InfoLevel with structured fields from key-value pairs. +func (l *GormLogger) Info(ctx context.Context, msg string, args ...any) { + if l.silent || l.level > zapcore.InfoLevel { + return + } + l.logger.Info(msg, argsToFields(args)...) +} + +// Warn logs at zap.WarnLevel with structured fields from key-value pairs. +func (l *GormLogger) Warn(ctx context.Context, msg string, args ...any) { + if l.silent || l.level > zapcore.WarnLevel { + return + } + l.logger.Warn(msg, argsToFields(args)...) +} + +// Error logs at zap.ErrorLevel with structured fields from key-value pairs. +func (l *GormLogger) Error(ctx context.Context, msg string, args ...any) { + if l.silent || l.level > zapcore.ErrorLevel { + return + } + l.logger.Error(msg, argsToFields(args)...) +} + +// Trace logs SQL query information based on execution results. +func (l *GormLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) { + if l.silent { + return + } + + elapsed := time.Since(begin) + sql, rows := fc() + + switch { + case err != nil && !errors.Is(err, gorm.ErrRecordNotFound): + l.logger.Error("gorm query error", + zap.Error(err), + zap.String("sql", sql), + zap.Int64("rows", rows), + zap.Duration("elapsed", elapsed), + ) + case elapsed > slowQueryThreshold: + l.logger.Warn("gorm slow query", + zap.String("sql", sql), + zap.Int64("rows", rows), + zap.Float64("elapsed_ms", float64(elapsed.Nanoseconds())/1e6), + ) + default: + if l.level > zapcore.InfoLevel { + return + } + l.logger.Info("gorm query", + zap.String("sql", sql), + zap.Int64("rows", rows), + zap.Duration("elapsed", elapsed), + ) + } +} + +// parseGormLevel parses a level string into a zapcore.Level. +// Defaults to zapcore.WarnLevel. +func parseGormLevel(level string) zapcore.Level { + if level == "" || level == "silent" { + return zapcore.WarnLevel + } + var lvl zapcore.Level + if err := lvl.UnmarshalText([]byte(level)); err != nil { + return zapcore.WarnLevel + } + return lvl +} + +// argsToFields converts alternating key-value pairs into zap fields. +func argsToFields(args []any) []zap.Field { + fields := make([]zap.Field, 0, len(args)/2) + for i := 0; i+1 < len(args); i += 2 { + key, ok := args[i].(string) + if !ok { + continue + } + fields = append(fields, zap.Any(key, args[i+1])) + } + return fields +} diff --git a/internal/logger/gorm_test.go b/internal/logger/gorm_test.go new file mode 100644 index 0000000..221416f --- /dev/null +++ b/internal/logger/gorm_test.go @@ -0,0 +1,509 @@ +package logger + +import ( + "context" + "errors" + "testing" + "time" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" + "gorm.io/gorm" + gormlogger "gorm.io/gorm/logger" +) + +// newObservedLogger creates a zap logger backed by an observer for test assertions. +func newObservedLogger() (*zap.Logger, *observer.ObservedLogs) { + core, recorded := observer.New(zapcore.DebugLevel) + return zap.New(core), recorded +} + +func TestNewGormLogger_DefaultLevel(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "") + g, ok := gl.(*GormLogger) + if !ok { + t.Fatal("expected *GormLogger") + } + if g.level != zapcore.WarnLevel { + t.Fatalf("expected warn level, got %v", g.level) + } + if g.silent { + t.Fatal("expected silent=false") + } +} + +func TestNewGormLogger_Silent(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "silent") + g, ok := gl.(*GormLogger) + if !ok { + t.Fatal("expected *GormLogger") + } + if !g.silent { + t.Fatal("expected silent=true") + } +} + +func TestNewGormLogger_ExplicitLevel(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "error") + g, ok := gl.(*GormLogger) + if !ok { + t.Fatal("expected *GormLogger") + } + if g.level != zapcore.ErrorLevel { + t.Fatalf("expected error level, got %v", g.level) + } +} + +func TestNewGormLogger_InvalidLevel(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "bogus") + g, ok := gl.(*GormLogger) + if !ok { + t.Fatal("expected *GormLogger") + } + // Should default to warn + if g.level != zapcore.WarnLevel { + t.Fatalf("expected warn level fallback, got %v", g.level) + } +} + +func TestGormLogger_Info(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "info") + + gl.Info(context.Background(), "test info", "key", "value") + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 log entry, got %d", len(entries)) + } + if entries[0].Message != "test info" { + t.Fatalf("expected message 'test info', got %q", entries[0].Message) + } + if entries[0].Level != zapcore.InfoLevel { + t.Fatalf("expected InfoLevel, got %v", entries[0].Level) + } +} + +func TestGormLogger_Warn(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + gl.Warn(context.Background(), "test warn", "code", 42) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 log entry, got %d", len(entries)) + } + if entries[0].Message != "test warn" { + t.Fatalf("expected message 'test warn', got %q", entries[0].Message) + } + if entries[0].Level != zapcore.WarnLevel { + t.Fatalf("expected WarnLevel, got %v", entries[0].Level) + } +} + +func TestGormLogger_Error(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "error") + + gl.Error(context.Background(), "test error", "module", "gorm") + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 log entry, got %d", len(entries)) + } + if entries[0].Message != "test error" { + t.Fatalf("expected message 'test error', got %q", entries[0].Message) + } + if entries[0].Level != zapcore.ErrorLevel { + t.Fatalf("expected ErrorLevel, got %v", entries[0].Level) + } +} + +func TestGormLogger_LevelFiltering(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + // Info should be suppressed at warn level + gl.Info(context.Background(), "should be suppressed") + if len(recorded.All()) != 0 { + t.Fatal("info should be suppressed at warn level") + } + + // Warn should pass + gl.Warn(context.Background(), "should pass") + if len(recorded.All()) != 1 { + t.Fatal("warn should pass at warn level") + } +} + +func TestGormLogger_SilentSuppressesAll(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "silent") + + gl.Info(context.Background(), "info msg") + gl.Warn(context.Background(), "warn msg") + gl.Error(context.Background(), "error msg") + + if len(recorded.All()) != 0 { + t.Fatalf("silent mode should suppress all logs, got %d", len(recorded.All())) + } +} + +func TestGormLogger_LogMode_ReturnsNewInstance(t *testing.T) { + log, _ := newObservedLogger() + original := NewGormLogger(log, "warn").(*GormLogger) + + modified := original.LogMode(gormlogger.Info) + + // Must be a different instance + if modified == original { + t.Fatal("LogMode should return a new instance") + } + + // Original should be unchanged + if original.level != zapcore.WarnLevel { + t.Fatalf("original level should remain warn, got %v", original.level) + } + + // New instance should have InfoLevel + mod := modified.(*GormLogger) + if mod.level != zapcore.InfoLevel { + t.Fatalf("modified level should be info, got %v", mod.level) + } +} + +func TestGormLogger_LogMode_Silent(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "info").(*GormLogger) + + silent := gl.LogMode(gormlogger.Silent).(*GormLogger) + if !silent.silent { + t.Fatal("LogMode(Silent) should set silent=true") + } + + // Original should not be silent + if gl.silent { + t.Fatal("original should not be affected") + } +} + +func TestGormLogger_LogMode_ErrorLevel(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "info").(*GormLogger) + + modified := gl.LogMode(gormlogger.Error).(*GormLogger) + if modified.level != zapcore.ErrorLevel { + t.Fatalf("expected ErrorLevel, got %v", modified.level) + } +} + +func TestGormLogger_LogMode_WarnLevel(t *testing.T) { + log, _ := newObservedLogger() + gl := NewGormLogger(log, "info").(*GormLogger) + + modified := gl.LogMode(gormlogger.Warn).(*GormLogger) + if modified.level != zapcore.WarnLevel { + t.Fatalf("expected WarnLevel, got %v", modified.level) + } +} + +func TestGormLogger_Trace_WithError(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT * FROM users", 0 } + err := errors.New("connection refused") + + gl.Trace(context.Background(), begin, fc, err) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + if entries[0].Level != zapcore.ErrorLevel { + t.Fatalf("expected ErrorLevel for real errors, got %v", entries[0].Level) + } + if entries[0].Message != "gorm query error" { + t.Fatalf("unexpected message: %q", entries[0].Message) + } +} + +func TestGormLogger_Trace_ErrRecordNotFound(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "info") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT * FROM users WHERE id = ?", 0 } + + gl.Trace(context.Background(), begin, fc, gorm.ErrRecordNotFound) + + // ErrRecordNotFound should NOT be logged as error + // At default level with no slow query, it should log as info + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + if entries[0].Level == zapcore.ErrorLevel { + t.Fatal("ErrRecordNotFound should NOT be logged at ErrorLevel") + } + if entries[0].Message != "gorm query" { + t.Fatalf("expected 'gorm query', got %q", entries[0].Message) + } +} + +func TestGormLogger_Trace_ErrRecordNotFound_SuppressedAtWarnLevel(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT * FROM users WHERE id = ?", 0 } + + gl.Trace(context.Background(), begin, fc, gorm.ErrRecordNotFound) + + // ErrRecordNotFound is not a real error, so it falls through to the default path. + // At warn level, the default path (info-level) is suppressed. + entries := recorded.All() + if len(entries) != 0 { + t.Fatalf("expected 0 entries at warn level, got %d", len(entries)) + } +} + +func TestGormLogger_Trace_SlowQuery(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + // Simulate a begin time far enough in the past to exceed the threshold + begin := time.Now().Add(-500 * time.Millisecond) + fc := func() (string, int64) { return "SELECT SLEEP(1)", 1 } + + gl.Trace(context.Background(), begin, fc, nil) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + if entries[0].Level != zapcore.WarnLevel { + t.Fatalf("expected WarnLevel for slow query, got %v", entries[0].Level) + } + if entries[0].Message != "gorm slow query" { + t.Fatalf("expected 'gorm slow query', got %q", entries[0].Message) + } +} + +func TestGormLogger_Trace_NormalQuery(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "info") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT 1", 1 } + + gl.Trace(context.Background(), begin, fc, nil) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + if entries[0].Level != zapcore.InfoLevel { + t.Fatalf("expected InfoLevel for normal query, got %v", entries[0].Level) + } + if entries[0].Message != "gorm query" { + t.Fatalf("expected 'gorm query', got %q", entries[0].Message) + } +} + +func TestGormLogger_Trace_NormalQuerySuppressedAtWarnLevel(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT 1", 1 } + + gl.Trace(context.Background(), begin, fc, nil) + + // Normal queries are info-level, suppressed at warn + if len(recorded.All()) != 0 { + t.Fatal("normal query should be suppressed at warn level") + } +} + +func TestGormLogger_Trace_SilentSuppressesAll(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "silent") + + begin := time.Now().Add(-500 * time.Millisecond) + fc := func() (string, int64) { return "SELECT SLEEP(1)", 1 } + err := errors.New("some error") + + gl.Trace(context.Background(), begin, fc, err) + + if len(recorded.All()) != 0 { + t.Fatal("silent mode should suppress even Trace errors") + } +} + +func TestGormLogger_Trace_StructuredFields(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "info") + + begin := time.Now() + fc := func() (string, int64) { return "SELECT * FROM users", 42 } + + gl.Trace(context.Background(), begin, fc, nil) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + + // Verify structured fields + fields := entries[0].ContextMap() + if fields["sql"] != "SELECT * FROM users" { + t.Fatalf("expected sql field, got %v", fields["sql"]) + } + if fields["rows"] != int64(42) { + t.Fatalf("expected rows=42, got %v", fields["rows"]) + } + if _, ok := fields["elapsed"]; !ok { + t.Fatal("expected elapsed field") + } +} + +func TestGormLogger_Trace_ErrorFields(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + begin := time.Now() + fc := func() (string, int64) { return "INSERT INTO users", 0 } + err := errors.New("duplicate key") + + gl.Trace(context.Background(), begin, fc, err) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + + fields := entries[0].ContextMap() + if fields["sql"] != "INSERT INTO users" { + t.Fatalf("expected sql field, got %v", fields["sql"]) + } + if _, ok := fields["error"]; !ok { + t.Fatal("expected error field") + } +} + +func TestGormLogger_Trace_SlowQueryFields(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "warn") + + begin := time.Now().Add(-500 * time.Millisecond) + fc := func() (string, int64) { return "SELECT * FROM large_table", 1000 } + + gl.Trace(context.Background(), begin, fc, nil) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + + fields := entries[0].ContextMap() + if fields["sql"] != "SELECT * FROM large_table" { + t.Fatalf("expected sql field, got %v", fields["sql"]) + } + if fields["rows"] != int64(1000) { + t.Fatalf("expected rows=1000, got %v", fields["rows"]) + } + if _, ok := fields["elapsed_ms"]; !ok { + t.Fatal("expected elapsed_ms field for slow query") + } +} + +func TestArgsToFields(t *testing.T) { + tests := []struct { + name string + args []interface{} + expected int + }{ + {"empty", nil, 0}, + {"single_pair", []interface{}{"key", "value"}, 1}, + {"two_pairs", []interface{}{"a", 1, "b", 2}, 2}, + {"odd_args_ignores_last", []interface{}{"key", "value", "orphan"}, 1}, + {"non_string_key_ignored", []interface{}{123, "value"}, 0}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + fields := argsToFields(tt.args) + if len(fields) != tt.expected { + t.Fatalf("expected %d fields, got %d", tt.expected, len(fields)) + } + }) + } +} + +func TestArgsToFields_FieldValues(t *testing.T) { + fields := argsToFields([]interface{}{"name", "test", "count", 42}) + if len(fields) != 2 { + t.Fatalf("expected 2 fields, got %d", len(fields)) + } + if fields[0].Key != "name" { + t.Fatalf("expected key 'name', got %q", fields[0].Key) + } + if fields[1].Key != "count" { + t.Fatalf("expected key 'count', got %q", fields[1].Key) + } +} + +func TestParseGormLevel(t *testing.T) { + tests := []struct { + input string + expected zapcore.Level + }{ + {"debug", zapcore.DebugLevel}, + {"info", zapcore.InfoLevel}, + {"warn", zapcore.WarnLevel}, + {"error", zapcore.ErrorLevel}, + {"", zapcore.WarnLevel}, + {"silent", zapcore.WarnLevel}, + {"invalid", zapcore.WarnLevel}, + } + + for _, tt := range tests { + t.Run(tt.input, func(t *testing.T) { + got := parseGormLevel(tt.input) + if got != tt.expected { + t.Fatalf("expected %v, got %v", tt.expected, got) + } + }) + } +} + +func TestGormLogger_InfoWithMultipleFields(t *testing.T) { + log, recorded := newObservedLogger() + gl := NewGormLogger(log, "info") + + gl.Info(context.Background(), "multi fields", "key1", "val1", "key2", 123, "key3", true) + + entries := recorded.All() + if len(entries) != 1 { + t.Fatalf("expected 1 entry, got %d", len(entries)) + } + + fields := entries[0].ContextMap() + if fields["key1"] != "val1" { + t.Fatalf("expected key1=val1, got %v", fields["key1"]) + } + if fields["key2"] != int64(123) { + t.Fatalf("expected key2=123, got %v", fields["key2"]) + } + if fields["key3"] != true { + t.Fatalf("expected key3=true, got %v", fields["key3"]) + } +} diff --git a/internal/logger/logger.go b/internal/logger/logger.go new file mode 100644 index 0000000..5a47d81 --- /dev/null +++ b/internal/logger/logger.go @@ -0,0 +1,93 @@ +package logger + +import ( + "fmt" + "os" + + "gcy_hpc_server/internal/config" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "gopkg.in/natefinch/lumberjack.v2" +) + +func NewLogger(cfg config.LogConfig) (*zap.Logger, error) { + level := applyDefault(cfg.Level, "info") + + var zapLevel zapcore.Level + if err := zapLevel.UnmarshalText([]byte(level)); err != nil { + return nil, fmt.Errorf("invalid log level %q: %w", level, err) + } + + encoding := applyDefault(cfg.Encoding, "json") + encoderConfig := zap.NewProductionEncoderConfig() + encoderConfig.TimeKey = "ts" + encoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder + encoderConfig.EncodeLevel = zapcore.CapitalLevelEncoder + + var encoder zapcore.Encoder + switch encoding { + case "console": + encoder = zapcore.NewConsoleEncoder(encoderConfig) + default: + encoder = zapcore.NewJSONEncoder(encoderConfig) + } + + var syncers []zapcore.WriteSyncer + + stdout := true + if cfg.OutputStdout != nil { + stdout = *cfg.OutputStdout + } + if stdout { + syncers = append(syncers, zapcore.AddSync(os.Stdout)) + } + + if cfg.FilePath != "" { + maxSize := applyDefaultInt(cfg.MaxSize, 100) + maxBackups := applyDefaultInt(cfg.MaxBackups, 5) + maxAge := applyDefaultInt(cfg.MaxAge, 30) + compress := cfg.Compress || cfg.MaxSize == 0 && cfg.MaxBackups == 0 && cfg.MaxAge == 0 + + lj := &lumberjack.Logger{ + Filename: cfg.FilePath, + MaxSize: maxSize, + MaxBackups: maxBackups, + MaxAge: maxAge, + Compress: compress, + } + syncers = append(syncers, zapcore.AddSync(lj)) + } + + if len(syncers) == 0 { + syncers = append(syncers, zapcore.AddSync(os.Stdout)) + } + + writeSyncer := syncers[0] + if len(syncers) > 1 { + writeSyncer = zapcore.NewMultiWriteSyncer(syncers...) + } + + core := zapcore.NewCore(encoder, writeSyncer, zapLevel) + + opts := []zap.Option{ + zap.AddCaller(), + zap.AddStacktrace(zapcore.ErrorLevel), + } + + return zap.New(core, opts...), nil +} + +func applyDefault(val, def string) string { + if val == "" { + return def + } + return val +} + +func applyDefaultInt(val, def int) int { + if val == 0 { + return def + } + return val +} diff --git a/internal/logger/logger_test.go b/internal/logger/logger_test.go new file mode 100644 index 0000000..691b816 --- /dev/null +++ b/internal/logger/logger_test.go @@ -0,0 +1,286 @@ +package logger + +import ( + "os" + "path/filepath" + "strings" + "testing" + + "gcy_hpc_server/internal/config" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest" +) + +func ptrBool(v bool) *bool { return &v } + +// TestNewLogger_JSONConfig creates a logger with JSON encoding and verifies +// that log entries are emitted successfully. +func TestNewLogger_JSONConfig(t *testing.T) { + cfg := config.LogConfig{ + Level: "debug", + Encoding: "json", + OutputStdout: ptrBool(true), + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + defer log.Sync() + + // Should not panic when logging + log.Info("json logger test", zap.String("key", "value")) +} + +// TestNewLogger_ConsoleConfig creates a logger with console encoding. +func TestNewLogger_ConsoleConfig(t *testing.T) { + cfg := config.LogConfig{ + Level: "info", + Encoding: "console", + OutputStdout: ptrBool(true), + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + defer log.Sync() + + log.Info("console logger test", zap.Int("num", 42)) +} + +// TestNewLogger_InvalidLevel verifies that an invalid log level returns an error. +func TestNewLogger_InvalidLevel(t *testing.T) { + cfg := config.LogConfig{ + Level: "bogus", + Encoding: "json", + } + + _, err := NewLogger(cfg) + if err == nil { + t.Fatal("expected error for invalid log level, got nil") + } +} + +// TestNewLogger_EmptyConfig verifies defaults are applied when config is zero-value. +func TestNewLogger_EmptyConfig(t *testing.T) { + cfg := config.LogConfig{} // all zero values + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + defer log.Sync() + + log.Info("default config test") +} + +// TestNewLogger_FileOutput verifies that file output with rotation config works. +func TestNewLogger_FileOutput(t *testing.T) { + tmpDir := t.TempDir() + logFile := filepath.Join(tmpDir, "test.log") + + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + FilePath: logFile, + MaxSize: 10, + MaxBackups: 3, + MaxAge: 7, + Compress: true, + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + + log.Info("file output test", zap.String("msg", "hello")) + log.Sync() + + data, err := os.ReadFile(logFile) + if err != nil { + t.Fatalf("failed to read log file: %v", err) + } + + if len(data) == 0 { + t.Fatal("log file is empty, expected output") + } + + if !strings.Contains(string(data), "file output test") { + t.Fatalf("log file content does not contain expected message;\ngot: %s", string(data)) + } +} + +// TestNewLogger_MultiWriter verifies that both stdout and file output work together. +func TestNewLogger_MultiWriter(t *testing.T) { + tmpDir := t.TempDir() + logFile := filepath.Join(tmpDir, "multi.log") + + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + OutputStdout: ptrBool(true), + FilePath: logFile, + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + + log.Info("multi writer test", zap.String("writer", "both")) + log.Sync() + + data, err := os.ReadFile(logFile) + if err != nil { + t.Fatalf("failed to read log file: %v", err) + } + + if !strings.Contains(string(data), "multi writer test") { + t.Fatalf("log file content does not contain expected message;\ngot: %s", string(data)) + } +} + +// TestNewLogger_Observer verifies actual log output content using zaptest. +func TestNewLogger_Observer(t *testing.T) { + // Use zaptest.NewLogger to capture logs in test output + log := zaptest.NewLogger(t, + zaptest.WrapOptions(zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel)), + zaptest.Level(zapcore.DebugLevel), + ) + + // These should all succeed without panicking + log.Debug("debug msg", zap.String("k", "v")) + log.Info("info msg", zap.Int("n", 1)) + log.Warn("warn msg") + log.Error("error msg") +} + +// TestNewLogger_AllLevels verifies all valid log levels parse correctly. +func TestNewLogger_AllLevels(t *testing.T) { + levels := []string{"debug", "info", "warn", "error", "dpanic", "panic", "fatal"} + for _, level := range levels { + t.Run(level, func(t *testing.T) { + cfg := config.LogConfig{ + Level: level, + Encoding: "json", + OutputStdout: ptrBool(true), + } + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("level %q: NewLogger returned error: %v", level, err) + } + log.Sync() + }) + } +} + +// TestNewLogger_InvalidEncoding falls back gracefully — the factory should +// treat an unrecognized encoding as an error or default to JSON. +func TestNewLogger_InvalidEncoding(t *testing.T) { + cfg := config.LogConfig{ + Level: "info", + Encoding: "xml", + OutputStdout: ptrBool(true), + } + + // The implementation should default to JSON for unknown encoding. + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("unexpected error for invalid encoding: %v", err) + } + defer log.Sync() + + log.Info("invalid encoding test") +} + +// TestNewLogger_DefaultRotation verifies rotation defaults are applied. +func TestNewLogger_DefaultRotation(t *testing.T) { + tmpDir := t.TempDir() + logFile := filepath.Join(tmpDir, "rotation.log") + + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + FilePath: logFile, + // MaxSize, MaxBackups, MaxAge, Compress all zero → defaults apply + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + + log.Info("rotation defaults test") + log.Sync() + + data, err := os.ReadFile(logFile) + if err != nil { + t.Fatalf("failed to read log file: %v", err) + } + + if len(data) == 0 { + t.Fatal("log file is empty") + } +} + +func TestNewLogger_OutputStdoutNil(t *testing.T) { + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + defer log.Sync() + + log.Info("default stdout test") +} + +func TestNewLogger_OutputStdoutFalseWithFile(t *testing.T) { + tmpDir := t.TempDir() + logFile := filepath.Join(tmpDir, "nostdout.log") + + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + OutputStdout: ptrBool(false), + FilePath: logFile, + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + log.Info("file only test") + log.Sync() + + data, err := os.ReadFile(logFile) + if err != nil { + t.Fatalf("failed to read log file: %v", err) + } + if !strings.Contains(string(data), "file only test") { + t.Fatalf("log file content does not contain expected message;\ngot: %s", string(data)) + } +} + +func TestNewLogger_OutputStdoutFalseFallback(t *testing.T) { + cfg := config.LogConfig{ + Level: "info", + Encoding: "json", + OutputStdout: ptrBool(false), + } + + log, err := NewLogger(cfg) + if err != nil { + t.Fatalf("NewLogger returned error: %v", err) + } + defer log.Sync() + + log.Info("fallback stdout test") +}