Logging Patterns

Strategic logging transforms applications from black boxes into transparent, observable systems. With AI assistance, you can implement sophisticated logging patterns that provide the right information at the right time, making debugging faster and operations smoother. This guide covers battle-tested logging patterns for real-world applications.

The Strategic Logging Mindset

Modern logging is about creating a narrative of your application’s behavior:

Structured Data

JSON-formatted logs with consistent fields

Contextual Information

Request IDs, user context, and trace data

Performance Awareness

Minimal overhead with maximum insight

Security First

Never log sensitive data

Core Logging Patterns

Pattern 1: Structured Logging Foundation

Transform unstructured logs into queryable, analyzable data.

Node.js

// Traditional logging (avoid this)
console.log('User ' + userId + ' logged in from ' + ipAddress);

// AI-recommended structured logging
import winston from 'winston';

const logger = winston.createLogger({
  level: 'info',
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.errors({ stack: true }),
    winston.format.json()
  ),
  defaultMeta: {
    service: 'api-gateway',
    version: process.env.APP_VERSION
  },
  transports: [
    new winston.transports.File({ filename: 'error.log', level: 'error' }),
    new winston.transports.File({ filename: 'combined.log' })
  ]
});

// Usage with structured data
logger.info('User login successful', {
  userId: user.id,
  email: user.email,
  ipAddress: req.ip,
  userAgent: req.get('User-Agent'),
  loginMethod: 'oauth',
  provider: 'google'
});

// Output:
{
  "timestamp": "2024-01-15T10:30:45.123Z",
  "level": "info",
  "message": "User login successful",
  "service": "api-gateway",
  "version": "1.2.3",
  "userId": "usr_123",
  "email": "user@example.com",
  "ipAddress": "192.168.1.1",
  "userAgent": "Mozilla/5.0...",
  "loginMethod": "oauth",
  "provider": "google"
}

Python

import structlog
import logging
from datetime import datetime

# Configure structured logging
structlog.configure(
    processors=[
        structlog.stdlib.filter_by_level,
        structlog.stdlib.add_logger_name,
        structlog.stdlib.add_log_level,
        structlog.stdlib.PositionalArgumentsFormatter(),
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.processors.UnicodeDecoder(),
        structlog.processors.JSONRenderer()
    ],
    context_class=dict,
    logger_factory=structlog.stdlib.LoggerFactory(),
    cache_logger_on_first_use=True,
)

# Create logger with context
logger = structlog.get_logger()
logger = logger.bind(
    service="api-gateway",
    environment="production",
    region="us-east-1"
)

# Log with structured data
logger.info(
    "user_login_successful",
    user_id=user.id,
    email=user.email,
    ip_address=request.remote_addr,
    login_method="oauth",
    provider="github",
    duration_ms=152
)

Pattern 2: Request Context Logging

Track requests across your entire system with correlation IDs.

// Express middleware for request context
import { v4 as uuidv4 } from 'uuid';

class ContextualLogger {
  constructor(baseLogger) {
    this.baseLogger = baseLogger;
  }

  createRequestLogger(req) {
    const requestId = req.headers['x-request-id'] || uuidv4();
    const userId = req.user?.id || 'anonymous';

    // Store in request for downstream use
    req.requestId = requestId;
    req.logger = this.baseLogger.child({
      requestId,
      userId,
      method: req.method,
      path: req.path,
      ip: req.ip
    });

    return req.logger;
  }
}

// Middleware implementation
const loggingMiddleware = (logger) => (req, res, next) => {
  const contextLogger = new ContextualLogger(logger);
  req.logger = contextLogger.createRequestLogger(req);

  // Log request start
  req.logger.info('Request started');

  // Capture response details
  const startTime = Date.now();
  const originalSend = res.send;

  res.send = function(data) {
    res.send = originalSend;

    req.logger.info('Request completed', {
      statusCode: res.statusCode,
      duration: Date.now() - startTime,
      responseSize: Buffer.byteLength(data)
    });

    return res.send(data);
  };

  next();
};

// Usage in routes
app.get('/api/users/:id', (req, res) => {
  req.logger.info('Fetching user', {
    targetUserId: req.params.id
  });

  // Your logic here...
});

Pattern 3: Performance Logging

Monitor application performance through strategic logging.

