Enhance request logging

README.md

@@ -420,6 +420,7 @@ The metadata for Open Graph is only set up for the home page (`home.pug`). Updat
 
 | Name                             | Description                                                          |
 | -------------------------------- | -------------------------------------------------------------------- |
+| **config**/morgan.js             | Configuration for request logging with morgan.                       |
 | **config**/nodemailer.js         | Configuration and helper function for sending email with nodemailer. |
 | **config**/passport.js           | Passport Local and OAuth strategies, plus login middleware.          |
 | **controllers**/api.js           | Controller for /api route and all api examples.                      |
@@ -474,6 +475,7 @@ Required to run the project before your modifications
 | @popperjs/core                | Frontend js library for poppers and tooltips.                         |
 | bootstrap                     | CSS Framework.                                                        |
 | bootstrap-social              | Social buttons library.                                               |
+| bowser                        | User agent parser                                                     |
 | chart.js                      | Frontend js library for creating charts.                              |
 | cheerio                       | Scrape web pages using jQuery-style syntax.                           |
 | compression                   | Node.js compression middleware.                                       |

app.js

@@ -5,7 +5,6 @@ const path = require('path');
 const express = require('express');
 const compression = require('compression');
 const session = require('express-session');
-const logger = require('morgan');
 const errorHandler = require('errorhandler');
 const lusca = require('lusca');
 const dotenv = require('dotenv');
@@ -53,6 +52,11 @@ const contactController = require('./controllers/contact');
  */
 const passportConfig = require('./config/passport');
 
+/**
+ * Request logging configuration
+ */
+const { morganLogger } = require('./config/morgan');
+
 /**
  * Create Express server.
  */
@@ -77,8 +81,8 @@ app.set('port', process.env.PORT || process.env.OPENSHIFT_NODEJS_PORT || 8080);
 app.set('views', path.join(__dirname, 'views'));
 app.set('view engine', 'pug');
 app.set('trust proxy', numberOfProxies);
+app.use(morganLogger());
 app.use(compression());
-app.use(logger('dev'));
 app.use(express.json());
 app.use(express.urlencoded({ extended: true }));
 app.use(limiter);

config/morgan.js

@@ -0,0 +1,134 @@
+const logger = require('morgan');
+const Bowser = require('bowser');
+
+// Color definitions for console output
+const colors = {
+  red: '\x1b[31m',
+  green: '\x1b[32m',
+  yellow: '\x1b[33m',
+  cyan: '\x1b[36m',
+  reset: '\x1b[0m',
+};
+
+// Custom colored status token
+logger.token('colored-status', (req, res) => {
+  const status = res.statusCode;
+  let color;
+  if (status >= 500) color = colors.red;
+  else if (status >= 400) color = colors.yellow;
+  else if (status >= 300) color = colors.cyan;
+  else color = colors.green;
+
+  return color + status + colors.reset;
+});
+
+// Custom token for timestamp without timezone offset
+logger.token('short-date', () => {
+  const now = new Date();
+  return now.toLocaleString('sv').replace(',', '');
+});
+
+// Custom token for simplified user agent using Bowser
+logger.token('parsed-user-agent', (req) => {
+  const userAgent = req.headers['user-agent'];
+  if (!userAgent) return 'Unknown';
+  const parsedUA = Bowser.parse(userAgent);
+  const osName = parsedUA.os.name || 'Unknown';
+  const browserName = parsedUA.browser.name || 'Unknown';
+
+  // Get major version number
+  const version = parsedUA.browser.version || '';
+  const majorVersion = version.split('.')[0];
+
+  return `${osName}/${browserName} v${majorVersion}`;
+});
+
+// Track bytes actually sent
+logger.token('bytes-sent', (req, res) => {
+  // Check for original uncompressed size first
+  let length =
+    res.getHeader('X-Original-Content-Length') || // Some compression middlewares add this
+    res.get('x-content-length') || // Alternative header
+    res.getHeader('Content-Length');
+
+  // For static files
+  if (!length && res.locals && res.locals.stat) {
+    length = res.locals.stat.size;
+  }
+
+  // For response bodies (API responses)
+  if (!length && res._contentLength) {
+    length = res._contentLength;
+  }
+
+  // If we found a length, format it
+  if (length && Number.isNaN(Number(length)) === false) {
+    return `${(parseInt(length, 10) / 1024).toFixed(2)}KB`;
+  }
+
+  // For chunked responses
+  const transferEncoding = res.getHeader('Transfer-Encoding');
+  if (transferEncoding === 'chunked') {
+    return 'chunked';
+  }
+
+  return '-';
+});
+
+// Track partial response info
+logger.token('transfer-state', (req, res) => {
+  if (!res._header) return 'NO_RESPONSE';
+  if (res.finished) return 'COMPLETE';
+  return 'PARTIAL';
+});
+
+// Define the custom request log format
+// In development/test environments, include the full IP address in the logs to facilitate debugging,
+// especially when collaborating with other developers testing the running instance.
+// In production, omit the IP address to reduce the risk of leaking sensitive information and to support
+// compliance with GDPR and other privacy regulations.
+// Also using a function so we can test it in our unit tests.
+const getMorganFormat = () =>
+  process.env.NODE_ENV === 'production' ? ':short-date :method :url :colored-status :response-time[0]ms :bytes-sent :transfer-state - :parsed-user-agent' : ':short-date :method :url :colored-status :response-time[0]ms :bytes-sent :transfer-state :remote-addr :parsed-user-agent';
+
+// Set the format once at initialization for the actual middleware so we don't have to evaluate on each call
+const morganFormat = getMorganFormat();
+
+// Create a middleware to capture original content length
+const captureContentLength = (req, res, next) => {
+  const originalWrite = res.write;
+  const originalEnd = res.end;
+  let length = 0;
+
+  res.write = (...args) => {
+    const [chunk] = args;
+    if (chunk) {
+      length += chunk.length;
+    }
+    return originalWrite.apply(res, args);
+  };
+
+  res.end = (...args) => {
+    const [chunk] = args;
+    if (chunk) {
+      length += chunk.length;
+    }
+    if (length > 0) {
+      res._contentLength = length;
+    }
+    return originalEnd.apply(res, args);
+  };
+
+  next();
+};
+
+exports.morganLogger = () => (req, res, next) => {
+  captureContentLength(req, res, () => {
+    logger(morganFormat, {
+      immediate: false,
+    })(req, res, next);
+  });
+};
+
+// Expose for testing
+exports._getMorganFormat = getMorganFormat;

