Skip to content

feat: Phase 10 observability — token/cost stats, per-phase timing, and OTel trace spans - #12

Merged
atharrison merged 6 commits into
mainfrom
fir-9/observability
Jun 13, 2026
Merged

feat: Phase 10 observability — token/cost stats, per-phase timing, and OTel trace spans#12
atharrison merged 6 commits into
mainfrom
fir-9/observability

Conversation

@atharrison

@atharrison atharrison commented Jun 13, 2026

Copy link
Copy Markdown
Owner

What

Phase 10 observability — token usage, cost, per-phase timing, and OTel traces wired into every review run.

Why

The pipeline was a black box: no visibility into how long each phase took, how many tokens were consumed, or what it cost. This makes it hard to demo, debug, and eventually optimize.

Changes

Stats SSE event + pipeline sidebar (feat: observability — token/cost/timing stats emitted at review completion)

  • context-agent.ts — changed return type to ContextAgentResult { context, tokensUsed, cost } so the coordinator can accumulate loop-level token/cost data
  • coordinator.ts — captures Date.now() at each phase boundary (INPUT → CONTEXT → DOMAIN → OUTPUT), accumulates total tokens and cost from all four phases, and emits a stats SSE event before done
  • Structured log — writes a harness_run_complete JSON line to stdout on every fresh run (queryable in Railway log search)
  • ReviewShell.tsx — listens for stats event and renders a footer in the pipeline widget once the review completes:
    • Token count, estimated cost in USD, total elapsed time
    • Per-phase horizontal bar chart (proportional to total duration)

OTel traces (feat: wire OpenTelemetry spans into the review pipeline)

  • src/harness/observability.ts (new) — singleton NodeTracerProvider init with exporter selection:
    • ConsoleSpanExporter by default → structured span JSON to stdout (queryable in Railway)
    • OTLPTraceExporter when OTEL_EXPORTER_OTLP_ENDPOINT is set → ships to Honeycomb/Jaeger/Datadog/etc.
    • Exports withSpan(name, attrs, fn) — wraps any async fn with context propagation for automatic parent/child nesting
  • instrumentation.ts (new) — Next.js standard OTel init hook; guards on NEXT_RUNTIME === 'nodejs' so it never runs in Edge
  • coordinator.ts — wraps the full review and each phase in spans:
harness.review                       review.id, pr.url, mode, tokens.total, cost.usd, findings.count, verdict
  harness.review.input               review.id
  harness.review.context             tokens.context, files.changed, external.calls
  harness.review.domain              tokens.correctness, tokens.security, findings.raw
  harness.review.output              tokens.summary, review.verdict

Notes

  • The three OTel packages (@opentelemetry/api, @opentelemetry/sdk-node, @opentelemetry/sdk-trace-node) were already in package.json — no new deps needed
  • Prometheus /metrics endpoint (scrape-based metrics) is not included — that's a separate OTel signal requiring sdk-metrics + exporter-prometheus; deferred post-hackathon
  • Connects to FIR-9

Checklist

  • tsc --noEmit passes (only pre-existing test-mock errors remain)
  • No new linter errors
  • stats SSE event emitted on fresh runs; cached replays skip it (no token data available)

atharrison and others added 2 commits June 13, 2026 15:04
…etion

- context-agent: return ContextAgentResult with tokensUsed + cost from the
  full loop run, so the coordinator can accumulate them
- coordinator: track wall-clock timing per phase (INPUT/CONTEXT/DOMAIN/OUTPUT),
  accumulate total tokens and cost from all four phases, emit 'stats' SSE event
  before 'done', and write a structured harness_run_complete JSON log line
- ReviewShell: listen for 'stats' event, store in runStats state; render a
  stats footer in the pipeline widget once complete — shows total tokens,
  estimated cost, elapsed time, and a per-phase horizontal bar chart
- HARNESS.md: fix "Five" → "Multiple" agents (accurate to current agent count)
- MASTER_CHECKLIST.md: clean up trailing space in FIR-9 link

Co-authored-by: Cursor <cursoragent@cursor.com>
- src/harness/observability.ts: initialize NodeTracerProvider with
  ConsoleSpanExporter (default) or OTLPTraceExporter when
  OTEL_EXPORTER_OTLP_ENDPOINT is set; export withSpan() helper with
  context propagation for automatic parent/child nesting
- instrumentation.ts: Next.js standard OTel init hook — calls initTracer()
  once at server start on the nodejs runtime only
- coordinator: wrap runReview in a harness.review root span; each phase
  (input/context/domain/output) gets its own child span with phase-specific
  attributes (tokens.context, tokens.correctness, tokens.security,
  files.changed, findings.raw, review.verdict); root span stamped with
  aggregated tokens.total, cost.usd, findings.count, duration.ms

Co-authored-by: Cursor <cursoragent@cursor.com>
@atharrison atharrison changed the title Fir 9/observability FIR-9: Observability Jun 13, 2026
@atharrison atharrison changed the title FIR-9: Observability feat: Phase 10 observability — token/cost stats, per-phase timing, and OTel trace spans Jun 13, 2026
@atharrison

Copy link
Copy Markdown
Owner Author

AI PR Review — REQUEST_CHANGES

The PR has 5 blocking issues: domain agent costs are not accumulated into estimatedCostUsd, AC 10.3 (OUTPUT phase timing) and AC 10.4 (structured stdout log) are not implemented, AC 10.5 (alarm badges) is absent, and the ordering of durationMs computation relative to emit('stats', ...) is suspect. These need to be resolved before merge since they would cause the core observability metrics to be incorrect or incomplete.

Phase 10 adds observability to the PR review harness: a stats SSE event surfaces token usage, estimated cost, and per-phase timing in the browser sidebar, and an OpenTelemetry tracer is wired in via Next.js instrumentation. The implementation is well-structured and the UI rendering is clean, but several acceptance criteria are either partially implemented or entirely missing, and there are correctness bugs in the cost/timing accumulation logic that would produce inaccurate stats.

🔴 Blocking Issues

totalCost for domain agents (correctness + security) is never accumulated (src/agents/pr-review/coordinator.ts)
The diff shows totalTokens += correctnessResult.tokensUsed + securityResult.tokensUsed for the DOMAIN phase, but there is no corresponding totalCost += correctnessResult.cost + securityResult.cost. This means the estimatedCostUsd in the stats event will be missing the cost of the two domain agents, which are likely the most expensive part of the run.

Suggested fix: Add totalCost += correctnessResult.cost + securityResult.cost alongside the token accumulation for the DOMAIN phase.

Acceptance criterion 10.5 (alarm badges in sidebar) not implemented (app/review/[id]/ReviewShell.tsx)
AC 10.5 requires showing alarm badges (e.g. '⚠ 2 alarms' with severity color) in the pipeline sidebar. The stats payload in the diff includes findingsCount but no alarms field, and the ReviewShell rendering code added in this PR shows only tokens/cost/duration/phase bars — no alarm badge UI is present.

phaseDurations.OUTPUT is never recorded — acceptance criterion 10.3 partially unmet (src/agents/pr-review/coordinator.ts)
The diff records phaseDurations.INPUT, phaseDurations.CONTEXT, and phaseDurations.DOMAIN, but there is no phaseDurations.OUTPUT assignment visible. Acceptance criterion 10.3 explicitly requires INPUT, CONTEXT, DOMAIN, and OUTPUT phases. The OUTPUT phase timing (coordinator summary + checkpoint) is absent from the stats payload.

Suggested fix: Add const outputStart = Date.now() before the Phase 4 coordinator summary, and phaseDurations.OUTPUT = Date.now() - outputStart after the OUTPUT checkpoint completes, before the emit('stats') call.

