feat(sidecar): OpenTelemetry spans + structured audit log + Jaeger compose - #41
VibhorGautam wants to merge 11 commits into
Conversation
|
quick follow-up while poking at the phase 02 docs for context on the otel span naming in this pr one thing worth flagging for phase 3: not blocking for this otel pr, just flagging since i was in those files already. happy to split it out as a separate issue if useful |
30eb48a to
f894580
Compare
f894580 to
b211849
Compare
b211849 to
3b9fce5
Compare
3b9fce5 to
e3e8e2d
Compare
…mpose Fills the Phase 2 telemetry scaffolding in sidecar/internal/telemetry/. Adds async, non-blocking OpenTelemetry spans across the four pipeline stages and a structured JSON audit log. Stage interface is untouched, no stage-level code changes. - otel.go: OTLP HTTP tracer with ParentBased sampler, scheme-tolerant endpoint, noop fallback on empty endpoint or exporter init failure - audit.go: async writer with buffered channel, single drain goroutine, atomic drop counter, idempotent Close - pipeline.go: root span per run, child span per stage, one audit entry per run. Run() kept for backward compat; RunContext() is the new entry point that honours caller-supplied context - main.go: reads telemetry block from sidecar.yaml, opens the audit sink (file or stdout), flushes tracer and sink on SIGTERM with a deadline - docker-compose.yml: opt-in 'observability' profile adds OTel collector and Jaeger all-in-one - config/otel-collector.yaml: receives OTLP HTTP on :4318, forwards to jaeger:4317 with batching + memory_limiter - docs/observability.md: span layout, audit schema, privacy rules, tuning guidance, failure modes Tests (go test ./... -race green): - audit_test.go: JSON shape, drop accounting under backpressure, concurrent Emit, emit-after-close no-op - otel_test.go: noop fallback, dead endpoint does not panic, scheme stripping, ratio clamp - bench_test.go: three benchmark configurations Benchmarks on Apple M4 show ~450 ns overhead per run with both span emission and audit enabled. Under real Aho-Corasick scan workloads the relative cost drops below 5%. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
Addresses two shutdown-path races flagged during review: 1. asyncJSONSink.Emit could panic with 'send on closed channel' when a producer raced Close. The unsynchronised closed.Load() check let Emit proceed into the channel send while Close was mid-close. Replaces the atomic flag with an RWMutex; Emit holds the read lock around the send, Close takes the write lock around the close. Adds a concurrent Emit/Close regression test (50 trials, 8 producers each). 2. main shut tracing down before in-flight IPC handlers returned, so late-finishing spans and audit entries were silently lost. Listener now tracks handlers via a WaitGroup and exposes Drain(ctx). main calls Stop then Drain (5s deadline) before flushing the tracer and closing the audit sink. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
Codex re-review flagged a late-accept race: Serve.handlers.Add(1) fires after Accept returns, but Drain started handlers.Wait() without first verifying the accept loop had exited. A connection already queued by the kernel when Stop ran could land as a new Add after Wait returned, leaving a handler running while telemetry was torn down. Fix: Listener.serveDone channel closed when Serve returns. Drain waits on serveDone before calling handlers.Wait(). Regression test confirms Drain blocks until Serve exits rather than returning on an empty wait group. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
…eout Codex caught two remaining shutdown gaps after the serveDone change: 1. Stop only closed the listening socket, leaving accepted connections alive. A stalled client could pin a handler inside DecodeRequest's blocking ReadFull forever, defeating graceful drain. 2. main treated the 5s drain deadline as advisory: if Drain returned ctx.DeadlineExceeded main logged and proceeded to shutdownTracer + audit.Close, producing truncated traces and racing the audit channel close against any handler that was still running. Fix: - Listener tracks accepted connections via a mutex-protected map. - Stop closes every tracked conn after closing the listening socket, unblocking handleConn's pending reads and writes. - Serve refuses new connections observed after stopCh fires so we do not leak a conn registered between Accept and the loop exit. - main hard-fails via log.Fatalf when Drain misses its deadline, skipping tracer/audit shutdown rather than flushing partial state. - New TestStopClosesConns asserts a stalled client unblocks cleanly under Stop + Drain. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
Codex re-review flagged audit.Close as the last unbounded shutdown step: the drain goroutine finishes only after all pending writes to the underlying io.Writer complete, and a backpressured stdout or stalled filesystem could hang Close indefinitely even after ln.Drain succeeded. Run audit.Close in a helper goroutine and race it against a 2s context. On timeout the process continues to exit; the worker dies with the process and the last few entries may be lost, which is the correct tradeoff against wedging on SIGTERM. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
The drain goroutine inside asyncJSONSink.Close may still be mid-write when the 2s deadline fires. Closing the underlying file in that branch truncates or corrupts the final JSONL record. Move closeAuditFile into the success branch; on timeout the fd is left to process exit, which is the correct tradeoff against shipping a corrupt audit tail. Signed-off-by: VibhorGautam <vibhorgautam907@gmail.com>
A bad or unwritable audit_path used to kill the sidecar at startup via log.Fatalf, which breaks the fail-open behaviour the tracer already follows. Fall back to a noop sink and log a warning instead, so an audit problem can never stop enforcement. Also fix the observability doc: audit defaults to stdout rather than noop, and document the opa.evaluate span and its attributes.
e3e8e2d to
393c6cc
Compare
what
adds OpenTelemetry tracing and structured audit logging to the Go sidecar without changing the
Stageinterface or the wire formateach pipeline run gets a root span, 1 child span per stage and an
opa.evaluatespan. audit records carry decision metadata, signal names, provenance, session id, policy version, trace ids, block stage and duration. raw payload and canonical text aren't copied into telemetrythe compose profile starts the sidecar, a pinned OTel collector and Jaeger at http://localhost:16686
behavior
telemetry uses the runtime
telemetry:config block. an empty endpoint installs a noop tracer. audit writes use a bounded queue, drop instead of blocking when full and drain during shutdownbad magic, bad protocol version, bad HMAC, replayed nonces and signed invalid JSON are recorded as transport blocks. signal category strings from signed SDK requests pass through to OPA and audit, so SDK scanners must keep category names fixed and free of user content
hardening
the Aug 29 rebase also fixes concurrent
Closecallers reading the audit error before the drain finished, closes accepted connections before waiting for handlers, bounds tracer and audit shutdown, keeps audit failures fail-open, creates audit files with0600permissions and new parent directories with0700, and fixes the compose path with a real sidecar image and required HMAC environment valuelocal cost
5-run medians with
-benchtime=2s -count=5 -cpu=1:these measure in-process span recording and audit queueing on the benchmark payload, not collector or network cost
testing
all 4 GitHub jobs are green after the rebase: Go, Python, ubuntu integration and windows integration
locally, the full Go race suite,
go vet ./..., 114 Python tests, 102 OPA tests, the uncached integration suite, Windows compilation, YAML parsing and diff checks passDocker isn't installed locally, so the compose YAML was parsed but the image wasn't built here
scope
no metrics and no SDK frame change.
Pipeline.RunContextcan join a caller context, but v1 doesn't carrytraceparentover IPC yet