8.9 KiB
ADR-027: Standardized Application-Wide Structured Logging
Date: 2026-02-10
Status: Accepted
Source: Imported from flyer-crawler project (ADR-004)
Related: ADR-017, ADR-028, ADR-029
Context
While ADR-017 established Pino as our logging framework, this ADR extends that foundation with application-wide standards for request tracing, context propagation, and structured log formats.
The implementation of logging can vary significantly across different modules. The error handler middleware may produce high-quality, structured JSON logs for errors, but logging within route handlers and service layers can become ad-hoc, using plain strings or inconsistent object structures.
This inconsistency leads to several problems:
- Difficult Debugging: It is hard to trace a single user request through the system or correlate events related to a specific operation
- Ineffective Log Analysis: Inconsistent log formats make it difficult to effectively query, filter, and create dashboards in log management systems (like Datadog, Splunk, or the ELK stack)
- Security Risks: There is no enforced standard for redacting sensitive information (like passwords or tokens) in logs outside of the error handler, increasing the risk of accidental data exposure
- Missing Context: Logs often lack crucial context, such as a unique request ID, the authenticated user's ID, or the source IP address, making them less useful for diagnosing issues
Decision
We will adopt a standardized, application-wide structured logging policy. All log entries MUST be in JSON format and adhere to a consistent schema.
1. Request-Scoped Logger with Context
We will create a middleware that runs at the beginning of the request lifecycle. This middleware will:
- Generate a unique
request_idfor each incoming request - Create a request-scoped logger instance (a "child logger") that automatically includes the
request_id,user_id(if authenticated), andip_addressin every log message it generates - Attach this child logger to the
reqobject (e.g.,req.log)
2. Mandatory Use of Request-Scoped Logger
All route handlers and any service functions called by them MUST use the request-scoped logger (req.log) instead of the global logger instance. This ensures all logs for a given request are automatically correlated.
3. Standardized Log Schema
All log messages should follow a base schema. The logger configuration will be updated to enforce this.
Base Fields: level, timestamp, message, request_id, user_id, ip_address
Error Fields: When logging an error, the log entry MUST include an error object with name, message, and stack.
4. Standardized Logging Practices
| Level | HTTP Status | Scenario |
|---|---|---|
| DEBUG | Any | Request incoming, internal state, development info |
| INFO | 2xx | Successful requests, business events |
| WARN | 4xx | Client errors, validation failures, not found |
| ERROR | 5xx | Server errors, unhandled exceptions |
Implementation Details
Logger Configuration
Located in src/services/logger.server.ts:
import pino from 'pino';
const isProduction = process.env.NODE_ENV === 'production';
const isTest = process.env.NODE_ENV === 'test';
export const logger = pino({
level: isProduction ? 'info' : 'debug',
transport:
isProduction || isTest
? undefined
: {
target: 'pino-pretty',
options: {
colorize: true,
translateTime: 'SYS:standard',
ignore: 'pid,hostname',
},
},
redact: {
paths: [
'req.headers.authorization',
'req.headers.cookie',
'*.body.password',
'*.body.newPassword',
'*.body.currentPassword',
'*.body.confirmPassword',
'*.body.refreshToken',
'*.body.token',
],
censor: '[REDACTED]',
},
});
Request Logger Middleware
Located in server.ts:
import { randomUUID } from 'crypto';
import type { Request, Response, NextFunction } from 'express';
import { logger } from './services/logger.server';
const requestLogger = (req: Request, res: Response, next: NextFunction) => {
const requestId = randomUUID();
const user = req.user as UserProfile | undefined;
const start = process.hrtime();
// Create request-scoped logger
req.log = logger.child({
request_id: requestId,
user_id: user?.user.user_id,
ip_address: req.ip,
});
req.log.debug({ method: req.method, originalUrl: req.originalUrl }, 'INCOMING');
res.on('finish', () => {
const duration = getDurationInMilliseconds(start);
const { statusCode, statusMessage } = res;
const logDetails = {
user_id: (req.user as UserProfile | undefined)?.user.user_id,
method: req.method,
originalUrl: req.originalUrl,
statusCode,
statusMessage,
duration: duration.toFixed(2),
};
// Include request details for failed requests (for debugging)
if (statusCode >= 400) {
logDetails.req = { headers: req.headers, body: req.body };
}
if (statusCode >= 500) req.log.error(logDetails, 'Request completed with server error');
else if (statusCode >= 400) req.log.warn(logDetails, 'Request completed with client error');
else req.log.info(logDetails, 'Request completed successfully');
});
next();
};
app.use(requestLogger);
TypeScript Support
The req.log property is typed via declaration merging in src/types/express.d.ts:
import { Logger } from 'pino';
declare global {
namespace Express {
export interface Request {
log: Logger;
}
}
}
Automatic Sensitive Data Redaction
The Pino logger automatically redacts sensitive fields:
// Before redaction
{
"body": {
"email": "user@example.com",
"password": "secret123",
"newPassword": "newsecret456"
}
}
// After redaction (in logs)
{
"body": {
"email": "user@example.com",
"password": "[REDACTED]",
"newPassword": "[REDACTED]"
}
}
Service Layer Logging
Services accept the request-scoped logger as an optional parameter:
export async function registerUser(email: string, password: string, reqLog?: Logger) {
const log = reqLog || logger; // Fall back to global logger
log.info({ email }, 'Registering new user');
// ... implementation
log.debug({ userId: user.user_id }, 'User created successfully');
return user;
}
// In route handler
router.post('/register', async (req, res, next) => {
await authService.registerUser(req.body.email, req.body.password, req.log);
});
Log Output Format
Development (pino-pretty):
[2026-01-09 12:34:56.789] INFO (request_id=abc123): Request completed successfully
method: "GET"
originalUrl: "/api/users"
statusCode: 200
duration: "45.23"
Production (JSON):
{
"level": 30,
"time": 1704812096789,
"request_id": "abc123",
"user_id": "user_456",
"ip_address": "192.168.1.1",
"method": "GET",
"originalUrl": "/api/users",
"statusCode": 200,
"duration": "45.23",
"msg": "Request completed successfully"
}
Consequences
Positive
- Enhanced Observability: Every log line from a single request can be instantly grouped and analyzed, dramatically speeding up debugging
- Improved Security: Centralizing the addition of context (like
user_id) reduces the chance of developers manually logging sensitive data - Scalable Log Management: Consistent JSON logs are easily ingested and indexed by any modern log aggregation tool
- Clearer Code: Removes the need to manually pass contextual information (like user ID) down to service functions just for logging purposes
Negative
- Refactoring Effort: Requires adding the
requestLoggermiddleware and refactoring all routes and services to usereq.loginstead of the globallogger - Slight Performance Overhead: Creating a child logger for every request adds a minor performance cost, though this is negligible for most modern logging libraries
Key Files
src/services/logger.server.ts- Pino logger configurationsrc/services/logger.client.ts- Client-side logger (for frontend)src/types/express.d.ts- TypeScript declaration forreq.logserver.ts- Request logger middleware
References
- ADR-017: Structured Logging with Pino
- ADR-001: Standardized Error Handling - Error handler uses
req.logfor error logging - ADR-028: Client-Side Structured Logging - Client-side logging strategy
- Pino Documentation