stats event emitted before durationMs is calculated — uses stale/undefined value (src/agents/pr-review/coordinator.ts)
The diff shows emit('stats', { tokensUsed: totalTokens, estimatedCostUsd, durationMs, findingsCount, phaseDurations }) but durationMs is derived from Date.now() - runStart. The emit call appears to happen before or at the same time as the OUTPUT phase timing is recorded. If durationMs is computed just before the emit it would be correct, but if phaseDurations.OUTPUT is set after the emit (as implied by the ordering in the diff where emit precedes emit('checkpoint', ...)) then durationMs may not include the OUTPUT phase time. More critically, estimatedCostUsd is referenced but never shown being assigned in the visible diff — it is a derived variable (likely totalCost) that may be undefined if the assignment was omitted in the truncated diff.

Suggested fix: Ensure durationMs = Date.now() - runStart and phaseDurations.OUTPUT = ... are both computed before the emit('stats', ...) call. Verify estimatedCostUsd is explicitly assigned (e.g. const estimatedCostUsd = totalCost) before use.

Acceptance criterion 10.4 (structured log to stdout) not visible in the diff (src/agents/pr-review/coordinator.ts)
AC 10.4 requires logging a one-line JSON summary to stdout on run completion: { reviewId, prUrl, tokensUsed, cost, durationMs, findings, alarms }. The diff only shows an emit('stats', ...) SSE call. There is no console.log(JSON.stringify(...)) or equivalent structured log visible anywhere in the coordinator or observability module diff. This criterion appears unimplemented.

Suggested fix: After computing final stats, add: console.log(JSON.stringify({ reviewId, prUrl, tokensUsed: totalTokens, cost: totalCost, durationMs, findings: findingsCount, alarms: review.alarms?.length ?? 0 }))

Phase bar widths are computed relative to total durationMs — phases summing beyond 100% or parallel phases render incorrectly (app/review/[id]/ReviewShell.tsx)
At line ~563, each phase bar width is (ms / runStats.durationMs) * 100. The DOMAIN phase runs correctness and security agents in parallel, so its duration is roughly the max of the two agents, not their sum. However the total durationMs is wall-clock time for the full run. Parallel phases (CONTEXT, DOMAIN overlap is impossible, but DOMAIN internally is parallel) will display correctly for wall-clock, but if the server ever sends phase durations that sum to more than durationMs (e.g. due to clock skew or if phases are measured differently), bars will exceed 100%. The Math.min(100, ...) clamp prevents visual overflow but masks the underlying data inconsistency silently.

⚠️ Suggestions

JSON.parse in stats SSE handler has no error handling — malformed event crashes silently (app/review/[id]/ReviewShell.tsx:223)
The es.addEventListener('stats', e => { const data = JSON.parse((e as MessageEvent).data) ... }) call has no try/catch. If the server sends a malformed stats payload, JSON.parse throws an uncaught exception in the event handler, which silently kills the handler. The error event handler below it does have error handling, but stats does not.

✅ What Looks Good

  • The withSpan abstraction in observability.ts cleanly wraps each coordinator phase without polluting business logic, and the Next.js instrumentation.ts guard (NEXT_RUNTIME === 'nodejs') correctly prevents OTel SDK initialization on the Edge runtime.
  • The phase duration bar chart in ReviewShell.tsx is a polished UX addition — using Math.min(100, ...) to clamp bar widths and formatting sub-1s durations as 'ms' vs 's' are both thoughtful details.
  • Renaming the result variable from result to loopResult in context-agent.ts and reshaping the return type to ContextAgentResult cleanly separates the enriched context from the telemetry metadata without breaking callers.
  • The stats SSE event listener is positioned correctly in the event stream setup block, consistent with the existing done and error handler patterns.

