Improve MCP server logging, adding Loki support (#9425)

*  Improve MCP server logging

Log only fingerprints of user tokens

*  Add Loki transport support to MCP server logger

Loki logging is enabled iff PENPOT_LOGGERS_LOKI_URI is non-empty.

File logging is now enabled iff PENPOT_MCP_LOG_DIR is set to a non-empty value
(previously defaulted to the "logs" directory when unset).

GitHub #9415
This commit is contained in:
Dr. Dominik Jain 2026-05-11 14:00:23 +02:00 committed by Andrey Antukh
parent feb49bc07a
commit 1f9f4126b7
6 changed files with 243 additions and 47 deletions

View File

@ -278,7 +278,7 @@ The Penpot MCP server can be configured using environment variables.
| Environment Variable | Description | Default |
|------------------------|------------------------------------------------------|----------|
| `PENPOT_MCP_LOG_LEVEL` | Log level: `trace`, `debug`, `info`, `warn`, `error` | `info` |
| `PENPOT_MCP_LOG_DIR` | Directory for log files | `logs` |
| `PENPOT_MCP_LOG_DIR` | Directory for log files; file logging is enabled iff this is set to a non-empty value | (unset) |
### Plugin Server Configuration

View File

@ -5,7 +5,7 @@
"type": "module",
"main": "dist/index.js",
"scripts": {
"build:server": "esbuild src/index.ts --bundle --platform=node --target=node18 --format=esm --outfile=dist/index.js --external:@modelcontextprotocol/* --external:ws --external:express --external:class-transformer --external:class-validator --external:reflect-metadata --external:pino --external:pino-pretty --external:js-yaml --external:sharp",
"build:server": "esbuild src/index.ts --bundle --platform=node --target=node18 --format=esm --outfile=dist/index.js --external:@modelcontextprotocol/* --external:ws --external:express --external:class-transformer --external:class-validator --external:reflect-metadata --external:pino --external:pino-pretty --external:pino-loki --external:js-yaml --external:sharp",
"build": "pnpm run build:server && node scripts/copy-resources.js",
"build:types": "tsc --emitDeclarationOnly --outDir dist",
"start": "node dist/index.js",
@ -31,6 +31,7 @@
"js-yaml": "^4.1.1",
"penpot-mcp": "file:..",
"pino": "^9.10.0",
"pino-loki": "^2.6.0",
"pino-pretty": "^13.1.1",
"reflect-metadata": "^0.1.13",
"sharp": "^0.34.5",

View File

@ -49,6 +49,28 @@ export class PenpotMcpServer {
*/
private static readonly SESSION_TIMEOUT_MINUTES = 60;
/**
* Returns a short, non-reversible fingerprint of a user token, suitable for
* correlating log lines without exposing the full credential.
*
* Penpot tokens are JWEs in compact serialization (RFC 7516 §7.1) with five
* dot-separated segments; we use the first 8 chars of the wrapped CEK
* (segment 1) as a stable per-token identifier. For malformed tokens (e.g.
* test stubs that aren't real JWEs), we fall back to the first 8 chars of
* the raw token.
*
* @param token - the token to fingerprint, or `undefined`
* @returns a short fingerprint, or `<none>` if no token was given
*/
private static tokenFingerprint(token: string | undefined): string {
if (!token) {
return "<none>";
}
const segments = token.split(".");
const source = segments.length === 5 ? segments[1] : token;
return source.slice(0, 8);
}
private readonly logger = createLogger("PenpotMcpServer");
private readonly tools: ToolInfo[];
public readonly configLoader: ConfigurationLoader;
@ -222,12 +244,14 @@ export class PenpotMcpServer {
userToken = session.userToken;
session.lastActiveTime = Date.now();
this.logger.info(
`Received request for existing session with id=${sessionId}; userToken=${session.userToken}`
`Received request for existing session with id=${sessionId}; userTokenFp=${PenpotMcpServer.tokenFingerprint(session.userToken)}`
);
} else {
// new session: create a fresh McpServer and transport
userToken = req.query.userToken as string | undefined;
this.logger.info(`Received new session request; userToken=${userToken}`);
this.logger.info(
`Received new session request; userTokenFp=${PenpotMcpServer.tokenFingerprint(userToken)}`
);
const { randomUUID } = await import("node:crypto");
const server = this.createMcpServer();
transport = new StreamableHTTPServerTransport({
@ -235,13 +259,15 @@ export class PenpotMcpServer {
onsessioninitialized: (id) => {
this.streamableTransports[id] = new StreamableSession(transport, userToken, Date.now());
this.logger.info(
`Session initialized with id=${id} for userToken=${userToken}; total sessions: ${Object.keys(this.streamableTransports).length}`
`Session initialized with id=${id} for userTokenFp=${PenpotMcpServer.tokenFingerprint(userToken)}; total sessions: ${Object.keys(this.streamableTransports).length}`
);
},
});
transport.onclose = () => {
if (transport.sessionId) {
this.logger.info(`Closing session with id=${transport.sessionId} for userToken=${userToken}`);
this.logger.info(
`Closing session with id=${transport.sessionId} for userTokenFp=${PenpotMcpServer.tokenFingerprint(userToken)}`
);
delete this.streamableTransports[transport.sessionId];
}
};

View File

@ -1,7 +1,7 @@
#!/usr/bin/env node
import { PenpotMcpServer } from "./PenpotMcpServer";
import { createLogger, logFilePath } from "./logger";
import { createLogger, logActiveTransports } from "./logger";
/**
* Entry point for Penpot MCP Server
@ -14,8 +14,8 @@ import { createLogger, logFilePath } from "./logger";
async function main(): Promise<void> {
const logger = createLogger("main");
// log the file path early so it appears before any potential errors
logger.info(`Logging to file: ${logFilePath}`);
// announce active transports early so they appear before any potential errors
logActiveTransports(logger);
try {
const args = process.argv.slice(2);

View File

@ -1,12 +1,21 @@
import pino from "pino";
import pino, { type TransportTargetOptions } from "pino";
import { join, resolve } from "path";
/**
* Configuration for log file location and level.
* Configured log level (defaults to `info`).
*/
const LOG_DIR = process.env.PENPOT_MCP_LOG_DIR || "logs";
const LOG_LEVEL = process.env.PENPOT_MCP_LOG_LEVEL || "info";
/**
* Configured log directory; file logging is enabled iff this is set to a non-empty value.
*/
const LOG_DIR = process.env.PENPOT_MCP_LOG_DIR;
/**
* Loki host URI; if set and non-empty, Loki logging is enabled.
*/
const LOKI_URI = process.env.PENPOT_LOGGERS_LOKI_URI;
/**
* Generates a timestamped log file name.
*
@ -24,56 +33,204 @@ function generateLogFileName(): string {
}
/**
* Absolute path to the log file being written.
* The pino transport target spec, as expected in `transport.targets[]`.
*/
export const logFilePath = resolve(join(LOG_DIR, generateLogFileName()));
type TransportTargetSpec = TransportTargetOptions;
/**
* Logger instance configured for both console and file output with metadata.
* Provides a single pino transport target, either active or inactive.
*
* Both console and file output use pretty formatting for human readability.
* Console output includes colors, while file output is plain text.
* Implementations decide their own activation based on environment configuration.
* An inactive provider returns `null` from {@link getTarget} and is skipped.
*/
interface LogTransportProvider {
/**
* Returns the pino transport target spec, or `null` if this transport is disabled.
*/
getTarget(): TransportTargetSpec | null;
/**
* Returns a human-readable startup message describing the transport, or `null` if disabled.
*/
getStartupMessage(): string | null;
}
/**
* Console transport with pretty-printed, colorized output. Always active.
*/
class ConsoleLogTransport implements LogTransportProvider {
public getTarget(): TransportTargetSpec {
return {
target: "pino-pretty",
level: LOG_LEVEL,
options: {
colorize: true,
translateTime: "SYS:yyyy-mm-dd HH:MM:ss.l",
ignore: "pid,hostname",
messageFormat: "{msg}",
levelFirst: true,
},
};
}
public getStartupMessage(): string {
return "Logging to console";
}
}
/**
* File transport writing pretty-formatted logs to a timestamped file in a configurable directory.
* Active iff `PENPOT_MCP_LOG_DIR` is set and non-empty.
*/
class FileLogTransport implements LogTransportProvider {
private readonly enabled: boolean;
private readonly filePath: string | null;
public constructor(logDir: string | undefined) {
this.enabled = logDir !== undefined && logDir !== "";
this.filePath = this.enabled ? resolve(join(logDir as string, generateLogFileName())) : null;
}
public isEnabled(): boolean {
return this.enabled;
}
public getTarget(): TransportTargetSpec | null {
if (!this.enabled) {
return null;
}
return {
target: "pino-pretty",
level: LOG_LEVEL,
options: {
destination: this.filePath,
colorize: false,
translateTime: "SYS:yyyy-mm-dd HH:MM:ss.l",
ignore: "pid,hostname",
messageFormat: "{msg}",
levelFirst: true,
mkdir: true,
},
};
}
public getStartupMessage(): string | null {
return this.enabled ? `Logging to file: ${this.filePath}` : null;
}
/**
* Returns the absolute path of the active log file, or `undefined` if file logging is disabled.
*/
public getFilePath(): string | undefined {
return this.filePath ?? undefined;
}
}
/**
* Loki transport forwarding logs to a Grafana Loki instance via `pino-loki`.
*
* Active iff `PENPOT_LOGGERS_LOKI_URI` is set and non-empty.
*/
class LokiLogTransport implements LogTransportProvider {
private readonly host: string | null;
public constructor(lokiUri: string | undefined) {
this.host = lokiUri !== undefined && lokiUri !== "" ? lokiUri : null;
}
public isEnabled(): boolean {
return this.host !== null;
}
public getTarget(): TransportTargetSpec | null {
if (this.host === null) {
return null;
}
return {
target: "pino-loki",
level: LOG_LEVEL,
options: {
host: this.host,
json: false,
batching: true,
interval: 5,
replaceTimestamp: true,
labels: this.buildLabels(),
},
};
}
/**
* Builds the set of static labels to attach to every log entry sent to Loki.
*
* The `environment` and `instance` labels are only included if their respective
* environment variables are set and non-empty.
*/
private buildLabels(): Record<string, string> {
const labels: Record<string, string> = {
job: process.env.PENPOT_LOGGERS_LOKI_JOB || "mcp",
};
const environment = process.env.PENPOT_LOGGERS_LOKI_ENVIRONMENT;
if (environment) {
labels.environment = environment;
}
const instance = process.env.PENPOT_LOGGERS_LOKI_INSTANCE;
if (instance) {
labels.instance = instance;
}
return labels;
}
public getStartupMessage(): string | null {
return this.host !== null ? `Logging to Loki: ${this.host}` : null;
}
}
// build the transport providers; each decides its own activation independently
const consoleTransport = new ConsoleLogTransport();
const fileTransport = new FileLogTransport(LOG_DIR);
const lokiTransport = new LokiLogTransport(LOKI_URI);
const transports: LogTransportProvider[] = [consoleTransport, fileTransport, lokiTransport];
/**
* Absolute path to the log file being written, or `undefined` if file logging is disabled.
*/
export const logFilePath: string | undefined = fileTransport.getFilePath();
/**
* Logger instance configured with the active transports (console, optional file, optional Loki).
*/
export const logger = pino({
level: LOG_LEVEL,
timestamp: pino.stdTimeFunctions.isoTime,
transport: {
targets: [
{
// console transport with pretty formatting
target: "pino-pretty",
level: LOG_LEVEL,
options: {
colorize: true,
translateTime: "SYS:yyyy-mm-dd HH:MM:ss.l",
ignore: "pid,hostname",
messageFormat: "{msg}",
levelFirst: true,
},
},
{
// file transport with pretty formatting (same as console)
target: "pino-pretty",
level: LOG_LEVEL,
options: {
destination: logFilePath,
colorize: false,
translateTime: "SYS:yyyy-mm-dd HH:MM:ss.l",
ignore: "pid,hostname",
messageFormat: "{msg}",
levelFirst: true,
mkdir: true,
},
},
],
targets: transports
.map((t) => t.getTarget())
.filter((target): target is TransportTargetSpec => target !== null),
},
});
/**
* Logs a startup line for each active transport, allowing the user to see at a glance
* where logs are being written.
*
* @param log - the logger to emit the startup messages on
*/
export function logActiveTransports(log: pino.Logger): void {
for (const t of transports) {
const msg = t.getStartupMessage();
if (msg !== null) {
log.info(msg);
}
}
}
/**
* Creates a child logger with the specified name/origin.
*
* @param name - The name/origin identifier for the logger
* @returns Child logger instance with the specified name
* @param name - the name/origin identifier for the logger
* @returns child logger instance with the specified name
*/
export function createLogger(name: string) {
return logger.child({ name });

12
mcp/pnpm-lock.yaml generated
View File

@ -66,6 +66,9 @@ importers:
pino:
specifier: ^9.10.0
version: 9.14.0
pino-loki:
specifier: ^2.6.0
version: 2.6.0
pino-pretty:
specifier: ^13.1.1
version: 13.1.3
@ -1268,6 +1271,10 @@ packages:
pino-abstract-transport@3.0.0:
resolution: {integrity: sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==}
pino-loki@2.6.0:
resolution: {integrity: sha512-Qy+NeIdb0YmZe/M5mgnO5aGaAyVaeqgwn45T6VajhRXZlZVfGe1YNYhFa9UZyCeNFAPGaUkD2e9yPGjx+2BBYA==}
hasBin: true
pino-pretty@13.1.3:
resolution: {integrity: sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==}
hasBin: true
@ -2481,6 +2488,11 @@ snapshots:
dependencies:
split2: 4.2.0
pino-loki@2.6.0:
dependencies:
pino-abstract-transport: 2.0.0
pump: 3.0.3
pino-pretty@13.1.3:
dependencies:
colorette: 2.0.20