Skip to content

Fallback structured-output completion events can have timestamps earlier than structured-output.start #1125

Description

@kolaworld

TanStack AI version

0.44.1

Framework/Library version

@tanstack/ai-groq: 0.6.0 | @tanstack/openai-base: 0.9.12

Describe the bug and the steps to reproduce it

When an adapter implements structuredOutput() but not structuredOutputStream(), TanStack wraps the non-streaming provider call with fallbackStructuredOutputStream().

The fallback records one timestamp before awaiting the provider and reuses it for every event emitted after the provider returns.

For a streaming consumer, TextEngine.runStructuredFinalization() synthesizes structured-output.start when it receives the fallback's first text event.

That synthesized start uses Date.now() after the provider request has completed. The resulting stream is ordered correctly, but its timestamps are reversed:

RUN_STARTED                   timestamp=t0
await adapter.structuredOutput()
structured-output.start      timestamp=t1
TEXT_MESSAGE_START            timestamp=t0
TEXT_MESSAGE_CONTENT          timestamp=t0
TEXT_MESSAGE_END              timestamp=t0
structured-output.complete   timestamp=t0
RUN_FINISHED                  timestamp=t0

This produces negative or misleading durations for consumers that derive timing from event timestamps. It can also make an otherwise valid persistence write fail when a consumer records structured-output.start as the start boundary and structured-output.complete as the end boundary.

The same problem exists on the error path: a RUN_ERROR emitted after the awaited provider rejection retains the pre-request timestamp and can appear earlier than the synthesized structured-output start.

The issue is limited to the fallback wrapper. An adapter that emits its own native structuredOutputStream() controls its event timestamps directly.

Suspected cause

fallbackStructuredOutputStream() captures const timestamp = Date.now() before calling adapter.structuredOutput() and then reuses that value for RUN_ERROR, every text event, structured-output.complete, and RUN_FINISHED: index.ts#L3996-L4083.

The surrounding structured-finalization loop creates the missing structured-output.start with a fresh Date.now() after it receives the first fallback text event: index.ts#L2858-L2869 and index.ts#L2904-L2922.

Expected behavior

Fallback events emitted after the provider call should use timestamps captured after that call settles. RUN_STARTED should retain its pre-request timestamp, while successful text, completion, and RUN_FINISHED events should use current, nondecreasing emission timestamps.

A RUN_ERROR should likewise use the time at which the provider failure is emitted.

This does not require a new event or API. It only requires the existing timestamp fields to reflect their emission boundaries. The following invariants should hold:

RUN_STARTED.timestamp <= structured-output.start.timestamp
structured-output.start.timestamp <= structured-output.complete.timestamp
structured-output.complete.timestamp <= RUN_FINISHED.timestamp

The error path should preserve the equivalent ordering through RUN_ERROR.

Your Minimal, Reproducible Example - (Sandbox Highly Recommended)

https://stackblitz.com/edit/vitejs-vite-ue2jettl?file=package.json,index.html,src%2Fmain.ts

Do you intend to try to help solve this bug with your own PR?

None

Terms & Code of Conduct

  • I agree to follow this project's Code of Conduct
  • I understand that if my bug cannot be reliable reproduced in a debuggable environment, it will probably not be fixed and this issue may even be closed.

Metadata

Metadata

Assignees

No one assigned

    Labels

    has-prAn open PR references this issuewaiting-on: maintainerThe ball is in the maintainers’ court

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions