Structured Logging für Node.js-Dienste in der Produktion
Structured Logging in Node.js: maschinenlesbare, durchsuchbare Einträge mit Korrelations-IDs, einheitlichen Schweregraden und Kontextweitergabe.
Warum structured logging?
Unstrukturierte Logs —console.log("User logged in:", userId)— sind für Menschen gut lesbar, aber für Maschinen kaum zu gebrauchen. Bei Tausenden Requests pro Sekunde über Dutzende Services hinweg musst du Log-Daten programmatisch filtern, aggregieren und für Alerts auswerten können. Structured logging erzeugt JSON-Objekte mit konsistenten Feldern, wodurch jeder Log-Eintrag durchsuchbar und auswertbar wird.
Die Grundlage des Loggers
Verwende eine Logging-Bibliothek, die JSON mit konsistenten Feldern erzeugt. Pino ist der Standard für Node.js: schnell, strukturiert und für den Produktionseinsatz konzipiert.
import pino from "pino";
const logger = pino({
level: process.env.LOG_LEVEL ?? "info",
formatters: {
level(label) {
return { level: label };
},
},
timestamp: pino.stdTimeFunctions.isoTime,
base: {
service: process.env.SERVICE_NAME ?? "api-server",
environment: process.env.NODE_ENV ?? "development",
version: process.env.APP_VERSION ?? "unknown",
},
});
export { logger };// ❌ Unstructured — impossible to search or filter
console.log("Payment processed for user " + userId + " amount: $" + amount);
console.log("ERROR: Payment failed", error.message);
// ✅ Structured — every field is searchable
logger.info(
{ userId, amount, currency: "USD", paymentId },
"Payment processed successfully"
);
logger.error(
{ userId, amount, paymentId, errorCode: error.code, err: error },
"Payment processing failed"
);Korrelations-IDs über Requests hinweg
Jeder eingehende Request erhält eine eindeutige Korrelations-ID, die an alle nachgelagerten Aufrufe weitergegeben wird. Beim Debuggen filterst du die Logs nach dieser ID, um den gesamten Weg eines Requests durch alle Services nachzuvollziehen.
import { randomUUID } from "node:crypto";
import { AsyncLocalStorage } from "node:async_hooks";
interface RequestContext {
correlationId: string;
userId?: string;
requestPath: string;
requestMethod: string;
}
const contextStorage = new AsyncLocalStorage<RequestContext>();
// Middleware: set correlation ID for every request
function correlationMiddleware(
req: Request,
res: Response,
next: NextFunction
): void {
const correlationId =
(req.headers["x-correlation-id"] as string) ?? randomUUID();
res.setHeader("x-correlation-id", correlationId);
const context: RequestContext = {
correlationId,
requestPath: req.path,
requestMethod: req.method,
};
contextStorage.run(context, () => next());
}
// Context-aware logger that automatically includes correlation ID
function getLogger(): pino.Logger {
const context = contextStorage.getStore();
if (context) {
return logger.child({
correlationId: context.correlationId,
userId: context.userId,
path: context.requestPath,
});
}
return logger;
}
// Usage anywhere in the request lifecycle
function processOrder(order: Order): void {
const log = getLogger();
log.info({ orderId: order.id, items: order.items.length }, "Processing order");
// Log automatically includes correlationId, userId, path
}Log-Level und wann man sie einsetzt
Einheitliche Schweregrade im gesamten Team verhindern sowohl Log-Rauschen als auch das Fehlen kritischer Informationen.
interface LogLevelGuidance {
level: string;
when: string;
example: string;
}
const guidelines: LogLevelGuidance[] = [
{
level: "fatal",
when: "Application cannot continue — process will exit",
example: "Database connection failed after all retries on startup",
},
{
level: "error",
when: "Operation failed — requires investigation but process continues",
example: "Payment processing failed for a specific transaction",
},
{
level: "warn",
when: "Unexpected condition that may indicate a problem",
example: "Cache miss rate exceeding threshold, falling back to database",
},
{
level: "info",
when: "Significant business events and operational milestones",
example: "Order completed, user registered, deployment started",
},
{
level: "debug",
when: "Detailed technical information for troubleshooting",
example: "SQL query executed, cache key checked, retry attempt 2 of 5",
},
{
level: "trace",
when: "Very verbose — function entry/exit, data payloads",
example: "Request body parsed, response serialized, middleware chain",
},
];Maskierung sensibler Daten
Produktions-Logs dürfen niemals Passwörter, Tokens, Kreditkartennummern oder PII enthalten. Maskiere diese Daten bereits auf Logger-Ebene, damit Entwickler nicht selbst daran denken müssen.
const sensitiveKeys = new Set([
"password",
"token",
"authorization",
"cookie",
"creditCard",
"ssn",
"secret",
"apiKey",
]);
const redactedLogger = pino({
level: "info",
redact: {
paths: [
"password",
"*.password",
"token",
"*.token",
"headers.authorization",
"headers.cookie",
"body.creditCard",
"body.ssn",
],
censor: "[REDACTED]",
},
});
// Automatic redaction — developers don't need to remember
redactedLogger.info(
{
userId: "u_123",
headers: { authorization: "Bearer eyJ..." }, // → [REDACTED]
body: { email: "user@example.com", password: "secret123" }, // password → [REDACTED]
},
"Request received"
);Logging von Requests und Responses
Protokolliere jeden Request und jede Response inklusive Zeitmessung. Das ist mit Abstand das nützlichste Log für die Fehlersuche bei Produktionsproblemen.
function requestLogMiddleware(
req: Request,
res: Response,
next: NextFunction
): void {
const start = performance.now();
const log = getLogger();
// Log request
log.info(
{
event: "request_received",
method: req.method,
path: req.path,
query: req.query,
userAgent: req.headers["user-agent"],
contentLength: req.headers["content-length"],
},
"Incoming request"
);
// Capture response
const originalEnd = res.end.bind(res);
res.end = function (...args: Parameters<typeof res.end>) {
const duration = Math.round(performance.now() - start);
log.info(
{
event: "request_completed",
method: req.method,
path: req.path,
statusCode: res.statusCode,
durationMs: duration,
contentLength: res.getHeader("content-length"),
},
"Request completed"
);
// Warn on slow requests
if (duration > 1000) {
log.warn(
{ durationMs: duration, path: req.path },
"Slow request detected"
);
}
return originalEnd(...args);
};
next();
}Fehler-Logging mit Kontext
Protokolliere Fehler mit vollständigem Kontext: Stack Traces, Eingabedaten und die fehlgeschlagene Operation. Das erspart dir das lästige Hin und Her von "Was hat der Nutzer gerade gemacht, als das passiert ist?".
function logError(
error: Error,
context: Record<string, unknown>
): void {
const log = getLogger();
log.error(
{
err: {
message: error.message,
name: error.name,
stack: error.stack,
...(error instanceof AppError && {
code: error.code,
statusCode: error.statusCode,
}),
},
...context,
},
`Operation failed: ${error.message}`
);
}
// Usage
try {
await processPayment(order);
} catch (error) {
logError(error as Error, {
operation: "processPayment",
orderId: order.id,
userId: order.userId,
amount: order.total,
});
throw error;
}Wichtigste Erkenntnisse
Structured logging erzeugt JSON-Objekte mit konsistenten Feldern, wodurch jeder Log-Eintrag durchsuchbar und filterbar wird. Verwende eine Bibliothek wie Pino, die JSON-Formatierung, Log-Level und child logger effizient handhabt. Gib Korrelations-IDs über AsyncLocalStorage an jeden Request weiter, damit sich ein einzelner Request über alle Services hinweg nachverfolgen lässt.
Maskiere sensible Daten bereits auf Ebene der Logger-Konfiguration – verlass dich nie darauf, dass Entwickler daran denken, Passwörter oder Tokens wegzulassen. Protokolliere jeden Request und jede Response mit Zeitmessung, denn das liefert die wertvollsten Debugging-Daten. Verwende Log-Level einheitlich im gesamten Team: error für Fehler, die untersucht werden müssen, warn für Auffälligkeiten, info für geschäftsrelevante Ereignisse. Die Investition in structured logging zahlt sich beim ersten Produktionsvorfall aus, den du in Minuten statt Stunden debuggst.
