[BUG] observability: `model_chunk` spans with `chunkType: 'tool-result'` export `endedAt: null` in a run that completes
Package & version
@mastra/core1.67.0@mastra/observability1.17.8- Node.js 24.14.0
Also seen on @mastra/core 1.63.0.
Summary
A run that completes with finishReason: 'stop' and one tool call produces four model_chunk spans. Three of them (reasoning, tool-call, text) carry a start time and an end time. The fourth (tool-result) carries a start time and no end time.
The cause is a span kind, not a missing end() call. tool-result uses createEventSpan, which creates a span with isEvent: true. BaseSpan.end() returns at once for an event span, so endTime stays undefined. Exporters write endedAt: span.endTime ?? null, so the stored record has endedAt: null.
The span type model_chunk therefore mixes two kinds of record. A consumer that computes a duration, or that detects open spans from endedAt, reports an open span in a run that finished. The consumer must read isEvent to separate the two kinds.
Issue #22972 covers the abort path and is closed. This report covers the success path.
Steps to reproduce
Install @mastra/[email protected], @mastra/[email protected] and zod in an empty package with "type": "module".
repro.mjs:
import { Agent } from '@mastra/core/agent';
import { Mastra } from '@mastra/core/mastra';
import { createTool } from '@mastra/core/tools';
import { Observability, TestExporter } from '@mastra/observability';
import { z } from 'zod';
const toolCallId = 'call-1';
function stream(parts) {
return {
stream: new ReadableStream({
start(controller) {
for (const p of parts) controller.enqueue(p);
controller.close();
},
}),
};
}
const step1 = () =>
stream([
{ type: 'stream-start', warnings: [] },
{ type: 'response-metadata', id: 'r1', modelId: 'mock', timestamp: new Date(0) },
{ type: 'reasoning-start', id: 'reason-1' },
{ type: 'reasoning-delta', id: 'reason-1', delta: 'thinking' },
{ type: 'reasoning-end', id: 'reason-1' },
{ type: 'tool-input-start', id: toolCallId, toolName: 'echo' },
{ type: 'tool-input-delta', id: toolCallId, delta: '{"text":"hi"}' },
{ type: 'tool-input-end', id: toolCallId },
{ type: 'tool-call', toolCallId, toolName: 'echo', input: '{"text":"hi"}' },
{ type: 'finish', finishReason: 'tool-calls', usage: { inputTokens: 1, outputTokens: 1, totalTokens: 2 } },
]);
const step2 = () =>
stream([
{ type: 'stream-start', warnings: [] },
{ type: 'response-metadata', id: 'r2', modelId: 'mock', timestamp: new Date(0) },
{ type: 'text-start', id: 'text-1' },
{ type: 'text-delta', id: 'text-1', delta: 'done' },
{ type: 'text-end', id: 'text-1' },
{ type: 'finish', finishReason: 'stop', usage: { inputTokens: 1, outputTokens: 1, totalTokens: 2 } },
]);
let call = 0;
const model = {
specificationVersion: 'v2',
provider: 'mock',
modelId: 'mock-model',
supportedUrls: {},
async doGenerate() {
throw new Error('not used');
},
async doStream() {
return call++ === 0 ? step1() : step2();
},
};
const echo = createTool({
id: 'echo',
description: 'echo the input',
inputSchema: z.object({ text: z.string() }),
execute: async ({ text }) => ({ echoed: text }),
});
const exporter = new TestExporter({ validateLifecycle: false, logMetricsOnFlush: false });
const agent = new Agent({ name: 'probe-agent', instructions: 'test', model, tools: { echo } });
const mastra = new Mastra({
agents: { agent },
observability: new Observability({
configs: { test: { name: 'test', serviceName: 'test', exporters: [exporter] } },
}),
logger: false,
});
const result = await mastra.getAgent('agent').stream('go');
for await (const _ of result.fullStream) {
/* drain */
}
await exporter.flush();
console.log('finishReason:', await result.finishReason);
for (const s of exporter.getAllSpans().filter(s => s.type === 'model_chunk')) {
console.log(
JSON.stringify({
chunkType: s.attributes?.chunkType,
sequenceNumber: s.attributes?.sequenceNumber,
isEvent: s.isEvent,
startedAt: s.startTime ? 'set' : null,
endedAt: s.endTime ? 'set' : null,
}),
);
}
console.log('incompleteSpans (TestExporter):', exporter.getStatistics().incompleteSpans);
console.log('validateFinalState.allSpansComplete:', exporter.validateFinalState().allSpansComplete);
await mastra.shutdown?.();Run node repro.mjs.
Expected
All four model_chunk spans of a completed run export an end timestamp. A point-in-time chunk can export endedAt equal to startedAt, which gives a zero duration.
Actual
The tool-result span exports no end timestamp.
finishReason: stop
model_chunk spans:
{"chunkType":"reasoning","sequenceNumber":0,"isEvent":false,"startedAt":"set","endedAt":"set"}
{"chunkType":"tool-call","sequenceNumber":1,"isEvent":false,"startedAt":"set","endedAt":"set"}
{"chunkType":"tool-result","sequenceNumber":2,"isEvent":true,"startedAt":"set","endedAt":null}
{"chunkType":"text","sequenceNumber":0,"isEvent":false,"startedAt":"set","endedAt":"set"}
incompleteSpans (TestExporter): 0
validateFinalState.allSpansComplete: trueThe span lifecycle itself is correct. SPAN_ENDED fires for the event span at creation, so TestExporter counts zero incomplete spans. Only the timestamp is absent.
This matches the production traces that started this report. A successful run with one tool call stores a model_chunk row with chunkType: 'tool-result', sequenceNumber: 2, startedAt set and endedAt null. The attributes are { chunkType: 'tool-result', sequenceNumber: 2 } and the metadata is { toolCallId, toolName }, plus isError, dynamic, providerExecuted and providerMetadata when the chunk payload carries them. The sibling reasoning, tool-call and text rows of the same run carry endedAt.
Evidence
tool-result takes the event-span path, the other chunk types take the child-span path:
observability/mastra/src/model-tracing.ts#L1005-L1038— thetool-resultcase ends withthis.#createEventSpan(chunk.type, spanOutput, { metadata }). The comment on line 1006 states the intent: "tool-result is always a point-in-time event span".observability/mastra/src/model-tracing.ts#L722-L745—#createEventSpancallscreateEventSpan, which setsisEvent: true.observability/mastra/src/model-tracing.ts#L672-L690and#L707-L717—text,reasoning,tool-callandobjectuse#startChunkSpanand#endChunkSpan, which callcreateChildSpanandend().
Why the timestamp stays absent:
observability/mastra/src/spans/default.ts#L80-L83—end()returns before it assignsthis.endTimewhenisEventis true.observability/mastra/src/instances/base.ts#L297-L298emitsSPAN_ENDEDfor an event span at creation, so the lifecycle closes but the timestamp does not.
Why consumers see null:
observability/mastra/src/exporters/cloud.ts#L427andobservability/mastra/src/exporters/mastra-platform.ts#L470— both writeendedAt: span.endTime ?? null.packages/core/src/storage/constants.ts—SPAN_SCHEMAholds bothendedAtandisEvent, so a stored row keeps the distinction. A consumer must combine the two columns to tell a point-in-time chunk from an open span.
tool-call-approval uses the same event-span path and has the same result.
Suggested fix
Set endTime to startTime when the span is an event span, so every exported span of a finished run carries an end timestamp and a zero duration. isEvent stays available for consumers that need the distinction.
One place covers all event spans. BaseSpan assigns startTime and isEvent next to each other:
// observability/mastra/src/spans/base.ts, constructor (near L221-L223)
this.startTime = options.startTime ?? new Date();
this.isEvent = options.isEvent ?? false;
if (this.isEvent) {
this.endTime = this.startTime;
}If the current shape must stay, please state in the MODEL_CHUNK reference that endedAt is null for event spans, and name isEvent as the field that separates a point-in-time chunk from an open span.
Source: mastra-ai/mastra