package.json

@@ -32,6 +32,7 @@
     "@popperjs/core": "^2.11.8",
     "bootstrap": "^5.3.5",
     "bootstrap-social": "github:SeattleDevs/bootstrap-social",
+    "bowser": "^2.11.0",
     "chart.js": "^4.4.8",
     "cheerio": "^1.0.0",
     "compression": "^1.8.0",
@@ -51,7 +52,7 @@
     "mongoose": "^8.13.2",
     "morgan": "^1.10.0",
     "multer": "^1.4.5-lts.1",
-    "nodemailer": "^6.10.0",
+    "nodemailer": "^6.10.1",
     "oauth": "^0.10.2",
     "passport": "^0.7.0",
     "passport-facebook": "^3.0.0",

test/morgan.js

@@ -0,0 +1,135 @@
+const morgan = require('morgan');
+const { expect } = require('chai');
+const sinon = require('sinon');
+
+// Import the morgan configuration to ensure tokens are registered
+const { _getMorganFormat } = require('../config/morgan');
+
+describe('Morgan Configuration Tests', () => {
+  let req;
+  let res;
+  let clock;
+  const originalEnv = process.env.NODE_ENV;
+
+  beforeEach(() => {
+    // Mock request
+    req = {
+      method: 'GET',
+      url: '/test',
+      headers: {
+        'user-agent': 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36',
+        'remote-addr': '127.0.0.1',
+      },
+      ip: '127.0.0.1',
+    };
+
+    // Enhanced mock response
+    res = {
+      statusCode: 200,
+      _header: true, // Set to true to indicate headers sent
+      finished: true, // Set to true to indicate response complete
+      _headers: {}, // for storing headers
+      getHeader(name) {
+        return this._headers[name.toLowerCase()];
+      },
+      get(name) {
+        return this.getHeader(name);
+      },
+      setHeader(name, value) {
+        this._headers[name.toLowerCase()] = value;
+      },
+    };
+
+    // Fix the date for consistent testing
+    clock = sinon.useFakeTimers(new Date('2024-01-01T12:00:00').getTime());
+  });
+
+  afterEach(() => {
+    clock.restore();
+    sinon.restore();
+    process.env.NODE_ENV = originalEnv;
+  });
+
+  describe('Custom Token: colored-status', () => {
+    it('should color status codes correctly', () => {
+      const testCases = [
+        { status: 200, color: '\x1b[32m' }, // green
+        { status: 304, color: '\x1b[36m' }, // cyan
+        { status: 404, color: '\x1b[33m' }, // yellow
+        { status: 500, color: '\x1b[31m' }, // red
+      ];
+
+      testCases.forEach(({ status, color }) => {
+        res.statusCode = status;
+        const formatter = morgan.compile(':colored-status');
+        const output = formatter(morgan, req, res);
+        expect(output).to.equal(`${color}${status}\x1b[0m`);
+      });
+    });
+  });
+
+  describe('Custom Token: short-date', () => {
+    it('should format date correctly', () => {
+      const formatter = morgan.compile(':short-date');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('2024-01-01 12:00:00');
+    });
+  });
+
+  describe('Custom Token: parsed-user-agent', () => {
+    it('should parse user agent correctly', () => {
+      const formatter = morgan.compile(':parsed-user-agent');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('Windows/Chrome v120');
+    });
+
+    it('should handle unknown user agent', () => {
+      req.headers['user-agent'] = undefined;
+      const formatter = morgan.compile(':parsed-user-agent');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('Unknown');
+    });
+  });
+
+  describe('Custom Token: bytes-sent', () => {
+    it('should format bytes correctly', () => {
+      res.setHeader('Content-Length', '2048');
+      const formatter = morgan.compile(':bytes-sent');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('2.00KB');
+    });
+
+    it('should handle missing content length', () => {
+      const formatter = morgan.compile(':bytes-sent');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('-');
+    });
+  });
+
+  describe('Custom Token: transfer-state', () => {
+    it('should show correct transfer state', () => {
+      const formatter = morgan.compile(':transfer-state');
+      const output = formatter(morgan, req, res);
+      expect(output).to.equal('COMPLETE');
+    });
+  });
+
+  describe('Complete Morgan Format', () => {
+    // const { _getMorganFormat } = require('../config/morgan');
+
+    it('should combine all tokens correctly in development', () => {
+      process.env.NODE_ENV = 'development';
+      const formatter = morgan.compile(_getMorganFormat());
+      const output = formatter(morgan, req, res);
+      expect(output).to.include('127.0.0.1'); // Should include IP in development
+    });
+
+    it('should exclude IP address in production', () => {
+      process.env.NODE_ENV = 'production';
+      const formatter = morgan.compile(_getMorganFormat());
+      const output = formatter(morgan, req, res);
+      expect(output).to.not.include('127.0.0.1'); // Should not include IP
+      expect(output).to.include(' - '); // Should have hyphen instead
+    });
+  });
+});