flyer-crawler.projectium.com/docs/adr/0004-standardized-application-wide-structured-logging.md

ADR-004: Standardized Application-Wide Structured Logging

Date: 2025-12-12

Status: Accepted

Implemented: 2026-01-07

Context

Our application currently uses a logger service, but the implementation of logging varies significantly across different modules. The errorHandler middleware produces high-quality, structured JSON logs for errors, but logging within route handlers and service layers is often 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 a log management system (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 errorHandler, 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.

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_id for each incoming request.
• Create a request-scoped logger instance (a "child logger") that automatically includes the request_id, user_id (if authenticated), and ip_address in every log message it generates.
• Attach this child logger to the req object (e.g., req.log).

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.

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.

Standardized Logging Practices: INFO: Log key business events, such as User logged in or Flyer processed. WARN: Log recoverable errors or unusual situations that do not break the request, such as Client Error: 404 on GET /api/non-existent-route or Retrying failed database connection. ERROR: Log only unhandled or server-side errors that cause a request to fail (typically handled by the errorHandler). Avoid logging expected client errors (like 4xx) at this level. DEBUG: Log detailed diagnostic information useful during development, such as function entry/exit points or variable states.

Example Usage

// In a new middleware file: logger.middleware.ts
import { logger } from '../services/logger.server';
import { randomUUID } from 'crypto';

export const requestLogger = (req, res, next) => {
  const requestId = randomUUID();
  // Create a child logger with context for this request
  req.log = logger.child({
    request_id: requestId,
    user_id: req.user?.user_id, // Assumes user is attached by auth middleware
    ip_address: req.ip,
  });
  next();
};

// In server/app setup:
// app.use(requestLogger); // Add this early in the middleware chain

// In a route handler:
router.get('/:id', async (req, res, next) => {
  // Use the request-scoped logger
  req.log.info({ flyerId: req.params.id }, 'Fetching flyer by ID');
  try {
    // ... business logic ...
    res.json(flyer);
  } catch (error) {
    // The error itself will be logged with full context by the errorHandler
    next(error);
  }
});

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 requestLogger middleware and refactoring all routes and services to use req.log instead of the global logger. Slight Performance Overhead: Creating a child logger for every request adds a minor performance cost, though this is negligible for most modern logging libraries.

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:

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]"
  }
}

Log Levels by Scenario

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

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/flyers"
    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/flyers",
  "statusCode": 200,
  "duration": "45.23",
  "msg": "Request completed successfully"
}

Routes Using req.log

All route files have been migrated to use the request-scoped logger:

• src/routes/auth.routes.ts
• src/routes/user.routes.ts
• src/routes/flyer.routes.ts
• src/routes/ai.routes.ts
• src/routes/admin.routes.ts
• src/routes/budget.routes.ts
• src/routes/recipe.routes.ts
• src/routes/gamification.routes.ts
• src/routes/personalization.routes.ts
• src/routes/stats.routes.ts
• src/routes/health.routes.ts
• src/routes/system.routes.ts

Key Files

• src/services/logger.server.ts - Pino logger configuration
• src/services/logger.client.ts - Client-side logger (for frontend)
• src/types/express.d.ts - TypeScript declaration for req.log
• server.ts - Request logger middleware

Related ADRs

• ADR-001 - Error handler uses req.log for error logging
• ADR-026 - Client-side logging strategy