// Performance logging utility
class PerformanceLogger {
  constructor(logger) {
    this.logger = logger;
    this.timers = new Map();
  }

  startTimer(operation, metadata = {}) {
    const id = `${operation}-${Date.now()}-${Math.random()}`;
    this.timers.set(id, {
      operation,
      startTime: process.hrtime.bigint(),
      metadata
    });

    this.logger.debug('Operation started', {
      operation,
      timerId: id,
      ...metadata
    });

    return id;
  }

  endTimer(timerId, additionalData = {}) {
    const timer = this.timers.get(timerId);
    if (!timer) {
      this.logger.warn('Timer not found', { timerId });
      return;
    }

    const endTime = process.hrtime.bigint();
    const durationMs = Number(endTime - timer.startTime) / 1e6;

    this.timers.delete(timerId);

    const logData = {
      operation: timer.operation,
      durationMs,
      ...timer.metadata,
      ...additionalData
    };

    // Log based on duration
    if (durationMs > 1000) {
      this.logger.warn('Slow operation detected', logData);
    } else {
      this.logger.info('Operation completed', logData);
    }

    // Emit metrics if configured
    if (this.metricsClient) {
      this.metricsClient.histogram(
        `operation.duration.${timer.operation}`,
        durationMs
      );
    }

    return durationMs;
  }

  async measureAsync(operation, fn, metadata = {}) {
    const timerId = this.startTimer(operation, metadata);
    try {
      const result = await fn();
      this.endTimer(timerId, { status: 'success' });
      return result;
    } catch (error) {
      this.endTimer(timerId, {
        status: 'error',
        error: error.message
      });
      throw error;
    }
  }
}

// Usage
const perfLogger = new PerformanceLogger(logger);

// Manual timing
const timerId = perfLogger.startTimer('database_query', {
  query: 'SELECT * FROM users',
  table: 'users'
});
const results = await db.query('SELECT * FROM users');
perfLogger.endTimer(timerId, { rowCount: results.length });

// Automatic timing
const user = await perfLogger.measureAsync(
  'fetch_user',
  () => userService.getUser(userId),
  { userId }
);

Pattern 4: Error Logging with Context

Capture comprehensive error information for faster debugging.

AI-Enhanced Error Logging

class ErrorLogger {
  constructor(logger) {
    this.logger = logger;
  }

  logError(error, context = {}) {
    // Extract useful error information
    const errorInfo = {
      message: error.message,
      name: error.name,
      stack: error.stack,
      code: error.code,
      statusCode: error.statusCode || 500
    };

    // Add request context if available
    if (context.req) {
      errorInfo.request = {
        method: context.req.method,
        url: context.req.url,
        headers: this.sanitizeHeaders(context.req.headers),
        body: this.sanitizeBody(context.req.body),
        user: context.req.user?.id
      };
    }

    // Add custom error properties
    if (error.details) {
      errorInfo.details = error.details;
    }

    // Log with appropriate level
    if (error.statusCode >= 500 || !error.statusCode) {
      this.logger.error('Application error', {
        ...errorInfo,
        ...context
      });
    } else if (error.statusCode >= 400) {
      this.logger.warn('Client error', {
        ...errorInfo,
        ...context
      });
    }

    // Log to error tracking service
    if (this.errorTracker) {
      this.errorTracker.captureException(error, {
        extra: context,
        user: context.req?.user
      });
    }
  }

  sanitizeHeaders(headers) {
    const sensitive = ['authorization', 'cookie', 'x-api-key'];
    const sanitized = { ...headers };

    sensitive.forEach(key => {
      if (sanitized[key]) {
        sanitized[key] = '[REDACTED]';
      }
    });

    return sanitized;
  }

  sanitizeBody(body) {
    if (!body) return body;

    const sensitive = ['password', 'token', 'secret', 'creditCard'];
    const sanitized = { ...body };

    const recursiveSanitize = (obj) => {
      Object.keys(obj).forEach(key => {
        if (sensitive.some(s => key.toLowerCase().includes(s))) {
          obj[key] = '[REDACTED]';
        } else if (typeof obj[key] === 'object' && obj[key] !== null) {
          recursiveSanitize(obj[key]);
        }
      });
    };

    recursiveSanitize(sanitized);
    return sanitized;
  }
}

