From 53c0d77ef53acc4bf1bf1d9bcdcefa90d426e1ee Mon Sep 17 00:00:00 2001 From: Jan Novak Date: Mon, 24 Aug 2026 11:09:48 +0200 Subject: [PATCH] Enrich GCP wire logs with trace context from the request ctx Co-Authored-By: Claude --- .../2026-08-24-1025-otel-tracing.md | 11 +++- internal/provider/gcp/wirelog.go | 10 ++++ internal/provider/gcp/wirelog_test.go | 50 +++++++++++++++++++ 3 files changed, 70 insertions(+), 1 deletion(-) create mode 100644 internal/provider/gcp/wirelog_test.go diff --git a/docs/plans-executions/2026-08-24-1025-otel-tracing.md b/docs/plans-executions/2026-08-24-1025-otel-tracing.md index b1f7579..9de685a 100644 --- a/docs/plans-executions/2026-08-24-1025-otel-tracing.md +++ b/docs/plans-executions/2026-08-24-1025-otel-tracing.md @@ -9,7 +9,7 @@ Plan: `docs/plans/2026-08-24-1025-otel-tracing.md` - [x] Step 5 — Reconciler spans - [x] Step 6 — Discovery server - [x] Step 7 — GC + health -- [ ] Step 8 — GCP wire-log enrichment +- [x] Step 8 — GCP wire-log enrichment - [ ] Step 9 — Manifests + docs ## Step 1 — Dependencies @@ -146,3 +146,12 @@ uninstrumented so no traceparent can leak through a proxy to external targets. Probe→reconcile span links stay out of scope (GenericEvent carries no ctx; the workqueue coalesces events) — recorded in the architecture Decisions in Step 9. + +## Step 8 — GCP wire-log enrichment + +`wireFilterHandler.Handle` clones the record and appends `traceID`/`spanID` +when the ctx carries a valid span — same keys as the logr enrichment, added +before the elision pass (both values are well under the 1KiB threshold). +The new `wirelog_test.go` covers the enrichment, that the JWT/token security +filter still drops non-wire Debug records even with a span present, and that +spanless records stay unchanged. diff --git a/internal/provider/gcp/wirelog.go b/internal/provider/gcp/wirelog.go index d93423b..91f90b4 100644 --- a/internal/provider/gcp/wirelog.go +++ b/internal/provider/gcp/wirelog.go @@ -6,6 +6,7 @@ import ( "log/slog" "github.com/go-logr/logr" + "go.opentelemetry.io/otel/trace" ) // wireLogMaxFieldBytes is the elision threshold for string fields in wire @@ -47,6 +48,15 @@ func (h *wireFilterHandler) Handle(ctx context.Context, rec slog.Record) error { if rec.Level <= slog.LevelDebug && rec.Message != "api request" && rec.Message != "api response" { return nil } + // The SDK logs with the request ctx, so wire records can carry the + // surrounding provider span — the one place slog's ctx-aware handlers + // beat logr, and the same keys the logr enrichment uses. + if sc := trace.SpanContextFromContext(ctx); sc.IsValid() { + rec = rec.Clone() + rec.AddAttrs( + slog.String("traceID", sc.TraceID().String()), + slog.String("spanID", sc.SpanID().String())) + } if h.fullPayloads { return h.inner.Handle(ctx, rec) } diff --git a/internal/provider/gcp/wirelog_test.go b/internal/provider/gcp/wirelog_test.go new file mode 100644 index 0000000..3e597aa --- /dev/null +++ b/internal/provider/gcp/wirelog_test.go @@ -0,0 +1,50 @@ +package gcp + +import ( + "context" + "strings" + "testing" + + "github.com/go-logr/logr/funcr" + sdktrace "go.opentelemetry.io/otel/sdk/trace" +) + +func TestWireFilterHandler_addsTraceContext(t *testing.T) { + t.Parallel() + + var lines []string + base := funcr.New(func(prefix, args string) { + lines = append(lines, prefix+" "+args) + }, funcr.Options{Verbosity: 5}) + log := wireLogger(base, WireLogOptions{}) + + tp := sdktrace.NewTracerProvider() + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + ctx, span := tp.Tracer("test").Start(context.Background(), "provider.create") + defer span.End() + + log.DebugContext(ctx, "api request", "url", "https://compute.googleapis.com/x") + if len(lines) != 1 { + t.Fatalf("got %d lines, want 1: %v", len(lines), lines) + } + traceID := span.SpanContext().TraceID().String() + if !strings.Contains(lines[0], "traceID") || !strings.Contains(lines[0], traceID) { + t.Errorf("wire record missing trace context %s: %s", traceID, lines[0]) + } + + // The security filter must still win: non-wire Debug records are + // dropped even when a span is present. + log.DebugContext(ctx, "token exchange", "assertion", "secret-jwt") + if len(lines) != 1 { + t.Fatalf("filtered record leaked: %v", lines[1:]) + } + + // No span in ctx: record passes through without trace keys. + log.DebugContext(context.Background(), "api response", "status", 200) + if len(lines) != 2 { + t.Fatalf("got %d lines, want 2", len(lines)) + } + if strings.Contains(lines[1], "traceID") { + t.Errorf("spanless record must not carry traceID: %s", lines[1]) + } +}