From 6b34f68469cdf29f0fc2eaeed7ce28712777825d Mon Sep 17 00:00:00 2001 From: Jan Novak Date: Mon, 24 Aug 2026 10:43:55 +0200 Subject: [PATCH] Add internal/tracing: env-gated OTel setup, span/log helpers, decorators Co-Authored-By: Claude --- .../2026-08-24-1025-otel-tracing.md | 29 +++- internal/tracing/http.go | 41 +++++ internal/tracing/http_test.go | 82 ++++++++++ internal/tracing/logger.go | 63 ++++++++ internal/tracing/logger_test.go | 136 +++++++++++++++++ internal/tracing/options.go | 48 ++++++ internal/tracing/reconciler.go | 52 +++++++ internal/tracing/reconciler_test.go | 86 +++++++++++ internal/tracing/tracing.go | 140 ++++++++++++++++++ internal/tracing/tracing_test.go | 129 ++++++++++++++++ internal/tracing/transport.go | 51 +++++++ internal/tracing/transport_test.go | 73 +++++++++ 12 files changed, 929 insertions(+), 1 deletion(-) create mode 100644 internal/tracing/http.go create mode 100644 internal/tracing/http_test.go create mode 100644 internal/tracing/logger.go create mode 100644 internal/tracing/logger_test.go create mode 100644 internal/tracing/options.go create mode 100644 internal/tracing/reconciler.go create mode 100644 internal/tracing/reconciler_test.go create mode 100644 internal/tracing/tracing.go create mode 100644 internal/tracing/tracing_test.go create mode 100644 internal/tracing/transport.go create mode 100644 internal/tracing/transport_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 b36a61c..39021a4 100644 --- a/docs/plans-executions/2026-08-24-1025-otel-tracing.md +++ b/docs/plans-executions/2026-08-24-1025-otel-tracing.md @@ -3,7 +3,7 @@ Plan: `docs/plans/2026-08-24-1025-otel-tracing.md` - [x] Step 1 — Dependencies -- [ ] Step 2 — New package `internal/tracing` +- [x] Step 2 — New package `internal/tracing` - [ ] Step 3 — `provider.WithTracing` decorator - [ ] Step 4 — `cmd/main.go` wiring - [ ] Step 5 — Reconciler spans @@ -40,3 +40,30 @@ modules again; the Step 2 tidy re-added them. The plan's semconv question resolved to `semconv/v1.43.0` — that's what `sdk@v1.45.0/resource/builtin.go` imports, so first-party code uses the same version to avoid `ErrSchemaURLConflict` in the common path. + +## Step 2 — `internal/tracing` package + +Landed as planned: `tracing.go` (env-gated `Setup`, hand-rolled exporter +selection), `logger.go` (`Start`/`StartSpan`/`ContextWithLogger` with the +base-logger ctx key that prevents duplicate `traceID` zap fields on nested +spans), `reconciler.go`, `transport.go`, `http.go`, `options.go`; tests for +all of it (first use of `sdk/trace/tracetest` in the repo). + +Two deviations from the plan's letter: + +- **k8s transport gating is a custom RoundTripper, not `otelhttp.WithFilter`** + (`parentGatedTransport`): requests without a parent span bypass the otel + transport entirely, so the no-root-spans-from-informers guarantee doesn't + depend on otelhttp filter semantics for transports. +- **`HTTPMiddleware` must copy the route pattern back.** The logger-injecting + inner handler wraps the request via `WithContext` (a shallow copy), so the + mux records the matched pattern on the copy while otelhttp's post-routing + span rename reads the original. Found by the middleware test (span named + `"GET"` instead of `"GET /v1/things/{id}"`); fixed with `r.Pattern = + r2.Pattern` after `next.ServeHTTP`. + +Also: both the transport and the middleware pass explicit W3C propagators +instead of relying on the global, so behavior is deterministic under tests +and when tracing is disabled. `Setup` tests reset the global provider to a +fresh noop per case — restoring otel's own default delegate triggers a +"Setting tracer provider to its current value" warning from the SDK. diff --git a/internal/tracing/http.go b/internal/tracing/http.go new file mode 100644 index 0000000..bcad955 --- /dev/null +++ b/internal/tracing/http.go @@ -0,0 +1,41 @@ +package tracing + +import ( + "net/http" + + "github.com/go-logr/logr" + "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" + "go.opentelemetry.io/otel/propagation" +) + +// HTTPMiddleware returns middleware that opens a server span per request +// (named from the mux route pattern once routing has happened) and hands +// handlers a request context whose logf.FromContext logger is base enriched +// with the trace context. Incoming W3C traceparent headers are honored, so +// clients see their own trace continue into the operator. /healthz is never +// traced. With tracing disabled the middleware degrades to injecting base +// unenriched — handlers can rely on logf.FromContext either way. +func HTTPMiddleware(operation string, base logr.Logger, opts ...Option) func(http.Handler) http.Handler { + o := newOptions(opts) + return func(next http.Handler) http.Handler { + inner := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + r2 := r.WithContext(ContextWithLogger(r.Context(), base)) + next.ServeHTTP(w, r2) + // WithContext copies the request, so the mux recorded the matched + // route on r2; surface it to otelhttp, which renames the span + // from r.Pattern after the handler returns. + r.Pattern = r2.Pattern + }) + otelOpts := []otelhttp.Option{ + otelhttp.WithFilter(func(r *http.Request) bool { return r.URL.Path != "/healthz" }), + // Explicit propagators: deterministic regardless of whether the + // global propagator has been installed (tests, disabled tracing). + otelhttp.WithPropagators(propagation.NewCompositeTextMapPropagator( + propagation.TraceContext{}, propagation.Baggage{})), + } + if o.tp != nil { + otelOpts = append(otelOpts, otelhttp.WithTracerProvider(o.tp)) + } + return otelhttp.NewHandler(inner, operation, otelOpts...) + } +} diff --git a/internal/tracing/http_test.go b/internal/tracing/http_test.go new file mode 100644 index 0000000..de9a1d9 --- /dev/null +++ b/internal/tracing/http_test.go @@ -0,0 +1,82 @@ +package tracing + +import ( + "context" + "net/http" + "net/http/httptest" + "strings" + "testing" + + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + logf "sigs.k8s.io/controller-runtime/pkg/log" +) + +const sampleTraceparent = "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01" + +func TestHTTPMiddleware(t *testing.T) { + t.Parallel() + + newServer := func(lines *[]string, tp *sdktrace.TracerProvider) http.Handler { + mux := http.NewServeMux() + handler := func(w http.ResponseWriter, r *http.Request) { + logf.FromContext(r.Context()).Info("handling") + w.WriteHeader(http.StatusOK) + } + mux.HandleFunc("GET /healthz", handler) + mux.HandleFunc("GET /v1/things/{id}", handler) + return HTTPMiddleware("discovery", captureLogger(lines), WithTracerProvider(tp))(mux) + } + + t.Run("route span, enriched handler logs, traceparent continuation", func(t *testing.T) { + t.Parallel() + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + + var lines []string + rec := httptest.NewRecorder() + req := httptest.NewRequest(http.MethodGet, "/v1/things/42", nil) + req.Header.Set("traceparent", sampleTraceparent) + newServer(&lines, tp).ServeHTTP(rec, req) + + ended := sr.Ended() + if len(ended) != 1 { + t.Fatalf("got %d spans, want 1", len(ended)) + } + if got := ended[0].Name(); got != "GET /v1/things/{id}" { + t.Errorf("span name = %q, want route pattern", got) + } + wantTrace := "4bf92f3577b34da6a3ce929d0e0e4736" + if got := ended[0].SpanContext().TraceID().String(); got != wantTrace { + t.Errorf("span traceID = %s, want continuation of client trace %s", got, wantTrace) + } + if len(lines) != 1 { + t.Fatalf("got %d log lines, want 1: %v", len(lines), lines) + } + if n := strings.Count(lines[0], `"traceID"`); n != 1 { + t.Errorf("traceID appears %d times, want 1: %s", n, lines[0]) + } + if !strings.Contains(lines[0], wantTrace) { + t.Errorf("handler log missing traceID %s: %s", wantTrace, lines[0]) + } + }) + + t.Run("healthz is not traced but still gets a logger", func(t *testing.T) { + t.Parallel() + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + + var lines []string + rec := httptest.NewRecorder() + newServer(&lines, tp).ServeHTTP(rec, httptest.NewRequest(http.MethodGet, "/healthz", nil)) + + if len(sr.Ended()) != 0 { + t.Fatalf("healthz produced %d spans, want 0", len(sr.Ended())) + } + if len(lines) != 1 || strings.Contains(lines[0], "traceID") { + t.Fatalf("want one unenriched log line, got %v", lines) + } + }) +} diff --git a/internal/tracing/logger.go b/internal/tracing/logger.go new file mode 100644 index 0000000..042bd1d --- /dev/null +++ b/internal/tracing/logger.go @@ -0,0 +1,63 @@ +package tracing + +import ( + "context" + + "github.com/go-logr/logr" + "go.opentelemetry.io/otel/trace" + logf "sigs.k8s.io/controller-runtime/pkg/log" +) + +// baseLoggerKey stores the pre-enrichment logger. logr sinks never see a +// context, so trace IDs must ride on the logger as WithValues — and zap does +// not dedupe repeated keys, so each nested span must re-derive from the same +// base instead of stacking traceID/spanID onto an already-enriched logger. +type baseLoggerKey struct{} + +// Start begins a span from the global tracer and returns a context whose +// logf.FromContext logger carries the span's traceID/spanID. With tracing +// disabled the span is a no-op with an invalid span context and the logger +// is left untouched. +// +// Trade-off, documented: values pushed via logf.IntoContext *between* two +// Start calls are dropped by the inner Start's re-derivation. Nothing +// first-party does that; controller-runtime's per-reconcile logger +// (reconcileID etc.) is captured as the base and survives. +func Start(ctx context.Context, name string, opts ...trace.SpanStartOption) (context.Context, trace.Span) { + return StartSpan(ctx, newOptions(nil).tracer(), name, opts...) +} + +// StartSpan is Start with an explicit tracer, for decorators that carry +// their own (test-injected) TracerProvider. +func StartSpan(ctx context.Context, tracer trace.Tracer, name string, opts ...trace.SpanStartOption) (context.Context, trace.Span) { + ctx, span := tracer.Start(ctx, name, opts...) + sc := span.SpanContext() + if !sc.IsValid() { + return ctx, span + } + base, ok := ctx.Value(baseLoggerKey{}).(logr.Logger) + if !ok { + base = logf.FromContext(ctx) + ctx = context.WithValue(ctx, baseLoggerKey{}, base) + } + return logf.IntoContext(ctx, withSpanValues(base, sc)), span +} + +// ContextWithLogger seeds ctx with base as both the current logger and the +// base for span enrichment. If ctx already carries a valid span (the HTTP +// middleware calls this inside the otelhttp handler), the logger is +// enriched immediately. +func ContextWithLogger(ctx context.Context, base logr.Logger) context.Context { + ctx = context.WithValue(ctx, baseLoggerKey{}, base) + if sc := trace.SpanContextFromContext(ctx); sc.IsValid() { + return logf.IntoContext(ctx, withSpanValues(base, sc)) + } + return logf.IntoContext(ctx, base) +} + +// withSpanValues uses lowerCamel keys to match the house style +// (reconcileID, providerID); Grafana/Loki derived fields must match +// "traceID", not the trace_id default. +func withSpanValues(base logr.Logger, sc trace.SpanContext) logr.Logger { + return base.WithValues("traceID", sc.TraceID().String(), "spanID", sc.SpanID().String()) +} diff --git a/internal/tracing/logger_test.go b/internal/tracing/logger_test.go new file mode 100644 index 0000000..555fa38 --- /dev/null +++ b/internal/tracing/logger_test.go @@ -0,0 +1,136 @@ +package tracing + +import ( + "context" + "strings" + "testing" + + "github.com/go-logr/logr" + "github.com/go-logr/logr/funcr" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + "go.opentelemetry.io/otel/trace" + "go.opentelemetry.io/otel/trace/noop" + logf "sigs.k8s.io/controller-runtime/pkg/log" +) + +// captureLogger records every emitted line so tests can assert on the +// rendered key/value output — the only place duplicate zap-style keys +// would show up. +func captureLogger(lines *[]string) logr.Logger { + return funcr.New(func(prefix, args string) { + *lines = append(*lines, prefix+" "+args) + }, funcr.Options{}) +} + +func recordingTracer(t *testing.T) (trace.Tracer, *tracetest.SpanRecorder) { + t.Helper() + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + return tp.Tracer("test"), sr +} + +func TestStartSpan_enrichesLoggerOncePerNesting(t *testing.T) { + t.Parallel() + tracer, sr := recordingTracer(t) + + var lines []string + ctx := logf.IntoContext(context.Background(), captureLogger(&lines)) + + ctx1, span1 := StartSpan(ctx, tracer, "outer") + logf.FromContext(ctx1).Info("outer work") + + ctx2, span2 := StartSpan(ctx1, tracer, "inner") + logf.FromContext(ctx2).Info("inner work") + + span2.End() + span1.End() + + if len(lines) != 2 { + t.Fatalf("got %d log lines, want 2: %v", len(lines), lines) + } + traceID := span1.SpanContext().TraceID().String() + for i, want := range []string{span1.SpanContext().SpanID().String(), span2.SpanContext().SpanID().String()} { + if n := strings.Count(lines[i], `"traceID"`); n != 1 { + t.Errorf("line %d: traceID appears %d times, want exactly 1: %s", i, n, lines[i]) + } + if n := strings.Count(lines[i], `"spanID"`); n != 1 { + t.Errorf("line %d: spanID appears %d times, want exactly 1: %s", i, n, lines[i]) + } + if !strings.Contains(lines[i], traceID) { + t.Errorf("line %d: missing traceID %s: %s", i, traceID, lines[i]) + } + if !strings.Contains(lines[i], want) { + t.Errorf("line %d: missing spanID %s: %s", i, want, lines[i]) + } + } + + ended := sr.Ended() + if len(ended) != 2 { + t.Fatalf("got %d spans, want 2", len(ended)) + } + // Ended in LIFO order: inner first. + if got := ended[0].Parent().SpanID(); got != span1.SpanContext().SpanID() { + t.Errorf("inner span parent = %s, want %s", got, span1.SpanContext().SpanID()) + } +} + +func TestStartSpan_noopTracerLeavesLoggerUntouched(t *testing.T) { + t.Parallel() + + var lines []string + ctx := logf.IntoContext(context.Background(), captureLogger(&lines)) + + ctx, span := StartSpan(ctx, noop.NewTracerProvider().Tracer("test"), "op") + defer span.End() + logf.FromContext(ctx).Info("work") + + if len(lines) != 1 { + t.Fatalf("got %d log lines, want 1", len(lines)) + } + if strings.Contains(lines[0], "traceID") { + t.Errorf("disabled tracing must not add traceID: %s", lines[0]) + } +} + +func TestContextWithLogger(t *testing.T) { + t.Parallel() + tracer, _ := recordingTracer(t) + + t.Run("no span injects base as-is", func(t *testing.T) { + t.Parallel() + var lines []string + ctx := ContextWithLogger(context.Background(), captureLogger(&lines)) + logf.FromContext(ctx).Info("plain") + if len(lines) != 1 || strings.Contains(lines[0], "traceID") { + t.Fatalf("want one line without traceID, got %v", lines) + } + }) + + t.Run("existing span enriches immediately and nested Start does not stack", func(t *testing.T) { + t.Parallel() + var lines []string + ctx, outer := tracer.Start(context.Background(), "server") + defer outer.End() + + ctx = ContextWithLogger(ctx, captureLogger(&lines)) + logf.FromContext(ctx).Info("handler") + + ctx, inner := StartSpan(ctx, tracer, "child") + defer inner.End() + logf.FromContext(ctx).Info("nested") + + if len(lines) != 2 { + t.Fatalf("got %d lines, want 2: %v", len(lines), lines) + } + for i, line := range lines { + if n := strings.Count(line, `"traceID"`); n != 1 { + t.Errorf("line %d: traceID appears %d times, want 1: %s", i, n, line) + } + } + if !strings.Contains(lines[1], inner.SpanContext().SpanID().String()) { + t.Errorf("nested line should carry the child spanID: %s", lines[1]) + } + }) +} diff --git a/internal/tracing/options.go b/internal/tracing/options.go new file mode 100644 index 0000000..07ac486 --- /dev/null +++ b/internal/tracing/options.go @@ -0,0 +1,48 @@ +package tracing + +import ( + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/trace" +) + +// tracerName is the instrumentation scope for every span this module emits. +const tracerName = "gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator" + +type options struct { + tp trace.TracerProvider +} + +// Option configures the tracing decorators. The zero configuration uses the +// global TracerProvider installed by Setup; tests inject their own recorder +// via WithTracerProvider so they can run in parallel without touching +// process-global state. +type Option func(*options) + +// WithTracerProvider overrides the global TracerProvider. +func WithTracerProvider(tp trace.TracerProvider) Option { + return func(o *options) { o.tp = tp } +} + +func newOptions(opts []Option) options { + var o options + for _, opt := range opts { + opt(&o) + } + return o +} + +// Tracer resolves a tracer from the given options, for decorators outside +// this package (provider.WithTracing). +func Tracer(opts ...Option) trace.Tracer { + return newOptions(opts).tracer() +} + +// tracer resolves the configured tracer. The global path goes through +// otel.Tracer, which delegates to whatever provider Setup installs later — +// construction order between decorators and Setup does not matter. +func (o options) tracer() trace.Tracer { + if o.tp != nil { + return o.tp.Tracer(tracerName) + } + return otel.Tracer(tracerName) +} diff --git a/internal/tracing/reconciler.go b/internal/tracing/reconciler.go new file mode 100644 index 0000000..82c6216 --- /dev/null +++ b/internal/tracing/reconciler.go @@ -0,0 +1,52 @@ +package tracing + +import ( + "context" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" + "sigs.k8s.io/controller-runtime/pkg/controller" + "sigs.k8s.io/controller-runtime/pkg/reconcile" +) + +// NewReconciler wraps inner so every reconcile runs in a root span named +// "Reconcile " and every log line under it carries the trace context. +// Reconciles are triggered by watch events with no incoming trace to +// continue, so each one starts a new trace. +func NewReconciler(kind string, inner reconcile.Reconciler, opts ...Option) reconcile.Reconciler { + return &tracedReconciler{ + spanName: "Reconcile " + kind, + inner: inner, + tracer: newOptions(opts).tracer(), + } +} + +type tracedReconciler struct { + spanName string + inner reconcile.Reconciler + tracer trace.Tracer +} + +func (t *tracedReconciler) Reconcile(ctx context.Context, req reconcile.Request) (reconcile.Result, error) { + ctx, span := StartSpan(ctx, t.tracer, t.spanName, + trace.WithAttributes( + attribute.String("k8s.namespace.name", req.Namespace), + attribute.String("k8s.object.name", req.Name), + )) + defer span.End() + if id := controller.ReconcileIDFromContext(ctx); id != "" { + span.SetAttributes(attribute.String("reconcile.id", string(id))) + } + + res, err := t.inner.Reconcile(ctx, req) + if err != nil { + span.SetStatus(codes.Error, err.Error()) + return res, err + } + span.SetStatus(codes.Ok, "") + if res.RequeueAfter > 0 { + span.SetAttributes(attribute.Int64("reconcile.requeue_after_ms", res.RequeueAfter.Milliseconds())) + } + return res, nil +} diff --git a/internal/tracing/reconciler_test.go b/internal/tracing/reconciler_test.go new file mode 100644 index 0000000..684d1d9 --- /dev/null +++ b/internal/tracing/reconciler_test.go @@ -0,0 +1,86 @@ +package tracing + +import ( + "context" + "errors" + "testing" + "time" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + "k8s.io/apimachinery/pkg/types" + "sigs.k8s.io/controller-runtime/pkg/reconcile" +) + +type fakeReconciler struct { + res reconcile.Result + err error +} + +func (f *fakeReconciler) Reconcile(context.Context, reconcile.Request) (reconcile.Result, error) { + return f.res, f.err +} + +func TestNewReconciler_spanPerReconcile(t *testing.T) { + t.Parallel() + + req := reconcile.Request{NamespacedName: types.NamespacedName{Namespace: "default", Name: "p1"}} + + tests := []struct { + name string + inner *fakeReconciler + wantStatus codes.Code + wantAttr attribute.KeyValue + }{ + { + name: "success records requeue", + inner: &fakeReconciler{res: reconcile.Result{RequeueAfter: 10 * time.Second}}, + wantStatus: codes.Ok, + wantAttr: attribute.Int64("reconcile.requeue_after_ms", 10_000), + }, + { + name: "error sets error status", + inner: &fakeReconciler{err: errors.New("boom")}, + wantStatus: codes.Error, + wantAttr: attribute.String("k8s.object.name", "p1"), + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + + r := NewReconciler("Proxy", tc.inner, WithTracerProvider(tp)) + res, err := r.Reconcile(context.Background(), req) + if res != tc.inner.res || !errors.Is(err, tc.inner.err) { + t.Fatalf("decorator changed the result: (%v, %v)", res, err) + } + + ended := sr.Ended() + if len(ended) != 1 { + t.Fatalf("got %d spans, want 1", len(ended)) + } + span := ended[0] + if span.Name() != "Reconcile Proxy" { + t.Errorf("span name = %q, want %q", span.Name(), "Reconcile Proxy") + } + if span.Status().Code != tc.wantStatus { + t.Errorf("status = %v, want %v", span.Status().Code, tc.wantStatus) + } + found := false + for _, a := range span.Attributes() { + if a == tc.wantAttr { + found = true + } + } + if !found { + t.Errorf("attribute %v missing in %v", tc.wantAttr, span.Attributes()) + } + }) + } +} diff --git a/internal/tracing/tracing.go b/internal/tracing/tracing.go new file mode 100644 index 0000000..4801d28 --- /dev/null +++ b/internal/tracing/tracing.go @@ -0,0 +1,140 @@ +// Package tracing wires OpenTelemetry tracing into the operator: SDK setup +// gated on standard OTEL_* environment variables, span helpers that keep the +// logr/zap logging enriched with trace context, and decorators for the +// reconciler, providers, HTTP server, and Kubernetes API transport. +package tracing + +import ( + "context" + "fmt" + "os" + "strings" + + "github.com/go-logr/logr" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc" + "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp" + "go.opentelemetry.io/otel/exporters/stdout/stdouttrace" + "go.opentelemetry.io/otel/propagation" + "go.opentelemetry.io/otel/sdk/resource" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + semconv "go.opentelemetry.io/otel/semconv/v1.43.0" +) + +// maxQueueSize bounds the batch processor's span buffer; the default 2048 +// is oversized for this process (3 concurrent reconciles, tickers) and the +// manager pod runs with a 128Mi memory limit. +const maxQueueSize = 512 + +// Setup initializes the global tracing pipeline from OTEL_* environment +// variables and returns a shutdown func that flushes pending spans. +// +// Tracing stays fully off — no exporter, no global provider, spans are +// no-ops, logs carry no traceID — unless the environment opts in by setting +// OTEL_TRACES_EXPORTER or an OTLP endpoint. OTEL_SDK_DISABLED=true and +// OTEL_TRACES_EXPORTER=none force it off (the Go SDK does not implement +// OTEL_SDK_DISABLED itself). Sampling, endpoints, TLS, and headers follow +// the standard SDK/exporter env vars (OTEL_TRACES_SAMPLER, OTEL_EXPORTER_OTLP_*). +func Setup(ctx context.Context, log logr.Logger, service, version string) (func(context.Context) error, error) { + noop := func(context.Context) error { return nil } + + exporterEnv := strings.ToLower(strings.TrimSpace(os.Getenv("OTEL_TRACES_EXPORTER"))) + endpointSet := os.Getenv("OTEL_EXPORTER_OTLP_ENDPOINT") != "" || + os.Getenv("OTEL_EXPORTER_OTLP_TRACES_ENDPOINT") != "" + sdkDisabled := strings.EqualFold(strings.TrimSpace(os.Getenv("OTEL_SDK_DISABLED")), "true") + + if sdkDisabled || exporterEnv == "none" || (exporterEnv == "" && !endpointSet) { + log.Info("tracing disabled", + "reason", disabledReason(sdkDisabled, exporterEnv)) + return noop, nil + } + + exp, expName, err := newExporter(ctx, exporterEnv) + if err != nil { + return noop, fmt.Errorf("tracing setup: %w", err) + } + + res, err := buildResource(ctx, service, version) + if err != nil { + if res == nil { + return noop, fmt.Errorf("tracing setup: building resource: %w", err) + } + // Schema-URL conflicts between semconv versions still yield a usable + // merged resource; keep it rather than losing tracing over metadata. + log.V(1).Info("tracing resource merge conflict; continuing", "err", err.Error()) + } + + tp := sdktrace.NewTracerProvider( + sdktrace.WithBatcher(exp, sdktrace.WithMaxQueueSize(maxQueueSize)), + sdktrace.WithResource(res), + ) + otel.SetTracerProvider(tp) + otel.SetTextMapPropagator(propagation.NewCompositeTextMapPropagator( + propagation.TraceContext{}, propagation.Baggage{})) + otelLog := log.WithName("otel") + otel.SetLogger(otelLog) + // V(1), not Error: an unreachable collector fails every export cycle and + // would otherwise spam the error log every few seconds. + otel.SetErrorHandler(otel.ErrorHandlerFunc(func(err error) { + otelLog.V(1).Info("otel error", "err", err.Error()) + })) + + log.Info("tracing enabled", "exporter", expName, "service", service) + return tp.Shutdown, nil +} + +func disabledReason(sdkDisabled bool, exporterEnv string) string { + switch { + case sdkDisabled: + return "OTEL_SDK_DISABLED=true" + case exporterEnv == "none": + return "OTEL_TRACES_EXPORTER=none" + default: + return "no OTEL_TRACES_EXPORTER or OTLP endpoint configured" + } +} + +// newExporter hand-rolls the OTEL_TRACES_EXPORTER / OTEL_EXPORTER_OTLP_* +// protocol selection instead of pulling in contrib's autoexport, which drags +// metric/log/prometheus exporters into a trace-only binary. +func newExporter(ctx context.Context, kind string) (sdktrace.SpanExporter, string, error) { + switch kind { + case "", "otlp": + proto := strings.ToLower(strings.TrimSpace(os.Getenv("OTEL_EXPORTER_OTLP_TRACES_PROTOCOL"))) + if proto == "" { + proto = strings.ToLower(strings.TrimSpace(os.Getenv("OTEL_EXPORTER_OTLP_PROTOCOL"))) + } + switch proto { + case "", "http/protobuf": + exp, err := otlptracehttp.New(ctx) + return exp, "otlp/http", err + case "grpc": + exp, err := otlptracegrpc.New(ctx) + return exp, "otlp/grpc", err + default: + return nil, "", fmt.Errorf("unsupported OTLP protocol %q (supported: http/protobuf, grpc)", proto) + } + case "console": + exp, err := stdouttrace.New() + return exp, "console", err + default: + return nil, "", fmt.Errorf("unsupported OTEL_TRACES_EXPORTER %q (supported: otlp, console, none)", kind) + } +} + +// buildResource layers defaults < service identity < environment, so +// OTEL_SERVICE_NAME / OTEL_RESOURCE_ATTRIBUTES always win. +func buildResource(ctx context.Context, service, version string) (*resource.Resource, error) { + base, err := resource.Merge(resource.Default(), resource.NewWithAttributes(semconv.SchemaURL, + semconv.ServiceName(service), + semconv.ServiceVersion(version), + )) + if err != nil { + return base, err + } + env, err := resource.New(ctx, resource.WithFromEnv()) + if err != nil { + return base, err + } + return resource.Merge(base, env) +} diff --git a/internal/tracing/tracing_test.go b/internal/tracing/tracing_test.go new file mode 100644 index 0000000..b90310b --- /dev/null +++ b/internal/tracing/tracing_test.go @@ -0,0 +1,129 @@ +package tracing + +import ( + "context" + "testing" + "time" + + "github.com/go-logr/logr" + "go.opentelemetry.io/otel" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/trace/noop" +) + +// clearOTelEnv pins every env var Setup reads, so developer shells with +// OTEL_* set can't change test outcomes. Not parallel-safe by design +// (t.Setenv forbids t.Parallel). +func clearOTelEnv(t *testing.T) { + t.Helper() + for _, k := range []string{ + "OTEL_SDK_DISABLED", + "OTEL_TRACES_EXPORTER", + "OTEL_EXPORTER_OTLP_ENDPOINT", + "OTEL_EXPORTER_OTLP_TRACES_ENDPOINT", + "OTEL_EXPORTER_OTLP_PROTOCOL", + "OTEL_EXPORTER_OTLP_TRACES_PROTOCOL", + } { + t.Setenv(k, "") + } +} + +func TestSetup_envGating(t *testing.T) { + tests := []struct { + name string + env map[string]string + wantEnabled bool + wantErr bool + }{ + {name: "no env means disabled", env: nil, wantEnabled: false}, + { + name: "endpoint enables otlp", + env: map[string]string{"OTEL_EXPORTER_OTLP_ENDPOINT": "http://localhost:4318"}, + wantEnabled: true, + }, + { + name: "traces endpoint enables otlp", + env: map[string]string{"OTEL_EXPORTER_OTLP_TRACES_ENDPOINT": "http://localhost:4318"}, + wantEnabled: true, + }, + { + name: "explicit console exporter", + env: map[string]string{"OTEL_TRACES_EXPORTER": "console"}, + wantEnabled: true, + }, + { + name: "grpc protocol", + env: map[string]string{"OTEL_TRACES_EXPORTER": "otlp", "OTEL_EXPORTER_OTLP_PROTOCOL": "grpc"}, + wantEnabled: true, + }, + { + name: "exporter none wins over endpoint", + env: map[string]string{ + "OTEL_TRACES_EXPORTER": "none", + "OTEL_EXPORTER_OTLP_ENDPOINT": "http://localhost:4318", + }, + wantEnabled: false, + }, + { + name: "OTEL_SDK_DISABLED wins over everything", + env: map[string]string{ + "OTEL_SDK_DISABLED": "true", + "OTEL_EXPORTER_OTLP_ENDPOINT": "http://localhost:4318", + }, + wantEnabled: false, + }, + { + name: "unsupported exporter errors", + env: map[string]string{"OTEL_TRACES_EXPORTER": "jaeger"}, + wantErr: true, + }, + { + name: "unsupported protocol errors", + env: map[string]string{ + "OTEL_TRACES_EXPORTER": "otlp", + "OTEL_EXPORTER_OTLP_PROTOCOL": "http/json", + }, + wantErr: true, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + clearOTelEnv(t) + for k, v := range tc.env { + t.Setenv(k, v) + } + // Fresh noop global per case: disabled paths must leave it + // untouched, and resetting avoids leaking one case's SDK + // provider into the next (or warning-prone restores of the + // process-default delegate). + before := noop.NewTracerProvider() + otel.SetTracerProvider(before) + + shutdown, err := Setup(context.Background(), logr.Discard(), "test-svc", "abc123") + if tc.wantErr { + if err == nil { + t.Fatal("want error, got nil") + } + return + } + if err != nil { + t.Fatalf("Setup: %v", err) + } + + _, isSDK := otel.GetTracerProvider().(*sdktrace.TracerProvider) + if isSDK != tc.wantEnabled { + t.Errorf("global provider is SDK = %v, want %v", isSDK, tc.wantEnabled) + } + if tc.wantEnabled && otel.GetTracerProvider() == before { + t.Error("enabled Setup must install a new global provider") + } + + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + if err := shutdown(ctx); err != nil { + t.Errorf("shutdown: %v", err) + } + }) + } +} diff --git a/internal/tracing/transport.go b/internal/tracing/transport.go new file mode 100644 index 0000000..3968a05 --- /dev/null +++ b/internal/tracing/transport.go @@ -0,0 +1,51 @@ +package tracing + +import ( + "net/http" + + "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp" + "go.opentelemetry.io/otel/propagation" + "go.opentelemetry.io/otel/trace" + "k8s.io/client-go/transport" +) + +// RestConfigWrapper returns a rest.Config.Wrap-compatible wrapper that adds +// a client span to every Kubernetes API request already running inside a +// trace. Requests with no parent span pass through untouched: informer +// list/watch long-polls, leader-election renewals, and metrics authn would +// otherwise each become meaningless (and in the watch case, minutes-long) +// root spans. client-go applies Wrap innermost, so the span sees the final +// authenticated request. +func RestConfigWrapper(opts ...Option) transport.WrapperFunc { + o := newOptions(opts) + return func(rt http.RoundTripper) http.RoundTripper { + otelOpts := []otelhttp.Option{ + // Explicit propagators: deterministic regardless of global + // state. The apiserver ignores incoming traceparent (by + // design), so injection is harmless there. + otelhttp.WithPropagators(propagation.NewCompositeTextMapPropagator( + propagation.TraceContext{}, propagation.Baggage{})), + } + if o.tp != nil { + otelOpts = append(otelOpts, otelhttp.WithTracerProvider(o.tp)) + } + return &parentGatedTransport{ + traced: otelhttp.NewTransport(rt, otelOpts...), + plain: rt, + } + } +} + +// parentGatedTransport enforces the parent-span requirement itself rather +// than relying on otelhttp filter semantics for transports. +type parentGatedTransport struct { + traced http.RoundTripper + plain http.RoundTripper +} + +func (t *parentGatedTransport) RoundTrip(r *http.Request) (*http.Response, error) { + if trace.SpanContextFromContext(r.Context()).IsValid() { + return t.traced.RoundTrip(r) + } + return t.plain.RoundTrip(r) +} diff --git a/internal/tracing/transport_test.go b/internal/tracing/transport_test.go new file mode 100644 index 0000000..6563dec --- /dev/null +++ b/internal/tracing/transport_test.go @@ -0,0 +1,73 @@ +package tracing + +import ( + "context" + "io" + "net/http" + "net/http/httptest" + "testing" + + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" + "go.opentelemetry.io/otel/trace" +) + +func TestRestConfigWrapper_parentGated(t *testing.T) { + t.Parallel() + + var gotTraceparent string + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + gotTraceparent = r.Header.Get("traceparent") + w.WriteHeader(http.StatusOK) + })) + t.Cleanup(srv.Close) + + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + t.Cleanup(func() { _ = tp.Shutdown(context.Background()) }) + + rt := RestConfigWrapper(WithTracerProvider(tp))(http.DefaultTransport) + do := func(ctx context.Context) { + t.Helper() + req, err := http.NewRequestWithContext(ctx, http.MethodGet, srv.URL, nil) + if err != nil { + t.Fatal(err) + } + resp, err := rt.RoundTrip(req) + if err != nil { + t.Fatal(err) + } + _, _ = io.Copy(io.Discard, resp.Body) + _ = resp.Body.Close() + } + + // No parent span: informer watches, leader election. Must not trace. + do(context.Background()) + if len(sr.Ended()) != 0 { + t.Fatalf("request without parent span produced %d spans, want 0", len(sr.Ended())) + } + if gotTraceparent != "" { + t.Fatalf("request without parent span injected traceparent %q", gotTraceparent) + } + + // Under a parent span: one client child span, traceparent injected. + ctx, parent := tp.Tracer("test").Start(context.Background(), "reconcile") + do(ctx) + parent.End() + + var client sdktrace.ReadOnlySpan + for _, s := range sr.Ended() { + if s.SpanKind() == trace.SpanKindClient { + client = s + } + } + if client == nil { + t.Fatalf("no client span recorded, got %d spans", len(sr.Ended())) + } + if got := client.Parent().SpanID(); got != parent.SpanContext().SpanID() { + t.Errorf("client span parent = %s, want %s", got, parent.SpanContext().SpanID()) + } + if gotTraceparent == "" { + t.Error("traceparent header not injected under a parent span") + } +}