Advanced Logging Patterns

Distributed Tracing Integration

Combine logging with distributed tracing for complete observability.

// OpenTelemetry integration
import { trace, context } from '@opentelemetry/api';

class TracingLogger {
  constructor(logger) {
    this.logger = logger;
    this.tracer = trace.getTracer('application');
  }

  log(level, message, attributes = {}) {
    const span = trace.getActiveSpan();

    if (span) {
      // Add trace context to logs
      const spanContext = span.spanContext();
      this.logger[level](message, {
        traceId: spanContext.traceId,
        spanId: spanContext.spanId,
        traceFlags: spanContext.traceFlags,
        ...attributes
      });

      // Add log event to span
      span.addEvent(message, attributes);
    } else {
      // No active span, log normally
      this.logger[level](message, attributes);
    }
  }

  async traceOperation(name, operation, attributes = {}) {
    return this.tracer.startActiveSpan(name, async (span) => {
      try {
        this.log('info', `Starting ${name}`, attributes);

        const result = await operation();

        span.setStatus({ code: 1 }); // OK
        this.log('info', `Completed ${name}`, {
          ...attributes,
          duration: span.duration
        });

        return result;
      } catch (error) {
        span.setStatus({
          code: 2, // ERROR
          message: error.message
        });
        span.recordException(error);

        this.log('error', `Failed ${name}`, {
          ...attributes,
          error: error.message,
          stack: error.stack
        });

        throw error;
      } finally {
        span.end();
      }
    });
  }
}

// Usage
const tracingLogger = new TracingLogger(logger);

await tracingLogger.traceOperation(
  'process_payment',
  async () => {
    // Your payment logic
    return await paymentService.process(payment);
  },
  {
    paymentId: payment.id,
    amount: payment.amount,
    currency: payment.currency
  }
);

Audit Logging

Track security-relevant events for compliance and forensics.

class AuditLogger {
  constructor(logger, options = {}) {
    this.logger = logger;
    this.options = {
      includeIp: true,
      includeUserAgent: true,
      includeTimestamp: true,
      ...options
    };
  }

  logAuditEvent(event, context = {}) {
    const auditEntry = {
      eventType: event.type,
      eventCategory: event.category,
      timestamp: new Date().toISOString(),
      actor: {
        userId: context.user?.id,
        username: context.user?.username,
        role: context.user?.role,
        ip: context.req?.ip,
        userAgent: context.req?.get('User-Agent')
      },
      target: event.target,
      action: event.action,
      result: event.result,
      reason: event.reason,
      metadata: event.metadata
    };

    // Sign the audit entry for tamper detection
    if (this.options.sign) {
      auditEntry.signature = this.signEntry(auditEntry);
    }

    // Log to separate audit log
    this.logger.info('AUDIT_EVENT', auditEntry);

    // Store in audit database if configured
    if (this.auditStore) {
      this.auditStore.save(auditEntry);
    }
  }

  // Common audit events
  logLogin(user, req, success = true) {
    this.logAuditEvent({
      type: 'AUTH_LOGIN',
      category: 'AUTHENTICATION',
      target: { type: 'USER', id: user.id },
      action: 'LOGIN',
      result: success ? 'SUCCESS' : 'FAILURE',
      metadata: {
        loginMethod: req.body.method,
        mfaUsed: user.mfaEnabled
      }
    }, { user, req });
  }

  logDataAccess(user, resource, action, req) {
    this.logAuditEvent({
      type: 'DATA_ACCESS',
      category: 'AUTHORIZATION',
      target: {
        type: resource.type,
        id: resource.id,
        name: resource.name
      },
      action: action.toUpperCase(),
      result: 'SUCCESS',
      metadata: {
        fields: resource.fields,
        filters: resource.filters
      }
    }, { user, req });
  }

  logConfigChange(user, config, req) {
    this.logAuditEvent({
      type: 'CONFIG_CHANGE',
      category: 'SYSTEM',
      target: {
        type: 'CONFIGURATION',
        id: config.key
      },
      action: 'UPDATE',
      result: 'SUCCESS',
      metadata: {
        oldValue: config.oldValue,
        newValue: config.newValue,
        changeReason: config.reason
      }
    }, { user, req });
  }
}

Log Sampling and Rate Limiting

