Skip to content

feat(tracing): instrument background worker jobs - #600

Merged
rodaddy merged 11 commits into
mainfrom
feat/569-background-worker-tracing
Aug 6, 2026
Merged

feat(tracing): instrument background worker jobs#600
rodaddy merged 11 commits into
mainfrom
feat/569-background-worker-tracing

Conversation

@rodaddy

@rodaddy rodaddy commented Aug 6, 2026

Copy link
Copy Markdown
Owner

Summary

  • extend the existing masked, env-gated, release-stamped Langfuse runtime with background-job traces and child observations
  • trace embedding repair batches and provider calls, preserving provider-reported token usage for cost attribution
  • trace DISTILL and DREAM Light/REM runs with stage spans, row identifiers, and LLM-backed model calls as Langfuse generations
  • trace each handled NATS message through handling and reply publication, including undeliverable error-envelope outcomes
  • keep instrumentation best-effort and preserve existing dry-run, retry, mutation, and wire behavior

Part of #569

Verification

  • Relevant Open Brain tests/typecheck/migrations passed
  • Python package checks passed or are not applicable — Python package unchanged
  • Live Open Brain smoke passed or is not applicable — no live Langfuse credentials/canary were used in this coding lane

Evidence:

  • bunx tsc --noEmit — passed with /Users/rico/.config/open-brain/env.release-test sourced
  • bun test — 3,677 passed, 35 skipped, 0 failed across 239 files
  • Postgres-gated tests did run: OPENBRAIN_TEST_DATABASE_URL was set by the release-test environment
  • mutation proof: suppressing BackgroundTraceRecorder.emit made 8 emission tests fail across 6 files; restoring it returned the suite to green. This proves background emission, not masking.
  • masking is covered separately by the shared masking-boundary regressions; it is not part of the emission mutation proof
  • payload-size portions of review findings H4/M1 are intentionally held for an operator decision and are not addressed by this fix lane

