From 1575fce711bce822854b302a2ea81dc21bbb1055 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jos=C3=A9=20Braulio=20Gonz=C3=A1lez=20Valido?= Date: Thu, 6 Aug 2026 09:23:37 +0100 Subject: [PATCH] fix(ai-builder): Bound eval lane requests and stop abandoned mocked executions (no-changelog) (#35228) Co-authored-by: Claude Opus 5 (1M context) --- .github/workflows/test-evals-instance-ai.yml | 49 +++++++- .../src/schemas/instance-ai.schema.ts | 13 ++- packages/@n8n/instance-ai/.gitignore | 2 + .../__tests__/build-orchestrator.test.ts | 31 +++++ .../__tests__/scenario-budget-stop.test.ts | 109 ++++++++++++++++++ .../__tests__/transient-error.test.ts | 32 +++++ .../clients/__tests__/n8n-client.test.ts | 64 +++++++++- .../clients/__tests__/wedged-lane.test.ts | 48 ++++++++ .../evaluations/clients/n8n-client.ts | 44 +++++-- .../evaluations/harness/agent-execution.ts | 9 +- .../evaluations/harness/scenario-execution.ts | 9 +- .../evaluations/harness/transient-error.ts | 24 ++++ .../evaluations/run/build-orchestrator.ts | 10 +- .../__tests__/agent-execution.service.test.ts | 32 +++++ .../eval/__tests__/execution.service.test.ts | 74 +++++++++++- .../eval/agent-execution.service.ts | 23 +++- .../instance-ai/eval/execution.service.ts | 74 +++++++++++- 17 files changed, 626 insertions(+), 21 deletions(-) create mode 100644 packages/@n8n/instance-ai/evaluations/__tests__/scenario-budget-stop.test.ts create mode 100644 packages/@n8n/instance-ai/evaluations/clients/__tests__/wedged-lane.test.ts diff --git a/.github/workflows/test-evals-instance-ai.yml b/.github/workflows/test-evals-instance-ai.yml index 2128aefd043..b969c1f3fcb 100644 --- a/.github/workflows/test-evals-instance-ai.yml +++ b/.github/workflows/test-evals-instance-ai.yml @@ -141,10 +141,15 @@ jobs: # Host OOMs and disk exhaustion leave no application trace — sample host # + container telemetry every 60s and ship it with the results artifact. + # + # `docker stats` names a hot lane but not the process inside it, and `comm` + # can't (Node reports `MainThread`). Sorted in the shell — `docker top` parses + # the ps output it asks for and the runner's ps rejects `--sort`. - name: Start host telemetry sampler run: | mkdir -p eval-diag { echo "=== disk at job start ==="; df -h /; docker system df; } > eval-diag/df-at-start.log + # shellcheck disable=SC2016 # deferred on purpose: the sampler expands these nohup bash -c 'while true; do { date -u +%FT%TZ @@ -152,6 +157,10 @@ jobs: df -h / | tail -1 docker stats --no-stream --format "{{.Name}} cpu={{.CPUPerc}} mem={{.MemUsage}}" ps -eo rss=,pid=,comm= --sort=-rss | head -5 + for c in $(docker ps --format "{{.Names}}" --filter name=n8n-eval-); do + docker top "$c" -o pid,pcpu,args 2>&1 | + tail -n +2 | sort -k2 -rn | head -2 | sed "s|^|$c |" | cut -c1-150 + done echo } >> eval-diag/host-samples.log 2>&1 sleep 60 @@ -214,12 +223,20 @@ jobs: # Bounded and self-healing: a lane that exhausts its capped heap is # restarted by docker instead of staying dead; pruning + log caps # keep per-lane disk and memory flat over a multi-hour run. + # + # Arms Node's diagnostic report on SIGUSR2 (requested in the log-capture + # step). Keep flag and signal in sync — unarmed, SIGUSR2 kills the process. + # --report-exclude-env is REQUIRED: the report embeds + # `environmentVariables` by default, and this container's env holds the + # Anthropic, LangSmith and licence secrets. `::add-mask::` only redacts + # log output, never an uploaded artifact, so without this the report + # would carry them into the run's artifacts verbatim. docker run -d --name "n8n-eval-$((i+1))" \ "${NETWORK_ARGS[@]}" \ --memory 2.5g --memory-swap 2.5g \ --restart on-failure \ --log-opt max-size=50m --log-opt max-file=2 \ - -e NODE_OPTIONS=--max-old-space-size=2048 \ + -e NODE_OPTIONS="--max-old-space-size=2048 --report-on-signal --report-signal=SIGUSR2 --report-directory=/tmp --report-exclude-env" \ -e EXECUTIONS_DATA_PRUNE=true \ -e EXECUTIONS_DATA_MAX_AGE=1 \ -e E2E_TESTS=true \ @@ -422,6 +439,25 @@ jobs: done <<< "$v" done + # A spin leaves no log line, so snapshot the processes and ask for a JS + # stack. Report is collected at the end of the step, once Node can write it. + HOT_LANES="" + while read -r name cpu; do + [ -n "$name" ] || continue + pct="${cpu%\%}" + pct="${pct%.*}" + # `docker stats` can emit a non-numeric CPUPerc (e.g. mid restart). With + # `-e`/pipefail an arithmetic compare on that aborts the whole step — and + # this step exists precisely to report on adverse conditions. + case "$pct" in ''|*[!0-9]*) continue ;; esac + [ "$pct" -ge 70 ] || continue + HOT_LANES="$HOT_LANES $name" + echo "" + echo "=== $name at $cpu — per-process snapshot ===" + docker top "$name" -o pid,ppid,pcpu,etime,args 2>&1 | cut -c1-200 || true + docker kill -s SIGUSR2 "$name" >/dev/null 2>&1 || true + done <<< "$(docker stats --no-stream --format '{{.Name}} {{.CPUPerc}}' 2>/dev/null | grep '^n8n-eval-' || true)" + # Layer 1 — accuracy filter: only surface diagnostic signals. # `tail -1000` after the filter so we get the LATEST matching lines # (post-eval failure signal), not the earliest startup-time ones. @@ -452,6 +488,17 @@ jobs: docker logs "$c" 2>&1 | tail -100 || true done + for name in $HOT_LANES; do + docker exec "$name" sh -c 'cat /tmp/report.*.json 2>/dev/null' \ + > "eval-diag/node-report-$name.json" 2>/dev/null || true + if [ -s "eval-diag/node-report-$name.json" ]; then + echo "captured Node diagnostic report for $name" + else + rm -f "eval-diag/node-report-$name.json" + echo "no Node diagnostic report from $name (loop never freed up)" + fi + done + - name: Stop n8n containers if: ${{ always() }} run: | diff --git a/packages/@n8n/api-types/src/schemas/instance-ai.schema.ts b/packages/@n8n/api-types/src/schemas/instance-ai.schema.ts index ce286ad13ec..9880665f36f 100644 --- a/packages/@n8n/api-types/src/schemas/instance-ai.schema.ts +++ b/packages/@n8n/api-types/src/schemas/instance-ai.schema.ts @@ -1667,6 +1667,12 @@ export class InstanceAiEvalExecutionRequest extends Z.class({ * as an error-shaped `InstanceAiEvalExecutionResult`. */ pinNodes: z.array(z.string().min(1)).max(50).optional(), + /** + * Budget for the whole run; the server waits indefinitely without it, leaving + * the execution running once the caller gives up. Generous ceiling: a per-case + * budget can exceed the 15 minutes a plain run takes. + */ + timeoutMs: z.number().int().min(30_000).max(3_600_000).optional(), }) {} // --------------------------------------------------------------------------- @@ -1739,8 +1745,11 @@ export class InstanceAiEvalAgentExecutionRequest extends Z.class({ /** Project the agent lives in (agent routes are project-scoped). */ projectId: z.string().min(1), scenarioHints: z.string().max(2000).optional(), - /** Overall run budget. Server default applies when omitted. */ - timeoutMs: z.number().int().min(30_000).max(900_000).optional(), + /** + * Overall run budget. Server default applies when omitted. Shares the workflow + * variant's ceiling — the old 900_000 cap truncated a `complex` case's budget. + */ + timeoutMs: z.number().int().min(30_000).max(3_600_000).optional(), }) {} export class InstanceAiEvalCredentialAllowlistRequest extends Z.class({ diff --git a/packages/@n8n/instance-ai/.gitignore b/packages/@n8n/instance-ai/.gitignore index 9a59c8dbb7a..d25b293aeea 100644 --- a/packages/@n8n/instance-ai/.gitignore +++ b/packages/@n8n/instance-ai/.gitignore @@ -2,3 +2,5 @@ eval-pr-comment.md eval-results.json eval-rows.jsonl +mcp-build-logs/ +logs/ diff --git a/packages/@n8n/instance-ai/evaluations/__tests__/build-orchestrator.test.ts b/packages/@n8n/instance-ai/evaluations/__tests__/build-orchestrator.test.ts index 11f30ba3225..2a4b85392d0 100644 --- a/packages/@n8n/instance-ai/evaluations/__tests__/build-orchestrator.test.ts +++ b/packages/@n8n/instance-ai/evaluations/__tests__/build-orchestrator.test.ts @@ -179,6 +179,37 @@ describe('createBuildOrchestrator', () => { expect(healthy).toHaveBeenCalledTimes(1); }); + it('retries a request-level abort on another lane — a wedged lane keeps passing readiness', async () => { + // Probe answers healthy, so the retry can only come from the message itself. + vi.stubGlobal('fetch', vi.fn().mockResolvedValue({ ok: true })); + const wedged = vi + .fn() + .mockResolvedValue(failedBuild('The operation was aborted due to timeout')); + const healthy = vi.fn().mockResolvedValue(okBuild()); + const orchestrator = createBuildOrchestrator( + makeDeps([makeLane(1, wedged), makeLane(2, healthy)]), + ); + + const { build } = await orchestrator.getOrBuild(0, 'case-a'); + + expect(build.success).toBe(true); + expect(wedged).toHaveBeenCalledTimes(1); + expect(healthy).toHaveBeenCalledTimes(1); + }); + + it("keeps the chat loop's own budget overrun a verdict, not a transport failure", async () => { + // Same shape, different message: the agent was slow on a healthy lane. + vi.stubGlobal('fetch', vi.fn().mockResolvedValue({ ok: true })); + const slow = vi.fn().mockResolvedValue(failedBuild('Run timed out after 900000ms')); + const orchestrator = createBuildOrchestrator(makeDeps([makeLane(1, slow)])); + + const { build } = await orchestrator.getOrBuild(0, 'case-a'); + + expect(build.success).toBe(false); + expect(build.transportFailure).toBe(false); + expect(slow).toHaveBeenCalledTimes(1); + }); + it('gives up after MAX_BUILD_ATTEMPTS, evicts the entry, and rebuilds on the next request', async () => { const failing1 = vi.fn().mockResolvedValue(failedBuild('fetch failed')); const failing2 = vi.fn().mockResolvedValue(failedBuild('fetch failed')); diff --git a/packages/@n8n/instance-ai/evaluations/__tests__/scenario-budget-stop.test.ts b/packages/@n8n/instance-ai/evaluations/__tests__/scenario-budget-stop.test.ts new file mode 100644 index 00000000000..78d24dfab3e --- /dev/null +++ b/packages/@n8n/instance-ai/evaluations/__tests__/scenario-budget-stop.test.ts @@ -0,0 +1,109 @@ +import type { + InstanceAiEvalAgentExecutionResult, + InstanceAiEvalExecutionResult, +} from '@n8n/api-types'; +import { mock } from 'vitest-mock-extended'; + +import type { N8nClient } from '../clients/n8n-client'; +import { executeAgentScenario } from '../harness/agent-execution'; +import type { EvalLogger } from '../harness/logger'; +import { executeScenario } from '../harness/scenario-execution'; +import type { ExecutionScenario } from '../types'; + +// A stopped run arrives in-band, so it must land on the timeout path rather than +// reach the judge as an ordinary failure. + +const silentLogger: EvalLogger = { + info: () => {}, + verbose: () => {}, + success: () => {}, + warn: () => {}, + error: () => {}, + isVerbose: false, +}; + +const scenario: ExecutionScenario = { + name: 'happy-path', + description: 'runs end to end', + dataSetup: 'one order arrives', + successCriteria: 'the order is forwarded', +}; + +function execResult(errors: string[]): InstanceAiEvalExecutionResult { + return { + executionId: 'exec-1', + success: false, + nodeResults: {}, + errors, + } as InstanceAiEvalExecutionResult; +} + +function agentResult(errors: string[]): InstanceAiEvalAgentExecutionResult { + return { + runId: 'run-1', + success: false, + errors, + finalText: '', + toolCalls: [], + modelTurns: [], + } as unknown as InstanceAiEvalAgentExecutionResult; +} + +describe('server-side budget stop', () => { + it('throws onto the timeout path instead of returning a judgeable failure', async () => { + const client = mock(); + client.executeWithLlmMock.mockResolvedValue( + execResult(['Execution exceeded its 895s eval budget and was stopped']), + ); + + await expect(executeScenario(client, 'wf-1', scenario, [], silentLogger)).rejects.toThrow( + /operation was aborted due to timeout/i, + ); + }); + + it('leaves an ordinary execution failure to the judge', async () => { + const client = mock(); + client.executeWithLlmMock.mockResolvedValue( + execResult(['Sheet with ID __evalMockResource not found']), + ); + + // Verification fails un-stubbed, so just assert the budget path did not fire. + const failure = await executeScenario(client, 'wf-1', scenario, [], silentLogger).catch( + (error: unknown) => error, + ); + + expect(String(failure)).not.toMatch(/eval budget|operation was aborted/i); + }); + + // The agent path stops a run for time on its OWN abort signal, so it reports in its + // own words. This fixture used to carry the workflow path's exact string — which + // `EvalAgentExecutionService` never produces — so it passed while a real timed-out + // agent run still fell through to the judge as a builder failure. + it('throws onto the timeout path for a stopped agent run', async () => { + const client = mock(); + client.getPersonalProjectId.mockResolvedValue('proj-1'); + client.executeAgentWithLlmMock.mockResolvedValue( + agentResult(['Agent run exceeded its 600s eval budget and was stopped']), + ); + + await expect( + executeAgentScenario(client, 'agent-1', scenario, 'context', silentLogger), + ).rejects.toThrow(/operation was aborted due to timeout/i); + }); + + it('leaves an ordinary agent failure to the judge', async () => { + const client = mock(); + client.getPersonalProjectId.mockResolvedValue('proj-1'); + client.executeAgentWithLlmMock.mockResolvedValue(agentResult(['Tool call returned a 500'])); + + const failure = await executeAgentScenario( + client, + 'agent-1', + scenario, + 'context', + silentLogger, + ).catch((error: unknown) => error); + + expect(String(failure)).not.toMatch(/eval budget|operation was aborted/i); + }); +}); diff --git a/packages/@n8n/instance-ai/evaluations/__tests__/transient-error.test.ts b/packages/@n8n/instance-ai/evaluations/__tests__/transient-error.test.ts index 3504acd8be2..1c42672cd58 100644 --- a/packages/@n8n/instance-ai/evaluations/__tests__/transient-error.test.ts +++ b/packages/@n8n/instance-ai/evaluations/__tests__/transient-error.test.ts @@ -1,6 +1,8 @@ import { extractErrorMessage, findProviderOutage, + isRequestAbort, + isServerBudgetStop, isTransientNetworkError, isTransientProviderError, MAX_EXEC_ATTEMPTS, @@ -59,6 +61,36 @@ describe('transient-error', () => { }); }); + describe('isRequestAbort', () => { + it('recognises the client abort message', () => { + expect(isRequestAbort('The operation was aborted due to timeout')).toBe(true); + }); + + it.each([ + // The chat loop's own budget overrun — the agent was slow, the lane is fine. + 'Run timed out after 900000ms', + // A node's timeout quoted in a build error must not evict the lane. + 'Tool errors: HTTP Request failed with TimeoutError', + ])('leaves %j to the lane health probe', (message) => { + expect(isRequestAbort(message)).toBe(false); + }); + }); + + describe('isServerBudgetStop', () => { + it('recognises the in-band error the server returns when it stops a run', () => { + expect(isServerBudgetStop(['Execution exceeded its 895s eval budget and was stopped'])).toBe( + true, + ); + }); + + it.each([[undefined], [[]], [['Sheet with ID __evalMockResource not found']]])( + 'leaves ordinary execution failures alone (%j)', + (errors) => { + expect(isServerBudgetStop(errors)).toBe(false); + }, + ); + }); + it('caps retries at a small positive number', () => { expect(MAX_EXEC_ATTEMPTS).toBeGreaterThan(1); expect(MAX_EXEC_ATTEMPTS).toBeLessThanOrEqual(5); diff --git a/packages/@n8n/instance-ai/evaluations/clients/__tests__/n8n-client.test.ts b/packages/@n8n/instance-ai/evaluations/clients/__tests__/n8n-client.test.ts index da6465ebe7a..4318e907721 100644 --- a/packages/@n8n/instance-ai/evaluations/clients/__tests__/n8n-client.test.ts +++ b/packages/@n8n/instance-ai/evaluations/clients/__tests__/n8n-client.test.ts @@ -1,4 +1,5 @@ import type { AgentJsonConfig, AgentSkill, EvaluationConfigDto } from '@n8n/api-types'; +import { jsonParse } from 'n8n-workflow'; import { N8nClient, @@ -19,9 +20,17 @@ function jsonResponse(body: unknown): Response { } as unknown as Response; } +/** Reads back what the client sent — its request bodies are always JSON strings. */ +function sentBody(init: RequestInit | undefined): { timeoutMs?: number } { + const body = init?.body; + return typeof body === 'string' ? jsonParse<{ timeoutMs?: number }>(body) : {}; +} + /** Stubs `global.fetch` to return `body` for any request, and returns the mock for assertions. */ function stubFetch(body: unknown) { - const fetchMock = vi.fn(async () => await Promise.resolve(jsonResponse(body))); + const fetchMock = vi.fn( + async (_url: string | URL, _init?: RequestInit) => await Promise.resolve(jsonResponse(body)), + ); vi.stubGlobal('fetch', fetchMock); return fetchMock; } @@ -72,6 +81,59 @@ describe('N8nClient — TRUST-229 artifact fetch methods', () => { }); }); + // undici's own timeouts are disabled process-wide, so an unsignalled request + // hangs forever against a lane that stops answering. + describe('request bound', () => { + it('applies the default floor to a call that passes no budget', async () => { + const timeoutSpy = vi.spyOn(AbortSignal, 'timeout'); + const fetchMock = stubFetch({ data: { id: 'proj-1' } }); + const client = new N8nClient(BASE_URL); + + await client.getPersonalProjectId(); + + expect(timeoutSpy).toHaveBeenCalledWith(120_000); + expect(fetchMock.mock.calls[0][1]?.signal).toBeInstanceOf(AbortSignal); + }); + + it("honours a caller's own budget instead of capping it at the floor", async () => { + const timeoutSpy = vi.spyOn(AbortSignal, 'timeout'); + const fetchMock = stubFetch({ data: { success: true, nodeResults: {}, errors: [] } }); + const client = new N8nClient(BASE_URL); + + await client.executeWithLlmMock('wf-1', undefined, 900_000); + + expect(timeoutSpy).toHaveBeenCalledWith(900_000); + expect(timeoutSpy).not.toHaveBeenCalledWith(120_000); + // Server gives up first, so the caller gets an in-band error. + expect(sentBody(fetchMock.mock.calls[0][1]).timeoutMs).toBe(895_000); + }); + + it('does not truncate a complex case budget when forwarding it', async () => { + const fetchMock = stubFetch({ data: {} }); + const client = new N8nClient(BASE_URL); + + // 1350s = the 1.5x budget a `complex` case carries. + await client.executeWithLlmMock('wf-1', undefined, 1_350_000); + await client.executeAgentWithLlmMock('agent-1', 'proj-1', undefined, 1_350_000); + + for (const call of fetchMock.mock.calls) { + expect(sentBody(call[1]).timeoutMs).toBe(1_345_000); + } + }); + + it('gives bulk thread restore its own larger budget', async () => { + const timeoutSpy = vi.spyOn(AbortSignal, 'timeout'); + stubFetch({ + data: { ok: true, threadId: 't-1', restored: 0, workflowIds: [], dataTableIds: [] }, + }); + const client = new N8nClient(BASE_URL); + + await client.restoreThread('t-1', [], []); + + expect(timeoutSpy).toHaveBeenCalledWith(300_000); + }); + }); + describe('getWorkflowEvaluationConfigs', () => { it('requests the workflow evaluation-configs route and unwraps the { data } envelope', async () => { const configs = [ diff --git a/packages/@n8n/instance-ai/evaluations/clients/__tests__/wedged-lane.test.ts b/packages/@n8n/instance-ai/evaluations/clients/__tests__/wedged-lane.test.ts new file mode 100644 index 00000000000..9ed16e0dc4a --- /dev/null +++ b/packages/@n8n/instance-ai/evaluations/clients/__tests__/wedged-lane.test.ts @@ -0,0 +1,48 @@ +import { createServer, type Server } from 'node:http'; + +import { + extractErrorMessage, + isExecutionTimeout, + isRequestAbort, + isTransientNetworkError, +} from '../../harness/transient-error'; +import { N8nClient } from '../n8n-client'; + +// Real undici, not a stubbed fetch: what matters is undici's own behaviour — that +// the per-request signal is what ends a call to a lane that never answers, and +// that the abort's message is the string the transport classifiers key on. +describe('a lane that accepts connections but never answers', () => { + let server: Server; + let baseUrl = ''; + + beforeAll(async () => { + server = createServer(() => {}); // accept and hold: no response, no close + await new Promise((resolve) => server.listen(0, '127.0.0.1', () => resolve())); + const address = server.address(); + if (address === null || typeof address === 'string') throw new Error('no port assigned'); + baseUrl = `http://127.0.0.1:${address.port}`; + }); + + afterAll(async () => { + await new Promise((resolve) => server.close(() => resolve())); + }); + + it('aborts at the budget instead of hanging, and reads as a transport failure', async () => { + const client = new N8nClient(baseUrl); + + // This route takes its own budget, so the assertion costs 200ms, not 120s. + const failure = await client + .listThreadDebugRuns('11111111-1111-4111-8111-111111111111', 200) + .catch((error: unknown) => error); + + expect(failure).toBeInstanceOf(Error); + const message = extractErrorMessage(failure); + expect(message).toBe('The operation was aborted due to timeout'); + + // Why isRequestAbort exists: the network predicate misses this, and a lane + // wedged with a live listener still passes the health probe. + expect(isRequestAbort(message)).toBe(true); + expect(isExecutionTimeout(message)).toBe(true); + expect(isTransientNetworkError(message)).toBe(false); + }); +}); diff --git a/packages/@n8n/instance-ai/evaluations/clients/n8n-client.ts b/packages/@n8n/instance-ai/evaluations/clients/n8n-client.ts index c1cab975414..4a753a0d0cc 100644 --- a/packages/@n8n/instance-ai/evaluations/clients/n8n-client.ts +++ b/packages/@n8n/instance-ai/evaluations/clients/n8n-client.ts @@ -29,6 +29,23 @@ import { z } from 'zod'; // eval CLI harness — never import into the n8n server or shared runtime code. setGlobalDispatcher(new Agent({ headersTimeout: 0, bodyTimeout: 0 })); +/** Floor for calls that pass no budget: the dispatcher above leaves those + * unbounded, so a silent lane would hang rather than fail. Sized for a plain + * REST call — slower callers pass their own. */ +const DEFAULT_REQUEST_TIMEOUT_MS = 120_000; + +/** Bulk creation of seed workflows + data tables; slower than a plain REST call. */ +const RESTORE_THREAD_TIMEOUT_MS = 300_000; + +/** How much longer the client waits than the server budget it hands over. */ +const CLIENT_ABORT_MARGIN_MS = 5_000; + +/** Server gives up just before the client, so the caller gets an in-band error + * rather than a bare abort. Uncapped: 15 min truncated `complex` budgets. */ +function serverBudgetFor(timeoutMs: number): number { + return Math.max(timeoutMs - CLIENT_ABORT_MARGIN_MS, 30_000); +} + // -- Conversation seeding response shapes ------------------------------------- const RestoreThreadEnvelope = z.object({ @@ -683,6 +700,7 @@ export class N8nClient { const result = await this.fetch('/rest/instance-ai/eval/restore-thread', { method: 'POST', body, + timeoutMs: RESTORE_THREAD_TIMEOUT_MS, }); return RestoreThreadEnvelope.parse(result).data; } @@ -813,14 +831,17 @@ export class N8nClient { timeoutMs: number = 120_000, pinNodes?: string[], ): Promise { - const body: { scenarioHints?: string; pinNodes?: string[] } = {}; + const body: { scenarioHints?: string; pinNodes?: string[]; timeoutMs?: number } = {}; if (scenarioHints) body.scenarioHints = scenarioHints; if (pinNodes && pinNodes.length > 0) body.pinNodes = pinNodes; + // Forwarded so the server stops the run rather than leaving it burning CPU. + const serverBudgetMs = serverBudgetFor(timeoutMs); + body.timeoutMs = serverBudgetMs; const result = (await this.fetch(`/rest/instance-ai/eval/execute-with-llm-mock/${workflowId}`, { method: 'POST', body, - timeoutMs, + timeoutMs: serverBudgetMs + CLIENT_ABORT_MARGIN_MS, })) as { data: InstanceAiEvalExecutionResult }; return result.data; } @@ -838,11 +859,7 @@ export class N8nClient { ): Promise { const body: { projectId: string; scenarioHints?: string; timeoutMs?: number } = { projectId }; if (scenarioHints) body.scenarioHints = scenarioHints; - // Forward the budget server-side so the run is aborted rather than - // orphaned when the client gives up. The server floor is the schema min - // (30s), so the client abort is floored to 5s above it — a smaller - // caller value would leave the server running long after the client quit. - const serverBudgetMs = Math.min(Math.max(timeoutMs - 5_000, 30_000), 900_000); + const serverBudgetMs = serverBudgetFor(timeoutMs); body.timeoutMs = serverBudgetMs; const result = (await this.fetch( @@ -850,7 +867,7 @@ export class N8nClient { { method: 'POST', body, - timeoutMs: serverBudgetMs + 5_000, + timeoutMs: serverBudgetMs + CLIENT_ABORT_MARGIN_MS, }, )) as { data: InstanceAiEvalAgentExecutionResult }; return result.data; @@ -903,11 +920,20 @@ export class N8nClient { const method = options.method ?? 'GET'; + // A bare `?? DEFAULT` would turn `timeoutMs: 0` into `AbortSignal.timeout(0)` — + // an instant abort, where the old truthiness check meant "unbounded". No caller + // passes one, and unbounded is what this path exists to remove, so a + // non-positive value falls back to the default: bounded either way. + const timeoutMs = + options.timeoutMs !== undefined && options.timeoutMs > 0 + ? options.timeoutMs + : DEFAULT_REQUEST_TIMEOUT_MS; + const res = await fetch(`${this.baseUrl}${path}`, { method, headers, body: options.body ? JSON.stringify(options.body) : undefined, - ...(options.timeoutMs ? { signal: AbortSignal.timeout(options.timeoutMs) } : {}), + signal: AbortSignal.timeout(timeoutMs), }); if (!res.ok) { diff --git a/packages/@n8n/instance-ai/evaluations/harness/agent-execution.ts b/packages/@n8n/instance-ai/evaluations/harness/agent-execution.ts index 1b5380237b7..bb3710cefa0 100644 --- a/packages/@n8n/instance-ai/evaluations/harness/agent-execution.ts +++ b/packages/@n8n/instance-ai/evaluations/harness/agent-execution.ts @@ -14,7 +14,11 @@ import { agentHandler } from './artifacts/agent-handler'; import { attributionForScenario } from './attribution'; import type { EvalLogger } from './logger'; import { writeScenarioVerificationSnapshot, type VerificationArtifact } from './scenario-execution'; -import { isTransientExecutionAbort, MAX_EXEC_ATTEMPTS } from './transient-error'; +import { + throwIfServerBudgetStop, + isTransientExecutionAbort, + MAX_EXEC_ATTEMPTS, +} from './transient-error'; import { verifyChecklist } from '../checklist/verifier'; import type { N8nClient } from '../clients/n8n-client'; import type { @@ -98,6 +102,9 @@ export async function executeAgentScenario( timeoutMs, ); } + // Killed for time, not by the builder — throw so the timeout path classifies it. + throwIfServerBudgetStop(evalResult); + const execMs = Date.now() - execStart; logger.info( diff --git a/packages/@n8n/instance-ai/evaluations/harness/scenario-execution.ts b/packages/@n8n/instance-ai/evaluations/harness/scenario-execution.ts index 4e4ac0b8b34..fc33042fbfd 100644 --- a/packages/@n8n/instance-ai/evaluations/harness/scenario-execution.ts +++ b/packages/@n8n/instance-ai/evaluations/harness/scenario-execution.ts @@ -15,7 +15,11 @@ import { setTimeout as delay } from 'node:timers/promises'; import { attributionForScenario } from './attribution'; import type { EvalLogger } from './logger'; import { reseedScenarioTables, type ScenarioSeedContext } from './seed-tables'; -import { isTransientExecutionAbort, MAX_EXEC_ATTEMPTS } from './transient-error'; +import { + throwIfServerBudgetStop, + isTransientExecutionAbort, + MAX_EXEC_ATTEMPTS, +} from './transient-error'; import { buildWorkflowContextBlock } from './workflow-context'; import { isMockableTriggerNodeType } from '../../src/tools/workflows/workflow-json-utils'; import { type VerifierAttemptDebug, verifyChecklist } from '../checklist/verifier'; @@ -306,6 +310,9 @@ async function runScenario( pinNodes, ); } + // Killed for time, not by the builder — throw so the timeout path classifies it. + throwIfServerBudgetStop(evalResult); + const execMs = Date.now() - execStart; const pinTag = pinNodes ? ` pinned=${pinNodes.join(',')}` : ''; diff --git a/packages/@n8n/instance-ai/evaluations/harness/transient-error.ts b/packages/@n8n/instance-ai/evaluations/harness/transient-error.ts index 623c401e29b..7e78589b80b 100644 --- a/packages/@n8n/instance-ai/evaluations/harness/transient-error.ts +++ b/packages/@n8n/instance-ai/evaluations/harness/transient-error.ts @@ -55,6 +55,30 @@ export function isExecutionTimeout(message: string): boolean { return /operation was aborted|TimeoutError/i.test(message); } +/** A request cut short by the client's own AbortSignal. Narrower than + * {@link isExecutionTimeout}: a node's quoted `TimeoutError` is not a dead lane. */ +export function isRequestAbort(message: string): boolean { + return /operation was aborted/i.test(message); +} + +/** The server stopped the run for exceeding the forwarded budget. In-band + * (`success: false`), so unrecognised it reads as an ordinary failure to the + * judge. Wording kept in sync with BOTH server paths that stop a run for time: + * `EvalExecutionService.awaitRunWithinBudget` (workflow) and + * `EvalAgentExecutionService`'s budget abort (agent). */ +export function isServerBudgetStop(errors: string[] | undefined): boolean { + return (errors ?? []).some((e) => /exceeded its .*eval budget/i.test(e)); +} + +/** Re-throw a budget stop as a timeout so the caller's timeout path classifies it + * instead of the judge scoring it as a builder failure. Shared by the workflow and + * agent scenario runners: the classification is one rule, so it lives in one place + * rather than being kept in sync by hand at two call sites. No-op otherwise. */ +export function throwIfServerBudgetStop(result: { success: boolean; errors: string[] }): void { + if (result.success || !isServerBudgetStop(result.errors)) return; + throw new Error(`The operation was aborted due to timeout: ${result.errors.join('; ')}`); +} + /** Retry decision for one failed scenario-execution attempt. */ export function shouldRetryScenarioExecution(message: string, attempt: number): boolean { if (isTransientNetworkError(message)) return attempt < MAX_EXEC_ATTEMPTS; diff --git a/packages/@n8n/instance-ai/evaluations/run/build-orchestrator.ts b/packages/@n8n/instance-ai/evaluations/run/build-orchestrator.ts index b2a3b386135..fdec3f3c1e6 100644 --- a/packages/@n8n/instance-ai/evaluations/run/build-orchestrator.ts +++ b/packages/@n8n/instance-ai/evaluations/run/build-orchestrator.ts @@ -37,6 +37,7 @@ import type { executeScenario } from '../harness/scenario-execution'; import type { ScenarioSeedContext } from '../harness/seed-tables'; import { findProviderOutage, + isRequestAbort, isTransientNetworkError, MAX_PROVIDER_BUILD_ATTEMPTS, providerRetryBackoffMs, @@ -264,9 +265,16 @@ export function createBuildOrchestrator(deps: BuildOrchestratorDeps): BuildOrche // A build that sat out its timeout against a dead lane reports "Run timed // out", not "fetch failed" — so any failed build also health-probes its lane. + // A request abort counts too; the chat loop's own overrun ("Run timed out after + // Nms") does not — that is the agent being slow on a healthy lane. async function isTransportFailure(build: BuildResult, lane: LaneState): Promise { if (build.success) return false; - if (build.error !== undefined && isTransientNetworkError(build.error)) return true; + if ( + build.error !== undefined && + (isTransientNetworkError(build.error) || isRequestAbort(build.error)) + ) { + return true; + } return !(await laneHealthy(lane)); } diff --git a/packages/cli/src/modules/instance-ai/eval/__tests__/agent-execution.service.test.ts b/packages/cli/src/modules/instance-ai/eval/__tests__/agent-execution.service.test.ts index 300b0c5ed79..12fdf63542b 100644 --- a/packages/cli/src/modules/instance-ai/eval/__tests__/agent-execution.service.test.ts +++ b/packages/cli/src/modules/instance-ai/eval/__tests__/agent-execution.service.test.ts @@ -623,6 +623,38 @@ describe('EvalAgentExecutionService.executeWithLlmMock', () => { expect(close).toHaveBeenCalledTimes(1); }); + // Killed for TIME, not by the builder. The harness classifies this off the wording + // ("exceeded its …s eval budget", `isServerBudgetStop`) and routes it to the timeout + // path; reported as a plain `Agent run failed:` it scored as a builder verdict — + // exactly the misattribution the budget plumbing exists to prevent. + it('reports a budget abort in the words the harness classifies as a timeout', async () => { + reconstructFromAgentEntity.mockResolvedValue({ + agent: { + generate: vi + .fn() + .mockImplementation(async (_message, opts: { abortSignal: AbortSignal }) => { + // What AbortSignal.timeout does once the budget elapses. + await new Promise((resolve) => setTimeout(resolve, 5)); + throw Object.assign(new Error('The operation was aborted due to timeout'), { + name: 'TimeoutError', + signalAborted: opts.abortSignal.aborted, + }); + }), + close: vi.fn().mockResolvedValue(undefined), + }, + toolRegistry: {}, + }); + + const result = await buildService().executeWithLlmMock('agent-1', user, { + ...request, + timeoutMs: 1, + }); + + expect(result.success).toBe(false); + expect(result.errors[0]).toMatch(/exceeded its \d+s eval budget/); + expect(result.errors[0]).not.toMatch(/Agent run failed/); + }); + it('flips success off when the run finishes with a model error', async () => { reconstructFromAgentEntity.mockResolvedValue({ agent: { diff --git a/packages/cli/src/modules/instance-ai/eval/__tests__/execution.service.test.ts b/packages/cli/src/modules/instance-ai/eval/__tests__/execution.service.test.ts index 03edb4f0f20..2fe10299fb8 100644 --- a/packages/cli/src/modules/instance-ai/eval/__tests__/execution.service.test.ts +++ b/packages/cli/src/modules/instance-ai/eval/__tests__/execution.service.test.ts @@ -11,7 +11,7 @@ import type { IWorkflowBase, INodeTypeDescription, } from 'n8n-workflow'; -import { UserError } from 'n8n-workflow'; +import { TimeoutExecutionCancelledError, UserError } from 'n8n-workflow'; import type { ActiveExecutions } from '@/active-executions'; import type { LoadNodesAndCredentials } from '@/load-nodes-and-credentials'; @@ -525,6 +525,78 @@ describe('EvalExecutionService', () => { expect(activeExecutions.getPostExecutePromise).toHaveBeenCalledWith(DB_EXECUTION_ID); }); + // Stopping rejects the promise the service awaits, as ActiveExecutions does — + // pinning that the budget is reported and not that rejection. + it('stops the execution and reports it when the run outlives the caller budget', async () => { + vi.useFakeTimers(); + try { + let rejectRun: (error: Error) => void = () => {}; + activeExecutions.getPostExecutePromise.mockImplementation( + async () => + await new Promise((_resolve, reject) => { + rejectRun = reject; + }), + ); + activeExecutions.stopExecution.mockImplementation((_id, cancellationError) => { + rejectRun(cancellationError); + }); + + const pending = service.executeWithLlmMock('wf-1', makeUser(), { timeoutMs: 30_000 }); + await vi.advanceTimersByTimeAsync(30_001); + const result = await pending; + + expect(activeExecutions.stopExecution).toHaveBeenCalledWith( + DB_EXECUTION_ID, + expect.any(TimeoutExecutionCancelledError), + ); + expect(result.success).toBe(false); + expect(result.errors).toEqual([expect.stringContaining('30s eval budget')]); + } finally { + vi.useRealTimers(); + } + }); + + // Hint generation is an LLM call, so it has to come out of the caller's + // budget — otherwise the request outlives the deadline it declared. + it('charges setup time against the caller budget', async () => { + vi.useFakeTimers(); + try { + let rejectRun: (error: Error) => void = () => {}; + activeExecutions.getPostExecutePromise.mockImplementation( + async () => + await new Promise((_resolve, reject) => { + rejectRun = reject; + }), + ); + activeExecutions.stopExecution.mockImplementation((_id, cancellationError) => { + rejectRun(cancellationError); + }); + // Setup burns 25s of the 30s budget. The clock moves without running + // timers — advancing them here would re-enter the timer queue the test + // drives below. + generateMockHintsMock.mockImplementation(async () => { + vi.setSystemTime(Date.now() + 25_000); + return makeEmptyHints(); + }); + + const pending = service.executeWithLlmMock('wf-1', makeUser(), { timeoutMs: 30_000 }); + // Only the 5s left after setup, not another full 30s. + await vi.advanceTimersByTimeAsync(5_001); + const result = await pending; + + expect(activeExecutions.stopExecution).toHaveBeenCalled(); + expect(result.errors).toEqual([expect.stringContaining('30s eval budget')]); + } finally { + vi.useRealTimers(); + } + }); + + it('keeps waiting indefinitely when the caller sends no budget', async () => { + await service.executeWithLlmMock('wf-1', makeUser()); + + expect(activeExecutions.stopExecution).not.toHaveBeenCalled(); + }); + it('wraps additionalData.credentialsHelper inside configureAdditionalData', async () => { await service.executeWithLlmMock('wf-1', makeUser()); diff --git a/packages/cli/src/modules/instance-ai/eval/agent-execution.service.ts b/packages/cli/src/modules/instance-ai/eval/agent-execution.service.ts index b0875cbbdc9..499a39d9a83 100644 --- a/packages/cli/src/modules/instance-ai/eval/agent-execution.service.ts +++ b/packages/cli/src/modules/instance-ai/eval/agent-execution.service.ts @@ -351,9 +351,12 @@ export class EvalAgentExecutionService { if (!segmentToolCalls.includes(entry)) segmentToolCalls.push(entry); } }; + const budgetSignal = AbortSignal.timeout(timeoutMs); try { - const abortSignal = AbortSignal.timeout(timeoutMs); - result = await agent.generate(seed.openingMessage, { abortSignal, maxIterations }); + result = await agent.generate(seed.openingMessage, { + abortSignal: budgetSignal, + maxIterations, + }); collectToolCalls(result); // Approval-gated tools suspend the run. In real usage the user @@ -368,7 +371,7 @@ export class EvalAgentExecutionService { result = await agent.approve('generate', { runId: pending.runId, toolCallId: pending.toolCallId, - abortSignal, + abortSignal: budgetSignal, maxIterations, }); collectToolCalls(result); @@ -380,6 +383,20 @@ export class EvalAgentExecutionService { const message = error instanceof Error ? error.message : String(error); // Flush so the failure result carries the recorded response bodies too. await recorder.flush(); + // A budget abort is the harness killing the run for time, NOT the builder + // failing. Say so in the words the WORKFLOW path already uses, so the one + // classifier (`isServerBudgetStop`) covers both — wrapping it as a plain + // `Agent run failed:` let a timed-out agent run score as a builder verdict, + // which is the misattribution this whole path exists to prevent. + if (budgetSignal.aborted) { + const seconds = Math.round(timeoutMs / 1000); + return this.errorResult( + `Agent run exceeded its ${seconds}s eval budget and was stopped`, + seed, + skippedFeatures, + { modelTurns: recorder.turns, toolLedger, credentialHelpers }, + ); + } return this.errorResult(`Agent run failed: ${message}`, seed, skippedFeatures, { modelTurns: recorder.turns, toolLedger, diff --git a/packages/cli/src/modules/instance-ai/eval/execution.service.ts b/packages/cli/src/modules/instance-ai/eval/execution.service.ts index 2668f1d192d..13728136784 100644 --- a/packages/cli/src/modules/instance-ai/eval/execution.service.ts +++ b/packages/cli/src/modules/instance-ai/eval/execution.service.ts @@ -34,6 +34,7 @@ import { createRunExecutionData, fileTypeFromMimeType, NodeHelpers, + TimeoutExecutionCancelledError, UserError, Workflow, } from 'n8n-workflow'; @@ -81,6 +82,13 @@ import { /** Max output items per branch kept in the artifact. The full count lives in `outputCount`. */ const MAX_OUTPUT_ITEMS_PER_BRANCH = 10; +/** A caller's run budget as a wall-clock deadline; setup counts against it, so + * the run gets what is left. `totalMs` is kept for the message. */ +interface RunBudget { + totalMs: number; + deadlineAt: number; +} + // --------------------------------------------------------------------------- // Service // --------------------------------------------------------------------------- @@ -110,6 +118,13 @@ export class EvalExecutionService { user: User, options: InstanceAiEvalExecutionRequest = {}, ): Promise { + // Anchored at receipt, before any setup: setup is LLM calls, so a budget + // anchored later would expire after the caller's own deadline. + const budget: RunBudget | undefined = + options.timeoutMs === undefined + ? undefined + : { totalMs: options.timeoutMs, deadlineAt: Date.now() + options.timeoutMs }; + // Eval routes through WorkflowRunner with a configureAdditionalData closure // that doesn't survive queue serialization. Refuse upfront so vendor calls // can never leak to real providers from a worker that never wires the mock. @@ -196,6 +211,7 @@ export class EvalExecutionService { options.scenarioHints, interceptionEnabled, vendorLlmRouting, + budget, ); } @@ -412,6 +428,8 @@ export class EvalExecutionService { scenarioHints?: string, interceptionEnabled = false, vendorLlmRouting?: VendorLlmRouting, + /** Caller's budget; unbounded when omitted. See awaitRunWithinBudget. */ + budget?: RunBudget, ): Promise { const nodeResults: Record = {}; @@ -544,7 +562,7 @@ export class EvalExecutionService { }; dbExecutionId = await this.workflowRunner.run(runData); - const runResult = await this.activeExecutions.getPostExecutePromise(dbExecutionId); + const runResult = await this.awaitRunWithinBudget(dbExecutionId, budget); if (!runResult) { return this.buildPartialFailureResult( @@ -920,6 +938,60 @@ export class EvalExecutionService { }; } + /** + * Await the execution, stopping it once the budget elapses. Eval mode skips + * concurrency reservation (see `ActiveExecutions.add`), so nothing else would, + * and an abandoned run keeps burning CPU on a shared instance. Omit to wait. + */ + private async awaitRunWithinBudget( + executionId: string, + budget: RunBudget | undefined, + ): Promise { + const postExecute = this.activeExecutions.getPostExecutePromise(executionId); + if (!budget) return await postExecute; + + // Race loser: our timer's cancellation must not surface as unhandled. + postExecute.catch(() => {}); + + // Clamped: setup may have eaten the budget, which stops the run at once. + const remainingMs = Math.max(budget.deadlineAt - Date.now(), 0); + const seconds = Math.round(budget.totalMs / 1000); + const budgetError = () => + new Error(`Execution exceeded its ${seconds}s eval budget and was stopped`); + + // `stopExecution` rejects the promise being raced, so report off this flag + // rather than whichever arm won — else a budget stop reads as any other + // cancellation. + let stoppedForBudget = false; + + let deadline: NodeJS.Timeout | undefined; + try { + return await Promise.race([ + postExecute, + new Promise((_resolve, reject) => { + deadline = setTimeout(() => { + stoppedForBudget = true; + this.logger.warn( + `[EvalMock] Execution ${executionId} exceeded its ${seconds}s budget — stopping it`, + ); + // No try/catch: `stopExecution` returns early for an unknown id + // rather than throwing, so an execution that finished between the + // timer firing and this call needs no handling here. + this.activeExecutions.stopExecution( + executionId, + new TimeoutExecutionCancelledError(executionId), + ); + reject(budgetError()); + }, remainingMs); + }), + ]); + } catch (error) { + throw stoppedForBudget ? budgetError() : error; + } finally { + if (deadline) clearTimeout(deadline); + } + } + /** * Build the failure result returned when execution threw partway through — * preserves the accumulated `nodeResults`, `hints`, and credential