Prevent log flooding while maintaining visibility.

class SamplingLogger {
  constructor(logger, config = {}) {
    this.logger = logger;
    this.config = {
      defaultSampleRate: 0.1, // 10%
      rules: [],
      windowSize: 60000, // 1 minute
      ...config
    };
    this.counters = new Map();
  }

  shouldLog(level, message, metadata = {}) {
    // Always log errors
    if (level === 'error' || level === 'fatal') {
      return true;
    }

    // Check custom rules
    for (const rule of this.config.rules) {
      if (rule.matches(level, message, metadata)) {
        return this.applySampling(rule.sampleRate, rule.key);
      }
    }

    // Apply default sampling
    return Math.random() < this.config.defaultSampleRate;
  }

  applySampling(rate, key) {
    if (rate === 1) return true;
    if (rate === 0) return false;

    // Ensure minimum representation
    const counter = this.getCounter(key);
    if (counter.total === 0) {
      counter.sampled++;
      counter.total++;
      return true;
    }

    const currentRate = counter.sampled / counter.total;
    if (currentRate < rate) {
      counter.sampled++;
      counter.total++;
      return true;
    }

    counter.total++;
    return false;
  }

  getCounter(key) {
    if (!this.counters.has(key)) {
      this.counters.set(key, {
        total: 0,
        sampled: 0,
        windowStart: Date.now()
      });
    }

    const counter = this.counters.get(key);

    // Reset counter if window expired
    if (Date.now() - counter.windowStart > this.config.windowSize) {
      counter.total = 0;
      counter.sampled = 0;
      counter.windowStart = Date.now();
    }

    return counter;
  }

  log(level, message, metadata = {}) {
    if (this.shouldLog(level, message, metadata)) {
      this.logger[level](message, metadata);
    } else {
      // Track dropped logs
      this.logger.debug('Log dropped due to sampling', {
        originalLevel: level,
        originalMessage: message
      });
    }
  }
}

// Configuration
const samplingLogger = new SamplingLogger(logger, {
  defaultSampleRate: 0.1,
  rules: [
    {
      key: 'health-check',
      matches: (level, msg) => msg.includes('health check'),
      sampleRate: 0.01 // 1% for health checks
    },
    {
      key: 'debug-verbose',
      matches: (level) => level === 'debug',
      sampleRate: 0.05 // 5% for debug logs
    }
  ]
});

Log Aggregation Patterns

Multi-Transport Logging

Send logs to multiple destinations based on criteria.

class MultiTransportLogger {
  constructor() {
    this.transports = [];
  }

  addTransport(transport, options = {}) {
    this.transports.push({
      transport,
      levels: options.levels || ['error', 'warn', 'info', 'debug'],
      filter: options.filter || (() => true),
      transform: options.transform || (log => log)
    });
  }

  log(level, message, metadata = {}) {
    const logEntry = {
      timestamp: new Date().toISOString(),
      level,
      message,
      ...metadata
    };

    this.transports.forEach(({ transport, levels, filter, transform }) => {
      if (levels.includes(level) && filter(logEntry)) {
        const transformed = transform(logEntry);
        transport.log(level, transformed);
      }
    });
  }

  // Convenience methods
  error(message, metadata) { this.log('error', message, metadata); }
  warn(message, metadata) { this.log('warn', message, metadata); }
  info(message, metadata) { this.log('info', message, metadata); }
  debug(message, metadata) { this.log('debug', message, metadata); }
}

// Configure multi-transport
const logger = new MultiTransportLogger();

// Console for development
logger.addTransport(new ConsoleTransport(), {
  levels: ['error', 'warn', 'info'],
  transform: (log) => ({
    ...log,
    // Add color coding
    message: colorize(log.level, log.message)
  })
});

// File for persistence
logger.addTransport(new FileTransport('app.log'), {
  levels: ['error', 'warn', 'info', 'debug']
});

// CloudWatch for production
logger.addTransport(new CloudWatchTransport(), {
  levels: ['error', 'warn', 'info'],
  filter: (log) => process.env.NODE_ENV === 'production',
  transform: (log) => ({
    ...log,
    environment: process.env.NODE_ENV,
    service: process.env.SERVICE_NAME
  })
});

