Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 11 additions & 2 deletions src/container/dependencies.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
* Manages all dependencies and their wiring for production use
*/
import { ContainerConfig } from './types.js';
import { createLogger } from '../utils/logger.js';
import { createLogger, detachSharedFileTransport } from '../utils/logger.js';
import {
IFileSystem,
IProcessManager,
Expand Down Expand Up @@ -55,6 +55,14 @@ export interface Dependencies {

// Adapter support
adapterRegistry: IAdapterRegistry;

/**
* Detach this container's logger from the shared file transport (issue
* #404). Called from DebugMcpServer.stop() so per-session servers in
* Streamable HTTP mode don't accumulate pipe edges on the process-lifetime
* transport. Optional: test containers may omit it.
*/
disposeLogger?: () => void;
}

/**
Expand Down Expand Up @@ -158,6 +166,7 @@ export function createProductionDependencies(config: ContainerConfig = {}): Depe
proxyProcessLauncher,
proxyManagerFactory,
sessionStoreFactory,
adapterRegistry
adapterRegistry,
disposeLogger: () => detachSharedFileTransport(logger)
};
}
9 changes: 8 additions & 1 deletion src/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -248,6 +248,8 @@ export class DebugMcpServer {
public server: Server;
private sessionManager: SessionManager;
private logger;
/** Detaches this server's logger from the shared file transport on stop() (issue #404). */
private readonly disposeLogger?: () => void;
private fileChecker: SimpleFileChecker;
private lineReader: LineReader;
private environment: IEnvironment;
Expand Down Expand Up @@ -938,8 +940,9 @@ export class DebugMcpServer {
};

const dependencies = createProductionDependencies(containerConfig);

this.logger = dependencies.logger;
this.disposeLogger = dependencies.disposeLogger;
this.environment = dependencies.environment;
this.logger.info('[DebugMcpServer Constructor] Main server logger instance assigned.');

Expand Down Expand Up @@ -2888,6 +2891,10 @@ export class DebugMcpServer {
this.subscribedUris.clear();
this.sessionManager.removeListener('output-captured', this.handleOutputCaptured);
this.logger.info('Debug MCP Server stopped');
// Last: detach this server's logger from the shared file transport so
// per-session servers in HTTP mode don't accumulate on it (issue #404).
// After this line the logger no longer writes to the shared file.
this.disposeLogger?.();
}

/**
Expand Down
46 changes: 45 additions & 1 deletion src/utils/logger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,13 @@ const STALE_LOG_MAX_AGE_MS = 7 * 24 * 60 * 60 * 1000;
*/
const fileTransportCache = new Map<string, winston.transport>();

/**
* Which shared file transport each logger attached, so per-session loggers
* can be detached on DebugMcpServer.stop() without closing the transport for
* everyone (issue #404). WeakMap: a discarded logger must not be retained here.
*/
const loggerFileTransports = new WeakMap<WinstonLoggerType, winston.transport>();

let staleLogCleanupDone = false;

/** Sends a signal to a pid; injectable so tests never spy the global process.kill (issue #183). */
Expand Down Expand Up @@ -189,6 +196,7 @@ export function createLogger(namespace: string, options: LoggerOptions = {}): Wi
cleanupStaleLogFiles(path.dirname(logFilePath));
}

let attachedFileTransport: winston.transport | undefined;
try {
const cacheKey = path.resolve(logFilePath);
let fileTransport = fileTransportCache.get(cacheKey);
Expand All @@ -206,20 +214,25 @@ export function createLogger(namespace: string, options: LoggerOptions = {}): Wi
fileTransportCache.set(cacheKey, fileTransport);
}
transports.push(fileTransport);
attachedFileTransport = fileTransport;
} catch (fileTransportError) {
// When console output is silenced we must not write to console as it corrupts transports
if (!isConsoleSilenced) {
console.error(`[Logger Init Error] Failed to create file transport for ${logFilePath}:`, fileTransportError);
}
}

const logger = winston.createLogger({
level,
transports,
defaultMeta: { namespace },
exitOnError: false
});

if (attachedFileTransport) {
loggerFileTransports.set(logger, attachedFileTransport);
}

