diff --git a/internal/runtime/trace/redact.go b/internal/runtime/trace/redact.go index 563adbe..ff1bf59 100644 --- a/internal/runtime/trace/redact.go +++ b/internal/runtime/trace/redact.go @@ -62,7 +62,27 @@ func IsSecretKey(key string) bool { // to maxSummaryRunes, so a published string can never carry a secret or an // unbounded blob. func RedactText(s string) string { - return truncate(redactSecrets(s), maxSummaryRunes) + return RedactTextLimited(s, maxSummaryRunes) +} + +// RedactTextLimited 是 RedactText 的**带上限**形态:同一套凭据形状清洗,截断长度 +// 由调用方给。它存在的理由是两个读面要的不是同一种东西 —— +// +// - **出图 / 摘要面**(span props、事件正文、工具结果摘要)要的是摘要 ⇒ +// `maxSummaryRunes`(80)足够,且保证一屏可读。这些调用方继续用 `RedactText`; +// - **日志面**(`GET /admin/observability/logs` 的一行)要的是**可排障的全文** ⇒ +// 80 会把长错误行拦腰截断,等于丢掉诊断信息。 +// +// 但它绝不接受「无上限散用」:一条日志可能是 `%v` 出来的 MiB 级对象,原样塞进 +// JSON 响应会撑爆面板的帧与响应体。因此上限**必须由调用方显式给出**并写清理由 +// (网关侧见 `maxLogMsgRunes`)。 +// +// limit <= 0 表示**不截断**(只打码),留给「体积已由自己界定」的调用方。 +// +// 🔴 清洗逻辑仍然只有一份(redactSecrets):上限是参数,不是第二条脱敏路径 —— +// 另写一套必然漂移,而漂移的方向总是「其中一面开始原样吐凭据」。 +func RedactTextLimited(s string, limit int) string { + return truncate(redactSecrets(s), limit) } // RedactEvent returns ev with every string value — including those nested in maps diff --git a/internal/services/gateway/observability_logs.go b/internal/services/gateway/observability_logs.go index f62ee35..61fc529 100644 --- a/internal/services/gateway/observability_logs.go +++ b/internal/services/gateway/observability_logs.go @@ -16,6 +16,17 @@ import ( const ( defaultLogLimit = 200 maxLogLimit = 1000 + // maxLogMsgRunes 是日志页**单行 msg** 的截断上限(M42 r2)。 + // + // 🔴 为什么不是 80:`trace.RedactText` 的 80 rune 是**出图摘要**那一档(span + // props / 工具结果摘要要的是「一眼看完的摘要」),而日志页是**排障面** —— + // 把一条长错误行拦腰截断就是丢诊断信息(实测一条 500 rune 的上游报错会被切到 + // 80 + 省略号,恰好切掉「谁拒了、为什么」)。 + // + // 🔴 为什么也不是无上限:单条日志可能是 `%v` 一个大对象(MiB 级),面板一次 + // 要 1000 条 ⇒ 原样透出会把 JSON 响应撑到 GB 量级。4096 rune 足够装下完整的 + // 技术栈 / 长错误行 / 一次请求的回显,而 4096 × 1000 条仍只是几 MB 量级。 + maxLogMsgRunes = 4096 ) // AdminLogEntry 是 GET /api/v1/admin/observability/logs 中一个条目的 @@ -94,22 +105,24 @@ func (s *Server) adminObservabilityLogs(w http.ResponseWriter, r *http.Request) // adminLogOf 把捕获的日志条目映射为驼峰式管理线上结构。 // // 🔴 读侧脱敏(M42 #3):`msg` 是日志正文,也是唯一可能夹带凭据/正文的字段 -// (本仓有过「把上游报文整段打进日志」的先例),因此出面板前过一遍 -// `trace.RedactText` —— 与写侧(trace.JSONRecorder)**同一个函数**,不另写一套; -// 两套脱敏必然漂移,而漂移的方向总是「其中一面开始原样吐凭据」。 +// (本仓有过「把上游报文整段打进日志」的先例),因此出面板前过一遍 trace 包的 +// 共享清洗 —— 与写侧同一条路径,**不另写一套**:两套脱敏必然漂移,而漂移的方向 +// 总是「其中一面开始原样吐凭据」。 +// +// 🔴 上限与出图摘要**故意不同**(M42 r2,塔 2026-10-26 裁定):这里用 +// `trace.RedactTextLimited(msg, maxLogMsgRunes)`(4096),而不是 `RedactText` +// 的 80 —— 日志页是排障面,80 会把长错误行拦腰截断(实质性 UX 回归)。出图那一侧 +// (span props / 摘要)仍是 80,两边**不该被统一**:一个要摘要,一个要全文。 // // 排障字段一律保住:`time`(RFC3339)、`level`、`source`(模块来源标签,编译期 // 常量构成,不含内容)原样透出,且 `msg` 的打码不改变条目条数、排序与级别过滤 // —— 面板因此照旧可诊断「谁在什么时候按什么级别报了哪一类错」。 -// -// 注意 `RedactText` 同时按 `maxSummaryRunes` 截断(与出图/落盘同一口径):超长 -// 正文会带省略号。这是复用同一个 helper 的既定代价,远小于「凭据原样上面板」。 func adminLogOf(e logger.Entry) AdminLogEntry { return AdminLogEntry{ Time: e.Time.UTC().Format(time.RFC3339), Level: e.Level, Source: e.Source, - Msg: trace.RedactText(e.Msg), + Msg: trace.RedactTextLimited(e.Msg, maxLogMsgRunes), } } diff --git a/internal/services/gateway/observability_redact_test.go b/internal/services/gateway/observability_redact_test.go index 2a73637..7da6179 100644 --- a/internal/services/gateway/observability_redact_test.go +++ b/internal/services/gateway/observability_redact_test.go @@ -26,6 +26,7 @@ import ( "strings" "testing" "time" + "unicode/utf8" "git.yeij.top/AskaEth/Cyrene_v2/internal/auth" "git.yeij.top/AskaEth/Cyrene_v2/internal/logger" @@ -193,3 +194,113 @@ func TestAdminObservabilityTrace_RedactsPropsAndEvents(t *testing.T) { t.Fatalf("事件非正文键 ok 应原样保留:%+v", sp.Events[0].Props) } } + +// obsLogTailMarker 是长日志行**末尾**的哨兵:按 80 rune 截断必然把它切掉,按 +// 4096(`maxLogMsgRunes`)必然留下它 —— 它就是「这一行有没有被拦腰截断」的判据。 +const obsLogTailMarker = "TAIL_OF_LONG_LOG_LINE" + +// longLogMsg 造一条 ~500 rune 的日志行:凭据放在**行首**(所以 80 rune 截断也能 +// 打码成功,红的是「截断」这一条而不是「没打码」),末尾带哨兵 —— 一旦被切到 80, +// 哨兵必然消失,判据因此指向问题本身。 +// 「排障上下文一行 」是 8 rune,×60 = 480 rune ⇒ 远超 80 的摘要上限。 +func longLogMsg() string { + return "upstream rejected " + obsLeakKey + " " + + strings.Repeat("排障上下文一行 ", 60) + obsLogTailMarker +} + +// TestAdminObservabilityLogs_LongLineKeepsFullText 钉住日志页的**上限与出图不同** +// (M42 r2,塔 2026-10-26 裁定):日志页是排障面,一条 500 rune 的错误行必须完整 +// 保留(凭据仍然打码),不能被 `maxSummaryRunes`(80)拦腰截断。 +// +// 变异:把 `adminLogOf` 改回 `trace.RedactText`(80)⇒ 本用例必红(末尾哨兵消失、 +// rune 数掉到 81)。 +func TestAdminObservabilityLogs_LongLineKeepsFullText(t *testing.T) { + t.Parallel() + srv, ts, jwt := buildEnv(t, cfgDefault(), Deps{}) + ring := logger.NewRingBuffer(8) + log := logger.New(logger.Options{Level: "debug", Format: "text", Out: io.Discard, Ring: ring}) + msg := longLogMsg() + if utf8.RuneCountInString(msg) <= maxLogMsgRunes/8 { + t.Fatalf("夹具只有 %d rune,不足以证明「不被 80 截断」", utf8.RuneCountInString(msg)) + } + log.Error(msg) + srv.SetLogBuffer(ring) + tok := signAny(t, jwt, "acct", auth.RoleOwner) + + resp, body := doReq(t, http.MethodGet, ts.URL+"/api/v1/admin/observability/logs", nil, tok) + if resp.StatusCode != http.StatusOK { + t.Fatalf("status = %d, want 200 (body=%s)", resp.StatusCode, body) + } + var env logEnvelope + if err := json.Unmarshal(body, &env); err != nil { + t.Fatalf("decode: %v (body=%s)", err, body) + } + if len(env.Data) != 1 { + t.Fatalf("日志条数 = %d, want 1", len(env.Data)) + } + got := env.Data[0].Msg + if strings.Contains(got, obsLeakPrefix) { + t.Fatalf("长行里的凭据没打码(%q):%q", obsLeakPrefix, got) + } + if !strings.Contains(got, "[redacted]") { + t.Fatalf("长行里的凭据位置应换成 [redacted]:%q", got) + } + if !strings.Contains(got, obsLogTailMarker) { + t.Fatalf("日志页把 %d rune 的行截断了(末尾哨兵 %q 消失),拿到 %d rune:…%s", + utf8.RuneCountInString(msg), obsLogTailMarker, utf8.RuneCountInString(got), + string([]rune(got)[max(0, utf8.RuneCountInString(got)-20):])) + } + // 长度只允许差「凭据 → [redacted]」那一处替换,不许多掉任何东西。 + wantLen := utf8.RuneCountInString(msg) - utf8.RuneCountInString(obsLeakKey) + + utf8.RuneCountInString("[redacted]") + if n := utf8.RuneCountInString(got); n != wantLen { + t.Fatalf("日志行 rune 数 = %d, want %d(只允许打码带来的差额,不许截断)", n, wantLen) + } +} + +// TestAdminObservabilityTrace_PropsStayAtSummaryBound 是上一条的**对偶**:日志页 +// 的上限调大到 4096 之后,出图这一侧(span props)不许被顺手统一 —— 那里要的是 +// 摘要(`maxSummaryRunes` = 80),不是一个更长的全文。 +// +// 变异:把 `maxSummaryRunes` 提到 4096(或让出图侧改用日志上限)⇒ 本用例必红。 +func TestAdminObservabilityTrace_PropsStayAtSummaryBound(t *testing.T) { + t.Parallel() + srv, ts, jwt := buildEnv(t, cfgDefault(), Deps{}) + started := time.Date(2026, 10, 26, 3, 4, 5, 0, time.UTC) + long := strings.Repeat("摘", 200) + srv.ObserveSpan(trace.SpanRecord{ + ID: "span-bound", + Name: "tool.execution", + Kind: trace.SpanKindTool, + Status: trace.SpanStatusOK, + StartedAt: started, + EndedAt: started.Add(time.Millisecond), + Duration: time.Millisecond, + Props: map[string]any{"tool": "web_search", "args_summary": long}, + }) + tok := signAny(t, jwt, "acct", auth.RoleOwner) + + resp, body := doReq(t, http.MethodGet, ts.URL+"/api/v1/admin/observability/trace", nil, tok) + if resp.StatusCode != http.StatusOK { + t.Fatalf("status = %d, want 200 (body=%s)", resp.StatusCode, body) + } + var env struct { + Data []AdminTraceSpan `json:"data"` + } + if err := json.Unmarshal(body, &env); err != nil { + t.Fatalf("decode: %v (body=%s)", err, body) + } + if len(env.Data) != 1 { + t.Fatalf("span 条数 = %d, want 1", len(env.Data)) + } + summary, _ := env.Data[0].Props["args_summary"].(string) + // 80 是 trace 包的摘要上限(`maxSummaryRunes`,未导出 ⇒ 这里按契约写常量)。 + const summaryBound = 80 + if n := utf8.RuneCountInString(summary); n != summaryBound+1 { + t.Fatalf("args_summary rune 数 = %d, want %d(%d rune 摘要 + 省略号)—— "+ + "出图侧不许跟日志页一起放宽到 %d", n, summaryBound+1, summaryBound, maxLogMsgRunes) + } + if !strings.HasSuffix(summary, "…") { + t.Fatalf("截断结果应以省略号收尾:%q", summary) + } +}