From 0c450a8f60ccbdc1bcf3d27824a5ffbb75e69361 Mon Sep 17 00:00:00 2001 From: Andrey Antukh Date: Fri, 9 Oct 2026 17:12:10 +0000 Subject: [PATCH] :bug: Skip pino transports inside node:test processes The pino transports run in a worker thread reached through a message port that stays referenced once a log line is in flight, so the node:test child process kept running after every test and hook had finished. The runner then canceled the file's root test with "Promise resolution is still pending but the event loop has already resolved" and the suite hung until something killed it, which happened in roughly two runs out of five. `logTransportTargets` returns no targets inside a node:test child process, which `node --test` marks with `NODE_TEST_CONTEXT`, so tests log straight to stdout and the process exit is deterministic. Production still uses the console, file, and Loki transports. AI-assisted-by: step-5-preview-free --- .serena/memories/mcp/core.md | 15 +++++++++++++++ mcp/packages/server/src/logger.test.ts | 14 ++++++++++++++ mcp/packages/server/src/logger.ts | 24 +++++++++++++++++++----- 3 files changed, 48 insertions(+), 5 deletions(-) create mode 100644 mcp/packages/server/src/logger.test.ts diff --git a/.serena/memories/mcp/core.md b/.serena/memories/mcp/core.md index 9d55a13105..a9d0b2164e 100644 --- a/.serena/memories/mcp/core.md +++ b/.serena/memories/mcp/core.md @@ -85,6 +85,21 @@ From the `mcp/` directory, run * `pnpm run build` to test the build of all packages * `pnpm run fmt` to apply the auto-formatter +* `pnpm run test` runs the tests of `plugin` (node test runner) and `server` (tsx). + The committed `typescript` version is 6.x: the 7.x line ships only a version stub + at the `typescript` entry point, and its synchronous compiler API is gone, so + `ts.transpileModule` (used by the plugin tests to compile `main.ts`/`plugin.ts` + into a sandboxed browser-like context) fails there. +* `packages/server` type-checks against the built `dist` of `@penpot/mcp-common`; + a stale `packages/common/dist` makes `types:check` fail with missing exports + (e.g. `PenpotSession`). Run `pnpm --filter mcp-common run build` first. +* The server logger (`packages/server/src/logger.ts`) uses pino transports only + outside `node:test` (`logTransportTargets`). A transport spawns a worker thread + whose message port stays referenced once a line is in flight, so the test child + process keeps running after the tests finish and the suite hangs intermittently + (node reports `Promise resolution is still pending but the event loop has + already resolved` for the file's root test). Inside tests the logger writes to + stdout directly. `NODE_TEST_CONTEXT` is the env var `node --test` sets. * Cross-cutting testing principles and anti-patterns: `mem:testing`. ## Devenv plugin/server wiring diff --git a/mcp/packages/server/src/logger.test.ts b/mcp/packages/server/src/logger.test.ts new file mode 100644 index 0000000000..ea0b6a0317 --- /dev/null +++ b/mcp/packages/server/src/logger.test.ts @@ -0,0 +1,14 @@ +import assert from "node:assert/strict"; +import test from "node:test"; +import { logTransportTargets } from "./logger"; + +test("test processes log to stdout instead of a transport worker thread", () => { + assert.deepEqual(logTransportTargets({ NODE_TEST_CONTEXT: "child-v8" }), []); +}); + +test("regular processes keep the configured pino transports", () => { + assert.deepEqual( + logTransportTargets({}).map((target) => target.target), + ["pino-pretty"] + ); +}); diff --git a/mcp/packages/server/src/logger.ts b/mcp/packages/server/src/logger.ts index 45cb359e90..e74f7cdda9 100644 --- a/mcp/packages/server/src/logger.ts +++ b/mcp/packages/server/src/logger.ts @@ -198,17 +198,31 @@ const transports: LogTransportProvider[] = [consoleTransport, fileTransport, lok */ export const logFilePath: string | undefined = fileTransport.getFilePath(); +/** + * The pino transport targets to configure, empty when the logger writes to stdout directly. + * + * @param env - environment to inspect, injectable for tests + * @returns the active transport targets, empty inside a node:test child process + */ +export function logTransportTargets(env: NodeJS.ProcessEnv = process.env): TransportTargetSpec[] { + if (env.NODE_TEST_CONTEXT !== undefined) { + return []; + } + return transports.map((t) => t.getTarget()).filter((target): target is TransportTargetSpec => target !== null); +} + +const transportTargets = logTransportTargets(); + /** * Logger instance configured with the active transports (console, optional file, optional Loki). + * + * Inside a node:test child process the transports are skipped and the logger writes to stdout, + * so the test process does not outlive its tests over a transport worker thread. */ export const logger = pino({ level: LOG_LEVEL, timestamp: pino.stdTimeFunctions.isoTime, - transport: { - targets: transports - .map((t) => t.getTarget()) - .filter((target): target is TransportTargetSpec => target !== null), - }, + ...(transportTargets.length > 0 ? { transport: { targets: transportTargets } } : {}), }); /**