From 3d5b4c16fe668f610a8b3fce694834c274b2c54c Mon Sep 17 00:00:00 2001 From: "yuheng.huang" Date: Thu, 21 May 2026 15:42:10 +0800 Subject: [PATCH] refactor(logger): support LOG_FORMAT template and harden level coloring --- docs/日志配置.md | 51 ++++++++++ internal/logger/logger_test.go | 166 +++++++++++++++++++++++++++++++++ 2 files changed, 217 insertions(+) create mode 100644 docs/日志配置.md create mode 100644 internal/logger/logger_test.go diff --git a/docs/日志配置.md b/docs/日志配置.md new file mode 100644 index 00000000..f5999d68 --- /dev/null +++ b/docs/日志配置.md @@ -0,0 +1,51 @@ +# 日志配置 + +WeKnora 的日志由 `internal/logger` 统一管理，所有行为通过环境变量驱动，无需改代码。 + +## 环境变量 + +| 变量 | 是否必填 | 默认值 | 说明 | +| --- | --- | --- | --- | +| `LOG_LEVEL` | 否 | `debug` | 日志级别，取值 `debug` / `info` / `warn`(`warning`) / `error` / `fatal`，无效值回退到 `debug` | +| `LOG_PATH` | 否 | 空（仅打到 stdout；macOS `.app` 打包模式下落到 `~/Library/Logs//.log`） | 落盘路径，启用后同时写 stdout 与该文件，文件按 lumberjack 滚动（单文件 50MB / 3 份 / 28 天 / 压缩归档） | +| `LOG_FORMAT` | 否 | 空（沿用内置默认格式） | 自定义日志输出模板，支持下列占位符 | + +> 终端环境下 ANSI 颜色自动启用；非 TTY（容器日志采集、`docker logs` 重定向等）会自动关闭颜色，避免日志聚合/检索异常。 + +## `LOG_FORMAT` 模板 + +`LOG_FORMAT` 为空时使用内置默认格式（与历史行为一致）： + +``` +INFO [2026-05-21 10:20:30.123] [req-abc k1=v1] file.go:42[fn] | message body +``` + +配置 `LOG_FORMAT` 后启用模板模式，支持如下占位符： + +| 占位符 | 含义 | +| --- | --- | +| `%d` | 时间戳（`2006-01-02 15:04:05.000`） | +| `%level` | 日志级别（`DEBUG` / `INFO` / `WARNING` / `ERROR` / `FATAL`），开启颜色时仅此占位符被染色 | +| `%thread` | 当前 goroutine ID。**未引用该占位符时不会调用 `runtime.Stack`，无额外开销** | +| `%logger` | caller 信息（`file.go:line[func]`），过长时从末尾截取后 50 字符 | +| `%traceId` | 请求 ID（即上下文中的 `request_id`） | +| `%msg` | 消息正文 + 剩余结构化字段（`key=value`，按 key 升序拼接） | + +示例： + +```bash +export LOG_FORMAT='[%d] %level %thread %logger %traceId | %msg' +``` + +输出（终端开启颜色时仅 `%level` 段着色）： + +``` +[2026-05-21 10:20:30.123] INFO 17 service.go:88[Handle] req-abc | hello extra=ok +``` + +### 实现细节与注意事项 + +- 占位符替换使用 `strings.NewReplacer` 单趟扫描，前一个占位符的值即使包含其它占位符字面串（如 `request_id=%msg`）也不会被二次替换。 +- 级别染色在 `%level` 替换阶段直接注入 ANSI 颜色，**不会**误染消息正文中字面出现的 `INFO` / `ERROR` 等字符串。 +- 结构化字段（`logger.WithField` / `WithFields`）会被拼接到 `%msg` 之后，模板模式下暂不支持把任意字段抽出为独立占位符 — 若需 K/V 结构化检索，请直接关闭 `LOG_FORMAT` 使用默认格式。 +- `LOG_LEVEL` 与 `LOG_PATH` 的设置会在 `main` 加载 `.env` 后由 `logger.ConfigureFromEnv()` 重新生效。 diff --git a/internal/logger/logger_test.go b/internal/logger/logger_test.go new file mode 100644 index 00000000..42da1f42 --- /dev/null +++ b/internal/logger/logger_test.go @@ -0,0 +1,166 @@ +package logger + +import ( + "strings" + "testing" + "time" + + "github.com/sirupsen/logrus" +) + +func newEntry(level logrus.Level, msg string, data logrus.Fields) *logrus.Entry { + e := logrus.NewEntry(logrus.New()) + e.Time = time.Date(2026, 5, 21, 10, 20, 30, 123_000_000, time.UTC) + e.Level = level + e.Message = msg + e.Data = data + return e +} + +func TestFormat_DefaultModeUnchanged(t *testing.T) { + f := &CustomFormatter{} // no template, no color + entry := newEntry(logrus.InfoLevel, "hello", logrus.Fields{ + "request_id": "req-1", + "caller": "logger_test.go:1[Test]", + "k1": "v1", + }) + + out, err := f.Format(entry) + if err != nil { + t.Fatalf("Format returned error: %v", err) + } + got := string(out) + + if !strings.HasPrefix(got, "INFO ") { + t.Errorf("expected INFO-prefixed default output, got %q", got) + } + for _, want := range []string{"2026-05-21 10:20:30.123", "req-1", "k1=v1", "logger_test.go:1[Test]", "hello"} { + if !strings.Contains(got, want) { + t.Errorf("default output missing %q: %s", want, got) + } + } + if !strings.HasSuffix(got, "\n") { + t.Errorf("default output should end with newline, got %q", got) + } +} + +func TestFormat_TemplateReplacesAllPlaceholders(t *testing.T) { + f := &CustomFormatter{ + Template: "[%d] %level %thread %logger %traceId | %msg", + threadNeeded: true, + } + entry := newEntry(logrus.WarnLevel, "boom", logrus.Fields{ + "request_id": "req-42", + "caller": "x.go:9[Fn]", + "extra": "ok", + }) + + out, err := f.Format(entry) + if err != nil { + t.Fatalf("Format error: %v", err) + } + got := string(out) + + for _, want := range []string{ + "[2026-05-21 10:20:30.123]", + "WARNING", + "x.go:9[Fn]", + "req-42", + "boom", + "extra=ok", + } { + if !strings.Contains(got, want) { + t.Errorf("template output missing %q: %s", want, got) + } + } + for _, placeholder := range []string{"%d", "%level", "%thread", "%logger", "%traceId", "%msg"} { + if strings.Contains(got, placeholder) { + t.Errorf("placeholder %q not substituted: %s", placeholder, got) + } + } +} + +func TestFormat_TemplateGoroutineIDSkippedWhenNotReferenced(t *testing.T) { + // 模板未引用 %thread 时，threadNeeded 应为 false，运行时不应取 goroutine ID。 + // 这里通过观察输出中不含数字-only goroutine ID 段来间接验证；更重要的是确保不 panic。 + f := &CustomFormatter{ + Template: "[%d] %level | %msg", + threadNeeded: false, + } + entry := newEntry(logrus.InfoLevel, "no-thread", nil) + if _, err := f.Format(entry); err != nil { + t.Fatalf("Format error: %v", err) + } +} + +// TestFormat_ColorDoesNotPolluteMessage 是修复 colorize 误染 bug 的回归测试。 +// 旧实现对整行做 ReplaceAll(line, "INFO", colored)，会把消息正文里的 "INFO" +// 一并染色；新实现只在 %level 替换位置注入颜色。 +func TestFormat_ColorDoesNotPolluteMessage(t *testing.T) { + f := &CustomFormatter{ + ForceColor: true, + Template: "%level | %msg", + threadNeeded: false, + } + entry := newEntry(logrus.InfoLevel, "user INFO loaded", nil) + + out, err := f.Format(entry) + if err != nil { + t.Fatalf("Format error: %v", err) + } + got := string(out) + + // 输出中 ANSI 序列总数应恰好为 2（开头一对 color + reset）， + // 而非旧实现下消息里的 "INFO" 也被替换导致出现 4 段。 + const ansiOpen = "\033[32m" // green for INFO + const ansiReset = "\033[0m" + if strings.Count(got, ansiOpen) != 1 { + t.Errorf("expected exactly 1 green-open sequence, got %d in %q", strings.Count(got, ansiOpen), got) + } + if strings.Count(got, ansiReset) != 1 { + t.Errorf("expected exactly 1 reset sequence, got %d in %q", strings.Count(got, ansiReset), got) + } + // 消息正文中的 "INFO" 字面串应保持未染色（其前驱字符不是 ANSI 开头）。 + idx := strings.Index(got, "user INFO loaded") + if idx < 0 { + t.Fatalf("message body not found verbatim in output: %q", got) + } +} + +// TestFormat_TemplateNoCascadingReplace 验证使用 NewReplacer 单趟替换， +// 字段值里含有占位符字面串（例如 traceId 值为 "%msg"）时不会被二次替换。 +func TestFormat_TemplateNoCascadingReplace(t *testing.T) { + f := &CustomFormatter{ + Template: "%traceId>%msg", + threadNeeded: false, + } + entry := newEntry(logrus.InfoLevel, "actual-msg", logrus.Fields{ + "request_id": "%msg", // 恶意/巧合的字段值 + }) + + out, err := f.Format(entry) + if err != nil { + t.Fatalf("Format error: %v", err) + } + got := strings.TrimRight(string(out), "\n") + want := "%msg>actual-msg" + if got != want { + t.Errorf("cascading-replace regression: got %q, want %q", got, want) + } +} + +func TestLevelColorFor(t *testing.T) { + cases := map[logrus.Level]string{ + logrus.DebugLevel: colorCyan, + logrus.InfoLevel: colorGreen, + logrus.WarnLevel: colorYellow, + logrus.ErrorLevel: colorRed, + logrus.FatalLevel: colorPurple, + logrus.TraceLevel: "", + } + for lvl, want := range cases { + if got := levelColorFor(lvl); got != want { + t.Errorf("levelColorFor(%v) = %q, want %q", lvl, got, want) + } + } +}