🧪 Testing Recommendations

  • Run a full review and inspect the emitted stats payload: verify that estimatedCostUsd reflects costs from all three agent phases (context + correctness + security), not just context and the coordinator summary.
  • Trigger a run and confirm phaseDurations contains all four keys: INPUT, CONTEXT, DOMAIN, and OUTPUT — assert OUTPUT is present and non-zero.
  • Send a malformed stats SSE event from the server (e.g. truncated JSON) and confirm the browser does not throw an uncaught exception and the UI degrades gracefully.
  • Verify that durationMs in the stats event equals or closely approximates the sum of all four phase durations, confirming Date.now() - runStart is computed after phaseDurations.OUTPUT is recorded.
  • Check Railway logs after a completed run to confirm a one-line JSON object matching the AC 10.4 schema ({ reviewId, prUrl, tokensUsed, cost, durationMs, findings, alarms }) is present in stdout.

Generated by PR Review Harness — multi-agent analysis (correctness + security)

atharrison and others added 2 commits June 13, 2026 15:18
… parse

- DomainResultSchema: add cost field (default 0) so domain agents can
  carry their model call cost through to the coordinator
- correctness-agent + security-agent: pass reply.cost to parseDomainResult;
  include cost in both successful parse and fallback return paths
- coordinator: accumulate domain agent costs — totalCost +=
  correctnessResult.cost + securityResult.cost — previously only context
  and summary costs were counted, silently dropping the two most expensive
  agent calls from estimatedCostUsd
- ReviewShell: wrap stats SSE JSON.parse in try/catch so a malformed payload
  doesn't throw an uncaught exception that silently kills the event handler

Co-authored-by: Cursor <cursoragent@cursor.com>
…ner on success

Co-authored-by: Cursor <cursoragent@cursor.com>
@atharrison

Copy link
Copy Markdown
Owner Author

AI PR Review — REQUEST_CHANGES

The observability instrumentation and SSE pipeline are well-implemented, but there are two blocking correctness bugs — a stale/error-string success banner on retry and a division-by-zero in the phase bar renderer — plus a missing null-guard on phaseDurations that will throw in production for cached or partial stats payloads. These should be fixed before merge.

This PR implements Phase 10 observability for the gauntlet-harness review system, adding token usage tracking, estimated cost display, per-phase timing bars, and structured logging to both the browser UI and Railway logs. The feature work is solid and well-scoped, covering the SSE stats event pipeline, the runStats state in ReviewShell, and the instrumentation.ts tracer bootstrap. However, several correctness issues in the React UI state management — particularly around the submitted flag and division-by-zero in the timing bar renderer — need to be addressed before this is safe to ship.

🔴 Blocking Issues

submitted is set to true even when submitResult is not yet updated, causing the success message to briefly show stale/null content (app/review/[id]/ReviewShell.tsx:302)
In both handleSubmit and handleApprove, setSubmitted(true) is called unconditionally when res.ok is true, but setSubmitResult(...) is called on the line immediately before. React batches state updates in event handlers, so both will render together — however, if setSubmitted(true) is reached before setSubmitResult processes (in async flows outside React 18 automatic batching), the success banner renders with submitResult still being null or its previous value. More critically: the condition {submitResult && !submitted} on the error path means that if a first submission fails (sets submitResult to an error string, submitted stays false), then the user retries and it succeeds, setSubmitted(true) fires but submitResult still holds the old error string — the error paragraph disappears correctly, but the green success banner inside the submitted branch will render submitResult (the old error message) as the success text. The success banner always displays {submitResult} which could be an error string from a previous attempt.

Suggested fix: Reset submitResult to null before setting submitted(true), or set the success message string explicitly before setting submitted. Alternatively, use a single discriminated state like type SubmitState = { status: 'idle' } | { status: 'success'; message: string } | { status: 'error'; message: string } to avoid the two states going out of sync.

Phase duration bar width calculation divides by runStats.durationMs which can be zero, producing Infinity or NaN (app/review/[id]/ReviewShell.tsx:580)
In the phaseDurations rendering, the bar width is computed as (ms / runStats.durationMs) * 100. If runStats.durationMs is 0 (e.g. a cached/instant result or a bug in timing), this produces Infinity, and Math.min(100, Infinity) returns 100 — so all bars would be full width. While Math.min guards against values over 100, a durationMs of 0 with any non-zero phase ms yields Infinity, and a durationMs of 0 with ms of 0 yields NaN, which would produce width: NaN% — an invalid CSS value that React would silently drop, rendering a zero-width bar. This is a real edge case for cached reviews.

