From 0cb20fb7f5d7ccac19740b125b9965f34528b514 Mon Sep 17 00:00:00 2001 From: JianFeeeee Date: Sat, 31 Oct 2026 18:49:36 +0800 Subject: [PATCH] =?UTF-8?q?fix(log):=20=E7=94=9F=E4=BA=A7=E6=97=A5?= =?UTF-8?q?=E5=BF=97=E9=BB=98=E8=AE=A4=E4=B8=8D=E5=86=8D=E5=B8=A6=E6=BA=90?= =?UTF-8?q?=E6=96=87=E4=BB=B6=E4=BD=8D=E7=BD=AE?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## 现象 生产日志每行都带 `file.go:NNN`： 2026/10/31 18:47:03 bootstrap.go:320: [homed] shutting down... 2026/10/31 18:47:03 builtin_skill.go:163: [plugin] seq: removed skill ... 2026/10/31 18:47:03 sidecar.go:419: [clawhubadapter] sidecar manager stopped 来源是 `cmd/homed/bootstrap.go` 里无条件 `log.SetFlags(... | log.Lshortfile)`。 ## 判断：生产确实不需要 - 多数日志**本身带模块前缀**（`[homed]` / `[plugin]` / `[kbtree]` / `[skillmgr]`）， 去掉行号后定位能力并不缺 - `Lshortfile` 在**每一次** log 调用里做一次 `runtime.Caller`，不为零 - 它还不能真的消歧：它只打基名，26 个插件里有多个 `plugin.go`， `plugin.go:104` 反而指不出是哪一个 —— 真正的消歧靠的是消息里的 `[插件名]` 前缀 ## 改法 `logFlags()` 抽出来，默认 `Ldate|Ltime`；`HOMED_LOG_SOURCE=1`（或 true/yes/on） 时追加 `Lshortfile`。 保留开关而不是删掉：排查插件/装配问题时行号仍有用，部署方临时开一下即可。 用法写进 `docs/zh/deploy-runbook.md` §3.0。 ## 判据 - `TestLogFlagsNoSourceByDefault`：默认不得有 Lshortfile，且日期时间必须保留 - `TestLogFlagsSourceOptIn`：开关的六种正向写法生效、四种关闭写法不误开 ## 验证 go build ./... ✓ go vet ./cmd/homed/ ✓ go test ./cmd/homed/ ✓（含新增两条） --- cmd/homed/bootstrap.go | 28 +++++++++++++++++++-- cmd/homed/logflags_test.go | 50 ++++++++++++++++++++++++++++++++++++++ docs/zh/deploy-runbook.md | 28 +++++++++++++++++++++ 3 files changed, 104 insertions(+), 2 deletions(-) create mode 100644 cmd/homed/logflags_test.go diff --git a/cmd/homed/bootstrap.go b/cmd/homed/bootstrap.go index effce133..be9d9955 100644 --- a/cmd/homed/bootstrap.go +++ b/cmd/homed/bootstrap.go @@ -29,12 +29,36 @@ import ( "github.com/JianFeeeee/HologramAgent/pkg/types" ) -// setupLogging 初始化日志：行号前缀 + 同时输出到控制台与 /log/ 下的本次启动文件。 +// logSourceEnv 是「日志带源文件位置」的开关环境变量。 +// +// 为什么默认关：生产日志要紧凑可读。加了 `file.go:NNN` 之后每行前面多出一截 +// 内部实现信息，而**大多数日志本身已经带了模块前缀**（`[kbtree]`、`[plugin]`、 +// `[agent]`），定位能力并不缺。 +// +// 而它也不便宜：`log.Lshortfile` 在**每一次** log 调用里做一次 runtime.Caller。 +// +// 为什么保留开关而不是删掉：排查插件/装配问题时，同名文件（多个插件都有自己的 +// plugin.go）靠行号才能区分。部署方临时 `HOMED_LOG_SOURCE=1` 重启即可。 +const logSourceEnv = "HOMED_LOG_SOURCE" + +// logFlags 返回日志前缀标志位（抽出来便于判据直接验，不必真去建目录/开文件）。 +func logFlags() int { + flags := log.Ldate | log.Ltime + switch strings.ToLower(strings.TrimSpace(os.Getenv(logSourceEnv))) { + case "1", "true", "yes", "on": + flags |= log.Lshortfile + } + return flags +} + +// setupLogging 初始化日志：时间前缀 + 同时输出到控制台与 /log/ 下的本次启动文件。 +// +// 源文件位置默认不带，见 logSourceEnv。 // // 本函数体是 main() 里对应启动阶段的整块平移：语句、日志文本、错误语义不变， // 只把「*dataDir」变成参数、把 defer 变成由调用点注册的 cleanup。 func setupLogging(dataDir string) string { - log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile) + log.SetFlags(logFlags()) // 文件日志：同时输出到控制台和 data/log/ 目录 logDir := filepath.Join(dataDir, "log") diff --git a/cmd/homed/logflags_test.go b/cmd/homed/logflags_test.go new file mode 100644 index 00000000..14c08ac9 --- /dev/null +++ b/cmd/homed/logflags_test.go @@ -0,0 +1,50 @@ +package main + +import ( + "log" + "testing" +) + +// TestLogFlagsNoSourceByDefault 钉住「默认日志不带源文件位置」。 +// +// 起因（2026-10-31，用户看生产日志时提出）： +// +// 2026/10/31 18:47:03 bootstrap.go:320: [homed] shutting down... +// 2026/10/31 18:47:03 builtin_skill.go:163: [plugin] seq: removed skill ... +// +// 生产日志不需要 `file.go:NNN`：多数日志本身带模块前缀（`[homed]` / `[plugin]` / +// `[kbtree]`），定位能力并不缺；而 Lshortfile 每行都多一次 runtime.Caller。 +// +// 判据形状：直接测 logFlags()，因为它在 setupLogging 里被原样交给 log.SetFlags。 +// 不去跑 setupLogging 本身——那会建目录、开文件，判据会变重且依赖文件系统。 +func TestLogFlagsNoSourceByDefault(t *testing.T) { + t.Setenv(logSourceEnv, "") + + flags := logFlags() + if flags&log.Lshortfile != 0 { + t.Error("默认不得带 Lshortfile（生产日志不该出现 file.go:NNN）") + } + if flags&log.Ldate == 0 || flags&log.Ltime == 0 { + t.Error("日期与时间必须保留：日志没有时间戳就没法关联事件") + } +} + +// TestLogFlagsSourceOptIn 钉住开关本身仍然可用。 +// +// 为什么保留它：排查插件/装配问题时，同名文件很多（每个插件都有自己的 +// plugin.go），行号是唯一能区分的东西。删掉开关等于把那条排查路径也删了。 +func TestLogFlagsSourceOptIn(t *testing.T) { + for _, v := range []string{"1", "true", "TRUE", "yes", "on", " 1 "} { + t.Setenv(logSourceEnv, v) + if logFlags()&log.Lshortfile == 0 { + t.Errorf("%s=%q 应打开 Lshortfile", logSourceEnv, v) + } + } + // 明确关掉的写法不能被当成开 + for _, v := range []string{"0", "false", "off", "no", ""} { + t.Setenv(logSourceEnv, v) + if logFlags()&log.Lshortfile != 0 { + t.Errorf("%s=%q 不应打开 Lshortfile", logSourceEnv, v) + } + } +} diff --git a/docs/zh/deploy-runbook.md b/docs/zh/deploy-runbook.md index 4549d4d8..fc824e2d 100644 --- a/docs/zh/deploy-runbook.md +++ b/docs/zh/deploy-runbook.md @@ -310,6 +310,34 @@ systemctl restart waiter-remote.service ## 3. 故障排查 +### 3.0 日志里要不要源文件位置 + +默认**不带**。生产日志长这样： + +``` +2026/10/31 18:47:03 [homed] shutting down... +``` + +排查插件/装配问题时可以临时打开，加上 `file.go:NNN`： + +```bash +systemctl edit hologramagent # 或直接改 drop-in +# [Service] +# Environment=HOMED_LOG_SOURCE=1 +systemctl restart hologramagent +``` + +打开后： + +``` +2026/10/31 18:47:03 bootstrap.go:320: [homed] shutting down... +``` + +为什么默认关：多数日志本身带模块前缀（`[homed]` / `[plugin]` / `[kbtree]`）， +定位能力并不缺；而 `Lshortfile` 每行都要多一次 `runtime.Caller`。 +保留开关是因为同名文件太多——每个插件都有自己的 `plugin.go`， +只有行号能区分。 + ### 3.1 "消息发过去没反应" 按这个顺序查，**别跳步**：