From 313e6e9a000e8968f47dba191074bce84c2c267f Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Wed, 5 Aug 2026 18:38:58 +0200 Subject: [PATCH 01/10] fix(workflow-executor): pass the executor logger to ai-proxy's AiClient ai-proxy holds an optional host logger and no-ops every emit when none is given, so a workflow MCP step that failed tool loading left no cause anywhere in the customer's own logs: a revoked token, a resource never shared and an unreachable server were indistinguishable. The cause is flattened to { error, stack } rather than handed over as the log context, because an Error's own properties are non-enumerable and would vanish from the serialised line. Co-Authored-By: Claude Opus 5 (1M context) --- packages/workflow-executor/CLAUDE.md | 2 +- .../src/adapters/ai-client-adapter.ts | 9 +- .../src/adapters/server-ai-adapter.ts | 8 ++ .../src/adapters/to-ai-proxy-logger.ts | 19 +++ .../src/build-workflow-executor.ts | 4 +- .../test/adapters/ai-client-adapter.test.ts | 46 ++++++- .../test/adapters/server-ai-adapter.test.ts | 53 ++++++++ .../test/adapters/to-ai-proxy-logger.test.ts | 123 ++++++++++++++++++ .../test/build-workflow-executor.test.ts | 38 +++++- 9 files changed, 289 insertions(+), 13 deletions(-) create mode 100644 packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts create mode 100644 packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts diff --git a/packages/workflow-executor/CLAUDE.md b/packages/workflow-executor/CLAUDE.md index c0070b30f4..265d8120ad 100644 --- a/packages/workflow-executor/CLAUDE.md +++ b/packages/workflow-executor/CLAUDE.md @@ -53,7 +53,7 @@ Front ◀──▶ Orchestrator ◀──pull/push──▶ Executor (this p - **Boundary validation** — wire/mapper types live in `types/validated/` as zod. Strictness by origin: executor-produced + frontend bodies use `.strict()`; the orchestrator collection schema **strips** unknowns and asserts step-specific props at use-time (resilient to orchestrator drift). Parse failure → `DomainValidationError`/`InvalidStepDefinitionError`. `StepOutcome` is validated only when it arrives via `previousSteps`; executor outputs are trusted by construction. - **DatabaseStore** — table `workflow_step_executions` + migration registry namespaced under a schema (default `forest`, override via `DATABASE_SCHEMA`), so a DB shared with the agent/server is safe. The schema is created idempotently at `init()`, but gated on a `pg_namespace` existence probe (not `CREATE SCHEMA IF NOT EXISTS` alone): Postgres checks database-level `CREATE` even for `IF NOT EXISTS`, so probing lets a pre-created schema boot with only schema-level `CREATE`. SQLite (tests) skips schemas. Migrations run behind a **transaction-scoped Postgres advisory lock** (`pg_advisory_xact_lock`, safe behind RDS Proxy / PgBouncer) so HA cold-starts migrate once; migrations are transactional + idempotent. Postgres-only; the lock key is a fixed constant — never change it. - **Graceful shutdown** — `stop()` drains in-flight steps (`idle → running → draining → stopped`), `stopTimeoutMs` default 30s, HTTP stays up during drain. Signal handling is the consumer's job. -- **Logging** — `Logger = (level, message, context?) => void`. `BaseStepExecutor` stamps `logCtx` (runId/stepId/stepIndex/stepType); type-specific ids via `getExtraLogContext()`. `createConsoleLogger`/`createPrettyLogger(minLevel)` factories; CLI level from `LOG_LEVEL` (default `Info`). +- **Logging** — `Logger = (level, message, context?) => void`. `BaseStepExecutor` stamps `logCtx` (runId/stepId/stepIndex/stepType); type-specific ids via `getExtraLogContext()`. `createConsoleLogger`/`createPrettyLogger(minLevel)` factories; CLI level from `LOG_LEVEL` (default `Info`). ai-proxy's logger takes the cause as a third `Error` argument instead of a context object, so both AI adapters bridge it with `toAiProxyLogger` (flattens to `{ error, stack }` — an `Error`'s own properties are non-enumerable and would vanish from the emitted line). - **Config comes from the boundary, never `process.env`** — no executor *config* is read from `process.env` outside `cli-core`: every knob is parsed there (standalone) or injected as an option (`ExecutorOptions` / the agent's `addWorkflowExecutor` options), and the check for a value is `Boolean(options.x)`, not `process.env`. Runtime-mode flags — `NODE_ENV` (forceAiError prod-guard, token-endpoint dev check) and the `OTEL_*` observability vars in `tracing.ts` — are the deliberate exception. This keeps the executor identically configurable standalone and embedded, and testable without mutating env. (Regression fixed once: `FOREST_EXECUTOR_ENCRYPTION_KEY` was read in `crypto/` — now injected via `executorEncryptionKey`.) - **AI** — import every AI type (`BaseChatModel`, `DynamicStructuredTool`, `SystemMessage`/`HumanMessage`, `RemoteTool`/`ToolConfig`) from `@forestadmin/ai-proxy`, **not** `@langchain/core` (which is not a dependency). `ExecutionContext.model` is a `BaseChatModel`. The only langchain mention in src is a comment in `cli.ts` about transitively loading `@langchain/openai`. diff --git a/packages/workflow-executor/src/adapters/ai-client-adapter.ts b/packages/workflow-executor/src/adapters/ai-client-adapter.ts index 43369caf16..1fb47481f1 100644 --- a/packages/workflow-executor/src/adapters/ai-client-adapter.ts +++ b/packages/workflow-executor/src/adapters/ai-client-adapter.ts @@ -1,4 +1,5 @@ import type { AiModelPort, GetModelOptions } from '../ports/ai-model-port'; +import type { Logger } from '../ports/logger-port'; import type { AiConfiguration, BaseChatModel, @@ -10,13 +11,17 @@ import type { import { AiClient } from '@forestadmin/ai-proxy'; import { AiModelPortError, WorkflowExecutorError } from '../errors'; +import toAiProxyLogger from './to-ai-proxy-logger'; export default class AiClientAdapter implements AiModelPort { private readonly aiClient: AiClient; - constructor(aiConfigurations: AiConfiguration[]) { + constructor(aiConfigurations: AiConfiguration[], logger?: Logger) { const withRetries = aiConfigurations.map(c => ({ maxRetries: 2, ...c })); - this.aiClient = new AiClient({ aiConfigurations: withRetries as AiConfiguration[] }); + this.aiClient = new AiClient({ + aiConfigurations: withRetries as AiConfiguration[], + logger: logger ? toAiProxyLogger(logger) : undefined, + }); } getModel({ aiConfigName }: GetModelOptions = {}): BaseChatModel { diff --git a/packages/workflow-executor/src/adapters/server-ai-adapter.ts b/packages/workflow-executor/src/adapters/server-ai-adapter.ts index 2d05307d30..6932553771 100644 --- a/packages/workflow-executor/src/adapters/server-ai-adapter.ts +++ b/packages/workflow-executor/src/adapters/server-ai-adapter.ts @@ -1,4 +1,6 @@ +import type { AiProxyLogger } from './to-ai-proxy-logger'; import type { AiModelPort, GetModelOptions } from '../ports/ai-model-port'; +import type { Logger } from '../ports/logger-port'; import type { AiConfiguration, BaseChatModel, @@ -10,20 +12,25 @@ import type { import { AiClient } from '@forestadmin/ai-proxy'; import { AiModelPortError, WorkflowExecutorError } from '../errors'; +import toAiProxyLogger from './to-ai-proxy-logger'; export interface ServerAiAdapterOptions { forestServerUrl: string; envSecret: string; + logger?: Logger; } export default class ServerAiAdapter implements AiModelPort { private readonly options: ServerAiAdapterOptions; + private readonly aiProxyLogger?: AiProxyLogger; private readonly aiClient: AiClient; constructor(options: ServerAiAdapterOptions) { this.options = options; + this.aiProxyLogger = options.logger ? toAiProxyLogger(options.logger) : undefined; this.aiClient = new AiClient({ aiConfigurations: [ServerAiAdapter.buildProxyConfiguration(options)], + logger: this.aiProxyLogger, }); } @@ -31,6 +38,7 @@ export default class ServerAiAdapter implements AiModelPort { try { const client = new AiClient({ aiConfigurations: [ServerAiAdapter.buildProxyConfiguration(this.options, userId)], + logger: this.aiProxyLogger, }); return client.getModel(); diff --git a/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts b/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts new file mode 100644 index 0000000000..d6751c98f8 --- /dev/null +++ b/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts @@ -0,0 +1,19 @@ +import type { Logger, LoggerLevel } from '../ports/logger-port'; + +import { extractErrorMessage } from '../errors'; + +// ai-proxy hands the cause as an Error, the executor's logger expects a context object. +export type AiProxyLogger = (level: LoggerLevel, message: string, error?: Error) => void; + +// An Error's own properties are non-enumerable, so forwarding it as the context would emit the line +// with the cause silently stripped — flatten it the way the rest of the executor logs causes. +export default function toAiProxyLogger(logger: Logger): AiProxyLogger { + return (level, message, error) => { + if (error === undefined || error === null) return logger(level, message); + + return logger(level, message, { + error: extractErrorMessage(error), + stack: error instanceof Error ? error.stack : undefined, + }); + }; +} diff --git a/packages/workflow-executor/src/build-workflow-executor.ts b/packages/workflow-executor/src/build-workflow-executor.ts index a440bac6d8..3096427d7a 100644 --- a/packages/workflow-executor/src/build-workflow-executor.ts +++ b/packages/workflow-executor/src/build-workflow-executor.ts @@ -119,9 +119,9 @@ function buildCommonDependencies(options: ExecutorOptions) { if (forceAiError) { aiModelPort = new AlwaysErrorAiModelPort(); } else if (options.aiConfigurations?.length) { - aiModelPort = new AiClientAdapter(options.aiConfigurations); + aiModelPort = new AiClientAdapter(options.aiConfigurations, logger); } else { - aiModelPort = new ServerAiAdapter({ forestServerUrl, envSecret: options.envSecret }); + aiModelPort = new ServerAiAdapter({ forestServerUrl, envSecret: options.envSecret, logger }); } // A TTL of 0/negative/non-finite would silently make the cache always-stale, so fall back. diff --git a/packages/workflow-executor/test/adapters/ai-client-adapter.test.ts b/packages/workflow-executor/test/adapters/ai-client-adapter.test.ts index 5dee091eac..b7a0246d89 100644 --- a/packages/workflow-executor/test/adapters/ai-client-adapter.test.ts +++ b/packages/workflow-executor/test/adapters/ai-client-adapter.test.ts @@ -1,17 +1,25 @@ +import type { AiProxyLogger } from '../../src/adapters/to-ai-proxy-logger'; +import type { Logger } from '../../src/ports/logger-port'; + import AiClientAdapter from '../../src/adapters/ai-client-adapter'; const mockGetModel = jest.fn().mockReturnValue({ invoke: jest.fn() }); const mockLoadRemoteTools = jest.fn().mockResolvedValue([]); const mockLoadRemoteToolsWithFailures = jest.fn().mockResolvedValue({ tools: [], failures: [] }); const mockCloseConnections = jest.fn().mockResolvedValue(undefined); +const mockAiClientConstructor = jest.fn(); jest.mock('@forestadmin/ai-proxy', () => ({ - AiClient: jest.fn().mockImplementation(() => ({ - getModel: mockGetModel, - loadRemoteTools: mockLoadRemoteTools, - loadRemoteToolsWithFailures: mockLoadRemoteToolsWithFailures, - closeConnections: mockCloseConnections, - })), + AiClient: jest.fn().mockImplementation((...args: unknown[]) => { + mockAiClientConstructor(...args); + + return { + getModel: mockGetModel, + loadRemoteTools: mockLoadRemoteTools, + loadRemoteToolsWithFailures: mockLoadRemoteToolsWithFailures, + closeConnections: mockCloseConnections, + }; + }), })); describe('AiClientAdapter', () => { @@ -62,4 +70,30 @@ describe('AiClientAdapter', () => { expect(mockCloseConnections).toHaveBeenCalled(); }); + + describe('logger', () => { + const buildAdapter = (logger?: Logger) => new AiClientAdapter([], logger); + + const aiProxyLoggerGivenToClient = () => + (mockAiClientConstructor.mock.calls[0][0] as { logger?: AiProxyLogger }).logger; + + it("routes ai-proxy's MCP diagnostics to the executor logger with the cause flattened", () => { + const executorLogger = jest.fn(); + buildAdapter(executorLogger); + const cause = new Error('401 Unauthorized'); + + aiProxyLoggerGivenToClient()?.('Error', 'Error loading tools for notion', cause); + + expect(executorLogger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: '401 Unauthorized', + stack: cause.stack, + }); + }); + + it('leaves AiClient without a logger when the adapter is built without one', () => { + buildAdapter(); + + expect(aiProxyLoggerGivenToClient()).toBeUndefined(); + }); + }); }); diff --git a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts index 42b917973e..5b77d8b59d 100644 --- a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts +++ b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts @@ -1,3 +1,6 @@ +import type { AiProxyLogger } from '../../src/adapters/to-ai-proxy-logger'; +import type { Logger } from '../../src/ports/logger-port'; + import ServerAiAdapter from '../../src/adapters/server-ai-adapter'; const mockGetModel = jest.fn().mockReturnValue({ id: 'fake-model' }); @@ -152,4 +155,54 @@ describe('ServerAiAdapter', () => { expect(mockCloseConnections).toHaveBeenCalled(); }); }); + + describe('logger', () => { + const buildAdapterWithLogger = (logger: Logger) => + new ServerAiAdapter({ + forestServerUrl: 'https://api.forestadmin.com', + envSecret: ENV_SECRET, + logger, + }); + + const aiProxyLoggerGivenToLatestClient = () => { + const { calls } = mockAiClientConstructor.mock; + + return (calls[calls.length - 1][0] as { logger?: AiProxyLogger }).logger; + }; + + it("routes ai-proxy's MCP diagnostics to the executor logger with the cause flattened", () => { + const executorLogger = jest.fn(); + buildAdapterWithLogger(executorLogger); + const cause = new Error('401 Unauthorized'); + + aiProxyLoggerGivenToLatestClient()?.('Error', 'Error loading tools for notion', cause); + + expect(executorLogger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: '401 Unauthorized', + stack: cause.stack, + }); + }); + + it('also gives the per-call AiClient built by getModel the executor logger', () => { + const executorLogger = jest.fn(); + buildAdapterWithLogger(executorLogger).getModel({ userId: 42 }); + + aiProxyLoggerGivenToLatestClient()?.( + 'Warn', + "AI configuration 'x' not found. Falling back to 'forest-server'", + ); + + expect(executorLogger).toHaveBeenCalledWith( + 'Warn', + "AI configuration 'x' not found. Falling back to 'forest-server'", + ); + }); + + // The adapter built in beforeEach carries no logger option. + it('leaves AiClient without a logger when none is configured', () => { + const params = mockAiClientConstructor.mock.calls[0][0] as { logger?: AiProxyLogger }; + + expect(params.logger).toBeUndefined(); + }); + }); }); diff --git a/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts new file mode 100644 index 0000000000..8e5acd5dde --- /dev/null +++ b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts @@ -0,0 +1,123 @@ +import createConsoleLogger from '../../src/adapters/console-logger'; +import toAiProxyLogger from '../../src/adapters/to-ai-proxy-logger'; + +describe('toAiProxyLogger', () => { + let logger: jest.Mock; + let aiProxyLogger: ReturnType; + + beforeEach(() => { + logger = jest.fn(); + aiProxyLogger = toAiProxyLogger(logger); + }); + + describe('without a cause', () => { + it('forwards every level and message unchanged, adding no context', () => { + aiProxyLogger('Debug', 'Loaded 3 tools from MCP server "notion" in 12ms'); + aiProxyLogger('Info', 'Using AI configuration default'); + aiProxyLogger('Warn', 'Unsupported integration: stripe'); + aiProxyLogger('Error', 'Error during tool provider cleanup'); + + expect(logger.mock.calls).toEqual([ + ['Debug', 'Loaded 3 tools from MCP server "notion" in 12ms'], + ['Info', 'Using AI configuration default'], + ['Warn', 'Unsupported integration: stripe'], + ['Error', 'Error during tool provider cleanup'], + ]); + }); + }); + + describe('with an Error cause', () => { + it('flattens the cause into enumerable error and stack context', () => { + const cause = new Error('401 Unauthorized'); + + aiProxyLogger('Error', 'Error loading tools for notion', cause); + + expect(logger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: '401 Unauthorized', + stack: cause.stack, + }); + }); + + // The reason the wrapper exists: an Error's own properties are non-enumerable, so a logger + // that spreads the context into JSON.stringify emits the line with the cause silently gone. + it('keeps the cause readable in the default-level console logger output', () => { + const spy = jest.spyOn(console, 'error').mockImplementation(); + + toAiProxyLogger(createConsoleLogger())( + 'Error', + 'Error loading tools for notion', + new Error('401 Unauthorized'), + ); + + const output = JSON.parse(spy.mock.calls[0][0]); + expect(output).toMatchObject({ + level: 'Error', + message: 'Error loading tools for notion', + error: '401 Unauthorized', + }); + expect(output.stack).toContain('Error: 401 Unauthorized'); + + spy.mockRestore(); + }); + + it('reports a stackless Error by its message alone', () => { + const cause = new Error('boom'); + delete cause.stack; + + aiProxyLogger('Error', 'Error loading tools for notion', cause); + + expect(logger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: 'boom', + stack: undefined, + }); + }); + + it('falls back to the error name when the Error carries an empty message', () => { + aiProxyLogger('Error', 'Error loading tools for notion', new Error('')); + + expect(logger).toHaveBeenCalledWith( + 'Error', + 'Error loading tools for notion', + expect.objectContaining({ error: 'Error' }), + ); + }); + + it('keeps each call independent when several servers fail in the same load', () => { + aiProxyLogger('Error', 'Error loading tools for notion', new Error('401 Unauthorized')); + aiProxyLogger('Error', 'Error loading tools for jira', new Error('ECONNREFUSED')); + aiProxyLogger('Warn', 'Unsupported integration: stripe'); + + expect(logger.mock.calls).toEqual([ + [ + 'Error', + 'Error loading tools for notion', + { error: '401 Unauthorized', stack: expect.any(String) }, + ], + [ + 'Error', + 'Error loading tools for jira', + { error: 'ECONNREFUSED', stack: expect.any(String) }, + ], + ['Warn', 'Unsupported integration: stripe'], + ]); + }); + }); + + describe('with a cause that is not an Error', () => { + // ai-proxy casts what it catches (`error as Error`), so any thrown value reaches the wrapper. + it('stringifies the thrown value and reports no stack', () => { + aiProxyLogger('Error', 'Error loading tools for notion', 'kaboom' as unknown as Error); + + expect(logger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: 'kaboom', + stack: undefined, + }); + }); + + it('treats a null cause as no cause instead of logging "null"', () => { + aiProxyLogger('Error', 'Error loading tools for notion', null as unknown as Error); + + expect(logger).toHaveBeenCalledWith('Error', 'Error loading tools for notion'); + }); + }); +}); diff --git a/packages/workflow-executor/test/build-workflow-executor.test.ts b/packages/workflow-executor/test/build-workflow-executor.test.ts index da5421dcb1..3ffc50382f 100644 --- a/packages/workflow-executor/test/build-workflow-executor.test.ts +++ b/packages/workflow-executor/test/build-workflow-executor.test.ts @@ -136,7 +136,10 @@ describe('buildInMemoryExecutor', () => { buildInMemoryExecutor(BASE_OPTIONS); - expect(AiClientAdapter).toHaveBeenCalledWith(BASE_OPTIONS.aiConfigurations); + expect(AiClientAdapter).toHaveBeenCalledWith( + BASE_OPTIONS.aiConfigurations, + expect.any(Function), + ); }); it('creates ServerAiAdapter when aiConfigurations is not provided', () => { @@ -149,6 +152,34 @@ describe('buildInMemoryExecutor', () => { expect(ServerAiAdapter).toHaveBeenCalledWith({ forestServerUrl: 'https://api.forestadmin.com', envSecret: BASE_OPTIONS.envSecret, + logger: expect.any(Function), + }); + }); + + // Without this the executor's own logs are the only place an MCP tool-load failure can surface, + // and ai-proxy emits its diagnostics into a logger nobody passed. + it('gives AiClientAdapter the executor logger', () => { + // eslint-disable-next-line @typescript-eslint/no-var-requires, global-require + const AiClientAdapter = require('../src/adapters/ai-client-adapter').default; + const logger = jest.fn(); + + buildInMemoryExecutor({ ...BASE_OPTIONS, logger }); + + expect(AiClientAdapter).toHaveBeenCalledWith(BASE_OPTIONS.aiConfigurations, logger); + }); + + it('gives ServerAiAdapter the executor logger', () => { + // eslint-disable-next-line @typescript-eslint/no-var-requires, global-require + const ServerAiAdapter = require('../src/adapters/server-ai-adapter').default; + const logger = jest.fn(); + + const { aiConfigurations, ...optionsWithoutAi } = BASE_OPTIONS; + buildInMemoryExecutor({ ...optionsWithoutAi, logger }); + + expect(ServerAiAdapter).toHaveBeenCalledWith({ + forestServerUrl: 'https://api.forestadmin.com', + envSecret: BASE_OPTIONS.envSecret, + logger, }); }); @@ -176,7 +207,10 @@ describe('buildInMemoryExecutor', () => { buildInMemoryExecutor({ ...BASE_OPTIONS, forceAiError: true }); expect(AlwaysErrorAiModelPort).not.toHaveBeenCalled(); - expect(AiClientAdapter).toHaveBeenCalledWith(BASE_OPTIONS.aiConfigurations); + expect(AiClientAdapter).toHaveBeenCalledWith( + BASE_OPTIONS.aiConfigurations, + expect.any(Function), + ); } finally { process.env.NODE_ENV = original; } From b7b165c263defadf44ce0d43d37573383bb4189b Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Wed, 5 Aug 2026 19:17:54 +0200 Subject: [PATCH 02/10] fix(workflow-executor): keep a throwing host logger out of ai-proxy MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ai-proxy logs from inside its per-server catch block before recording the failure it caught, so a host logger that threw would reject the whole Promise.all: tools from healthy servers discarded, and the OAuth reauth pause never reached. Guarding the bridge keeps logging out of control flow, the invariant the embedded executor's formatLog already states. Also carries the cause chain, so a wrapped `fetch failed` still names the ECONNREFUSED underneath it — the difference between an unreachable server and a rejected token. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/adapters/to-ai-proxy-logger.ts | 23 ++++++++++--- .../test/adapters/server-ai-adapter.test.ts | 11 +++---- .../test/adapters/to-ai-proxy-logger.test.ts | 32 +++++++++++++++++++ 3 files changed, 55 insertions(+), 11 deletions(-) diff --git a/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts b/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts index d6751c98f8..0640f2422c 100644 --- a/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts +++ b/packages/workflow-executor/src/adapters/to-ai-proxy-logger.ts @@ -9,11 +9,24 @@ export type AiProxyLogger = (level: LoggerLevel, message: string, error?: Error) // with the cause silently stripped — flatten it the way the rest of the executor logs causes. export default function toAiProxyLogger(logger: Logger): AiProxyLogger { return (level, message, error) => { - if (error === undefined || error === null) return logger(level, message); + // ai-proxy logs from inside its catch blocks before recording the failure it caught, so a host + // logger that throws here would abort a whole tool load instead of one server's. + try { + if (error === undefined || error === null) { + logger(level, message); - return logger(level, message, { - error: extractErrorMessage(error), - stack: error instanceof Error ? error.stack : undefined, - }); + return; + } + + const { cause } = error as { cause?: unknown }; + + logger(level, message, { + error: extractErrorMessage(error), + cause: extractErrorMessage(cause), + stack: error instanceof Error ? error.stack : undefined, + }); + } catch { + // A broken logger must not become control flow. + } }; } diff --git a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts index 5b77d8b59d..a5fe20ed27 100644 --- a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts +++ b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts @@ -183,18 +183,17 @@ describe('ServerAiAdapter', () => { }); }); - it('also gives the per-call AiClient built by getModel the executor logger', () => { + // Wiring only: the captured logger is invoked directly, since a client built for a single + // unnamed configuration reaches none of AiClient's own emit sites. + it('wires the same logger into the per-call AiClient built by getModel', () => { const executorLogger = jest.fn(); buildAdapterWithLogger(executorLogger).getModel({ userId: 42 }); - aiProxyLoggerGivenToLatestClient()?.( - 'Warn', - "AI configuration 'x' not found. Falling back to 'forest-server'", - ); + aiProxyLoggerGivenToLatestClient()?.('Warn', 'Error during remote tool connection cleanup'); expect(executorLogger).toHaveBeenCalledWith( 'Warn', - "AI configuration 'x' not found. Falling back to 'forest-server'", + 'Error during remote tool connection cleanup', ); }); diff --git a/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts index 8e5acd5dde..45f4582e0d 100644 --- a/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts +++ b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts @@ -60,6 +60,21 @@ describe('toAiProxyLogger', () => { spy.mockRestore(); }); + // A wrapped `TypeError: fetch failed` is the difference between "server unreachable" and "401". + it('reports the cause of a wrapped error alongside its own message', () => { + const wrapped = Object.assign(new Error('fetch failed'), { + cause: new Error('ECONNREFUSED 127.0.0.1:9100'), + }); + + aiProxyLogger('Error', 'Error loading tools for notion', wrapped); + + expect(logger).toHaveBeenCalledWith('Error', 'Error loading tools for notion', { + error: 'fetch failed', + cause: 'ECONNREFUSED 127.0.0.1:9100', + stack: wrapped.stack, + }); + }); + it('reports a stackless Error by its message alone', () => { const cause = new Error('boom'); delete cause.stack; @@ -103,6 +118,23 @@ describe('toAiProxyLogger', () => { }); }); + // ai-proxy logs from inside its catch blocks before recording the failure, so a throw here would + // fail a whole tool load — including the OAuth reauth path — instead of one server's load. + describe('when the host logger throws', () => { + it('keeps the throw away from ai-proxy, with and without a cause', () => { + const throwing = jest.fn(() => { + throw new Error('host logger exploded'); + }); + const guarded = toAiProxyLogger(throwing); + + expect(() => + guarded('Error', 'Error loading tools for notion', new Error('401 Unauthorized')), + ).not.toThrow(); + expect(() => guarded('Warn', 'Unsupported integration: stripe')).not.toThrow(); + expect(throwing).toHaveBeenCalledTimes(2); + }); + }); + describe('with a cause that is not an Error', () => { // ai-proxy casts what it catches (`error as Error`), so any thrown value reaches the wrapper. it('stringifies the thrown value and reports no stack', () => { From 16f908960c3016dabe7d87aca7dc367e76986efb Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Thu, 6 Aug 2026 11:02:50 +0200 Subject: [PATCH 03/10] fix(workflow-executor): name the cause when MCP tools fail to load MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The "MCP servers failed to load tools" line inferred failure by diffing config ids against loaded tool ids, so it could name the server but never why it failed — a revoked token, an unreachable host and a 15s timeout all logged identically. The providers already classify each failure and carry its error; the main load path was calling the tools-only method and dropping them. Reading the failures channel also removes a false positive the diff could not avoid: a healthy server exposing no tools contributed no ids, so it was reported as failed and the tool-listing endpoint answered 503 for it. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/ports/ai-model-port.ts | 4 +- .../src/remote-tool-fetcher.ts | 49 +++++------ .../integration/workflow-execution.test.ts | 10 ++- .../test/remote-tool-fetcher.test.ts | 87 ++++++++++++++----- .../workflow-executor/test/runner.test.ts | 38 ++++---- 5 files changed, 116 insertions(+), 72 deletions(-) diff --git a/packages/workflow-executor/src/ports/ai-model-port.ts b/packages/workflow-executor/src/ports/ai-model-port.ts index 30d0f18abf..06a193914d 100644 --- a/packages/workflow-executor/src/ports/ai-model-port.ts +++ b/packages/workflow-executor/src/ports/ai-model-port.ts @@ -13,8 +13,8 @@ export interface GetModelOptions { export interface AiModelPort { getModel(options?: GetModelOptions): BaseChatModel; loadRemoteTools(configs: Record): Promise; - // Loads tools and exposes per-server failures classified by cause (auth vs connection), so the - // OAuth path can tell a revoked token from an unreachable server. Default consumers use loadRemoteTools. + // Loads tools and exposes per-server failures classified by cause (auth vs connection), so a + // caller can tell a revoked token from an unreachable server and name it in its logs. loadRemoteToolsWithFailures( configs: Record, ): Promise<{ tools: RemoteTool[]; failures: McpServerLoadFailure[] }>; diff --git a/packages/workflow-executor/src/remote-tool-fetcher.ts b/packages/workflow-executor/src/remote-tool-fetcher.ts index 21c854a690..bb9329a89f 100644 --- a/packages/workflow-executor/src/remote-tool-fetcher.ts +++ b/packages/workflow-executor/src/remote-tool-fetcher.ts @@ -2,7 +2,7 @@ import type OAuthTokenService from './oauth/token-service'; import type { AiModelPort } from './ports/ai-model-port'; import type { Logger } from './ports/logger-port'; import type { WorkflowPort } from './ports/workflow-port'; -import type { RemoteTool, ToolConfig } from '@forestadmin/ai-proxy'; +import type { McpServerLoadFailure, RemoteTool, ToolConfig } from '@forestadmin/ai-proxy'; import { injectOauthTokens } from '@forestadmin/ai-proxy'; @@ -10,6 +10,10 @@ import { OAuthReauthRequiredError } from './errors'; const OAUTH2_AUTH_TYPE = 'oauth2'; +function hasAuthFailure(failures: McpServerLoadFailure[]): boolean { + return failures.some(failure => failure.kind === 'auth'); +} + // Match by config.id, not by Record key: server names can collide across configs. export function scopeConfigsToServer( configs: Record, @@ -71,8 +75,8 @@ export default class RemoteToolFetcher { return this.fetchOAuthTools(scoped, mcpServerName, mcpServerId, userId); } - const tools = await this.aiModelPort.loadRemoteTools(scoped); - const loadFailed = this.errorOnPartialLoadFailure(scoped, tools, mcpServerId, mcpServerName); + const { tools, failures } = await this.aiModelPort.loadRemoteToolsWithFailures(scoped); + const loadFailed = this.errorOnPartialLoadFailure(failures, mcpServerId, mcpServerName); return { tools, mcpServerName, loadFailed }; } @@ -90,7 +94,7 @@ export default class RemoteToolFetcher { const attemptLoad = async ( forceRefresh: boolean, - ): Promise<{ tools: RemoteTool[]; hasAuthFailure: boolean }> => { + ): Promise<{ tools: RemoteTool[]; failures: McpServerLoadFailure[] }> => { const token = await tokenService.getAccessToken(userId, mcpServerId, { forceRefresh }); const bearer = `Bearer ${token}`; // All scoped configs share this mcpServerId, so inject the token for every one — not just the @@ -102,31 +106,25 @@ export default class RemoteToolFetcher { Object.keys(scoped).map(name => [name, bearer]), ), }) ?? scoped; - const { tools, failures } = await this.aiModelPort.loadRemoteToolsWithFailures(injected); - return { tools, hasAuthFailure: failures.some(failure => failure.kind === 'auth') }; + return this.aiModelPort.loadRemoteToolsWithFailures(injected); }; const reloadWithFreshAuth = async (): Promise => { const attempt = await attemptLoad(true); - if (attempt.hasAuthFailure) throw new OAuthReauthRequiredError(mcpServerId); - this.errorOnPartialLoadFailure(scoped, attempt.tools, mcpServerId, mcpServerName); + if (hasAuthFailure(attempt.failures)) throw new OAuthReauthRequiredError(mcpServerId); + this.errorOnPartialLoadFailure(attempt.failures, mcpServerId, mcpServerName); return attempt.tools; }; const initial = await attemptLoad(false); - if (initial.hasAuthFailure) { + if (hasAuthFailure(initial.failures)) { return { tools: await reloadWithFreshAuth(), mcpServerName, reloadWithFreshAuth }; } - const loadFailed = this.errorOnPartialLoadFailure( - scoped, - initial.tools, - mcpServerId, - mcpServerName, - ); + const loadFailed = this.errorOnPartialLoadFailure(initial.failures, mcpServerId, mcpServerName); return { tools: initial.tools, mcpServerName, reloadWithFreshAuth, loadFailed }; } @@ -155,26 +153,23 @@ export default class RemoteToolFetcher { ); } - // Partial-failure detection: McpClient swallows per-server load errors and returns whatever - // succeeded. Match config.id against tool.mcpServerId — both providers populate it from the - // orchestrator's persisted id, so the check is uniform across MCP and Forest connectors. + // Report what the providers said failed, with why. Inferring it from absent tools instead would + // flag a healthy server that exposes none, and could never name a cause. private errorOnPartialLoadFailure( - scoped: Record, - tools: RemoteTool[], + failures: McpServerLoadFailure[], mcpServerId: string, mcpServerName: string | undefined, ): boolean { - const loadedMcpServerIds = new Set(tools.map(t => t.mcpServerId)); - const failedConfigNames = Object.entries(scoped) - .filter(([, cfg]) => !loadedMcpServerIds.has(cfg.id)) - .map(([name]) => name); - - if (failedConfigNames.length === 0) return false; + if (failures.length === 0) return false; this.logger('Error', 'MCP servers failed to load tools', { requestedMcpServerId: mcpServerId, mcpServerName, - failedConfigNames, + failures: failures.map(failure => ({ + server: failure.server, + kind: failure.kind, + error: failure.error.message, + })), }); return true; diff --git a/packages/workflow-executor/test/integration/workflow-execution.test.ts b/packages/workflow-executor/test/integration/workflow-execution.test.ts index 0593ac5f10..d40b5af2ae 100644 --- a/packages/workflow-executor/test/integration/workflow-execution.test.ts +++ b/packages/workflow-executor/test/integration/workflow-execution.test.ts @@ -140,6 +140,7 @@ function createMockAiClient(model: BaseChatModel): AiModelPort { return { getModel: jest.fn().mockReturnValue(model), loadRemoteTools: jest.fn().mockResolvedValue([]), + loadRemoteToolsWithFailures: jest.fn().mockResolvedValue({ tools: [], failures: [] }), closeConnections: jest.fn().mockResolvedValue(undefined), } as unknown as AiModelPort; } @@ -619,7 +620,10 @@ describe('workflow execution (integration)', () => { ); const aiClient = createMockAiClient(model); - (aiClient.loadRemoteTools as jest.Mock).mockResolvedValue([fakeRemoteTool]); + (aiClient.loadRemoteToolsWithFailures as jest.Mock).mockResolvedValue({ + tools: [fakeRemoteTool], + failures: [], + }); const step = buildPendingStep({ stepDefinition: { @@ -635,7 +639,7 @@ describe('workflow execution (integration)', () => { .fn() .mockResolvedValue({ step, auth: { forestServerToken: 'test-forest-token' } }), // Two configs but only one matches step.mcpServerId — the assertion below proves - // RemoteToolFetcher actually scopes the Record before calling loadRemoteTools. + // RemoteToolFetcher actually scopes the Record before loading tools. getMcpServerConfigs: jest.fn().mockResolvedValue({ 'mcp-server-1': { id: 'mcp-1', url: 'http://fake' }, 'mcp-server-2': { id: 'mcp-2', url: 'http://other' }, @@ -676,7 +680,7 @@ describe('workflow execution (integration)', () => { expect.objectContaining({ type: 'mcp', status: 'success' }), ); // Scoping must reach the AI port — only the matching server is forwarded, not the full map. - expect(aiClient.loadRemoteTools).toHaveBeenCalledWith({ + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenCalledWith({ 'mcp-server-1': expect.objectContaining({ id: 'mcp-1' }), }); }); diff --git a/packages/workflow-executor/test/remote-tool-fetcher.test.ts b/packages/workflow-executor/test/remote-tool-fetcher.test.ts index 2da8bfe4a9..a4b7c95a1a 100644 --- a/packages/workflow-executor/test/remote-tool-fetcher.test.ts +++ b/packages/workflow-executor/test/remote-tool-fetcher.test.ts @@ -2,7 +2,7 @@ import type OAuthTokenService from '../src/oauth/token-service'; import type { AiModelPort } from '../src/ports/ai-model-port'; import type { Logger } from '../src/ports/logger-port'; import type { WorkflowPort } from '../src/ports/workflow-port'; -import type { RemoteTool, ToolConfig } from '@forestadmin/ai-proxy'; +import type { McpServerLoadFailure, RemoteTool, ToolConfig } from '@forestadmin/ai-proxy'; import { OAuthReauthRequiredError } from '../src/errors'; import RemoteToolFetcher, { scopeConfigsToServer } from '../src/remote-tool-fetcher'; @@ -30,6 +30,14 @@ function makeRemoteTool(sourceId: string, mcpServerId?: string): RemoteTool { return { sourceId, mcpServerId } as unknown as RemoteTool; } +function makeFailure(server: string, kind: string, message: string): McpServerLoadFailure { + return { server, kind, error: new Error(message) } as McpServerLoadFailure; +} + +function loadsWithFailures(tools: RemoteTool[], failures: McpServerLoadFailure[] = []) { + return jest.fn().mockResolvedValue({ tools, failures }); +} + function makeFetcher(overrides?: { workflowPort?: Partial>>; aiModelPort?: Partial>; @@ -127,10 +135,10 @@ describe('RemoteToolFetcher.fetch', () => { await fetcher.fetch('id-A', USER_ID); - expect(aiModelPort.loadRemoteTools).toHaveBeenCalledWith({ 'srv-a': cfg('id-A') }); + expect(aiModelPort.loadRemoteToolsWithFailures).toHaveBeenCalledWith({ 'srv-a': cfg('id-A') }); }); - it('returns no tools and an undefined mcpServerName, skipping loadRemoteTools, when the scoped Record is empty', async () => { + it('returns no tools and an undefined mcpServerName, skipping the tool load, when the scoped Record is empty', async () => { const { fetcher, aiModelPort } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({}) }, }); @@ -138,7 +146,7 @@ describe('RemoteToolFetcher.fetch', () => { const result = await fetcher.fetch('id-A', USER_ID); expect(result).toEqual({ tools: [], mcpServerName: undefined }); - expect(aiModelPort.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiModelPort.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); }); it('resolves mcpServerName from the scoped Record key', async () => { @@ -147,7 +155,7 @@ describe('RemoteToolFetcher.fetch', () => { workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue(remoteTools) }, + aiModelPort: { loadRemoteToolsWithFailures: loadsWithFailures(remoteTools) }, }); const result = await fetcher.fetch('id-A', USER_ID); @@ -208,12 +216,17 @@ describe('RemoteToolFetcher.fetch', () => { expect(logger.mock.calls.find(c => c[0] === 'Warn')).toBeUndefined(); }); - it('flags the scoped MCP config when no tool was loaded for its id', async () => { + it('names the failing server, its failure kind and its cause', async () => { const { fetcher, logger } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue([]) }, + aiModelPort: { + loadRemoteToolsWithFailures: loadsWithFailures( + [], + [makeFailure('srv-a', 'connection', 'connect ECONNREFUSED 10.0.4.12:8080')], + ), + }, }); await fetcher.fetch('id-A', USER_ID); @@ -221,28 +234,49 @@ describe('RemoteToolFetcher.fetch', () => { expect(logger).toHaveBeenCalledWith('Error', 'MCP servers failed to load tools', { requestedMcpServerId: 'id-A', mcpServerName: 'srv-a', - failedConfigNames: ['srv-a'], + failures: [ + { server: 'srv-a', kind: 'connection', error: 'connect ECONNREFUSED 10.0.4.12:8080' }, + ], }); }); - it('sets loadFailed when the scoped server produced no tools', async () => { + it('sets loadFailed when a server reported a load failure', async () => { const { fetcher } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue([]) }, + aiModelPort: { + loadRemoteToolsWithFailures: loadsWithFailures( + [], + [makeFailure('srv-a', 'auth', '401 Unauthorized')], + ), + }, }); expect((await fetcher.fetch('id-A', USER_ID)).loadFailed).toBe(true); }); + // A server can be reachable and expose nothing; the tool-listing endpoint answers 503 on + // loadFailed, so inferring failure from an empty list reports a healthy server as unreachable. + it('does not set loadFailed when a healthy server exposes no tools', async () => { + const { fetcher, logger } = makeFetcher({ + workflowPort: { + getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), + }, + aiModelPort: { loadRemoteToolsWithFailures: loadsWithFailures([]) }, + }); + + expect((await fetcher.fetch('id-A', USER_ID)).loadFailed).toBe(false); + expect(logger.mock.calls.find(call => call[0] === 'Error')).toBeUndefined(); + }); + it('does not set loadFailed when tools load successfully', async () => { const { fetcher } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, aiModelPort: { - loadRemoteTools: jest.fn().mockResolvedValue([makeRemoteTool('srv-a', 'id-A')]), + loadRemoteToolsWithFailures: loadsWithFailures([makeRemoteTool('srv-a', 'id-A')]), }, }); @@ -255,7 +289,7 @@ describe('RemoteToolFetcher.fetch', () => { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, aiModelPort: { - loadRemoteTools: jest.fn().mockResolvedValue([makeRemoteTool('srv-a', 'id-A')]), + loadRemoteToolsWithFailures: loadsWithFailures([makeRemoteTool('srv-a', 'id-A')]), }, }); @@ -277,7 +311,7 @@ describe('RemoteToolFetcher.fetch', () => { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'zendesk-prod': forestConfig }), }, aiModelPort: { - loadRemoteTools: jest.fn().mockResolvedValue([makeRemoteTool('zendesk', 'id-zendesk')]), + loadRemoteToolsWithFailures: loadsWithFailures([makeRemoteTool('zendesk', 'id-zendesk')]), }, }); @@ -296,7 +330,12 @@ describe('RemoteToolFetcher.fetch', () => { workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'zendesk-prod': forestConfig }), }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue([]) }, + aiModelPort: { + loadRemoteToolsWithFailures: loadsWithFailures( + [], + [makeFailure('zendesk-prod', 'unknown', 'Unsupported integration: Zendesk')], + ), + }, }); await fetcher.fetch('id-zendesk', USER_ID); @@ -304,17 +343,19 @@ describe('RemoteToolFetcher.fetch', () => { expect(logger).toHaveBeenCalledWith('Error', 'MCP servers failed to load tools', { requestedMcpServerId: 'id-zendesk', mcpServerName: 'zendesk-prod', - failedConfigNames: ['zendesk-prod'], + failures: [ + { server: 'zendesk-prod', kind: 'unknown', error: 'Unsupported integration: Zendesk' }, + ], }); }); - it('returns the tools produced by loadRemoteTools verbatim', async () => { + it('returns the tools produced by the port verbatim', async () => { const remoteTools = [makeRemoteTool('srv-a', 'id-A')]; const { fetcher } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue(remoteTools) }, + aiModelPort: { loadRemoteToolsWithFailures: loadsWithFailures(remoteTools) }, }); const result = await fetcher.fetch('id-A', USER_ID); @@ -322,13 +363,13 @@ describe('RemoteToolFetcher.fetch', () => { expect(result.tools).toBe(remoteTools); }); - it('propagates a rejection from loadRemoteTools without logging partial-failure', async () => { + it('propagates a rejection from the tool load without logging partial-failure', async () => { const { fetcher, logger } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }), }, aiModelPort: { - loadRemoteTools: jest.fn().mockRejectedValue(new Error('MCP unreachable')), + loadRemoteToolsWithFailures: jest.fn().mockRejectedValue(new Error('MCP unreachable')), }, }); @@ -336,7 +377,7 @@ describe('RemoteToolFetcher.fetch', () => { expect(logger.mock.calls.find(c => c[0] === 'Error')).toBeUndefined(); }); - it('propagates a rejection from getMcpServerConfigs without calling loadRemoteTools', async () => { + it('propagates a rejection from getMcpServerConfigs without loading tools', async () => { const { fetcher, aiModelPort } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockRejectedValue(new Error('orchestrator down')), @@ -344,7 +385,7 @@ describe('RemoteToolFetcher.fetch', () => { }); await expect(fetcher.fetch('id-A', USER_ID)).rejects.toThrow('orchestrator down'); - expect(aiModelPort.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiModelPort.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); }); }); @@ -482,14 +523,14 @@ describe('RemoteToolFetcher.fetch — OAuth2 servers', () => { const tool = makeRemoteTool('srv-a', 'id-A'); const { fetcher, aiModelPort } = makeFetcher({ workflowPort: { getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': cfg('id-A') }) }, - aiModelPort: { loadRemoteTools: jest.fn().mockResolvedValue([tool]) }, + aiModelPort: { loadRemoteToolsWithFailures: loadsWithFailures([tool]) }, tokenService: makeTokenService(getAccessToken), }); const result = await fetcher.fetch('id-A', USER_ID); expect(getAccessToken).not.toHaveBeenCalled(); - expect(aiModelPort.loadRemoteTools).toHaveBeenCalled(); + expect(aiModelPort.loadRemoteToolsWithFailures).toHaveBeenCalled(); expect(result.reloadWithFreshAuth).toBeUndefined(); }); }); diff --git a/packages/workflow-executor/test/runner.test.ts b/packages/workflow-executor/test/runner.test.ts index 9f278ed56f..8da4c00392 100644 --- a/packages/workflow-executor/test/runner.test.ts +++ b/packages/workflow-executor/test/runner.test.ts @@ -61,6 +61,7 @@ function createMockAiClient() { return { getModel: jest.fn().mockReturnValue({} as BaseChatModel), loadRemoteTools: jest.fn().mockResolvedValue([]), + loadRemoteToolsWithFailures: jest.fn().mockResolvedValue({ tools: [], failures: [] }), closeConnections: jest.fn().mockResolvedValue(undefined), }; } @@ -1339,10 +1340,10 @@ describe('MCP lazy loading (via once thunk)', () => { await runner.triggerPoll('run-1'); expect(workflowPort.getMcpServerConfigs).not.toHaveBeenCalled(); - expect(aiClient.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiClient.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); }); - it('skips loadRemoteTools when the orchestrator returns an empty Record', async () => { + it('skips the tool load when the orchestrator returns an empty Record', async () => { const workflowPort = createMockWorkflowPort(); const aiClient = createMockAiClient(); const step = makePendingStep({ @@ -1362,7 +1363,7 @@ describe('MCP lazy loading (via once thunk)', () => { await runner.triggerPoll('run-1'); expect(workflowPort.getMcpServerConfigs).toHaveBeenCalledTimes(1); - expect(aiClient.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiClient.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); // Distinguish the short-circuit from a regression that throws before reaching the guard: // the step must actually have executed and reported a success outcome. expect(workflowPort.updateStepExecution).toHaveBeenCalledWith( @@ -1373,7 +1374,7 @@ describe('MCP lazy loading (via once thunk)', () => { }); describe('MCP fetch scoping', () => { - it('passes only the matching config to loadRemoteTools when step.mcpServerId is set', async () => { + it('passes only the matching config to the tool load when step.mcpServerId is set', async () => { const workflowPort = createMockWorkflowPort(); const aiClient = createMockAiClient(); const step = makePendingStep({ @@ -1400,8 +1401,8 @@ describe('MCP fetch scoping', () => { ); await runner.triggerPoll('run-1'); - expect(aiClient.loadRemoteTools).toHaveBeenCalledTimes(1); - expect(aiClient.loadRemoteTools).toHaveBeenCalledWith({ + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenCalledTimes(1); + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenCalledWith({ 'server-A': expect.objectContaining({ id: 'id-A' }), }); }); @@ -1435,12 +1436,12 @@ describe('MCP fetch scoping', () => { ); await runner.triggerPoll('run-1'); - expect(aiClient.loadRemoteTools).toHaveBeenCalledWith({ + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenCalledWith({ 'server-B': expect.objectContaining({ id: 'server-A' }), }); }); - it('skips loadRemoteTools and warns with availableMcpServerIds when no config matches', async () => { + it('skips the tool load and warns with availableMcpServerIds when no config matches', async () => { const workflowPort = createMockWorkflowPort(); const aiClient = createMockAiClient(); const logger = createMockLogger(); @@ -1473,7 +1474,7 @@ describe('MCP fetch scoping', () => { await runner.triggerPoll('run-1'); expect(workflowPort.getMcpServerConfigs).toHaveBeenCalledTimes(1); - expect(aiClient.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiClient.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); expect(logger).toHaveBeenCalledWith( 'Warn', 'MCP step targets a server not advertised by the orchestrator', @@ -1514,7 +1515,7 @@ describe('MCP fetch scoping', () => { ); await runner.triggerPoll('run-1'); - expect(aiClient.loadRemoteTools).not.toHaveBeenCalled(); + expect(aiClient.loadRemoteToolsWithFailures).not.toHaveBeenCalled(); expect(logger).toHaveBeenCalledWith( 'Warn', 'MCP step targets a server but orchestrator returned no MCP configs', @@ -1530,7 +1531,7 @@ describe('MCP fetch scoping', () => { // The diagnostic must not short-circuit dispatch — the executor is still constructed (and // will surface NoMcpToolsError downstream). Asserting on executeSpy.mock.instances bypasses // the global execute() spy to confirm the executor saw the (empty) tool list. - it('logs partial-failure and still dispatches to the executor when the scoped server loaded zero tools', async () => { + it('logs the reported failure and still dispatches to the executor with no tools', async () => { const workflowPort = createMockWorkflowPort(); const aiClient = createMockAiClient(); const logger = createMockLogger(); @@ -1551,7 +1552,10 @@ describe('MCP fetch scoping', () => { workflowPort.getMcpServerConfigs.mockResolvedValue({ 'server-A': { id: 'id-A', url: 'https://a.example', type: 'http', headers: {} }, }); - aiClient.loadRemoteTools.mockResolvedValue([]); + aiClient.loadRemoteToolsWithFailures.mockResolvedValue({ + tools: [], + failures: [{ server: 'server-A', kind: 'connection', error: new Error('socket hang up') }], + }); runner = new Runner( createRunnerConfig({ @@ -1565,7 +1569,7 @@ describe('MCP fetch scoping', () => { expect(logger).toHaveBeenCalledWith('Error', 'MCP servers failed to load tools', { requestedMcpServerId: 'id-A', mcpServerName: 'server-A', - failedConfigNames: ['server-A'], + failures: [{ server: 'server-A', kind: 'connection', error: 'socket hang up' }], }); expect(executeSpy).toHaveBeenCalledTimes(1); const executorInstance = executeSpy.mock.instances[0]; @@ -1575,7 +1579,7 @@ describe('MCP fetch scoping', () => { ).toEqual([]); }); - it('re-scopes loadRemoteTools per dispatch when chained MCP steps target different servers', async () => { + it('re-scopes the tool load per dispatch when chained MCP steps target different servers', async () => { const workflowPort = createMockWorkflowPort(); const aiClient = createMockAiClient(); const mcpDef = (id: string) => @@ -1615,11 +1619,11 @@ describe('MCP fetch scoping', () => { ); await runner.triggerPoll('run-1'); - expect(aiClient.loadRemoteTools).toHaveBeenCalledTimes(2); - expect(aiClient.loadRemoteTools).toHaveBeenNthCalledWith(1, { + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenCalledTimes(2); + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenNthCalledWith(1, { 'server-A': expect.objectContaining({ id: 'id-A' }), }); - expect(aiClient.loadRemoteTools).toHaveBeenNthCalledWith(2, { + expect(aiClient.loadRemoteToolsWithFailures).toHaveBeenNthCalledWith(2, { 'server-B': expect.objectContaining({ id: 'id-B' }), }); }); From 16d12e97e1b41389f93f050b111a2f4ba8de0ef2 Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Thu, 6 Aug 2026 15:16:17 +0200 Subject: [PATCH 04/10] refactor(workflow-executor): tighten comments to why-only One comment described the state this PR ends ("ai-proxy emits its diagnostics into a logger nobody passed"), which would read as false the moment it merged. The rest restated their code or duplicated the source comment they sat next to. Replaces the one what-comment that stood in for a missing Arrange step: the no-logger case now builds its own adapter instead of reaching into the one beforeEach made. Records the failures-channel rule as an invariant, since inferring a load failure from absent tools is user-visible through the 503. Co-Authored-By: Claude Opus 5 (1M context) --- packages/workflow-executor/CLAUDE.md | 3 ++- packages/workflow-executor/src/remote-tool-fetcher.ts | 4 ++-- .../test/adapters/server-ai-adapter.test.ts | 11 +++++------ .../test/adapters/to-ai-proxy-logger.test.ts | 6 ++---- .../test/build-workflow-executor.test.ts | 3 +-- .../test/remote-tool-fetcher.test.ts | 3 +-- 6 files changed, 13 insertions(+), 17 deletions(-) diff --git a/packages/workflow-executor/CLAUDE.md b/packages/workflow-executor/CLAUDE.md index 265d8120ad..77ea807720 100644 --- a/packages/workflow-executor/CLAUDE.md +++ b/packages/workflow-executor/CLAUDE.md @@ -53,7 +53,8 @@ Front ◀──▶ Orchestrator ◀──pull/push──▶ Executor (this p - **Boundary validation** — wire/mapper types live in `types/validated/` as zod. Strictness by origin: executor-produced + frontend bodies use `.strict()`; the orchestrator collection schema **strips** unknowns and asserts step-specific props at use-time (resilient to orchestrator drift). Parse failure → `DomainValidationError`/`InvalidStepDefinitionError`. `StepOutcome` is validated only when it arrives via `previousSteps`; executor outputs are trusted by construction. - **DatabaseStore** — table `workflow_step_executions` + migration registry namespaced under a schema (default `forest`, override via `DATABASE_SCHEMA`), so a DB shared with the agent/server is safe. The schema is created idempotently at `init()`, but gated on a `pg_namespace` existence probe (not `CREATE SCHEMA IF NOT EXISTS` alone): Postgres checks database-level `CREATE` even for `IF NOT EXISTS`, so probing lets a pre-created schema boot with only schema-level `CREATE`. SQLite (tests) skips schemas. Migrations run behind a **transaction-scoped Postgres advisory lock** (`pg_advisory_xact_lock`, safe behind RDS Proxy / PgBouncer) so HA cold-starts migrate once; migrations are transactional + idempotent. Postgres-only; the lock key is a fixed constant — never change it. - **Graceful shutdown** — `stop()` drains in-flight steps (`idle → running → draining → stopped`), `stopTimeoutMs` default 30s, HTTP stays up during drain. Signal handling is the consumer's job. -- **Logging** — `Logger = (level, message, context?) => void`. `BaseStepExecutor` stamps `logCtx` (runId/stepId/stepIndex/stepType); type-specific ids via `getExtraLogContext()`. `createConsoleLogger`/`createPrettyLogger(minLevel)` factories; CLI level from `LOG_LEVEL` (default `Info`). ai-proxy's logger takes the cause as a third `Error` argument instead of a context object, so both AI adapters bridge it with `toAiProxyLogger` (flattens to `{ error, stack }` — an `Error`'s own properties are non-enumerable and would vanish from the emitted line). +- **Logging** — `Logger = (level, message, context?) => void`. `BaseStepExecutor` stamps `logCtx` (runId/stepId/stepIndex/stepType); type-specific ids via `getExtraLogContext()`. `createConsoleLogger`/`createPrettyLogger(minLevel)` factories; CLI level from `LOG_LEVEL` (default `Info`). ai-proxy's logger takes the cause as a third `Error` argument instead of a context object, so both AI adapters bridge it with `toAiProxyLogger` (flattens to `{ error, cause, stack }` — an `Error`'s own properties are non-enumerable and would vanish from the emitted line — and swallows a throwing host logger, which ai-proxy calls from inside its catch blocks). +- **MCP load failures come from the `failures` channel** — `RemoteToolFetcher` loads through `loadRemoteToolsWithFailures` and reports what the providers classified (`server`/`kind`/`error`); never infer failure from absent tools, which flags a healthy server exposing none. `loadFailed` drives the 503 on `GET /list-mcp-tools`, so a wrong inference is user-visible. - **Config comes from the boundary, never `process.env`** — no executor *config* is read from `process.env` outside `cli-core`: every knob is parsed there (standalone) or injected as an option (`ExecutorOptions` / the agent's `addWorkflowExecutor` options), and the check for a value is `Boolean(options.x)`, not `process.env`. Runtime-mode flags — `NODE_ENV` (forceAiError prod-guard, token-endpoint dev check) and the `OTEL_*` observability vars in `tracing.ts` — are the deliberate exception. This keeps the executor identically configurable standalone and embedded, and testable without mutating env. (Regression fixed once: `FOREST_EXECUTOR_ENCRYPTION_KEY` was read in `crypto/` — now injected via `executorEncryptionKey`.) - **AI** — import every AI type (`BaseChatModel`, `DynamicStructuredTool`, `SystemMessage`/`HumanMessage`, `RemoteTool`/`ToolConfig`) from `@forestadmin/ai-proxy`, **not** `@langchain/core` (which is not a dependency). `ExecutionContext.model` is a `BaseChatModel`. The only langchain mention in src is a comment in `cli.ts` about transitively loading `@langchain/openai`. diff --git a/packages/workflow-executor/src/remote-tool-fetcher.ts b/packages/workflow-executor/src/remote-tool-fetcher.ts index bb9329a89f..1c26a87640 100644 --- a/packages/workflow-executor/src/remote-tool-fetcher.ts +++ b/packages/workflow-executor/src/remote-tool-fetcher.ts @@ -153,8 +153,8 @@ export default class RemoteToolFetcher { ); } - // Report what the providers said failed, with why. Inferring it from absent tools instead would - // flag a healthy server that exposes none, and could never name a cause. + // Inferring failure from absent tools would flag a healthy server that exposes none, and could + // never name a cause. private errorOnPartialLoadFailure( failures: McpServerLoadFailure[], mcpServerId: string, diff --git a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts index a5fe20ed27..b1a7fe9e54 100644 --- a/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts +++ b/packages/workflow-executor/test/adapters/server-ai-adapter.test.ts @@ -157,7 +157,7 @@ describe('ServerAiAdapter', () => { }); describe('logger', () => { - const buildAdapterWithLogger = (logger: Logger) => + const buildAdapter = (logger?: Logger) => new ServerAiAdapter({ forestServerUrl: 'https://api.forestadmin.com', envSecret: ENV_SECRET, @@ -172,7 +172,7 @@ describe('ServerAiAdapter', () => { it("routes ai-proxy's MCP diagnostics to the executor logger with the cause flattened", () => { const executorLogger = jest.fn(); - buildAdapterWithLogger(executorLogger); + buildAdapter(executorLogger); const cause = new Error('401 Unauthorized'); aiProxyLoggerGivenToLatestClient()?.('Error', 'Error loading tools for notion', cause); @@ -187,7 +187,7 @@ describe('ServerAiAdapter', () => { // unnamed configuration reaches none of AiClient's own emit sites. it('wires the same logger into the per-call AiClient built by getModel', () => { const executorLogger = jest.fn(); - buildAdapterWithLogger(executorLogger).getModel({ userId: 42 }); + buildAdapter(executorLogger).getModel({ userId: 42 }); aiProxyLoggerGivenToLatestClient()?.('Warn', 'Error during remote tool connection cleanup'); @@ -197,11 +197,10 @@ describe('ServerAiAdapter', () => { ); }); - // The adapter built in beforeEach carries no logger option. it('leaves AiClient without a logger when none is configured', () => { - const params = mockAiClientConstructor.mock.calls[0][0] as { logger?: AiProxyLogger }; + buildAdapter(); - expect(params.logger).toBeUndefined(); + expect(aiProxyLoggerGivenToLatestClient()).toBeUndefined(); }); }); }); diff --git a/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts index 45f4582e0d..26e37737be 100644 --- a/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts +++ b/packages/workflow-executor/test/adapters/to-ai-proxy-logger.test.ts @@ -38,8 +38,7 @@ describe('toAiProxyLogger', () => { }); }); - // The reason the wrapper exists: an Error's own properties are non-enumerable, so a logger - // that spreads the context into JSON.stringify emits the line with the cause silently gone. + // A raw Error spread into the context emits nothing: its own properties are non-enumerable. it('keeps the cause readable in the default-level console logger output', () => { const spy = jest.spyOn(console, 'error').mockImplementation(); @@ -118,8 +117,7 @@ describe('toAiProxyLogger', () => { }); }); - // ai-proxy logs from inside its catch blocks before recording the failure, so a throw here would - // fail a whole tool load — including the OAuth reauth path — instead of one server's load. + // A throw escaping here fails a whole tool load — including the OAuth reauth path. describe('when the host logger throws', () => { it('keeps the throw away from ai-proxy, with and without a cause', () => { const throwing = jest.fn(() => { diff --git a/packages/workflow-executor/test/build-workflow-executor.test.ts b/packages/workflow-executor/test/build-workflow-executor.test.ts index 3ffc50382f..71f187f3db 100644 --- a/packages/workflow-executor/test/build-workflow-executor.test.ts +++ b/packages/workflow-executor/test/build-workflow-executor.test.ts @@ -156,8 +156,7 @@ describe('buildInMemoryExecutor', () => { }); }); - // Without this the executor's own logs are the only place an MCP tool-load failure can surface, - // and ai-proxy emits its diagnostics into a logger nobody passed. + // ai-proxy holds the host logger optionally and no-ops every emit without one. it('gives AiClientAdapter the executor logger', () => { // eslint-disable-next-line @typescript-eslint/no-var-requires, global-require const AiClientAdapter = require('../src/adapters/ai-client-adapter').default; diff --git a/packages/workflow-executor/test/remote-tool-fetcher.test.ts b/packages/workflow-executor/test/remote-tool-fetcher.test.ts index a4b7c95a1a..68556b9d04 100644 --- a/packages/workflow-executor/test/remote-tool-fetcher.test.ts +++ b/packages/workflow-executor/test/remote-tool-fetcher.test.ts @@ -256,8 +256,7 @@ describe('RemoteToolFetcher.fetch', () => { expect((await fetcher.fetch('id-A', USER_ID)).loadFailed).toBe(true); }); - // A server can be reachable and expose nothing; the tool-listing endpoint answers 503 on - // loadFailed, so inferring failure from an empty list reports a healthy server as unreachable. + // A reachable server can expose nothing, and loadFailed answers 503 on the tool-listing endpoint. it('does not set loadFailed when a healthy server exposes no tools', async () => { const { fetcher, logger } = makeFetcher({ workflowPort: { From b1a1fe97e56a3eedea73d60f79c3281bfcfebf8d Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Thu, 6 Aug 2026 15:59:28 +0200 Subject: [PATCH 05/10] refactor(workflow-executor): collapse the OAuth fetch tail to one return MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The two exits differed only in which attempt produced the tools, so naming the rejected-token case and reading the retry's result once says the same thing with less branching — and clears the many-returns smell the analyser reports now that the function was touched. Co-Authored-By: Claude Opus 5 (1M context) --- .../workflow-executor/src/remote-tool-fetcher.ts | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/packages/workflow-executor/src/remote-tool-fetcher.ts b/packages/workflow-executor/src/remote-tool-fetcher.ts index 1c26a87640..942b781853 100644 --- a/packages/workflow-executor/src/remote-tool-fetcher.ts +++ b/packages/workflow-executor/src/remote-tool-fetcher.ts @@ -119,14 +119,14 @@ export default class RemoteToolFetcher { }; const initial = await attemptLoad(false); - - if (hasAuthFailure(initial.failures)) { - return { tools: await reloadWithFreshAuth(), mcpServerName, reloadWithFreshAuth }; - } - - const loadFailed = this.errorOnPartialLoadFailure(initial.failures, mcpServerId, mcpServerName); - - return { tools: initial.tools, mcpServerName, reloadWithFreshAuth, loadFailed }; + const hasRejectedToken = hasAuthFailure(initial.failures); + // The retry supersedes a rejected cached token, and reports its own partial failure. + const tools = hasRejectedToken ? await reloadWithFreshAuth() : initial.tools; + const loadFailed = hasRejectedToken + ? undefined + : this.errorOnPartialLoadFailure(initial.failures, mcpServerId, mcpServerName); + + return { tools, mcpServerName, reloadWithFreshAuth, loadFailed }; } // Distinguish "no configs at all" (deployment misconfig) from "configs exist but none match" From 1d26e339860a9865aacbe7abbc5b4c5d690367ba Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Thu, 6 Aug 2026 18:16:06 +0200 Subject: [PATCH 06/10] docs(workflow-executor): say what a failed MCP tool load logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The README covered OpenTelemetry but never the logs, which are the first thing an operator reads when a step fails. Now that the line names the failing server and why it failed, say so — and what each failure kind means for the fix, since that is the difference between reconnecting a credential and chasing a firewall. LOG_LEVEL itself stays documented in .env.example, where the README already points for the full variable list. Co-Authored-By: Claude Opus 5 (1M context) --- packages/workflow-executor/README.md | 28 ++++++++++++++++++++++++++++ 1 file changed, 28 insertions(+) diff --git a/packages/workflow-executor/README.md b/packages/workflow-executor/README.md index bf15b324a9..628440b7da 100644 --- a/packages/workflow-executor/README.md +++ b/packages/workflow-executor/README.md @@ -166,6 +166,34 @@ When your workflows use OAuth-protected MCP connectors, the executor stores each --- +## When an MCP step fails to load its tools + +The executor names the reason at `Error`, so it is in your logs at the default level: + +```json +{ + "level": "Error", + "message": "MCP servers failed to load tools", + "requestedMcpServerId": "39", + "mcpServerName": "acme-crm", + "failures": [ + { "server": "acme-crm", "kind": "connection", "error": "connect ECONNREFUSED 10.0.4.12:8080" } + ] +} +``` + +`kind` tells you where to look: + +- `auth` — the server rejected the credential. Reconnect the connector, or renew its token. +- `connection` — unreachable, refused, or slower than the 15s per-server load timeout. +- `unknown` — the server answered but the load failed anyway; the `error` text carries the reason. + +A server that answers but exposes no tools is not a failure: you get an empty tool list and no error. + +Set `LOG_LEVEL=Debug` to add one line per server with its tool count and load time, which is how you find the connector that is slowing a step down. + +--- + ## Testing only The following modes skip the database requirement but are **not suitable for production** — state is lost on restart. From 743d48ab727a2e3c1a8755cdfc1193d33cede464 Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Fri, 7 Aug 2026 09:23:25 +0200 Subject: [PATCH 07/10] fix(workflow-executor): drop undefined context keys from pretty logs Callers build a fixed context shape and leave what they have nothing for undefined, so the CLI's human-readable output carried `cause=undefined` on every MCP failure and `stack=undefined` wherever the thrown value was not an Error. JSON output never showed them, since JSON.stringify omits them. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/adapters/pretty-logger.ts | 6 +++++- .../test/adapters/pretty-logger.test.ts | 14 ++++++++++++++ 2 files changed, 19 insertions(+), 1 deletion(-) diff --git a/packages/workflow-executor/src/adapters/pretty-logger.ts b/packages/workflow-executor/src/adapters/pretty-logger.ts index 7f845c9ab3..4b7091b72b 100644 --- a/packages/workflow-executor/src/adapters/pretty-logger.ts +++ b/packages/workflow-executor/src/adapters/pretty-logger.ts @@ -12,7 +12,11 @@ const LABEL: Record = { }; function formatContext(context: Record): string { - const parts = Object.entries(context).map(([key, value]) => `${key}=${JSON.stringify(value)}`); + // Callers build a fixed context shape and leave the fields they have nothing for undefined, + // which JSON.stringify would render as the literal `undefined`. + const parts = Object.entries(context) + .filter(([, value]) => value !== undefined) + .map(([key, value]) => `${key}=${JSON.stringify(value)}`); if (parts.length === 0) return ''; return pc.dim(parts.join(' ')); diff --git a/packages/workflow-executor/test/adapters/pretty-logger.test.ts b/packages/workflow-executor/test/adapters/pretty-logger.test.ts index 8f9ffe74af..5c777562dd 100644 --- a/packages/workflow-executor/test/adapters/pretty-logger.test.ts +++ b/packages/workflow-executor/test/adapters/pretty-logger.test.ts @@ -45,6 +45,20 @@ describe('createPrettyLogger', () => { expect(output).toMatch(/^\d{2}:\d{2}:\d{2} info {2}Ready$/); }); + it('drops keys whose value is undefined, keeping the rest', () => { + logger('Info', 'Tools loaded', { server: 'acme-crm', cause: undefined, stack: undefined }); + + const output = stripAnsi(infoSpy.mock.calls[0][0] as string); + expect(output).toMatch(/^\d{2}:\d{2}:\d{2} info {2}Tools loaded server="acme-crm"$/); + }); + + it('omits the context chunk when every value is undefined', () => { + logger('Info', 'Ready', { cause: undefined }); + + const output = stripAnsi(infoSpy.mock.calls[0][0] as string); + expect(output).toMatch(/^\d{2}:\d{2}:\d{2} info {2}Ready$/); + }); + it('JSON-quotes string values in context', () => { logger('Info', 'Step execution started', { runId: '42', stepIndex: 2 }); From db5ba6565b2bc21aec0fa027b9b6be91a9c9a83c Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Fri, 7 Aug 2026 11:35:51 +0200 Subject: [PATCH 08/10] fix(workflow-executor): say when an MCP load recovered after a refresh MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A rejected cached credential is logged at Error by the provider, and the retry that fixes it only logged at Debug — so at the default level a run that recovered read as a pure failure, with nothing saying it continued. Observed on a live executor against a revoked access token. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/remote-tool-fetcher.ts | 6 +++++ .../test/remote-tool-fetcher.test.ts | 27 +++++++++++++++++++ 2 files changed, 33 insertions(+) diff --git a/packages/workflow-executor/src/remote-tool-fetcher.ts b/packages/workflow-executor/src/remote-tool-fetcher.ts index 942b781853..de9908c32a 100644 --- a/packages/workflow-executor/src/remote-tool-fetcher.ts +++ b/packages/workflow-executor/src/remote-tool-fetcher.ts @@ -114,6 +114,12 @@ export default class RemoteToolFetcher { const attempt = await attemptLoad(true); if (hasAuthFailure(attempt.failures)) throw new OAuthReauthRequiredError(mcpServerId); this.errorOnPartialLoadFailure(attempt.failures, mcpServerId, mcpServerName); + // The rejected credential was already logged at Error. Without this the default level shows + // the failure and never says it recovered. + this.logger('Info', 'MCP tools loaded after refreshing the credential', { + requestedMcpServerId: mcpServerId, + mcpServerName, + }); return attempt.tools; }; diff --git a/packages/workflow-executor/test/remote-tool-fetcher.test.ts b/packages/workflow-executor/test/remote-tool-fetcher.test.ts index 68556b9d04..028d1d484d 100644 --- a/packages/workflow-executor/test/remote-tool-fetcher.test.ts +++ b/packages/workflow-executor/test/remote-tool-fetcher.test.ts @@ -466,6 +466,33 @@ describe('RemoteToolFetcher.fetch — OAuth2 servers', () => { expect(result.tools).toEqual([tool]); }); + // The rejected credential is logged at Error by the provider, so a run that recovers reads as a + // pure failure at the default level unless the recovery is stated too. + it('reports the recovery after a forced refresh succeeds', async () => { + const loadRemoteToolsWithFailures = jest + .fn() + .mockResolvedValueOnce({ tools: [], failures: [authFailure] }) + .mockResolvedValueOnce({ tools: [makeRemoteTool('srv-a', 'id-A')], failures: [] }); + const { fetcher, logger } = makeFetcher({ + workflowPort: { + getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': oauthCfg('id-A') }), + }, + aiModelPort: { loadRemoteToolsWithFailures }, + tokenService: makeTokenService(jest.fn().mockResolvedValue('tok')), + }); + + await fetcher.fetch('id-A', USER_ID); + + expect(logger).toHaveBeenCalledWith( + 'Info', + 'MCP tools loaded after refreshing the credential', + { + requestedMcpServerId: 'id-A', + mcpServerName: 'srv-a', + }, + ); + }); + it('raises OAuthReauthRequiredError when the auth failure persists after a forced refresh', async () => { const getAccessToken = jest.fn().mockResolvedValue('tok'); const loadRemoteToolsWithFailures = jest From 71e1e25e3da676c4b69a02366c1070ccc72df1d9 Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Fri, 7 Aug 2026 18:33:54 +0200 Subject: [PATCH 09/10] fix(workflow-executor): report a retry that fails for a non-auth reason On the OAuth path the forced-refresh retry's outcome was discarded: a retry that failed to connect returned an empty tool list as a success, so the listing endpoint answered 200 instead of 503, and the recovery line claimed the credential refresh had worked. The reload hook is public API for the caller's own post-401 retry, so it keeps returning tools and reports the outcome through the enclosing scope. Co-Authored-By: Claude Opus 5 (1M context) --- .../src/remote-tool-fetcher.ts | 21 +++++++++----- .../test/remote-tool-fetcher.test.ts | 28 +++++++++++++++++++ 2 files changed, 42 insertions(+), 7 deletions(-) diff --git a/packages/workflow-executor/src/remote-tool-fetcher.ts b/packages/workflow-executor/src/remote-tool-fetcher.ts index de9908c32a..2acf02d879 100644 --- a/packages/workflow-executor/src/remote-tool-fetcher.ts +++ b/packages/workflow-executor/src/remote-tool-fetcher.ts @@ -110,26 +110,33 @@ export default class RemoteToolFetcher { return this.aiModelPort.loadRemoteToolsWithFailures(injected); }; + // The reload hook is handed to the caller for its own post-401 retry, so it cannot widen its + // return type; it reports the retry's outcome here instead. + let reloadFailed: boolean | undefined; + const reloadWithFreshAuth = async (): Promise => { const attempt = await attemptLoad(true); if (hasAuthFailure(attempt.failures)) throw new OAuthReauthRequiredError(mcpServerId); - this.errorOnPartialLoadFailure(attempt.failures, mcpServerId, mcpServerName); + reloadFailed = this.errorOnPartialLoadFailure(attempt.failures, mcpServerId, mcpServerName); + // The rejected credential was already logged at Error. Without this the default level shows // the failure and never says it recovered. - this.logger('Info', 'MCP tools loaded after refreshing the credential', { - requestedMcpServerId: mcpServerId, - mcpServerName, - }); + if (!reloadFailed) { + this.logger('Info', 'MCP tools loaded after refreshing the credential', { + requestedMcpServerId: mcpServerId, + mcpServerName, + }); + } return attempt.tools; }; const initial = await attemptLoad(false); const hasRejectedToken = hasAuthFailure(initial.failures); - // The retry supersedes a rejected cached token, and reports its own partial failure. + // The retry supersedes a rejected cached token, so its outcome is the one that counts. const tools = hasRejectedToken ? await reloadWithFreshAuth() : initial.tools; const loadFailed = hasRejectedToken - ? undefined + ? reloadFailed : this.errorOnPartialLoadFailure(initial.failures, mcpServerId, mcpServerName); return { tools, mcpServerName, reloadWithFreshAuth, loadFailed }; diff --git a/packages/workflow-executor/test/remote-tool-fetcher.test.ts b/packages/workflow-executor/test/remote-tool-fetcher.test.ts index 028d1d484d..9c736e8bff 100644 --- a/packages/workflow-executor/test/remote-tool-fetcher.test.ts +++ b/packages/workflow-executor/test/remote-tool-fetcher.test.ts @@ -493,6 +493,34 @@ describe('RemoteToolFetcher.fetch — OAuth2 servers', () => { ); }); + // The tool-listing endpoint answers 503 on loadFailed, so a retry that fails for a non-auth + // reason must reach the caller as a failure rather than as an empty success. + it('sets loadFailed when the retry fails for a reason other than auth', async () => { + const loadRemoteToolsWithFailures = jest + .fn() + .mockResolvedValueOnce({ tools: [], failures: [authFailure] }) + .mockResolvedValueOnce({ + tools: [], + failures: [makeFailure('srv-a', 'connection', 'socket hang up')], + }); + const { fetcher, logger } = makeFetcher({ + workflowPort: { + getMcpServerConfigs: jest.fn().mockResolvedValue({ 'srv-a': oauthCfg('id-A') }), + }, + aiModelPort: { loadRemoteToolsWithFailures }, + tokenService: makeTokenService(jest.fn().mockResolvedValue('tok')), + }); + + const result = await fetcher.fetch('id-A', USER_ID); + + expect(result.loadFailed).toBe(true); + expect(logger).not.toHaveBeenCalledWith( + 'Info', + 'MCP tools loaded after refreshing the credential', + expect.anything(), + ); + }); + it('raises OAuthReauthRequiredError when the auth failure persists after a forced refresh', async () => { const getAccessToken = jest.fn().mockResolvedValue('tok'); const loadRemoteToolsWithFailures = jest From 1c2aabcd68c9254c79f66002b744aa921039636d Mon Sep 17 00:00:00 2001 From: Brian Fox Date: Fri, 7 Aug 2026 18:43:15 +0200 Subject: [PATCH 10/10] test(workflow-executor): assert which configs reach the tool load Co-Authored-By: Claude Opus 5 (1M context) --- packages/workflow-executor/test/remote-tool-fetcher.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/workflow-executor/test/remote-tool-fetcher.test.ts b/packages/workflow-executor/test/remote-tool-fetcher.test.ts index 9c736e8bff..ecf554baca 100644 --- a/packages/workflow-executor/test/remote-tool-fetcher.test.ts +++ b/packages/workflow-executor/test/remote-tool-fetcher.test.ts @@ -584,7 +584,7 @@ describe('RemoteToolFetcher.fetch — OAuth2 servers', () => { const result = await fetcher.fetch('id-A', USER_ID); expect(getAccessToken).not.toHaveBeenCalled(); - expect(aiModelPort.loadRemoteToolsWithFailures).toHaveBeenCalled(); + expect(aiModelPort.loadRemoteToolsWithFailures).toHaveBeenCalledWith({ 'srv-a': cfg('id-A') }); expect(result.reloadWithFreshAuth).toBeUndefined(); }); });