feat(agent): stamp an absolute emittedAt on persisted run events - #3519
Conversation
`elapsedMs` is measured from the encoder's construction, so reading it correctly requires knowing which encoder instance produced it and when. That anchor is not incidental -- it is the defect behind three of the four attempts it took to land `elapsedMs` at all. #3483 clocked `run-chunk-mirror`, #3497 clocked `hosted-lifecycle`, and each was a correct fix to an encoder production does not use. `emittedAt` has no anchor. It means the same thing regardless of which encoder, run, pod or service produced it, which is what makes it the durable primitive: - durations between any two events, not only from run start - lines up with Tempo traces and Loki logs, which are already wall clock - ingest lag becomes `created_at - emittedAt`, turning the gap that produced the phantom 30ms delta cadence in the original trace analysis into a measurable quantity rather than a trap Stored as epoch milliseconds rather than an ISO string: comparable without parsing, and roughly a third of the bytes on a stream that can carry thousands of events per run. Both fields are kept, because they fail differently. A wall clock can step backwards under NTP correction and yield a negative duration; the monotonic reading cannot. So `emittedAt` is the durable record and `elapsedMs` remains the trustworthy intra-run measure. Declared in the `ag-ui-sse` allow-list in the same change. That is the second edit a run-event field needs, and omitting it is silent: the schema `parse` result is what reaches the wire, so an undeclared field is dropped after being stamped. A test asserts `emittedAt` survives to the wire and fails with exactly that symptom without the declaration.
📝 WalkthroughWalkthroughAG-UI encoders now use grouped timing options. They can add independent elapsed and epoch timestamps. SSE schemas preserve both fields, and API reference links were refreshed. ChangesAG-UI timing
Estimated code review effort: 3 (Moderate) | ~20 minutes Sequence Diagram(s)sequenceDiagram
participant RuntimeEventEncoder
participant AgUiBrowserEncoderState
participant BrowserEventMapper
participant AgUiSSESchema
RuntimeEventEncoder->>AgUiBrowserEncoderState: pass timing configuration
AgUiBrowserEncoderState->>BrowserEventMapper: provide elapsed and epoch clocks
BrowserEventMapper->>AgUiSSESchema: emit event with elapsedMs and emittedAt
AgUiSSESchema-->>RuntimeEventEncoder: validate and serialize AG-UI payload
Possibly related PRs
Suggested reviewers: 🚥 Pre-merge checks | ✅ 4 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (4 passed)
✨ Finishing Touches 💡 1📝 Generate docstrings 💡
🧪 Generate unit tests (beta)
Comment |
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 7fdca927da
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| if (state.epochMs) { | ||
| timing.emittedAt = Math.round(state.epochMs()); |
There was a problem hiding this comment.
Stamp directly emitted lifecycle frames
When any AG-UI response starts, RunStarted, StateSnapshot, and MessagesSnapshot are written directly through formatAgUiEvent in handler.ts, runtime-handler.ts, and browser-response-stream.ts; catch-path RunError frames follow the same path. Because only events passed through stampTiming receive emittedAt, these frames omit the new timestamp on every run, preventing ingest-lag or cross-event timing analysis for those persisted rows. Route these direct frames through the timing stamper or add the timestamp before formatting.
Useful? React with 👍 / 👎.
The four wrappers between a caller and the encoder state each declared and
re-forwarded `nowMs` and `epochMs` individually. Adding `emittedAt` meant
touching all four, purely to pass a value through.
That repetition is the same shape as the bug this field spent four
releases on: a value that has to be re-declared at every layer is a value
that only has to be missed once. Forwarding a single `timing` object means
adding a clock is one edit in `AgUiBrowserEncoderStateOptions`, and the
wrappers do not change at all.
runtime-event-encoder, chunk-encoder-bridge -> createAgUiBrowserEncoderState(options.timing ?? {})
browser-chunk-encoder, chat-ui-chunk-browser-encoder -> pass `timing` straight through
No behaviour change: 1212 tests pass, and the timing tests still assert
`emittedAt` and `elapsedMs` reach the wire independently.
There was a problem hiding this comment.
Actionable comments posted: 1
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@src/agent/ag-ui/runtime-event-encoder.ts`:
- Around line 23-35: Retain the deprecated top-level nowMs option across
src/agent/ag-ui/runtime-event-encoder.ts:23-35,
src/agent/ag-ui/browser-chunk-encoder.ts:23-28,
src/agent/ag-ui/chat-ui-chunk-browser-encoder.ts:24-29, and
src/agent/ag-ui/chunk-encoder-bridge.ts:22-34 so existing TypeScript and
JavaScript callers remain compatible. Forward or normalize nowMs into timing,
define and consistently apply precedence when both are provided, and preserve
explicit values such as { nowMs: null }; add regression tests covering that
case.
🪄 Autofix
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Repository UI
Review profile: CHILL
Plan: Pro Plus
Run ID: bf84a063-32ab-4d46-a76b-da621eb825dd
📒 Files selected for processing (12)
docs/api-reference/veryfront/agent.mdsrc/agent/ag-ui/browser-chunk-encoder.test.tssrc/agent/ag-ui/browser-chunk-encoder.tssrc/agent/ag-ui/browser-encoder.test.tssrc/agent/ag-ui/browser-encoder.tssrc/agent/ag-ui/chat-ui-chunk-browser-encoder.test.tssrc/agent/ag-ui/chat-ui-chunk-browser-encoder.tssrc/agent/ag-ui/chunk-encoder-bridge.tssrc/agent/ag-ui/runtime-event-encoder.test.tssrc/agent/ag-ui/runtime-event-encoder.tssrc/internal-agents/ag-ui-sse.test.tssrc/internal-agents/ag-ui-sse.ts
| /** | ||
| * Timing clocks forwarded verbatim to the encoder state. A single object so | ||
| * that adding a clock is one edit in `AgUiBrowserEncoderStateOptions`, not a | ||
| * sweep through every wrapper that happens to sit in between. | ||
| */ | ||
| timing?: AgUiBrowserEncoderStateOptions; | ||
| } | ||
|
|
||
| /** Create AG-UI runtime event encoder. */ | ||
| export function createAgUiRuntimeEventEncoder( | ||
| options: CreateAgUiRuntimeEventEncoderOptions = {}, | ||
| ): AgUiRuntimeEventEncoder { | ||
| const state = createAgUiBrowserEncoderState( | ||
| options.nowMs === undefined ? {} : { nowMs: options.nowMs }, | ||
| ); | ||
| const state = createAgUiBrowserEncoderState(options.timing ?? {}); |
There was a problem hiding this comment.
🗄️ Data Integrity & Integration | 🟠 Major | ⚡ Quick win
Preserve the top-level nowMs option.
These exported option types remove nowMs. Existing TypeScript callers now fail type checking. Existing JavaScript callers silently use default clocks.
Keep nowMs as a deprecated alias. Normalize it into timing. Define precedence when callers provide both options. Add regression tests that use { nowMs: null }.
src/agent/ag-ui/runtime-event-encoder.ts#L23-L35: retain and normalize the legacy option.src/agent/ag-ui/browser-chunk-encoder.ts#L23-L28: retain and forward the legacy option.src/agent/ag-ui/chat-ui-chunk-browser-encoder.ts#L24-L29: retain and forward the legacy option.src/agent/ag-ui/chunk-encoder-bridge.ts#L22-L34: retain and normalize the legacy option.
As per coding guidelines, “Prefer the smallest viable diff; preserve public API compatibility.”
📍 Affects 4 files
src/agent/ag-ui/runtime-event-encoder.ts#L23-L35(this comment)src/agent/ag-ui/browser-chunk-encoder.ts#L23-L28src/agent/ag-ui/chat-ui-chunk-browser-encoder.ts#L24-L29src/agent/ag-ui/chunk-encoder-bridge.ts#L22-L34
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@src/agent/ag-ui/runtime-event-encoder.ts` around lines 23 - 35, Retain the
deprecated top-level nowMs option across
src/agent/ag-ui/runtime-event-encoder.ts:23-35,
src/agent/ag-ui/browser-chunk-encoder.ts:23-28,
src/agent/ag-ui/chat-ui-chunk-browser-encoder.ts:24-29, and
src/agent/ag-ui/chunk-encoder-bridge.ts:22-34 so existing TypeScript and
JavaScript callers remain compatible. Forward or normalize nowMs into timing,
define and consistently apply precedence when both are provided, and preserve
explicit values such as { nowMs: null }; add regression tests covering that
case.
Source: Coding guidelines
Follow-up to #3509, which finally landed
elapsedMsin production. This adds the primitive that would have prevented most of the detour getting there.Why an absolute timestamp
elapsedMsis measured from the encoder's construction, so reading it correctly requires knowing which encoder instance produced it and when. That anchor is not incidental — it is the defect behind three of the four attempts it took to land the field at all:run-chunk-mirrorhosted-lifecycleBoth were correct fixes to encoders production does not use.
emittedAthas no anchor: it means the same thing regardless of which encoder, run, pod or service produced it.What that buys:
created_at − emittedAt— turning the gap that produced the phantom "metronomic 30ms delta cadence" in the original trace analysis into a measurable quantity rather than a trapTwo deliberate choices
Epoch milliseconds, not an ISO string. Comparable without parsing, and roughly a third of the bytes on a stream that carries thousands of events per run.
Both fields kept, because they fail differently. A wall clock can step backwards under NTP correction and yield a negative duration;
performance.now()cannot. SoemittedAtis the durable record andelapsedMsstays the trustworthy intra-run measure. They are complementary, not redundant.Both edits, in one change
A run-event field needs two edits, and omitting the second is silent —
formatAgUiEventserializes the schemaparseresult, so an undeclared field is dropped after being correctly stamped. That is exactly what cost four releases forelapsedMs.browser-encoder(stampElapsed→stampTiming)ag-ui-sseallow-list (withElapsed→withTiming, applied to all 18 event schemas)Verification
End-to-end through the real production composition root:
Tests, all verified to fail without the change:
emittedAtis the wall clock in epoch ms, andelapsedMsstays anchored to construction — pinning that the two are independentemittedAt— losing one clock must not silently lose the other, which is this field's whole failure historyemittedAtreaches the wire; removing the allow-list declaration fails with the identical historical symptom:{"stepName":"step-1"}1,214 tests pass across
src/agent,src/internal-agents,src/chat,src/runtime. Typecheck, lint, fmt clean; API reference regenerated.Note
The clock options are threaded through four wrapper layers (
runtime-event-encoder,chunk-encoder-bridge,browser-chunk-encoder,chat-ui-chunk-browser-encoder). That repetition is a mild smell — a singletimingoptions object passed wholesale would be tidier — but it is left as-is here to keep this change reviewable alongside the shippedelapsedMswork.Summary by CodeRabbit
New Features
emittedAttimestamps alongside elapsed-time tracking.Bug Fixes
Documentation