Skip to content

feat(sidecar): OpenTelemetry spans + structured audit log + Jaeger compose - #41

Open
VibhorGautam wants to merge 11 commits into
c2siorg:mainfrom
VibhorGautam:feat/telemetry-observability
Open

VibhorGautam wants to merge 11 commits into
c2siorg:mainfrom
VibhorGautam:feat/telemetry-observability

Conversation

@VibhorGautam

@VibhorGautam VibhorGautam commented Apr 14, 2026

Copy link
Copy Markdown
Contributor

what

adds OpenTelemetry tracing and structured audit logging to the Go sidecar without changing the Stage interface or the wire format

each pipeline run gets a root span, 1 child span per stage and an opa.evaluate span. 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 telemetry

the 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 shutdown

bad 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 Close callers 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 with 0600 permissions and new parent directories with 0700, and fixes the compose path with a real sidecar image and required HMAC environment value

local cost

5-run medians with -benchtime=2s -count=5 -cpu=1:

config ns/op B/op allocs/op
no telemetry 3,837 1,776 29
audit only 4,153 2,025 30
sampled tracer plus audit 6,207 5,745 44

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 pass

Docker 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.RunContext can join a caller context, but v1 doesn't carry traceparent over IPC yet

@VibhorGautam

Copy link
Copy Markdown
Contributor Author

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: docs/pipeline.md signal table lists hmac_invalid: 1.0 # always hard block, but sidecar/internal/pipeline/aggregate.go computes score = maxSignalWeight * provenanceWeight in AggregateStage.Run and always returns hardBlock=false. so if phase 3's opa path emits hmac_invalid for a memory-provenance payload (trust weight 0.6), the score ends up 1.0 × 0.6 = 0.6, which is sanitise under the default 0.85 block threshold, not block. since memory is exactly where hmac_invalid is supposed to be strict (tampered stored state), either it needs a validate-style hardBlock return before aggregate runs, or the "always hard block" note should say it's provenance-weighted like every other signal

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

@VibhorGautam
VibhorGautam force-pushed the feat/telemetry-observability branch 2 times, most recently from 30eb48a to f894580 Compare June 2, 2026 10:57
@VibhorGautam
VibhorGautam force-pushed the feat/telemetry-observability branch from f894580 to b211849 Compare June 19, 2026 17:04
@VibhorGautam
VibhorGautam force-pushed the feat/telemetry-observability branch from b211849 to 3b9fce5 Compare August 14, 2026 11:22
@VibhorGautam
VibhorGautam force-pushed the feat/telemetry-observability branch from 3b9fce5 to e3e8e2d Compare August 29, 2026 09:08
…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.
@VibhorGautam
VibhorGautam force-pushed the feat/telemetry-observability branch from e3e8e2d to 393c6cc Compare September 14, 2026 16:45
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant