Shatteredvoid/src/middleware/logging.middleware.js

/**
 * Request/Response Logging Middleware
 * Comprehensive logging for HTTP requests with performance tracking and audit trails
 */

const logger = require('../utils/logger');
const { performance } = require('perf_hooks');

/**
 * Main request logging middleware
 * @param {Object} req - Express request object
 * @param {Object} res - Express response object
 * @param {Function} next - Express next function
 */
function requestLogger(req, res, next) {
  const startTime = performance.now();
  const correlationId = req.correlationId;

  // Extract request information
  const requestInfo = {
    correlationId,
    method: req.method,
    url: req.originalUrl || req.url,
    path: req.path,
    query: Object.keys(req.query).length > 0 ? req.query : undefined,
    ip: req.ip || req.connection.remoteAddress,
    userAgent: req.get('User-Agent'),
    contentType: req.get('Content-Type'),
    contentLength: req.get('Content-Length'),
    referrer: req.get('Referrer'),
    origin: req.get('Origin'),
    timestamp: new Date().toISOString(),
  };

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

  // Store original methods to override
  const originalSend = res.send;
  const originalJson = res.json;
  const originalEnd = res.end;

  let responseBody = null;
  let responseSent = false;

  // Override res.send to capture response
  res.send = function (data) {
    if (!responseSent) {
      responseBody = data;
      logResponse();
    }
    return originalSend.call(this, data);
  };

  // Override res.json to capture JSON response
  res.json = function (data) {
    if (!responseSent) {
      responseBody = data;
      logResponse();
    }
    return originalJson.call(this, data);
  };

  // Override res.end to capture empty responses
  res.end = function (data) {
    if (!responseSent) {
      responseBody = data;
      logResponse();
    }
    return originalEnd.call(this, data);
  };

  /**
     * Log the response details
     */
  function logResponse() {
    if (responseSent) return;
    responseSent = true;

    const endTime = performance.now();
    const duration = Math.round(endTime - startTime);
    const statusCode = res.statusCode;

    const responseInfo = {
      correlationId,
      method: req.method,
      url: req.originalUrl || req.url,
      statusCode,
      duration: `${duration}ms`,
      contentLength: res.get('Content-Length'),
      contentType: res.get('Content-Type'),
      timestamp: new Date().toISOString(),
    };

    // Add user information if available
    if (req.user) {
      responseInfo.userId = req.user.playerId || req.user.adminId;
      responseInfo.userType = req.user.type;
      responseInfo.username = req.user.username;
    }

    // Determine log level based on status code
    let logLevel = 'info';
    if (statusCode >= 400 && statusCode < 500) {
      logLevel = 'warn';
    } else if (statusCode >= 500) {
      logLevel = 'error';
    }

    // Add response body for errors (but sanitize sensitive data)
    if (statusCode >= 400 && responseBody) {
      responseInfo.responseBody = sanitizeResponseBody(responseBody);
    }

    // Log slow requests as warnings
    if (duration > 5000) { // 5 seconds
      logLevel = 'warn';
      responseInfo.slow = true;
    }

    logger[logLevel]('Request completed', responseInfo);

    // Log audit trail for sensitive operations
    if (shouldAudit(req, statusCode)) {
      logAuditTrail(req, res, duration, correlationId);
    }

    // Track performance metrics
    trackPerformanceMetrics(req, res, duration);
  }

  next();
}

/**
 * Sanitize response body to remove sensitive information
 * @param {any} responseBody - Response body to sanitize
 * @returns {any} Sanitized response body
 */
function sanitizeResponseBody(responseBody) {
  if (!responseBody) return responseBody;

  try {
    let sanitized = responseBody;

    // If it's a string, try to parse as JSON
    if (typeof responseBody === 'string') {
      try {
        sanitized = JSON.parse(responseBody);
      } catch {
        return responseBody; // Return as-is if not JSON
      }
    }

    // Remove sensitive fields
    if (typeof sanitized === 'object') {
      const sensitiveFields = ['password', 'token', 'secret', 'key', 'hash'];
      const cloned = JSON.parse(JSON.stringify(sanitized));

      function removeSensitiveFields(obj) {
        if (typeof obj !== 'object' || obj === null) return obj;

        Object.keys(obj).forEach(key => {
          if (sensitiveFields.some(field => key.toLowerCase().includes(field))) {
            obj[key] = '[REDACTED]';
          } else if (typeof obj[key] === 'object') {
            removeSensitiveFields(obj[key]);
          }
        });

        return obj;
      }

      return removeSensitiveFields(cloned);
    }

    return sanitized;

  } catch (error) {
    return '[SANITIZATION_ERROR]';
  }
}

/**
 * Determine if request should be audited
 * @param {Object} req - Express request object
 * @param {number} statusCode - Response status code
 * @returns {boolean} True if should audit
 */
