vvzvlad/gitmost
1
0
Fork 0
Code Issues 28 Pull Requests 19 Packages Projects Releases Activity

perf(ai-chat): формат трейса tool_calls v2 — outputs только в parts (#490)

Browse Source 
Каждый tool-output хранился ДВАЖДЫ: в metadata.parts (assistantParts) И в
tool_calls (serializeSteps). При 50-шаговом ране с outputs по 50–200 KB это
127–510 МБ записи в Postgres за ход (+WAL/TOAST/dead tuples), т.к. onStepFinish
переписывает всю строку. Копия в parts — та, что реально реплеится модели и
рендерится UI/markdown-экспортом, так что копия в трейсе была чистым дублем.

Новый формат элементов tool_calls (v2), парно на каждый вызов:
  {toolName, input}                      — вызов
  {toolName, ok: true}                   — успех (БЕЗ output)
  {toolName, error, kind: 'thrown'}      — брошенный tool-error
  {toolName, error, kind: 'interrupted'} — прерван mid-step (abort/restart)

kind обязателен: синтетический «Tool call did not complete.» при прерывании иначе
неотличим от реального hard-fail и загрязняет error-rate. Различие структурное
(errorsById-хит против синтетической ветки), НЕ per-tool классификатор — soft-
маркеры в трейс не выносятся (остаются в metadata.parts).

metadata.toolTraceVersion: 2 — маркер эры; старые строки НЕ мигрируются
(перезапись гигантских jsonb — тот самый WAL-чарн). serializeSteps пейрит
результаты/ошибки по toolCallId (как assistantParts); общая константа
TOOL_CALL_INCOMPLETE_TEXT держит текст реплея и трейса в синхроне.

docs/reading-ai-logs.md переписан dual-shape: ветвление по toolTraceVersion,
soft-анализ v2 через metadata.parts, правило «не сравнивать агрегаты через границу
эр». UI action-log и markdown-экспорт читают только parts — не затронуты.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This commit is contained in:
agent_coder
2026-07-11 10:39:42 +03:00
parent 17e3b3d882
commit 48a074e0d2
3 changed files with 343 additions and 114 deletions
Download Patch File Download Diff File Expand all files Collapse all files
apps/server/src/core/ai-chat/ai-chat.service.spec.ts
+89 -13
View File
@@ -231,61 +231,137 @@ describe('assistantParts', () => {
});
});
describe('serializeSteps', () => {
// #490 trace format v2: per call the trace stores { input } for the call and an
// OUTCOME element — { ok: true } on success, { error, kind: 'thrown' } on a
// thrown tool-error, { error, kind: 'interrupted' } on a mid-step abort. The tool
// OUTPUT is no longer duplicated here (it lives once in metadata.parts).
describe('serializeSteps (trace v2)', () => {
it('returns null when there are no calls or results', () => {
expect(serializeSteps([])).toBeNull();
});
it('flattens calls and results into a compact trace', () => {
it('pairs a successful call with an { ok: true } outcome and NO output', () => {
const trace = serializeSteps([
{
toolCalls: [{ toolName: 'getPage', input: { id: 'p1' } }],
toolResults: [{ toolName: 'getPage', output: { title: 'T' } }],
toolCalls: [{ toolCallId: 'c1', toolName: 'getPage', input: { id: 'p1' } }],
toolResults: [{ toolCallId: 'c1', toolName: 'getPage' }],
},
]) as Array<Record<string, unknown>>;
expect(trace).toHaveLength(2);
expect(trace[0]).toEqual({ toolName: 'getPage', input: { id: 'p1' } });
expect(trace[1]).toEqual({ toolName: 'getPage', output: { title: 'T' } });
expect(trace[1]).toEqual({ toolName: 'getPage', ok: true });
// The output is NOT stored in the trace any more (dedup: it lives in parts).
expect(trace.some((e) => 'output' in e)).toBe(false);
});
it('records a THROWN tool failure (tool-error part) with its error message', () => {
it('records a THROWN failure with { error, kind: "thrown" }', () => {
const trace = serializeSteps([
{
toolCalls: [{ toolName: 'editPageText', input: { id: 'p1' } }],
toolCalls: [
{ toolCallId: 'c1', toolName: 'editPageText', input: { id: 'p1' } },
],
toolResults: [],
content: [
{
type: 'tool-error',
toolCallId: 'c1',
toolName: 'editPageText',
error: new Error('page is locked'),
},
],
},
]) as Array<Record<string, unknown>>;
// The call element is followed by a paired error element (mirroring how a
// successful result is appended), so the failure survives in the trace.
expect(trace).toHaveLength(2);
expect(trace[0]).toEqual({ toolName: 'editPageText', input: { id: 'p1' } });
expect(trace[1]).toEqual({
toolName: 'editPageText',
error: 'page is locked',
kind: 'thrown',
});
});
it('truncates a very long tool-error message to the tool-output limit', () => {
it('marks an interrupted call (no result, no throw) with kind "interrupted"', () => {
const trace = serializeSteps([
{
toolCalls: [
{ toolCallId: 'c1', toolName: 'createComment', input: { x: 1 } },
],
toolResults: [],
content: [],
},
]) as Array<Record<string, unknown>>;
expect(trace).toHaveLength(2);
expect(trace[1]).toEqual({
toolName: 'createComment',
error: 'Tool call did not complete.',
kind: 'interrupted',
});
// Structurally distinct from a thrown hard-fail so it never inflates an
// error-rate scan.
expect((trace[1] as { kind: string }).kind).not.toBe('thrown');
});
it('truncates a very long thrown-error message to the tool-output limit', () => {
const long = 'x'.repeat(5000);
const trace = serializeSteps([
{
toolCalls: [{ toolName: 'editPageText', input: {} }],
toolCalls: [{ toolCallId: 'c1', toolName: 'editPageText', input: {} }],
toolResults: [],
content: [{ type: 'tool-error', toolName: 'editPageText', error: long }],
content: [
{
type: 'tool-error',
toolCallId: 'c1',
toolName: 'editPageText',
error: long,
},
],
},
]) as Array<Record<string, unknown>>;
const errorText = trace[1].error as string;
// Truncated (not the full 5000 chars) and carries the omission marker.
expect(errorText.length).toBeLessThan(long.length);
expect(errorText).toContain('chars omitted');
});
it('pairs parallel calls in one step with their outcomes by id', () => {
const trace = serializeSteps([
{
toolCalls: [
{ toolCallId: 'a', toolName: 'getPage', input: {} },
{ toolCallId: 'b', toolName: 'searchPages', input: {} },
],
toolResults: [{ toolCallId: 'b', toolName: 'searchPages' }],
content: [
{ type: 'tool-error', toolCallId: 'a', toolName: 'getPage', error: 'nope' },
],
},
]) as Array<Record<string, unknown>>;
// call a, outcome a (thrown), call b, outcome b (ok)
expect(trace).toHaveLength(4);
expect(trace[1]).toEqual({ toolName: 'getPage', error: 'nope', kind: 'thrown' });
expect(trace[3]).toEqual({ toolName: 'searchPages', ok: true });
});
});
// #490: every assistant row flushAssistant writes carries the v2 era marker so a
// dual-shape diagnostic query can branch on the trace shape without inspecting it.
describe('toolTraceVersion era marker (#490)', () => {
it('stamps metadata.toolTraceVersion = 2 on every flushed row', () => {
const seed = flushAssistant([], '', 'streaming');
expect(seed.metadata.toolTraceVersion).toBe(2);
const done = flushAssistant(
[
{
text: 'ok',
toolCalls: [{ toolCallId: 'c1', toolName: 'getPage', input: {} }],
toolResults: [{ toolCallId: 'c1', toolName: 'getPage' }],
},
],
'',
'completed',
{ finishReason: 'stop' },
);
expect(done.metadata.toolTraceVersion).toBe(2);
});
});
describe('rowToUiMessage', () => {
apps/server/src/core/ai-chat/ai-chat.service.ts
+80 -23
View File
@@ -2164,6 +2164,15 @@ export function sanitizeUserParts(
/** Marker for a history row whose tool parts could not be replayed (#489). */
export const TOOL_CONTEXT_OMITTED_MARKER = '[tool context omitted]';
/**
* Synthetic error text for a tool call that neither returned a result nor threw
* a `tool-error` — i.e. it was interrupted mid-step (an abort / server restart).
* Shared by `assistantParts` (the replayed `output-error` part) and
* `serializeSteps` (the `{ kind: 'interrupted' }` trace element) so the replay
* text and the trace stay in lockstep (#490).
*/
export const TOOL_CALL_INCOMPLETE_TEXT = 'Tool call did not complete.';
/**
* Convert persisted UI history to model messages, tolerating a single poisoned
* row (#489). `convertToModelMessages` over the WHOLE array throws if ANY row is
@@ -2431,7 +2440,7 @@ export function assistantParts(
toolCallId: call.toolCallId,
state: 'output-error',
input: call.input,
errorText: 'Tool call did not complete.',
errorText: TOOL_CALL_INCOMPLETE_TEXT,
});
}
}
@@ -2614,6 +2623,11 @@ export function flushAssistant(
const metadata: Record<string, unknown> = {
parts: parts as unknown as UIMessage['parts'],
// Era marker for the `tool_calls` trace shape (#490): v2 stores outcome flags
// ({ ok } / { error, kind }) and NO tool output (the output lives once in
// `parts`). Old rows have no marker and the legacy { output } shape; a
// dual-shape query branches on this. Old rows are deliberately NOT migrated.
toolTraceVersion: 2,
};
// finishReason: prefer an explicit one; else derive a sensible value from the
// terminal status (so onError/onAbort records keep their historical reason).
@@ -2654,42 +2668,85 @@ export function flushAssistant(
/**
* Reduce SDK step objects to a compact, JSON-serializable trace for the
* `tool_calls` column. Stores only what the UI action-log and history need —
* never raw provider payloads or keys.
* `tool_calls` column — trace format **v2** (#490).
*
* v2 stores, per call, ONLY the metadata a queryable trace needs — never the
* tool OUTPUT. Before #490 each output was persisted TWICE: once here (compacted)
* and once in `metadata.parts` (via `assistantParts`), so a 50-step run with
* 50–200 KB outputs wrote hundreds of MB per turn (each `onStepFinish` rewrote
* the whole row). The parts copy is the one the model replays and the UI/Markdown
* export render, so the trace copy of the output was pure duplication. v2 keeps
* the output ONLY in parts and reduces the trace to outcome flags.
*
* Element shapes (paired per call, in order):
* - `{ toolName, input }` — the call
* - `{ toolName, ok: true }` — it returned a result (success)
* - `{ toolName, error, kind: 'thrown' }` — it threw a `tool-error`
* - `{ toolName, error, kind: 'interrupted' }` — no result and no throw (an
* abort / server restart mid-step). `kind` is MANDATORY: without it a
* synthetic "Tool call did not complete." is indistinguishable from a real
* hard-fail and pollutes any error-rate scan. The distinction is STRUCTURAL
* (an `errorsById` hit vs the synthetic fallback branch), NOT a per-tool
* classifier — soft failures stay OUT of the trace (they live in
* `metadata.parts` outputs; a per-tool mirror would persist its own bugs).
*
* Rows carry `metadata.toolTraceVersion: 2` (set by {@link flushAssistant}) so a
* dual-shape query can branch on the era. Old rows are NOT migrated (rewriting
* giant jsonb is the very WAL churn this removes); see docs/reading-ai-logs.md.
*/
export function serializeSteps(
steps: ReadonlyArray<{
toolCalls?: ReadonlyArray<{ toolName?: string; input?: unknown }>;
toolResults?: ReadonlyArray<{ toolName?: string; output?: unknown }>;
toolCalls?: ReadonlyArray<{
toolCallId?: string;
toolName?: string;
input?: unknown;
}>;
toolResults?: ReadonlyArray<{ toolCallId?: string; toolName?: string }>;
content?: ReadonlyArray<{
type?: string;
toolCallId?: string;
toolName?: string;
error?: unknown;
}>;
}>,
): unknown {
const calls: Array<{
toolName?: string;
input?: unknown;
output?: unknown;
error?: string;
}> = [];
const calls: Array<
| { toolName?: string; input?: unknown }
| { toolName?: string; ok: true }
| { toolName?: string; error: string; kind: 'thrown' | 'interrupted' }
> = [];
for (const step of steps ?? []) {
// Index this step's results + thrown errors by tool call id, so each call is
// paired with its outcome (mirrors assistantParts' pairing exactly).
const resultIds = new Set<string>();
for (const r of step.toolResults ?? []) {
if (r.toolCallId) resultIds.add(r.toolCallId);
}
const errorsById = new Map<string, unknown>();
for (const part of step.content ?? []) {
if (part.type === 'tool-error' && part.toolCallId) {
errorsById.set(part.toolCallId, part.error);
}
}
for (const call of step.toolCalls ?? []) {
calls.push({ toolName: call.toolName, input: call.input });
}
for (const r of step.toolResults ?? []) {
calls.push({ toolName: r.toolName, output: compactToolOutput(r.output) });
}
// ai@6 surfaces a THROWN tool failure as a `tool-error` content part, NOT as
// a `toolResults` entry. Record it as its own paired element (mirroring how a
// successful result is appended) so the failure and its reason survive in the
// trace instead of leaving an orphaned call with no result.
for (const part of step.content ?? []) {
if (part.type === 'tool-error') {
if (call.toolCallId && resultIds.has(call.toolCallId)) {
// Success: the output itself lives in metadata.parts, not here.
calls.push({ toolName: call.toolName, ok: true });
} else if (call.toolCallId && errorsById.has(call.toolCallId)) {
// Hard fail: the tool threw. Persist the real (bounded) reason.
calls.push({
toolName: part.toolName,
error: normalizeToolError(part.error),
toolName: call.toolName,
error: normalizeToolError(errorsById.get(call.toolCallId)),
kind: 'thrown',
});
} else {
// Neither a result nor a throw: interrupted mid-step (abort/restart).
// Marked structurally so it never inflates a thrown-error count.
calls.push({
toolName: call.toolName,
error: TOOL_CALL_INCOMPLETE_TEXT,
kind: 'interrupted',
});
}
}