Critical Self-Review

  • Highest-risk behavior: tracing summarizers or emitter failures could accidentally alter a background job; the recorder separates worker callback failures from instrumentation failures, logs instrumentation faults content-free, and preserves the original result or error.
  • Assumptions that could be wrong: OpenAI-compatible embedding providers report usage as prompt_tokens/total_tokens; usage degrades to omitted metadata. NATS session identity is attached only after server-side schema/auth/lane binding succeeds.
  • Missing/weak tests: no live OTLP export to the operator Langfuse instance occurred; fake-exporter tests cover emitted trace shape, masking, disabled no-op behavior, generations, usage details, identifiers/hashes, composition-root wiring, and failure outcomes. The Postgres-backed suite ran under the release-test environment.
  • Security/permission risk: background evidence observations use identifiers, hashes, lengths, and counts instead of source/candidate text. NATS wire-declared session keys remain untrusted until server binding and are otherwise represented only by a fixed masked marker. Auth and namespace enforcement remain server-side.
  • Migration/deploy risk: no database migration or configuration key was added; activation uses the existing OPENBRAIN_TRACING_* gate and existing release stamp, so rollback is a code revert with no stored-state cleanup.
  • Downstream client/runtime risk: no MCP schema, Python client, error-envelope contract, or agent-facing call shape changed; NATS wire responses remain byte-contract compatible.
  • Rollback/cleanup concern: reverting the PR removes the instrumentation; traces already exported to Langfuse are observational records and are not replayed into Open Brain.
  • Fixes made before PR: wired both production composition roots, bound NATS session identity after auth, isolated global DREAM sweeps, removed raw evidence content, added emitter-failure tests, added Light version parity, and pinned NATS reply-failure propagation.
  • Known residual risk: Langfuse cost computation still depends on providers reporting usage and on the configured model name matching Langfuse pricing; live exporter timing and cost display remain unverified. Payload-size policy remains an explicit operator decision.
  • SME review-memory update: [x] docs/sme/ updated (security x2, gotcha-agent — commit 7e36d5b on this branch; provenance pull/600#issuecomment-5202749565)

Review Gate

  • Critical self-review fields above are filled with specific, non-placeholder content
  • MEDIUM+ review findings were captured in docs/sme/ (commit 7e36d5b)
  • Live Open Brain checks: [ ] linked below or [x] not applicable because: this lane had no live Langfuse credentials/canary; fake exporters and the full repository suite were used.

Contract Parity

  • Contract parity: [ ] fixtures updated
  • Contract parity: [x] runtime-specific because: this is internal observability instrumentation and changes no MCP, NATS, Python, or agent-facing contract.

Downstream Rollout

  • I checked docs/downstream-rollout.md
  • rtech-mcps handoff is complete or not applicable — not applicable; no registry or public contract changed
  • mcp2cli cache/skill refresh is complete or not applicable — not applicable; tool schemas and guidance are unchanged
  • rtech-hermes Python runtime/plugin changes are complete or not applicable — not applicable; no client call shape changed
  • Hermes live rollout/canaries are complete or not applicable — not applicable; this is server-internal tracing

Notes/evidence:

  • The MEDIUM+ review-findings box is intentionally left unchecked for the controller to complete after the required review follow-up.
  • Latent bugs found outside this instrumentation scope: none.

Add masked, release-stamped Langfuse traces for embedding repair, DREAM/distill stages, and NATS message handling. Preserve provider usage metadata and record LLM-backed calls as generations.\n\nCo-Authored-By: Claude <noreply@anthropic.com>
@rodaddy

rodaddy commented Aug 6, 2026

Copy link
Copy Markdown
Owner Author

Review swarm findings (posted before fixes, per program mandate)

Opposite-family swarm at head 3cfbd75: 3 Claude Opus lanes (correctness / security / adversarial) with the freshly promoted #599 SME patterns injected, plus an independent mutation-proof re-verification. Deduplicated; lane attribution noted. No fixes have been made at the time of this comment.

HIGH

H1 (correctness + security + adversarial — all three lanes independently): the instrumentation is dead in BOTH production processes. Two distinct wiring gaps, same class as #599 H1 (review.instrumentation_reaches_production_tree):

  • src/index.ts (the core01 tree, package.json start / start:two-worker) never builds a tracing runtime: no createTracingRuntime import, startMaintenanceQueue({pool, logger}) and startNatsContextPackBridge(...) are called with no tracing key — and StartMaintenanceQueueOptions doesn't even declare one, so every BackgroundTraceRecorder in embedding.repair, memory.distill, dream.light, dream.rem, and nats.message has emitter === undefined there.
  • scripts/run-nats-worker.ts — the entrypoint of the DEDICATED launchd NATS worker (com.rico.open-brain-nats-worker, the process that serves real bus traffic per the runbook) — calls startWorker({env, pool, tokenMap}) with no tracing and is untouched by this PR. The only wired caller is the in-server bridge on the local-clone tree.
    Every new test passes because it injects a recording emitter directly into the handler factory, bypassing both composition roots. Fix: add tracing to StartMaintenanceQueueOptions and forward into composeMaintenanceHandlers; construct the runtime in src/index.ts and in startNatsWorkerProcess (env-gated, so a no-op when tracing is off), wire shutdown/flush; add a composition-root test per process asserting an injected sink receives a background trace body.

H2 (security): NATS trace sessionId is taken from the unauthenticated wire envelope BEFORE any auth/size/kind/namespace check (src/nats-bridge.ts:216). Any publisher on the subject sets identity.session_key to an arbitrary string — including another tenant's real session key — and the trace is emitted even for REJECTED requests (denied paths return error envelopes, so trace.finish runs). The field bypasses masking entirely (sessionId/userId are spread through untouched). Result: forged or cross-tenant session timelines in Langfuse. Fix: derive the trace sessionId from the server-resolved binding AFTER handleNatsContextPackMessage; if the wire-declared key must be recorded, put it in metadata as declared_session_key_unverified, masked and length-bounded. Regression: forged identity.session_key without valid bearer under require_auth=true → emitted trace carries no sessionId.

H3 (security): global (namespace-null) DREAM/distill sweeps attach EVERY tenant's verbatim content to one job-supplied session trace. runRemGrading with job.namespace === null sweeps all namespaces, each candidate becomes an observation carrying namespace, full content, and hashes — all joined to sessionId = job.payload.session_key, with batch_size read unbounded off the payload. memory.distill has the identical shape. A Langfuse viewer scoped to one session sees rows from namespaces that session can never read. Fix: return undefined trace sessionId whenever job.namespace === null; stamp per-observation namespace metadata; bound observations per trace. Regression: global REM job with a payload session_key and candidates in two namespaces → emitted body has no sessionId.

H4 (adversarial + security + correctness: the #599 H2 amplifier reproduced in the background lane): unbounded full row/candidate content in span inputs, with no projection bound, no dedup, no total-payload bound. tracedEmbedFn input:{text} (full row content × up to MAX_BATCH=500 rows held in RAM until finish()), resolveEmbeddings input:{text: candidate.content}, runRemGrading generation input: candidate (whole object incl. content), and runDistillUnit output:{candidates} re-serializes every candidate's full content — 2-3 copies of the same content per job trace. This directly contradicts the modules' own stated "content-free telemetry" contracts (comments in distill-handler.ts and embedding-repair-handler.ts). None of the three SME requirements (projection bound / no re-serialization / recorded degradation) is present. Fix: identifiers + lengths + hashes instead of raw text ({row_id, text_length, content_hash}, {candidate_id}); dedupe row_ids via Set with truncation markers; port the #599 total-payload degradation into BackgroundTraceRecorder.

MEDIUM

M1 (correctness): unbounded per-job observation array — one distill job can build tens of thousands of observations (per-unit + per-hash) held in RAM and emitted as one synchronous loop on the poller's event loop. Cap with first-N/last-N + truncated_observations count, or emit per-unit traces joined by sessionId. (Largely addressed by porting the payload bound from H4's fix — but the COUNT bound is distinct from the BYTES bound; do both.)

M2 (adversarial): vacuous tracing tests. The embedding-repair tracing test never asserts observations[].input (passes identically with full text, bounded text, or nothing), and the pre-existing "telemetry is content-free" regression inspects only LOGGER output and never passes a tracing emitter — so the content-ful trace path sits entirely outside the guard that claims to cover it. Fix: extend the content-free regression to assert over JSON.stringify(tracing.bodies); positively pin the bounded input shape.

M3 (adversarial): no test proves a throwing emitter cannot fail a job — the module's central best-effort claim has zero coverage; every fixture is a recording emitter that cannot throw. Add throwingEmitter() tests for both finish() and fail() (a throwing emitter must not mask the original job error).

LOW

  • L1 (correctness): makeDreamLightHandler now requires a MaintenanceJob and constructs the recorder BEFORE the try block (a throw there never reaches trace.fail); also dream.light still lacks the job-version guard its siblings have (pre-existing, but this PR makes the handler read the job). Move recorder construction inside the try; consider the version-guard parity.
  • L2 (adversarial): the instrumented subscribe callback interposes trace.fail + rethrow on reply failures; ack/redelivery semantics for a rejected handler are undocumented and untested both before and after. Add the throwing-respond test with a recording emitter; document the intended contract.

Mutation-proof re-verification: CONFIRMED for emission, REFUTED for masking; perf test is a credible flake

Independent reproduction at 3cfbd75: suppressing BackgroundTraceRecorder.emit turned 8 tests red across 6 files (verbatim failures recorded) — emission is genuinely mutation-proven. BUT the PR's headline claim named the masking test, and that test stays GREEN under the mutation: it calls runtime.background!.emitBackground directly with a hand-built body, covering the masking boundary, not the recorder. Masking and emission are covered by disjoint tests, and neither proof exercises the WIRING seam — which is exactly why H1 survived. A proof that survives deleting the wiring is not proving the instrumentation is live.

Perf test (ob-backfill sanitize wall-clock assertion): 0/3 failures locally, ~575-586ms against a 1000ms bound with the sanitize calls measured at 210-293ms (4.3-7x headroom, tight spread). Machine-speed-dependent wall-clock with no algorithmic invariant — the CI failure reads as runner-load flake, pre-existing, not this PR's defect.


Verdict: not mergeable as-is. H1 defeats the purpose in both production processes; H2/H3 are trace-lane identity/isolation defects of exactly the kind this observability work exists to prevent; H4 is the measured amplifier class again. Fix lane launching next; fixes will be delta-verified before the Review Gate box is checked.

rodaddy and others added 8 commits August 6, 2026 05:26
…orker-tracing

# Conflicts:
#	server/observability/langfuse-tracing.ts
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Claude <noreply@anthropic.com>
@rodaddy

rodaddy commented Aug 6, 2026

Copy link
Copy Markdown
Owner Author

Fix-delta verification receipt (controller-posted) — 3cfbd75..06430ef

Independent opposite-family verification against the CODE. All eight in-scope findings FIXED_VERIFIED (H1 wiring both composition roots — mutation-checked: deleting the wiring spread turns exactly the two composition-root tests red; H2 session binding after auth with the forged-key regression; H3 global sweeps emit no sessionId + per-observation namespace attribution; H4 non-size half — identifiers/hashes replace raw text everywhere named; M2 content-free regression now inspects tracing bodies with positive shape pins; M3 throwing-emitter identity-preserving tests; L1 dream.light try-scoped recorder + version guard; L2 rejection-propagation test + documented ack contract). Out-of-scope check clean: the fix delta touches nothing under server/, no size machinery snuck in, PR body correctly holds the size follow-up for the operator and corrects the mutation-proof claim (emission, not masking).

BUT: mergeable = false on one NEW HIGH introduced by the trunk merge (55d701d), now being fixed: the merge's rewrite of defaultSinkFactory.emit dropped the emitTraceBodyWithObservations call — the only code that renders body.spans — so #599's retrieval-evidence children would be built, masked, handed to the sink, and silently discarded. Proven behaviorally: the same spans-bearing body renders ["search_brain","retrieval.evidence"] at trunk 97957f0 and only ["search_brain"] at PR head 06430ef. The suite is green on both sides because no test drives the REAL sink's emit with a spans-bearing body — the rendering seam was uncovered on both branches. Same class as H1: instrumentation that never reaches production, this time reintroduced against the sibling feature by a merge.

A targeted fix lane is restoring the spans rendering with a real-sink seam test (red-then-green proof required). Merge happens only after that lands and is re-verified.

rodaddy added 2 commits August 6, 2026 06:29
Route retrieval spans and background observations through one parent lifecycle, and cover the real default sink with a red-then-green regression test.\n\nCo-Authored-By: Claude <noreply@anthropic.com>
H2 (trace session identity binds after auth) and H3 (global sweeps never
session-joined) -> security; the trunk-merge silent-reversion catch ->
gotcha-agent. Provenance: pull/600#issuecomment-5202749565 and
pull/600#issuecomment-5203353650.
@rodaddy
rodaddy merged commit b2bd77d into main Aug 6, 2026
22 of 24 checks passed
@rodaddy
rodaddy deleted the feat/569-background-worker-tracing branch August 6, 2026 10:41
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