function shouldAudit(req, statusCode) {
  // Audit admin actions
  if (req.user?.type === 'admin') {
    return true;
  }

  // Audit authentication attempts
  if (req.path.includes('/auth/') || req.path.includes('/login')) {
    return true;
  }

  // Audit failed requests
  if (statusCode >= 400) {
    return true;
  }

  // Audit sensitive game actions
  const sensitiveActions = [
    '/colonies',
    '/fleets',
    '/research',
    '/messages',
    '/profile',
  ];

  if (sensitiveActions.some(action => req.path.includes(action)) && req.method !== 'GET') {
    return true;
  }

  return false;
}

/**
 * Log audit trail for sensitive operations
 * @param {Object} req - Express request object
 * @param {Object} res - Express response object
 * @param {number} duration - Request duration in milliseconds
 * @param {string} correlationId - Request correlation ID
 */
function logAuditTrail(req, res, duration, correlationId) {
  const auditInfo = {
    correlationId,
    event: 'api_request',
    method: req.method,
    path: req.path,
    statusCode: res.statusCode,
    duration: `${duration}ms`,
    ip: req.ip,
    userAgent: req.get('User-Agent'),
    timestamp: new Date().toISOString(),
  };

  // Add user information
  if (req.user) {
    auditInfo.userId = req.user.playerId || req.user.adminId;
    auditInfo.userType = req.user.type;
    auditInfo.username = req.user.username;
  }

  // Add request parameters for POST/PUT/PATCH requests (sanitized)
  if (['POST', 'PUT', 'PATCH'].includes(req.method) && req.body) {
    auditInfo.requestBody = sanitizeRequestBody(req.body);
  }

  // Add query parameters
  if (Object.keys(req.query).length > 0) {
    auditInfo.queryParams = req.query;
  }

  logger.audit('Audit trail', auditInfo);
}

/**
 * Sanitize request body for audit logging
 * @param {Object} body - Request body to sanitize
 * @returns {Object} Sanitized request body
 */
function sanitizeRequestBody(body) {
  if (!body || typeof body !== 'object') return body;

  try {
    const sensitiveFields = ['password', 'oldPassword', 'newPassword', 'token', 'secret'];
    const cloned = JSON.parse(JSON.stringify(body));

    sensitiveFields.forEach(field => {
      if (cloned[field]) {
        cloned[field] = '[REDACTED]';
      }
    });

    return cloned;
  } catch {
    return '[SANITIZATION_ERROR]';
  }
}

/**
 * Track performance metrics
 * @param {Object} req - Express request object
 * @param {Object} res - Express response object
 * @param {number} duration - Request duration in milliseconds
 */
function trackPerformanceMetrics(req, res, duration) {
  // Only track metrics for non-health check endpoints
  if (req.path === '/health') return;

  const metrics = {
    endpoint: `${req.method} ${req.route?.path || req.path}`,
    duration,
    statusCode: res.statusCode,
    timestamp: Date.now(),
  };

  // Log slow requests
  if (duration > 1000) { // 1 second
    logger.warn('Slow request detected', {
      correlationId: req.correlationId,
      ...metrics,
      threshold: '1000ms',
    });
  }

  // Log very slow requests as errors
  if (duration > 10000) { // 10 seconds
    logger.error('Very slow request detected', {
      correlationId: req.correlationId,
      ...metrics,
      threshold: '10000ms',
    });
  }

  // TODO: Send metrics to monitoring system (Prometheus, DataDog, etc.)
  // This would integrate with your monitoring infrastructure
}

/**
 * Middleware to skip logging for specific paths
 * @param {Array<string>} skipPaths - Array of paths to skip
 * @returns {Function} Middleware function
 */
function skipLogging(skipPaths = ['/health', '/favicon.ico']) {
  return (req, res, next) => {
    const shouldSkip = skipPaths.some(path => req.path === path);

    if (shouldSkip) {
      return next();
    }

    return requestLogger(req, res, next);
  };
}

/**
 * Error logging middleware (for unhandled errors)
 * @param {Error} error - Error object
 * @param {Object} req - Express request object
 * @param {Object} res - Express response object
 * @param {Function} next - Express next function
 */
function errorLogger(error, req, res, next) {
  logger.error('Unhandled request error', {
    correlationId: req.correlationId,
    error: error.message,
    stack: error.stack,
    method: req.method,
    url: req.originalUrl,
    ip: req.ip,
    userAgent: req.get('User-Agent'),
    userId: req.user?.playerId || req.user?.adminId,
    userType: req.user?.type,
  });

  next(error);
}

module.exports = {
  requestLogger,
  skipLogging,
  errorLogger,
  sanitizeResponseBody,
  sanitizeRequestBody,
};