Suggested fix: Guard against zero: runStats.durationMs > 0 ? Math.min(100, (ms / runStats.durationMs) * 100) : 0

The submitted state is shared between the 'Submit + Post to GitHub' branch (total > 0) and the 'Approve PR' branch (total === 0), causing the wrong branch to show a success message (app/review/[id]/ReviewShell.tsx:495)
Both the total > 0 (submit findings) and total === 0 (approve) code paths check the same submitted boolean. Since total > 0 and total === 0 are mutually exclusive, only one branch renders at a time, so this cannot directly cause both to show simultaneously. However, the issue is that if a user somehow navigates between states (e.g. accepts/rejects findings mid-flow changing total), the submitted flag from one flow could persist and cause the wrong success banner to appear in the other branch. More concretely: submitted is never reset when the user edits findings after a failed submit, so if they submit, get an error, edit a finding (changing total), and try again — the state is inconsistent. This is a logic error given that submitted represents a permanent terminal state but the UI allows continued interaction.

⚠️ Suggestions

stats SSE event listener does not handle the case where runStats.durationMs is missing or phaseDurations is undefined (app/review/[id]/ReviewShell.tsx:221)
The stats event listener parses the payload with JSON.parse and calls setRunStats(data) directly. The downstream rendering code at line ~575 calls Object.entries(runStats.phaseDurations) — if the server emits a stats event where phaseDurations is absent or null (e.g. for a cached review that skips phase tracking, or a partial implementation), Object.entries(null) throws a TypeError, crashing the component. There is no schema validation or optional-chaining guard before Object.entries.

✅ What Looks Good

  • Graceful degradation in the stats SSE listener: wrapping JSON.parse in a try/catch and silently swallowing malformed payloads prevents the event handler from crashing the component.
  • The instrumentation.ts pattern correctly gates the tracer initialization behind NEXT_RUNTIME === 'nodejs', avoiding any attempt to run Node-specific tracing code in the Edge runtime.
  • The submit flow UX improvement — replacing the button with a persistent green success banner after a successful submission — is a clean, intentional improvement that prevents accidental double-submits.
  • Using Math.min(100, ...) as a guard in the phase duration bar width calculation shows awareness of overflow, even if a zero-denominator edge case remains.
  • Changing 'Five specialized agents' to 'Multiple specialized agents' in HARNESS.md is a good housekeeping fix that decouples the docs from a hardcoded agent count.
  • Linking the checklist phase header to the Linear ticket (FIR-9) is a nice traceability improvement.

🧪 Testing Recommendations

  • Simulate a failed submission followed by a successful retry: verify that the green success banner shows the correct success message and not the stale error string from the first attempt.
  • Emit a stats SSE event where durationMs is 0 and verify the phase timing bars render with zero width rather than full width or invalid CSS.
  • Emit a stats SSE event where phaseDurations is omitted or null and confirm the component does not throw a TypeError (currently it would via Object.entries(null)).
  • Test the cached review path end-to-end: confirm whether a stats event is emitted and whether the UI handles the absence of that event gracefully (i.e., runStats remaining null).
  • Verify the structured Railway log line is emitted on run completion and contains all required fields: reviewId, prUrl, tokensUsed, cost, durationMs, findings, and alarms.
  • Accept and then reject a finding after a first failed submit (changing total between 0 and non-zero) and verify the correct submit/approve branch renders without stale submitted state leaking across branches.

Generated by PR Review Harness — multi-agent analysis (correctness + security)

atharrison and others added 2 commits June 13, 2026 15:24
…uick mode UI toggle

Co-authored-by: Cursor <cursoragent@cursor.com>
…urationMs zero-divide

Co-authored-by: Cursor <cursoragent@cursor.com>
@atharrison
atharrison merged commit e426679 into main Jun 13, 2026
3 checks passed
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