logger.on('error', (error: Error) => {
// When console output is silenced we must not write to console as it corrupts transports
if (!isConsoleSilenced) {
Expand All @@ -235,6 +248,37 @@ export function createLogger(namespace: string, options: LoggerOptions = {}): Wi
return logger;
}

/**
* Detach a logger from the shared file transport it attached in createLogger,
* WITHOUT closing the transport for the other loggers still piping into it
* (issue #404). This is the per-session disposal path for Streamable HTTP
* mode, where every MCP session builds a DebugMcpServer whose logger would
* otherwise stay piped into the process-lifetime shared transport forever.
*
* winston-transport registers `once('unpipe', src => { if (src ===
* this.parent) { this.parent = null; this.close(); } })`, where `parent` is
* the FIRST logger that piped the transport — so a plain logger.remove() from
* that logger would close the shared file stream for everyone. The close is
* neutralized by shadowing `close` with an own undefined property for the
* duration of the remove (`if (this.close)` in the handler is then falsy),
* and restored in finally. logger.close() remains forbidden as documented on
* the transport cache above.
*/
export function detachSharedFileTransport(logger: WinstonLoggerType): void {
const transport = loggerFileTransports.get(logger);
if (!transport) {
return;
}
loggerFileTransports.delete(logger);
const t = transport as unknown as Record<string, unknown>;
t.close = undefined;
try {
logger.remove(transport);
} finally {
delete t.close;
}
}

/**
* Get the default logger instance. If no root logger has been created, a fallback logger is created.
* @returns The default logger instance.
Expand Down
14 changes: 12 additions & 2 deletions tests/core/unit/server/server-lifecycle.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -58,13 +58,23 @@ describe('Server Lifecycle Tests', () => {
it('should stop server and close all sessions', async () => {
debugServer = new DebugMcpServer();
mockSessionManager.closeAllSessions.mockResolvedValue(undefined);

await debugServer.stop();

expect(mockSessionManager.closeAllSessions).toHaveBeenCalled();
expect(mockDependencies.logger.info).toHaveBeenCalledWith('Debug MCP Server stopped');
});

it('stop() disposes the container logger so churning HTTP sessions do not leak (issue #404)', async () => {
mockDependencies.disposeLogger = vi.fn();
debugServer = new DebugMcpServer();
mockSessionManager.closeAllSessions.mockResolvedValue(undefined);

await debugServer.stop();

expect(mockDependencies.disposeLogger).toHaveBeenCalledTimes(1);
});

it('should propagate closeAllSessions errors from stop', async () => {
debugServer = new DebugMcpServer();
mockSessionManager.closeAllSessions.mockRejectedValue(new Error('Close sessions failed'));
Expand Down
17 changes: 16 additions & 1 deletion tests/unit/container/dependencies.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,11 @@ const sessionStoreFactoryInstance = { tag: 'session-factory' };
const registerMock = vi.fn();
const getSupportedLanguagesMock = vi.fn(() => []);

const detachSharedFileTransportMock = vi.fn();

vi.mock('../../../src/utils/logger.js', () => ({
createLogger: createLoggerMock
createLogger: createLoggerMock,
detachSharedFileTransport: detachSharedFileTransportMock
}));

vi.mock('../../../src/implementations/index.js', () => ({
Expand Down Expand Up @@ -114,6 +117,18 @@ describe('createProductionDependencies', () => {
);
});

it('returns a disposeLogger that detaches the shared file transport (issue #404)', () => {
const dependencies = createProductionDependencies({ logFile: '/tmp/debug.log' });

expect(typeof dependencies.disposeLogger).toBe('function');
expect(detachSharedFileTransportMock).not.toHaveBeenCalled();

dependencies.disposeLogger!();

expect(detachSharedFileTransportMock).toHaveBeenCalledTimes(1);
expect(detachSharedFileTransportMock).toHaveBeenCalledWith(dependencies.logger);
});

it('registers bundled adapters and logs async failures', async () => {
const firstFactoryInstance = { instance: 'first' };
const secondFactoryInstance = { instance: 'second' };
Expand Down
87 changes: 87 additions & 0 deletions tests/unit/utils/logger-detach.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
/**
* Leak regression tests for issue #404: every per-session DebugMcpServer's
* logger pipes into the process-lifetime shared file transport and nothing
* ever unpiped, so the transport accumulated one listener set + retained
* logger per HTTP session forever.
*
* Uses REAL winston (no module mock): the leak lives in winston's pipe
* mechanics, and the fix must neutralize winston-transport's close-on-unpipe
* behavior (transport.parent is the FIRST logger that piped it; a plain
* logger.remove() from that logger closes the shared transport for everyone).
*/
import { describe, it, expect, beforeAll, afterAll, vi } from 'vitest';
import fs from 'fs';
import os from 'os';
import path from 'path';
import { createLogger, detachSharedFileTransport } from '../../../src/utils/logger.js';

let tmpDir: string;
let logFile: string;

beforeAll(() => {
tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'logger-detach-test-'));
logFile = path.join(tmpDir, 'shared.log');
});

afterAll(() => {
// The shared transport deliberately stays open for the process lifetime;
// best-effort cleanup only.
try {
fs.rmSync(tmpDir, { recursive: true, force: true });
} catch {
// Windows may hold the handle — fine, it's a temp dir.
}
});

function fileTransportOf(logger: ReturnType<typeof createLogger>) {
const t = logger.transports.find((tr) => (tr as { filename?: string }).filename !== undefined);
expect(t).toBeDefined();
return t!;
}

describe('detachSharedFileTransport (issue #404)', () => {
it('detaches a later logger without growing or closing the shared transport', () => {
const first = createLogger('detach-test-first', { file: logFile });
const shared = fileTransportOf(first);

const baselineUnpipe = shared.listenerCount('unpipe');
const baselineError = shared.listenerCount('error');

// N churning sessions attach and detach
for (let i = 0; i < 5; i++) {
const session = createLogger(`detach-test-session-${i}`, { file: logFile });
expect(fileTransportOf(session)).toBe(shared); // cache: one transport per path
detachSharedFileTransport(session);
expect(session.transports).not.toContain(shared);
}

// No listener growth on the shared transport after the churn
expect(shared.listenerCount('unpipe')).toBeLessThanOrEqual(baselineUnpipe);
expect(shared.listenerCount('error')).toBeLessThanOrEqual(baselineError);
});

it('does not close the shared transport even when the FIRST attacher detaches', () => {
const file = path.join(tmpDir, 'first-attacher.log');
const first = createLogger('detach-test-owner', { file });
const shared = fileTransportOf(first);
const closeSpy = vi.spyOn(shared as unknown as { close: () => void }, 'close');

const second = createLogger('detach-test-tenant', { file });
expect(fileTransportOf(second)).toBe(shared);

// winston-transport's close-on-unpipe fires when transport.parent (the
// first attacher) unpipes — the detach must neutralize it.
detachSharedFileTransport(first);

expect(closeSpy).not.toHaveBeenCalled();
// The surviving logger still carries the open shared transport
expect(second.transports).toContain(shared);
expect(() => second.info('still alive')).not.toThrow();
closeSpy.mockRestore();
});

it('is a no-op for a logger with no shared file transport', () => {
const bare = createLogger('detach-test-bare');
expect(() => detachSharedFileTransport(bare)).not.toThrow();
});
});
Loading