fix(session-goal): bound length recovery after truncation (#3278)

Thanks to alvins82 for tracing the truncation failure and to bashrusakh for adding bounded recovery and error precedence. We will finish the explicit Resume behavior in the same batch.

Closes #3255

Co-authored-by: alvins82 <alvins82@gmail.com>
This commit is contained in:
Leonid
2026-09-05 10:46:18 +03:00
committed by GitHub
co-authored by alvins82
parent 47e2049427
commit c5086e0250
3 changed files with 477 additions and 18 deletions
@@ -108,13 +108,23 @@ before touching the filesystem). Rationale: metadata rides every
stop), with a tick-side safety net. Messages sent while paused leave
the goal alone; Resume re-arms the loop, and resuming over an aborted
tail skips the audit and goes straight to a continuation nudge;
- terminal checks, cheapest first: assistant turn error → `blocked`;
`tokensUsed >= tokenBudget``budgetLimited`;
`turnsUsed >= MAX_AUTO_TURNS` (20) → `blocked`;
- if the latest message is a compaction summary, skip the audit and
continue unconditionally — running into the context window mid-work is
by definition "in progress, not finished" (the summary is a retelling,
not evidence, and must not be judged);
- terminal checks, cheapest first: assistant turn error → `blocked`;
`tokensUsed >= tokenBudget``budgetLimited`;
`turnsUsed >= MAX_AUTO_TURNS` (20) → `blocked`;
- error classification is independent of `finish`: `MessageAbortedError`
keeps the pause/resume behavior; only a `finish: "length"` with no
error, or `MessageOutputLengthError`, is an in-progress truncation that
skips the audit and continues. Any other non-null error wins over a
length finish and blocks with its non-empty `error.name`, or
`assistant turn failed` when unnamed;
- length recovery is bounded separately from the token budget and
auto-continuation cap: the first truncation permits one continuation, but
a second consecutive completed, non-summary assistant turn that is also
truncated settles the goal as `blocked` (`repeated output truncation`).
The consecutive state is derived from the loaded message history, not
persisted, using `info.time.created` chronology rather than message IDs.
Summary messages are not agent turns; an ordinary completed assistant
turn naturally breaks the consecutive condition;
- otherwise, small-model audit of the objective + the last assistant turn
only — no conversation history and no continuation prompts
(`restrictToPreferredProvider`, session's own provider/model preferred):
+76 -11
View File
@@ -244,6 +244,57 @@ const messageTokenTotal = (info) => {
return input + cachedRead + output;
};
const getErrorName = (error) => error?.name?.trim?.() ?? '';
const isLengthTruncated = (info, errorName = getErrorName(info?.error)) => {
const error = info?.error;
const hasError = error !== null && error !== undefined;
return errorName === 'MessageOutputLengthError' || (!hasError && info?.finish === 'length');
};
// Summary messages are assistant-shaped, but they are compaction turns rather
// than agent turns. They must not break or satisfy the consecutive truncation
// check; only completed, non-summary assistant turns participate. Chronology
// comes from `time.created`, never from message IDs; array position is only a
// tie-breaker for equal timestamps.
const hasRepeatedLengthTail = (messages, latestAssistant, goalCreatedAt) => {
const latestInfo = latestAssistant?.info;
if (latestInfo?.summary === true) return false;
const latestIndex = messages.indexOf(latestAssistant);
const latestCreated = latestInfo?.time?.created;
if (
latestIndex < 0
|| !(latestInfo?.time?.completed > 0)
|| !(Number.isFinite(latestCreated) && latestCreated > 0)
|| !isLengthTruncated(latestInfo)
) return false;
let previous = null;
for (let i = 0; i < messages.length; i += 1) {
const info = messages[i]?.info;
if (info?.role !== 'assistant' || info.summary === true || !(info.time?.completed > 0)) continue;
const created = info.time?.created;
// An unknown timestamp cannot safely participate in chronology. Ignore it
// rather than letting an unrelated older message hide known chronology.
if (!(Number.isFinite(created) && created > 0)) continue;
if (i === latestIndex) continue;
if (created > latestCreated || (created === latestCreated && i > latestIndex)) continue;
if (
!previous
|| created > previous.created
|| (created === previous.created && i > previous.index)
) {
previous = { info, created, index: i };
}
}
return Boolean(
previous
&& previous.created > goalCreatedAt
&& isLengthTruncated(previous.info),
);
};
export const createSessionGoalRuntime = ({
buildOpenCodeUrl,
getOpenCodeAuthHeaders,
@@ -609,7 +660,11 @@ export const createSessionGoalRuntime = ({
// resumed over an aborted tail: that is an explicit "keep going", so it
// falls through to the continuation below (skipping the audit — an
// aborted reply is not evidence of anything).
const abortedTail = lastAssistantInfo.error?.name === 'MessageAbortedError';
const error = lastAssistantInfo.error;
const errorName = getErrorName(error);
const hasError = error !== null && error !== undefined;
const abortedTail = errorName === 'MessageAbortedError';
const lengthTail = isLengthTruncated(lastAssistantInfo, errorName);
if (abortedTail && goal.statusReason !== 'resumed') {
await writeGoal(sessionId, directory, goal.id, () => ({
status: 'paused',
@@ -623,13 +678,12 @@ export const createSessionGoalRuntime = ({
return;
}
// Turn error → blocked (prevents runaway auto-continuation into failures).
if (!abortedTail && lastAssistantInfo.error && typeof lastAssistantInfo.error === 'object') {
const reason = typeof lastAssistantInfo.error.name === 'string' && lastAssistantInfo.error.name
? lastAssistantInfo.error.name
: 'assistant turn failed';
// Non-length turn error → blocked (prevents runaway auto-continuation into
// failures). Recognized length cutoffs are in-progress continuations, not
// hard failures.
if (!abortedTail && !lengthTail && hasError) {
await settleGoal({
sessionId, directory, goal, status: 'blocked', statusReason: reason, tokensUsed, tokensBaseline, tokensCommitted, lastAccountedMessageID,
sessionId, directory, goal, status: 'blocked', statusReason: errorName || 'assistant turn failed', tokensUsed, tokensBaseline, tokensCommitted, lastAccountedMessageID,
});
return;
}
@@ -650,17 +704,28 @@ export const createSessionGoalRuntime = ({
return;
}
// A second consecutive completed, non-summary length-truncated turn is a
// bounded recovery failure. Derive this from the loaded transcript rather
// than persisting another goal counter.
if (lengthTail && hasRepeatedLengthTail(messages, lastAssistant, goal.createdAt)) {
await settleGoal({
sessionId, directory, goal, status: 'blocked', statusReason: 'repeated output truncation', tokensUsed, tokensBaseline, tokensCommitted, lastAccountedMessageID,
});
return;
}
// --- Small-model audit: the sole termination authority besides the hard
// stops above (turn error, budget, continuation cap). The working agent
// has no channel to settle its own goal.
//
// Exception: when the latest message is a compaction summary, the agent
// by definition ran into the context window mid-work — that IS
// "in progress, not finished". No audit call; continue unconditionally.
// Exception: when the latest message is a compaction summary or was cut off
// by the output token limit (length stop), the agent by definition ran into
// the context/output limit mid-work — that IS "in progress, not finished".
// No audit call; continue unconditionally.
let audit = null;
let blockedStreak = 0;
let auditFailStreak = goal.auditFailStreak;
if (lastAssistantInfo.summary === true || abortedTail) {
if (lastAssistantInfo.summary === true || abortedTail || lengthTail) {
blockedStreak = goal.blockedStreak;
} else {
audit = await runAudit({ goal: { ...goal, objective: effectiveObjective }, assistantText, directory, lastAssistantInfo: executionInfo ?? lastAssistantInfo });
@@ -46,6 +46,75 @@ const startIdleTick = async (fetchImpl) => {
return { runtime, getSmallModelService };
};
const assistantMessage = (id, infoOverrides = {}) => ({
info: {
id,
sessionID: SESSION_ID,
role: 'assistant',
providerID: 'provider',
modelID: 'model',
time: { created: 2, completed: 2 },
tokens: { input: 1, output: 1, cache: { read: 0 } },
...infoOverrides,
},
parts: [{ type: 'text', text: 'The agent made progress.' }],
});
const createRuntimeHarness = ({ messages, messageFactory, goalOverrides = {}, maxAutoTurns = 20 }) => {
const requests = [];
let messageFetchCount = 0;
const activeSession = {
...session,
metadata: { openchamber: { goal: { ...goal, ...goalOverrides } } },
};
const service = {
generateSmallModelText: vi.fn(async () => ({
text: '{"verdict":"continue","note":"More work remains"}',
providerID: 'provider',
modelID: 'model',
})),
};
const fetchImpl = vi.fn(async (input, init = {}) => {
const pathname = requestPath(input);
requests.push({ pathname, method: init.method ?? 'GET', body: init.body });
if (pathname === `/session/${SESSION_ID}` && init.method === 'PATCH') return jsonResponse(activeSession);
if (pathname === `/session/${SESSION_ID}`) return jsonResponse(activeSession);
if (pathname === '/session/status') return jsonResponse({});
if (pathname === `/session/${SESSION_ID}/children`) return jsonResponse([]);
if (pathname === `/session/${SESSION_ID}/message`) {
const nextMessages = messageFactory ? messageFactory(messageFetchCount) : messages;
messageFetchCount += 1;
return jsonResponse(nextMessages);
}
if (pathname === `/session/${SESSION_ID}/prompt_async`) return jsonResponse({ ok: true });
throw new Error(`Unexpected request: ${pathname}`);
});
vi.stubGlobal('fetch', fetchImpl);
const runtime = createSessionGoalRuntime({
buildOpenCodeUrl: (pathname) => `http://opencode.test${pathname}`,
getOpenCodeAuthHeaders: () => ({}),
getSmallModelService: async () => service,
isEnabled: () => true,
idleQuietMs: 10,
maxAutoTurns,
});
return { runtime, requests, service };
};
const runIdleTick = async (runtime) => {
runtime.processPayload({
type: 'session.status',
properties: { sessionID: SESSION_ID, status: { type: 'idle' }, directory: DIRECTORY },
});
await vi.runOnlyPendingTimersAsync();
};
const lastPatchedGoal = (requests) => {
const patches = requests.filter((request) => request.pathname === `/session/${SESSION_ID}` && request.method === 'PATCH');
expect(patches.length).toBeGreaterThan(0);
return JSON.parse(patches.at(-1).body).metadata.openchamber.goal;
};
describe('session goal live activity gate', () => {
beforeEach(() => {
vi.useFakeTimers();
@@ -178,4 +247,319 @@ describe('session goal live activity gate', () => {
});
runtime.stop();
});
it('skips audit and sends continuation prompt when assistant message finishes with length stop', async () => {
const requests = [];
const fetchImpl = vi.fn(async (input, init = {}) => {
const pathname = requestPath(input);
requests.push({ pathname, method: init.method ?? 'GET', body: init.body });
if (pathname === `/session/${SESSION_ID}` && init.method === 'PATCH') return jsonResponse(session);
if (pathname === `/session/${SESSION_ID}`) return jsonResponse(session);
if (pathname === '/session/status') return jsonResponse({});
if (pathname === `/session/${SESSION_ID}/children`) return jsonResponse([]);
if (pathname === `/session/${SESSION_ID}/prompt_async`) return jsonResponse({ ok: true });
if (pathname === `/session/${SESSION_ID}/message`) {
return jsonResponse([{
info: {
id: 'msg_assistant_len',
sessionID: SESSION_ID,
role: 'assistant',
providerID: 'provider',
modelID: 'model',
finish: 'length',
time: { completed: 2 },
tokens: { input: 100, output: 4096, reasoning: 4096, cache: { read: 0 } },
},
parts: [{ type: 'reasoning', text: 'Drafting extensive implementation...' }],
}]);
}
throw new Error(`Unexpected request: ${pathname}`);
});
const service = {
generateSmallModelText: vi.fn(),
};
vi.stubGlobal('fetch', fetchImpl);
const runtime = createSessionGoalRuntime({
buildOpenCodeUrl: (pathname) => `http://opencode.test${pathname}`,
getOpenCodeAuthHeaders: () => ({}),
getSmallModelService: async () => service,
isEnabled: () => true,
idleQuietMs: 10,
});
runtime.processPayload({
type: 'session.status',
properties: { sessionID: SESSION_ID, status: { type: 'idle' }, directory: DIRECTORY },
});
await vi.runOnlyPendingTimersAsync();
// Audit must be skipped on length-truncated turn
expect(service.generateSmallModelText).not.toHaveBeenCalled();
// Goal accounting is persisted and turnsUsed incremented
const patch = requests.find((request) => request.pathname === `/session/${SESSION_ID}` && request.method === 'PATCH');
expect(patch).toBeDefined();
const writtenGoal = JSON.parse(patch.body).metadata.openchamber.goal;
expect(writtenGoal).toMatchObject({
status: 'active',
turnsUsed: 2,
});
// Continuation prompt is dispatched
const promptAsync = requests.find((request) => request.pathname === `/session/${SESSION_ID}/prompt_async` && request.method === 'POST');
expect(promptAsync).toBeDefined();
const promptBody = JSON.parse(promptAsync.body);
expect(promptBody.parts[0].text).toContain('Continue working toward the active session goal.');
runtime.stop();
});
it('skips audit and sends continuation prompt when assistant message carries MessageOutputLengthError', async () => {
const requests = [];
const fetchImpl = vi.fn(async (input, init = {}) => {
const pathname = requestPath(input);
requests.push({ pathname, method: init.method ?? 'GET', body: init.body });
if (pathname === `/session/${SESSION_ID}` && init.method === 'PATCH') return jsonResponse(session);
if (pathname === `/session/${SESSION_ID}`) return jsonResponse(session);
if (pathname === '/session/status') return jsonResponse({});
if (pathname === `/session/${SESSION_ID}/children`) return jsonResponse([]);
if (pathname === `/session/${SESSION_ID}/prompt_async`) return jsonResponse({ ok: true });
if (pathname === `/session/${SESSION_ID}/message`) {
return jsonResponse([{
info: {
id: 'msg_assistant_len_err',
sessionID: SESSION_ID,
role: 'assistant',
providerID: 'provider',
modelID: 'model',
error: { name: 'MessageOutputLengthError', message: 'Maximum token limit reached' },
time: { completed: 2 },
tokens: { input: 100, output: 4096, reasoning: 4096, cache: { read: 0 } },
},
parts: [{ type: 'reasoning', text: 'Drafting extensive implementation...' }],
}]);
}
throw new Error(`Unexpected request: ${pathname}`);
});
const service = {
generateSmallModelText: vi.fn(),
};
vi.stubGlobal('fetch', fetchImpl);
const runtime = createSessionGoalRuntime({
buildOpenCodeUrl: (pathname) => `http://opencode.test${pathname}`,
getOpenCodeAuthHeaders: () => ({}),
getSmallModelService: async () => service,
isEnabled: () => true,
idleQuietMs: 10,
});
runtime.processPayload({
type: 'session.status',
properties: { sessionID: SESSION_ID, status: { type: 'idle' }, directory: DIRECTORY },
});
await vi.runOnlyPendingTimersAsync();
// Audit must be skipped on MessageOutputLengthError
expect(service.generateSmallModelText).not.toHaveBeenCalled();
// Goal remains active and turnsUsed incremented
const patch = requests.find((request) => request.pathname === `/session/${SESSION_ID}` && request.method === 'PATCH');
expect(patch).toBeDefined();
const writtenGoal = JSON.parse(patch.body).metadata.openchamber.goal;
expect(writtenGoal).toMatchObject({
status: 'active',
turnsUsed: 2,
});
// Continuation prompt is dispatched
const promptAsync = requests.find((request) => request.pathname === `/session/${SESSION_ID}/prompt_async` && request.method === 'POST');
expect(promptAsync).toBeDefined();
runtime.stop();
});
it.each([
{ name: 'APIError', error: { name: 'APIError', message: 'provider failed' } },
{ name: 'StructuredOutputError', error: { name: 'StructuredOutputError', message: 'invalid output' } },
{ name: 'unnamed errors', error: {} },
])('blocks a length finish when the assistant also has a non-length $name', async ({ error }) => {
const { runtime, requests, service } = createRuntimeHarness({
messages: [assistantMessage('msg_assistant_error', { finish: 'length', error })],
});
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.some((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toBe(false);
expect(lastPatchedGoal(requests)).toMatchObject({
status: 'blocked',
statusReason: error.name || 'assistant turn failed',
});
runtime.stop();
});
it('blocks after two consecutive length-truncated agent turns without persisting a counter, regardless of message IDs', async () => {
const firstLength = assistantMessage('z', { finish: 'length', time: { created: 10, completed: 11 } });
const summary = assistantMessage('summary', { summary: true, time: { created: 15, completed: 16 } });
const secondLength = assistantMessage('a', { finish: 'length', time: { created: 20, completed: 21 } });
const { runtime, requests, service } = createRuntimeHarness({
messageFactory: (fetchCount) => fetchCount < 2 ? [firstLength] : [firstLength, summary, secondLength],
});
await runIdleTick(runtime);
runtime.processPayload({
type: 'session.status',
properties: { sessionID: SESSION_ID, status: { type: 'idle' }, directory: DIRECTORY },
});
await vi.runOnlyPendingTimersAsync();
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(1);
expect(lastPatchedGoal(requests)).toMatchObject({
status: 'blocked',
statusReason: 'repeated output truncation',
});
runtime.stop();
});
it('continues after a truncated agent turn followed by a length-finished summary', async () => {
const firstLength = assistantMessage('agent-length', { finish: 'length', time: { created: 10, completed: 11 } });
const summary = assistantMessage('summary', {
summary: true,
finish: 'length',
time: { created: 15, completed: 16 },
});
const { runtime, requests, service } = createRuntimeHarness({
messageFactory: (fetchCount) => fetchCount < 2 ? [firstLength] : [firstLength, summary],
});
await runIdleTick(runtime);
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(2);
expect(lastPatchedGoal(requests)).toMatchObject({ status: 'active' });
runtime.stop();
});
it('does not infer a repeated streak when a completed assistant timestamp is missing', async () => {
const firstLength = assistantMessage('z', { finish: 'length', time: { completed: 11 } });
const secondLength = assistantMessage('a', { finish: 'length', time: { created: 20, completed: 21 } });
const { runtime, requests, service } = createRuntimeHarness({
messageFactory: (fetchCount) => fetchCount < 2 ? [firstLength] : [firstLength, secondLength],
});
await runIdleTick(runtime);
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(2);
expect(lastPatchedGoal(requests)).toMatchObject({ status: 'active' });
runtime.stop();
});
it('ignores a missing timestamp on an older assistant when known post-goal turns establish a streak', async () => {
const olderLength = assistantMessage('legacy', { finish: 'length', time: { completed: 5 } });
const firstLength = assistantMessage('z', { finish: 'length', time: { created: 10, completed: 11 } });
const secondLength = assistantMessage('a', { finish: 'length', time: { created: 20, completed: 21 } });
const { runtime, requests, service } = createRuntimeHarness({
goalOverrides: { createdAt: 6 },
messageFactory: (fetchCount) => fetchCount < 2 ? [firstLength] : [olderLength, firstLength, secondLength],
});
await runIdleTick(runtime);
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(1);
expect(lastPatchedGoal(requests)).toMatchObject({
status: 'blocked',
statusReason: 'repeated output truncation',
});
runtime.stop();
});
it('does not count a previous truncated turn created at the goal boundary', async () => {
const firstLength = assistantMessage('before-boundary', { finish: 'length', time: { created: 10, completed: 11 } });
const secondLength = assistantMessage('after-boundary', { finish: 'length', time: { created: 20, completed: 21 } });
const { runtime, requests, service } = createRuntimeHarness({
goalOverrides: { createdAt: 10 },
messageFactory: (fetchCount) => fetchCount < 2 ? [firstLength] : [firstLength, secondLength],
});
await runIdleTick(runtime);
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(2);
expect(lastPatchedGoal(requests)).toMatchObject({ status: 'active' });
runtime.stop();
});
it('allows length recovery after an ordinary assistant turn breaks the streak', async () => {
const firstLength = assistantMessage('msg_length_before_normal', { finish: 'length' });
const normal = assistantMessage('msg_normal');
const secondLength = assistantMessage('msg_length_after_normal', { finish: 'length' });
const { runtime, requests, service } = createRuntimeHarness({
messageFactory: (fetchCount) => fetchCount < 2
? [firstLength]
: [firstLength, normal, secondLength],
});
await runIdleTick(runtime);
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.filter((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toHaveLength(2);
expect(lastPatchedGoal(requests)).toMatchObject({ status: 'active' });
runtime.stop();
});
it('keeps MessageAbortedError pause behavior instead of continuing', async () => {
const { runtime, requests, service } = createRuntimeHarness({
messages: [assistantMessage('msg_aborted', { error: { name: 'MessageAbortedError' } })],
});
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.some((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toBe(false);
expect(lastPatchedGoal(requests)).toMatchObject({
status: 'paused',
statusReason: 'paused after abort',
});
runtime.stop();
});
it('checks the token budget before allowing length recovery', async () => {
const { runtime, requests, service } = createRuntimeHarness({
goalOverrides: { tokenBudget: 5 },
messages: [assistantMessage('msg_budget_length', {
finish: 'length',
tokens: { input: 3, output: 3, cache: { read: 0 } },
})],
});
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.some((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toBe(false);
expect(lastPatchedGoal(requests)).toMatchObject({ status: 'budgetLimited' });
runtime.stop();
});
it('checks the auto-continuation cap before allowing length recovery', async () => {
const { runtime, requests, service } = createRuntimeHarness({
maxAutoTurns: 1,
messages: [assistantMessage('msg_cap_length', { finish: 'length' })],
});
await runIdleTick(runtime);
expect(service.generateSmallModelText).not.toHaveBeenCalled();
expect(requests.some((request) => request.pathname === `/session/${SESSION_ID}/prompt_async`)).toBe(false);
expect(lastPatchedGoal(requests)).toMatchObject({
status: 'blocked',
statusReason: 'auto-continuation limit reached',
});
runtime.stop();
});
});