// Sentry for errors
logger.addTransport(new SentryTransport(), {
  levels: ['error'],
  transform: (log) => ({
    ...log,
    fingerprint: generateFingerprint(log)
  })
});

Best Practices

Log Levels

• ERROR: System failures requiring immediate attention
• WARN: Potential issues or degraded functionality
• INFO: Significant business events
• DEBUG: Detailed diagnostic information

What to Log

• Request/response summaries
• State changes
• External API calls
• Performance metrics
• Security events

What NOT to Log

• Passwords or secrets
• Credit card numbers
• Personal health information
• Large binary data
• High-frequency operations

Performance Tips

• Use async logging
• Implement log sampling
• Batch log writes
• Set appropriate log levels
• Monitor logging overhead

Log Message Templates

Use consistent, searchable log messages:

// AI-recommended log message patterns
const LogMessages = {
  // Operation lifecycle
  OPERATION_START: (op) => `Starting ${op}`,
  OPERATION_SUCCESS: (op) => `Completed ${op}`,
  OPERATION_FAILURE: (op) => `Failed to ${op}`,
  OPERATION_RETRY: (op, attempt) => `Retrying ${op} (attempt ${attempt})`,

  // API patterns
  API_REQUEST: (method, path) => `${method} ${path}`,
  API_RESPONSE: (method, path, status) => `${method} ${path} ${status}`,
  API_ERROR: (method, path, error) => `${method} ${path} failed: ${error}`,

  // Database patterns
  DB_QUERY: (operation, table) => `Database ${operation} on ${table}`,
  DB_CONNECTION: (action) => `Database connection ${action}`,
  DB_TRANSACTION: (action) => `Transaction ${action}`,

  // Authentication
  AUTH_LOGIN: (method) => `User login via ${method}`,
  AUTH_LOGOUT: () => 'User logout',
  AUTH_FAILURE: (reason) => `Authentication failed: ${reason}`,

  // Performance
  SLOW_OPERATION: (op, duration) => `Slow operation detected: ${op} took ${duration}ms`,
  MEMORY_WARNING: (usage) => `High memory usage: ${usage}MB`,

  // Business events
  ORDER_PLACED: () => 'Order placed',
  PAYMENT_PROCESSED: () => 'Payment processed',
  USER_REGISTERED: () => 'New user registered'
};

// Usage
logger.info(LogMessages.OPERATION_START('payment_processing'), {
  paymentId: payment.id,
  amount: payment.amount
});

Testing Your Logging

Wskazówka

Always test your logging implementation to ensure it captures the right information without impacting performance or exposing sensitive data.

// Jest test example
describe('Logging Tests', () => {
  let logger;
  let mockTransport;

  beforeEach(() => {
    mockTransport = {
      logs: [],
      log: jest.fn((level, entry) => {
        mockTransport.logs.push({ level, ...entry });
      })
    };

    logger = new Logger();
    logger.addTransport(mockTransport);
  });

  test('should log structured data', () => {
    logger.info('User action', {
      userId: '123',
      action: 'login'
    });

    expect(mockTransport.logs).toHaveLength(1);
    expect(mockTransport.logs[0]).toMatchObject({
      level: 'info',
      message: 'User action',
      userId: '123',
      action: 'login'
    });
  });

  test('should sanitize sensitive data', () => {
    logger.info('User update', {
      userId: '123',
      password: 'secret123',
      creditCard: '4111111111111111'
    });

    expect(mockTransport.logs[0].password).toBe('[REDACTED]');
    expect(mockTransport.logs[0].creditCard).toBe('[REDACTED]');
  });

  test('should respect sampling rules', () => {
    const samplingLogger = new SamplingLogger(logger, {
      defaultSampleRate: 0
    });

    samplingLogger.info('Should be dropped');
    expect(mockTransport.logs).toHaveLength(0);

    samplingLogger.error('Should be logged');
    expect(mockTransport.logs).toHaveLength(1);
  });
});

Next Steps

Master logging with:

• Debugging Patterns - Strategic debugging techniques
• Monitoring Patterns - Proactive system monitoring
• Recovery Patterns - Graceful error recovery

Wskazówka

Pro Tip: Great logging is invisible when everything works but invaluable when things go wrong. Invest in your logging infrastructure—your future self will thank you during that 3 AM production incident.