From af1cd70986d189261d49b53d9fe011666246f6d0 Mon Sep 17 00:00:00 2001 From: youfak Date: Sun, 2 Aug 2026 14:29:10 +0800 Subject: [PATCH] feat: add secret-safe process logging --- README.md | 2 +- cmd/proxy-checker/main.go | 3 +- cmd/proxy-controller/main.go | 3 +- cmd/proxy-controller/main_test.go | 4 +- cmd/proxy-gateway/main.go | 3 +- docs/configuration/reference.md | 4 +- docs/development/implementation-plan.md | 7 +- docs/requirements/completion-audit.md | 3 +- docs/requirements/traceability.md | 2 +- findings.md | 10 +- internal/platform/logging/logging.go | 130 ++++++++++++++++++++++ internal/platform/logging/logging_test.go | 41 +++++++ progress.md | 9 +- 13 files changed, 204 insertions(+), 17 deletions(-) create mode 100644 internal/platform/logging/logging.go create mode 100644 internal/platform/logging/logging_test.go diff --git a/README.md b/README.md index 7be00af..6b96de7 100644 --- a/README.md +++ b/README.md @@ -105,7 +105,7 @@ flowchart LR ## 当前完成度 -截至 **2026-08-02**，实施计划中可直接勾选的检查项为 **57 / 74（77.0%）**。详情见 +截至 **2026-08-02**，实施计划中可直接勾选的检查项为 **58 / 74（78.4%）**。详情见 [实施计划](docs/development/implementation-plan.md)和 [交付完成度审计](docs/requirements/completion-audit.md)。 diff --git a/cmd/proxy-checker/main.go b/cmd/proxy-checker/main.go index bfd1e14..2af83bd 100644 --- a/cmd/proxy-checker/main.go +++ b/cmd/proxy-checker/main.go @@ -15,6 +15,7 @@ import ( controlplanev1 "proxy-pool/gen/controlplane/v1" "proxy-pool/internal/checker/bootstrap" "proxy-pool/internal/config" + "proxy-pool/internal/platform/logging" ) const ( @@ -81,7 +82,7 @@ func execute(ctx context.Context, args []string, getenv environmentLookup, run c if err == nil || (errors.Is(err, context.Canceled) && ctx.Err() != nil) { return 0 } - _, _ = fmt.Fprintf(stderr, "proxy-checker: %v\n", err) + logging.WriteProcessError(stderr, "proxy-checker", err) return 1 } diff --git a/cmd/proxy-controller/main.go b/cmd/proxy-controller/main.go index b9a8806..e35d031 100644 --- a/cmd/proxy-controller/main.go +++ b/cmd/proxy-controller/main.go @@ -13,6 +13,7 @@ import ( "proxy-pool/internal/config" "proxy-pool/internal/controller/bootstrap" + "proxy-pool/internal/platform/logging" ) const ( @@ -67,6 +68,6 @@ func execute( if err == nil || (errors.Is(err, context.Canceled) && ctx.Err() != nil) { return 0 } - _, _ = fmt.Fprintf(stderr, "proxy-controller: %v\n", err) + logging.WriteProcessError(stderr, "proxy-controller", err) return 1 } diff --git a/cmd/proxy-controller/main_test.go b/cmd/proxy-controller/main_test.go index b3bf0b1..1d6f8b7 100644 --- a/cmd/proxy-controller/main_test.go +++ b/cmd/proxy-controller/main_test.go @@ -75,7 +75,9 @@ func TestExecuteMapsStartupFailureAndSignalCancellation(t *testing.T) { ) error { return want }, &stderr) - if code != 1 || !bytes.Contains(stderr.Bytes(), []byte(want.Error())) { + if code != 1 || !bytes.Contains(stderr.Bytes(), []byte(`"msg":"process failed"`)) || + !bytes.Contains(stderr.Bytes(), []byte(`"component":"proxy-controller"`)) || + bytes.Contains(stderr.Bytes(), []byte(want.Error())) { t.Fatalf("execute(startup failure) = %d, stderr = %q", code, stderr.String()) } diff --git a/cmd/proxy-gateway/main.go b/cmd/proxy-gateway/main.go index 6735616..8658b6f 100644 --- a/cmd/proxy-gateway/main.go +++ b/cmd/proxy-gateway/main.go @@ -13,6 +13,7 @@ import ( "proxy-pool/internal/config" "proxy-pool/internal/gateway/bootstrap" + "proxy-pool/internal/platform/logging" ) const ( @@ -82,7 +83,7 @@ func execute( if err == nil || (errors.Is(err, context.Canceled) && ctx.Err() != nil) { return 0 } - _, _ = fmt.Fprintf(stderr, "proxy-gateway: %v\n", err) + logging.WriteProcessError(stderr, "proxy-gateway", err) return 1 } diff --git a/docs/configuration/reference.md b/docs/configuration/reference.md index a080dd8..8249022 100644 --- a/docs/configuration/reference.md +++ b/docs/configuration/reference.md @@ -531,7 +531,9 @@ Capacity 和 Drain 业务指标也已接入，所有标签均为固定枚举； Client、路由、目标 URL 或凭据标签。Capacity 从既有 Provider 库存对账循环聚合， 不进入 Gateway 热路径。Distribution 启用时 `/readyz` 只以 Redis 活动池为 服务流量门槛，PostgreSQL 故障由 Admin 接口独立报告。Metrics 开关或监听地址 -变更需要重启 Controller。 +变更需要重启 Controller。Controller、Gateway 和 Checker 的进程级致命错误以 JSON +结构化日志输出，包含组件和稳定错误类型，不输出错误原文；敏感属性、URL 用户信息和 +查询 Secret 在写出前统一替换为 `[REDACTED]`。 ## 10. 启动前校验清单 diff --git a/docs/development/implementation-plan.md b/docs/development/implementation-plan.md index ad58465..c725e40 100644 --- a/docs/development/implementation-plan.md +++ b/docs/development/implementation-plan.md @@ -206,7 +206,7 @@ Distribution/Admin 服务构造、错误合并和资源关闭。生产 Provider 组合 fixture 已验证隔离 Redis namespace 下的选主、Provider HTTP 调用、模板解析 和活动池写入。Controller Metrics 独立入口现已提供 `/livez`、`/readyz` 与基础 Prometheus 运行时指标，三监听器隔离已通过测试；Checker、Gateway、Drain、 -Provider、Extraction 与容量业务指标已接入，密钥安全的结构化日志仍待实现。双存储 bootstrap 已通过 PostgreSQL 18 + Redis 8.2 组合 fixture，覆盖 +Provider、Extraction 与容量业务指标已接入；进程级密钥安全结构化日志也已落地。双存储 bootstrap 已通过 PostgreSQL 18 + Redis 8.2 组合 fixture，覆盖 迁移、启动配置提交、Readiness、Admin Status 和 Metrics 探针。 WorkerControlPlane 现已接入 Controller 生命周期：Register、ACK 和 Runtime @@ -341,7 +341,7 @@ Supervisor 也改为同时服从静态配置与管理态，消除两条启停消 Grafana/HAProxy. - [ ] Add Kubernetes Deployments, Services, PDBs, HPA, NetworkPolicy, Secrets examples, probes, resource limits, topology spread, and graceful termination. -- [ ] Add low-cardinality Prometheus metrics and structured secret-safe logs. +- [x] Add low-cardinality Prometheus metrics and structured secret-safe logs. - [ ] Document backup, recovery, rollout, rollback, capacity, kernel, file descriptor, NAT/conntrack, and incident runbooks. @@ -356,7 +356,8 @@ Supervisor 也改为同时服从静态配置与管理态，消除两条启停消 `proxy_pool_controller_provider_new_proxies_total`；`class` 仅允许 `valid`、`empty`、 `duplicate_only`、`error`。Extraction 还暴露固定 `result` 的请求次数、请求数与响应 交付数，幂等重放按响应交付统计。容量指标由既有 Provider 库存对账周期聚合，不进入 -Gateway 热路径；仅密钥安全的结构化日志仍待补齐。 +Gateway 热路径。`platform/logging` 以 JSON `slog` 输出进程级致命错误，字段、URL +用户信息、查询 Secret 和错误对象均经过脱敏，且不在请求热路径逐条写日志。 ## Task 14: Documentation, Examples, and Diagrams diff --git a/docs/requirements/completion-audit.md b/docs/requirements/completion-audit.md index b0e527e..9be25b9 100644 --- a/docs/requirements/completion-audit.md +++ b/docs/requirements/completion-audit.md @@ -105,7 +105,8 @@ Controller/Gateway 入口，完整 mTLS 运行时拓扑仍只有静态验证。 `proxy-controller` 已完成 Admin/Distribution/Metrics 与 PostgreSQL/Redis 启动装配，`proxy-gateway` 已完成 HTTP/Metrics 与控制面 Session 装配；Checker、Gateway Outcome、Drain、Provider、 - Extraction 与 Capacity 的低基数业务指标已闭环，密钥安全的结构化日志仍待补齐。 + Extraction 与 Capacity 的低基数业务指标已闭环；Controller、Gateway、Checker 的 + 进程级致命错误现使用统一 JSON 脱敏日志出口，不输出错误原文。 2. Gateway 的生产连接池调优与代表性流量压测。 3. Provider 分布式 singleflight/Leader、长期凭据回收和累计额度执行器。 4. Controller 的 PostgreSQL 连接池、迁移和 pgx Adapter 启动装配已完成； diff --git a/docs/requirements/traceability.md b/docs/requirements/traceability.md index 4f8282b..a1fd3d5 100644 --- a/docs/requirements/traceability.md +++ b/docs/requirements/traceability.md @@ -87,5 +87,5 @@ | OPS-001 | 配置校验后构建不可变快照并原子替换 | 8959-8999 | 100k 索引、版本/epoch 与并发 Apply/Acquire 测试 | | OPS-002 | 优雅停机停止新请求/Fetch，等待现有流量后超时关闭 | 8981-9000 | Provider Run 收敛与 `Handler.Shutdown` HTTP 排空、Hijacked CONNECT 超时关闭测试 | | OPS-003 | PostgreSQL 只保存管理修订、Upstream/Routing 状态、Admin 审计与 Outbox | 当前会话 | ADR-006、`adminstate` 公用契约和六表 Schema 边界测试；真实 PostgreSQL 契约待完成 | -| OBS-001 | 指标禁止 Proxy IP、session、Client、完整 URL 高基数标签 | 9001-9029 | Controller Prometheus/探针模块已实现；Checker Collector 暴露固定等级和结果，Gateway Collector 暴露 `proxy_pool_gateway_outcomes_total{stage,result}` 与 `proxy_pool_gateway_outcome_queue_dropped_total`，Drain Collector 暴露 `proxy_pool_controller_drain_candidates_total{reason}` 与 `proxy_pool_controller_drains_started_total{reason}`，其中 reason 固定为 unhealthy/upstream_disabled；Provider Collector 暴露固定 class 的拉取次数与候选计数；Extraction Collector 暴露固定 result 的请求、请求数与交付数；Capacity Collector 按 Controller 进程聚合库存 Gauge，并只暴露固定 success/error 的库存读取结果，不把 Upstream 写成标签。注册表测试锁定标签集；密钥安全的结构化日志仍待实现 | +| OBS-001 | 指标禁止 Proxy IP、session、Client、完整 URL 高基数标签 | 9001-9029 | Controller Prometheus/探针模块已实现；Checker Collector 暴露固定等级和结果，Gateway Collector 暴露 `proxy_pool_gateway_outcomes_total{stage,result}` 与 `proxy_pool_gateway_outcome_queue_dropped_total`，Drain Collector 暴露 `proxy_pool_controller_drain_candidates_total{reason}` 与 `proxy_pool_controller_drains_started_total{reason}`，其中 reason 固定为 unhealthy/upstream_disabled；Provider Collector 暴露固定 class 的拉取次数与候选计数；Extraction Collector 暴露固定 result 的请求、请求数与交付数；Capacity Collector 按 Controller 进程聚合库存 Gauge，并只暴露固定 success/error 的库存读取结果，不把 Upstream 写成标签。`platform/logging` 使用 JSON `slog`，敏感字段、URL 用户信息、查询 Secret 和错误对象写出前均被脱敏；回归测试锁定标签集与 Secret 不泄露 | | TEST-001 | 覆盖对话中列出的 11 个关键并发与故障场景 | 9030-9082 | 测试清单；Redis 活动池由 Memory/Redis 公用契约覆盖，跨进程故障场景仍按清单推进 | diff --git a/findings.md b/findings.md index 7cdc54f..b21d59b 100644 --- a/findings.md +++ b/findings.md @@ -54,17 +54,21 @@ Extract 请求使用哪些 Upstream。 - Provider 拉取结果只按固定 `class` 聚合：`valid`、`empty`、`duplicate_only`、`error`。 指标分别记录拉取结果次数、合法候选数和新入池代理数，不按 Upstream、Proxy、IP、错误 文本或凭据拆分。 -- Provider 指标已完成；密钥安全的结构化日志仍待实现。 +- Provider 指标已完成。 - Extraction 只按固定 `result` 聚合请求：`complete`、`partial`、`empty`、 `insufficient`、`idempotency_conflict`、`rate_limited`、`unavailable`、`invalid`、 `error`。计数只记录请求数量和响应交付数量；幂等重放不被误记为新的 Proxy 消费。 -- Extraction 指标已完成；密钥安全的结构化日志仍待实现。 +- Extraction 指标已完成。 - 容量指标由 Provider 库存对账循环采样，聚合 managed、available、effective、pending 与 active Upstream Gauge。Upstream ID 仅保留在 Controller 进程内用于聚合替换和 任期结束清理，不输出为 Prometheus 标签；读取结果只允许 `success` 或 `error`。 -- 容量指标已完成；密钥安全的结构化日志仍待实现。 +- 容量指标已完成。 + +- 进程级致命错误统一经 JSON `slog` 输出；敏感属性、错误对象、URL 用户信息和查询 + Secret 在写出前脱敏。该出口只用于生命周期边界，不在 Gateway/Distribution 请求热路径 + 逐条写日志。 ## 集群与性能 diff --git a/internal/platform/logging/logging.go b/internal/platform/logging/logging.go new file mode 100644 index 0000000..d7b8dfa --- /dev/null +++ b/internal/platform/logging/logging.go @@ -0,0 +1,130 @@ +package logging + +import ( + "context" + "io" + "log/slog" + "reflect" + "regexp" + "strings" + "unicode" +) + +const redacted = "[REDACTED]" + +var ( + urlCredentialPattern = regexp.MustCompile(`(?i)([a-z][a-z0-9+.-]*://)([^/@\s:]+)(?::[^@/\s]*)?@`) + secretAssignment = regexp.MustCompile(`(?i)\b(password|token|secret|authorization|api[_-]?key)\b\s*[:=]\s*(?:"[^"]*"|'[^']*'|[^\s,;&]+)`) + bearerValue = regexp.MustCompile(`(?i)\bbearer\s+[^\s,;]+`) +) + +// NewJSONLogger returns a structured logger that redacts sensitive fields and +// recognizable secret material before delegating to the JSON handler. +func NewJSONLogger(writer io.Writer) *slog.Logger { + if writer == nil { + writer = io.Discard + } + return slog.New(&redactingHandler{next: slog.NewJSONHandler(writer, nil)}) +} + +// WriteProcessError emits one structured process-level failure. It is for +// lifecycle boundaries only and must not be called for per-request failures. +func WriteProcessError(writer io.Writer, component string, err error) { + NewJSONLogger(writer).Error("process failed", "component", component, "error_type", errorType(err)) +} + +type redactingHandler struct{ next slog.Handler } + +func (handler *redactingHandler) Enabled(ctx context.Context, level slog.Level) bool { + return handler != nil && handler.next != nil && handler.next.Enabled(ctx, level) +} + +func (handler *redactingHandler) Handle(ctx context.Context, record slog.Record) error { + if handler == nil || handler.next == nil { + return nil + } + clean := slog.NewRecord(record.Time, record.Level, record.Message, record.PC) + record.Attrs(func(attribute slog.Attr) bool { + clean.AddAttrs(sanitizeAttribute(attribute)) + return true + }) + return handler.next.Handle(ctx, clean) +} + +func (handler *redactingHandler) WithAttrs(attributes []slog.Attr) slog.Handler { + if handler == nil || handler.next == nil { + return handler + } + return &redactingHandler{next: handler.next.WithAttrs(sanitizeAttributes(attributes))} +} + +func (handler *redactingHandler) WithGroup(name string) slog.Handler { + if handler == nil || handler.next == nil { + return handler + } + return &redactingHandler{next: handler.next.WithGroup(name)} +} + +func sanitizeAttributes(attributes []slog.Attr) []slog.Attr { + result := make([]slog.Attr, 0, len(attributes)) + for _, attribute := range attributes { + result = append(result, sanitizeAttribute(attribute)) + } + return result +} + +func sanitizeAttribute(attribute slog.Attr) slog.Attr { + if sensitiveKey(attribute.Key) { + return slog.String(attribute.Key, redacted) + } + switch attribute.Value.Kind() { + case slog.KindString: + return slog.String(attribute.Key, sanitizeText(attribute.Value.String())) + case slog.KindAny: + if _, ok := attribute.Value.Any().(error); ok { + return slog.String(attribute.Key, redacted) + } + case slog.KindGroup: + return slog.Attr{Key: attribute.Key, Value: slog.GroupValue(sanitizeAttributes(attribute.Value.Group())...)} + } + return attribute +} + +func sensitiveKey(key string) bool { + switch normalizeKey(key) { + case "password", "passphrase", "token", "apitoken", "apikey", "authorization", "secret", "credential", "credentials", "privatekey", "error", "err": + return true + default: + return false + } +} + +func errorType(err error) string { + if err == nil { + return "" + } + return reflect.TypeOf(err).String() +} + +func normalizeKey(value string) string { + var normalized strings.Builder + normalized.Grow(len(value)) + for _, character := range value { + if unicode.IsLetter(character) || unicode.IsDigit(character) { + normalized.WriteRune(unicode.ToLower(character)) + } + } + return normalized.String() +} + +func sanitizeText(value string) string { + value = urlCredentialPattern.ReplaceAllString(value, "${1}"+redacted+"@") + value = secretAssignment.ReplaceAllStringFunc(value, func(match string) string { + separator := strings.IndexAny(match, ":=") + if separator < 0 { + return redacted + } + return match[:separator+1] + redacted + }) + return bearerValue.ReplaceAllString(value, "Bearer "+redacted) +} diff --git a/internal/platform/logging/logging_test.go b/internal/platform/logging/logging_test.go new file mode 100644 index 0000000..66e0567 --- /dev/null +++ b/internal/platform/logging/logging_test.go @@ -0,0 +1,41 @@ +package logging + +import ( + "bytes" + "errors" + "strings" + "testing" +) + +func TestJSONLoggerRedactsSensitiveAttributesAndErrorText(t *testing.T) { + var output bytes.Buffer + logger := NewJSONLogger(&output) + logger.Error("provider fetch failed", + "password", "password-marker", + "apiToken", "token-marker", + "provider_url", "https://user:proxy-secret@example.test/path?api_key=query-secret", + "error", errors.New("unmarked-secret authorization=header-secret bearer bearer-secret"), + ) + + text := output.String() + for _, secret := range []string{"password-marker", "token-marker", "proxy-secret", "query-secret", "unmarked-secret", "header-secret", "bearer-secret"} { + if strings.Contains(text, secret) { + t.Fatalf("structured log leaked %q: %s", secret, text) + } + } + if !strings.Contains(text, "[REDACTED]") || !strings.Contains(text, `"msg":"provider fetch failed"`) { + t.Fatalf("structured log did not preserve message and redaction: %s", text) + } +} + +func TestWriteProcessErrorProducesStructuredRedactedEvent(t *testing.T) { + var output bytes.Buffer + WriteProcessError(&output, "proxy-controller", errors.New("unmarked-secret")) + text := output.String() + if strings.Contains(text, "unmarked-secret") { + t.Fatalf("process error was not redacted: %s", text) + } + if !strings.Contains(text, `"msg":"process failed"`) || !strings.Contains(text, `"component":"proxy-controller"`) { + t.Fatalf("process error is not structured: %s", text) + } +} diff --git a/progress.md b/progress.md index 16007fe..5124c80 100644 --- a/progress.md +++ b/progress.md @@ -6,18 +6,21 @@ 进程级 managed/available/effective/pending/active Gauge，失败只增加固定 `success`/`error` 的读取计数。Upstream 仅用于进程内聚合，领导任期结束即清除， 不成为 Prometheus 标签；不进入 Gateway 10 万 QPS 容量热路径，也不增加 Redis 查询。 - 密钥安全的结构化日志仍待实现。 - Extraction 可观测性已接入公用 `MetricsObserver`：Controller 暴露固定 `result` 的请求计数、请求 Proxy 总数和响应交付 Proxy 总数。事件在服务单一出口分类，覆盖 complete/partial/empty/insufficient/idempotency_conflict/rate_limited/unavailable/ invalid/error；不带 Client、Request、Filter、Upstream、Proxy 或错误文本标签。 - 幂等重放统计响应交付而不误计为新的 Redis 消费。密钥安全结构化日志仍待实现。 + 幂等重放统计响应交付而不误计为新的 Redis 消费。 - Provider 拉取可观测性已接入公用 `ResultObserver`：Controller 暴露 `proxy_pool_controller_provider_fetch_results_total{class}`、 `proxy_pool_controller_provider_valid_candidates_total` 与 `proxy_pool_controller_provider_new_proxies_total`。`class` 仅允许 `valid`、`empty`、 `duplicate_only`、`error`；指标不包含 Upstream、Proxy、IP、错误文本或凭据标签。 - Provider 指标已完成；密钥安全的结构化日志仍待实现。 + Provider 指标已完成。 +- 新增统一 JSON 结构化日志出口：Controller、Gateway、Checker 的进程级致命错误只输出 + 组件和稳定错误类型，不输出原始错误文本。敏感字段、错误对象、Bearer、URL 用户信息和 + 查询 Secret 均由 `platform/logging` 脱敏；回归验证使用真实 Secret 标记，且不在请求 + 热路径逐条写日志。 - 已实现管理态驱动的即时完整快照刷新：`SnapshotRefreshBroker` 以每个 Worker 流一格的 非阻塞通道广播，连续变更自动合并。Admin 成功提交 Upstream 启停、Routing 切换和配置 发布时触发通知；Worker 保留原有定时刷新作为失效保护。Routing 切换不按旧 Upstream