Logging and monitoring of middleware

The Necessity of Logging

Logging is an indispensable part of middleware development. It helps developers track application runtime status and identify the root causes of issues. In an Express application, the absence of a robust logging system is like debugging code in the dark—making it difficult to uncover potential errors and performance bottlenecks.

Logging Middleware in Express

The Express ecosystem offers several mature logging middleware options. The most commonly used is morgan, which is specifically designed for HTTP request logging. Installation is straightforward:

npm install morgan

Basic usage example:

const express = require('express');
const morgan = require('morgan');

const app = express();

// Use predefined log format
app.use(morgan('combined'));

// Custom log format
app.use(morgan(':method :url :status :res[content-length] - :response-time ms'));

morgan supports several predefined formats:

• 'combined': Standard Apache combined log format
• 'common': Basic log format
• 'dev': Colorized development logs
• 'short': Minimalist format
• 'tiny': Most concise format

Custom Logging Middleware

When predefined middleware doesn't meet requirements, you can create custom logging middleware:

function requestLogger(req, res, next) {
  const start = Date.now();
  
  res.on('finish', () => {
    const duration = Date.now() - start;
    console.log(`${req.method} ${req.originalUrl} ${res.statusCode} - ${duration}ms`);
  });

  next();
}

app.use(requestLogger);

This custom middleware logs the request method, URL, status code, and response time.

Log Level Management

Production environments require log level differentiation. Common levels include:

• error: Error logs
• warn: Warning logs
• info: General information logs
• debug: Debugging information
• verbose: Detailed logs

The winston library can be used to implement log leveling:

const winston = require('winston');

const logger = winston.createLogger({
  levels: winston.config.syslog.levels,
  transports: [
    new winston.transports.Console({
      level: 'debug',
      format: winston.format.combine(
        winston.format.colorize(),
        winston.format.simple()
      )
    }),
    new winston.transports.File({
      filename: 'error.log',
      level: 'error'
    })
  ]
});

// Usage example
logger.error('Database connection failed');
logger.info('Server started on port 3000');

Log Storage Strategies

Log storage requires consideration of several aspects:

1. Local file storage
2. Database storage
3. Cloud service storage

Log rotation is a common requirement and can be implemented using winston-daily-rotate-file:

const DailyRotateFile = require('winston-daily-rotate-file');

logger.add(new DailyRotateFile({
  filename: 'application-%DATE%.log',
  datePattern: 'YYYY-MM-DD',
  zippedArchive: true,
  maxSize: '20m',
  maxFiles: '14d'
}));

Monitoring Middleware Performance

Beyond logging, performance monitoring is equally important. express-status-monitor can be used:

const monitor = require('express-status-monitor')();

app.use(monitor);

This middleware provides a visual dashboard displaying:

• Request response times
• Memory usage
• CPU load
• Event loop latency

Custom Performance Monitoring

For performance monitoring of specific routes, you can create middleware:

function performanceMonitor(req, res, next) {
  const start = process.hrtime();
  
  res.on('finish', () => {
    const diff = process.hrtime(start);
    const duration = diff[0] * 1e3 + diff[1] * 1e-6; // Convert to milliseconds
    
    if(duration > 500) {
      logger.warn(`Slow request: ${req.method} ${req.url} took ${duration.toFixed(2)}ms`);
    }
  });

  next();
}

// Apply to specific route
app.get('/api/complex', performanceMonitor, (req, res) => {
  // Complex processing logic
});

Error Tracking and Log Correlation

When errors occur, it's essential to correlate error information with requests. Extend the error-handling middleware:

app.use((err, req, res, next) => {
  const requestId = req.headers['x-request-id'] || require('crypto').randomBytes(8).toString('hex');
  
  logger.error({
    requestId,
    method: req.method,
    url: req.url,
    error: err.stack,
    user: req.user ? req.user.id : 'anonymous'
  });

  res.status(500).json({
    error: 'Internal Server Error',
    requestId
  });
});

Log Analysis and Visualization

After collecting logs, the ELK stack (Elasticsearch, Logstash, Kibana) can be used for analysis:

1. Use Filebeat to collect logs
2. Process log data with Logstash
3. Store logs in Elasticsearch
4. Visualize with Kibana

Configuration example (filebeat.yml):

filebeat.inputs:
- type: log
  paths:
    - /var/log/node-app/*.log

output.logstash:
  hosts: ["logstash:5044"]

Real-Time Monitoring and Alerts

For critical metrics, set up real-time alerts using Prometheus and Grafana:

1. Collect metrics with express-prom-bundle
2. Store time-series data in Prometheus
3. Display dashboards with Grafana

const promBundle = require("express-prom-bundle");
const metricsMiddleware = promBundle({
  includeMethod: true,
  includePath: true,
  customLabels: { project: 'my-app' }
});

app.use(metricsMiddleware);

Log Security Considerations

Logging requires attention to security:

1. Avoid logging sensitive information (passwords, tokens, etc.)
2. Sanitize user data
3. Set appropriate log access permissions

function sanitizeData(data) {
  if (typeof data !== 'object') return data;
  
  const sensitiveKeys = ['password', 'creditCard', 'token'];
  const sanitized = {...data};
  
  sensitiveKeys.forEach(key => {
    if (sanitized[key]) {
      sanitized[key] = '******';
    }
  });
  
  return sanitized;
}

// Usage example
logger.info('User login', {
  user: req.body.username,
  ...sanitizeData(req.body)
});

Distributed System Log Tracing

In microservice architectures, requests must be traced across services. Use OpenTelemetry:

const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node');
const { SimpleSpanProcessor } = require('@opentelemetry/sdk-trace-base');
const { JaegerExporter } = require('@opentelemetry/exporter-jaeger');

const provider = new NodeTracerProvider();
provider.addSpanProcessor(
  new SimpleSpanProcessor(
    new JaegerExporter({
      serviceName: 'express-app'
    })
  )
);
provider.register();

Log Handling in Container Environments

Log handling differs in Docker or Kubernetes environments:

1. Output logs to stdout/stderr
2. Use Fluentd or Fluent Bit to collect logs
3. Configure appropriate log drivers

FROM node:14

# Create non-root user
RUN useradd -m appuser
USER appuser

WORKDIR /app

COPY package*.json ./
RUN npm install

COPY . .

CMD ["node", "server.js"]

Performance Optimization Tips

Logging itself can impact performance, so consider:

1. Avoid synchronous log writes
2. Reduce debug logs in production
3. Use batch writes instead of frequent I/O

// Batch write example
const logQueue = [];
let isWriting = false;

async function batchWriteLogs() {
  if (isWriting || logQueue.length === 0) return;
  
  isWriting = true;
  const logsToWrite = [...logQueue];
  logQueue.length = 0;
  
  try {
    await writeToDatabase(logsToWrite);
  } catch (err) {
    console.error('Log write failed', err);
    // Re-add failed logs to the queue
    logQueue.unshift(...logsToWrite);
  } finally {
    isWriting = false;
    if (logQueue.length > 0) {
      setImmediate(batchWriteLogs);
    }
  }
}

function logToQueue(message) {
  logQueue.push(message);
  if (logQueue.length >= 100) {
    batchWriteLogs();
  }
}

Log Sampling Strategies

High-traffic applications require log sampling to avoid storage overload:

function shouldSample(req) {
  // Always log important requests
  if (req.url.startsWith('/api/payment')) return true;
  
  // Always log error requests
  if (res.statusCode >= 500) return true;
  
  // Sample 10% of other requests
  return Math.random() < 0.1;
}

app.use((req, res, next) => {
  if (shouldSample(req)) {
    logger.info(`${req.method} ${req.url}`);
  }
  next();
});

Context-Enhanced Logging

Adding more context to logs aids debugging:

const cls = require('cls-hooked');
const namespace = cls.createNamespace('app');

function contextLogger(req, res, next) {
  namespace.run(() => {
    namespace.set('requestId', req.headers['x-request-id'] || require('crypto').randomBytes(8).toString('hex'));
    namespace.set('userId', req.user?.id || 'anonymous');
    next();
  });
}

function logWithContext(message) {
  const requestId = namespace.get('requestId');
  const userId = namespace.get('userId');
  logger.info(`${requestId} [${userId}] ${message}`);
}