express-logging - npm Package Compare versions

Comparing version 1.0.0 to 1.1.0

lib/logging.js

@@ -27,6 +27,15 @@ /**
  *    Logger.
+ * @param {Object} opts
+ *    Object with optional arguments including:
+ *      - blacklist: Array of URL paths to be ignored (e.g. paths for static content)
+ *      - policy: Policy to generate the log entry in the logger. Possible values:
+ *          - message. Only message. Params are included into the message.
+ *          - params. Logger receives an object with the params, and the message.
  * @return {Function(req, res, next)} Express middleware.
  */
-module.exports = function(logger) {
+module.exports = function(logger, opts) {
 
+  var blacklist = opts && opts.blacklist || [];
+  var policy = opts && opts.policy;
+
   /**
@@ -56,15 +65,48 @@ * Return the client address from the last IP address in X-Forwarded-For HTTP header. If not possible to
 
+  /**
+   * Check if the request URL starts with any of the blacklist paths.
+   *
+   * @param {String} url
+   *    Request url
+   * @return {Boolean}
+   *    True if the request URL is included in the blacklist.
+   */
+  function isUrlBlackedListed(url) {
+    return blacklist.some(url.startsWith.bind(url));
+  }
+
   return function loggingMiddleware(req, res, next) {
-    var startTime = new Date();
-    logger.info('Request from %s: %s %s', getClientIp(req), req.method, req.originalUrl);
-
-    onHeaders(res, function onResponse() {
-      var duration = new Date() - startTime;
-      var location = res.get('location');
-      if (location) {
-        logger.info('Response with status %d in %d ms. Location: %s', res.statusCode, duration, location);
+    if (!isUrlBlackedListed(req.originalUrl)) {
+      var startTime = Date.now();
+      if (policy === 'params') {
+        var requestParams = {
+          requestClientIp: getClientIp(req),
+          requestMethod: req.method,
+          requestUrl: req.originalUrl
+        };
+        logger.info(requestParams, 'Request: %s %s', req.method, req.originalUrl);
       } else {
-        logger.info('Response with status %d in %d ms.', res.statusCode, duration);
+        logger.info('Request from %s: %s %s', getClientIp(req), req.method, req.originalUrl);
       }
-    });
+
+      onHeaders(res, function onResponse() {
+        var duration = Date.now() - startTime;
+        var location = res.get('location');
+        if (policy === 'params') {
+          var responseParams = {
+            responseStatusCode: res.statusCode,
+            responseDuration: duration,
+            responseLocation: location
+          };
+          logger.info(responseParams, 'Response with status %d', res.statusCode);
+        } else {
+          if (location) {
+            logger.info('Response with status %d in %d ms. Location: %s', res.statusCode, duration, location);
+          } else {
+            logger.info('Response with status %d in %d ms.', res.statusCode, duration);
+          }
+        }
+      });
+    }
+
     next();
@@ -71,0 +113,0 @@ };

package.json

 {
   "name": "express-logging",
   "description": "Express middleware to log each request and response",
-  "version": "1.0.0",
+  "version": "1.1.0",
   "license": "Apache-2.0",
@@ -44,3 +44,2 @@ "author": {
   "dependencies": {
-    "node-uuid": "^1.4.2",
     "on-headers": "^1.0.0"
@@ -47,0 +46,0 @@ },

README.md

@@ -28,4 +28,20 @@ # express-logging
 
+## Extended usage with options
+
+An optional argument `options` can customize enhanced aspects for the logging. This argument is an object with the following elements:
+
+ - `blacklist` is available to prevent some resources from being logged (for example, static resources). This argument is an array of strings. If the URL path starts with any of the elements of the blacklist array, then the logging of this request/response is ignored.
+ - `policy` is a string to customize how the info is logged. It supports two values: `message` or `params`. The former serializes all the log entry into a single string message. The latter passes to the logger an object with the log entry parameters and a second argument with the message; this policy is useful in order to process these parameters by systems like logstash. The default value is `message`.
+
+The following example would ignore any resource available at either `/images` or `/html`. It also activates the logging policy `params`.
+
+```js
+var blacklist = ['/images', '/html'];
+app.use(expressLogging(logger, {blacklist: blacklist, policy: 'params'}));
+```
+
 ## Logs
 
+### Logging with default policy **message**
+
 The request is logged with:
@@ -51,5 +67,30 @@
 
+### Logging with policy **params**
+
+The request is logged with:
+
+```js
+var params = {requestClientIp: requestClientIp, requestMethod: requestMethod, requestUrl: requestUrl};
+logger.info(params, 'Request from %s: %s', requestMethod, requestUrl);
+```
+
+A response without `Location` header is logged with:
+
+```js
+var params = {responseStatusCode: responseStatusCode, responseDuration: duration};
+logger.info(params, 'Response with status %d', responseStatusCode);
+```
+
+A response with `Location` header is logged with:
+
+```js
+var params = {responseStatusCode: responseStatusCode, responseDuration: duration, responseLocation: locationHeader};
+logger.info(params, 'Response with status %d', responseStatusCode);
+```
+
+Both response log entries include the `duration` of the whole transaction (between receiving the request until replying with the response).
+
 ## License
 
-Copyright 2015 [Telefónica Investigación y Desarrollo, S.A.U](http://www.tid.es)
+Copyright 2015, 2016 [Telefónica Investigación y Desarrollo, S.A.U](http://www.tid.es)
 
@@ -56,0 +97,0 @@ Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at

test/unit/logging-test.js

@@ -153,1 +153,248 @@ 'use strict';
 });
+
+describe('Logging Middleware Tests with params policy', function() {
+
+  var loggingMiddleware,
+      loggerSpy;
+
+  beforeEach(function() {
+    var loggerMock = {
+      info: function() {}
+    };
+    loggerSpy = sinon.spy(loggerMock, 'info');
+
+    var onHeadersMock = function(res, cb) {
+      cb();
+    };
+
+    var LoggingMiddleware = proxyquire('../../lib/logging', {
+      'on-headers': onHeadersMock
+    });
+    loggingMiddleware = new LoggingMiddleware(loggerMock, {policy: 'params'});
+  });
+
+  it('should log the request and response', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/test?jwt=xxx',
+      get: function() {
+        return null;
+      }
+    };
+    var res = {
+      statusCode: 200,
+      get: function() {
+        return null;
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.calledTwice).to.be.true;
+      expect(loggerSpy.getCall(0).args).to.be.deep.equal([
+        {
+          requestClientIp: '10.128.201.134',
+          requestMethod: 'GET',
+          requestUrl: '/test?jwt=xxx'
+        },
+        'Request: %s %s',
+        'GET',
+        '/test?jwt=xxx'
+      ]);
+      expect(loggerSpy.getCall(1).args[0].responseStatusCode).to.be.equal(200);
+      expect(loggerSpy.getCall(1).args[0].responseLocation).not.to.be.defined;
+      expect(loggerSpy.getCall(1).args[1]).to.be.equal('Response with status %d');
+      expect(loggerSpy.getCall(1).args[2]).to.be.equal(200);
+    });
+  });
+
+  it('should log the request and response with location header', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/test?jwt=xxx',
+      get: function() {
+        return null;
+      }
+    };
+    var res = {
+      statusCode: 302,
+      get: function(headerName) {
+        if (headerName === 'location') {
+          return 'http://localhost:9000/location';
+        } else {
+          return null;
+        }
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.calledTwice).to.be.true;
+      expect(loggerSpy.getCall(0).args).to.be.deep.equal([
+        {
+          requestClientIp: '10.128.201.134',
+          requestMethod: 'GET',
+          requestUrl: '/test?jwt=xxx'
+        },
+        'Request: %s %s',
+        'GET',
+        '/test?jwt=xxx'
+      ]);
+      expect(loggerSpy.getCall(1).args[0].responseStatusCode).to.be.equal(302);
+      expect(loggerSpy.getCall(1).args[0].responseLocation).to.be.equal('http://localhost:9000/location');
+      expect(loggerSpy.getCall(1).args[1]).to.be.equal('Response with status %d');
+      expect(loggerSpy.getCall(1).args[2]).to.be.equal(302);
+    });
+  });
+
+  it('should log the request and response with client IP from XFF header', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/test?jwt=xxx',
+      get: function(name) {
+        if (name === 'x-forwarded-for') {
+          return '1.1.1.1, 10.128.201.200';
+        } else {
+          return null;
+        }
+      }
+    };
+    var res = {
+      statusCode: 200,
+      get: function() {
+        return null;
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.calledTwice).to.be.true;
+      expect(loggerSpy.getCall(0).args).to.be.deep.equal([
+        {
+          requestClientIp: '10.128.201.200',
+          requestMethod: 'GET',
+          requestUrl: '/test?jwt=xxx'
+        },
+        'Request: %s %s',
+        'GET',
+        '/test?jwt=xxx'
+      ]);
+      expect(loggerSpy.getCall(1).args[0].responseStatusCode).to.be.equal(200);
+      expect(loggerSpy.getCall(1).args[0].responseLocation).not.to.be.defined;
+      expect(loggerSpy.getCall(1).args[1]).to.be.equal('Response with status %d');
+      expect(loggerSpy.getCall(1).args[2]).to.be.equal(200);
+    });
+  });
+
+  it('should log the request and response with client IP from request if invalid XFF header', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/test?jwt=xxx',
+      get: function(name) {
+        if (name === 'x-forwarded-for') {
+          return '1.1.1.1, 10.128.201.200, ';
+        } else {
+          return null;
+        }
+      }
+    };
+    var res = {
+      statusCode: 200,
+      get: function() {
+        return null;
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.calledTwice).to.be.true;
+      expect(loggerSpy.getCall(0).args).to.be.deep.equal([
+        {
+          requestClientIp: '10.128.201.134',
+          requestMethod: 'GET',
+          requestUrl: '/test?jwt=xxx'
+        },
+        'Request: %s %s',
+        'GET',
+        '/test?jwt=xxx'
+      ]);
+      expect(loggerSpy.getCall(1).args[0].responseStatusCode).to.be.equal(200);
+      expect(loggerSpy.getCall(1).args[0].responseLocation).not.to.be.defined;
+      expect(loggerSpy.getCall(1).args[1]).to.be.equal('Response with status %d');
+      expect(loggerSpy.getCall(1).args[2]).to.be.equal(200);
+    });
+  });
+
+});
+
+describe('Logging Middleware Tests with blacklist', function() {
+
+  var loggingMiddleware,
+      loggerSpy;
+
+  beforeEach(function() {
+    var loggerMock = {
+      info: function() {}
+    };
+    loggerSpy = sinon.spy(loggerMock, 'info');
+
+    var onHeadersMock = function(res, cb) {
+      cb();
+    };
+
+    var LoggingMiddleware = proxyquire('../../lib/logging', {
+      'on-headers': onHeadersMock
+    });
+    loggingMiddleware = new LoggingMiddleware(loggerMock, {blacklist: ['/blacklist']});
+  });
+
+  it('should log the request and response', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/test?jwt=xxx',
+      get: function() {
+        return null;
+      }
+    };
+    var res = {
+      statusCode: 200,
+      get: function() {
+        return null;
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.calledTwice).to.be.true;
+      expect(loggerSpy.getCall(0).args).to.be.deep.equal([
+        'Request from %s: %s %s',
+        '10.128.201.134',
+        'GET',
+        '/test?jwt=xxx']);
+      expect(loggerSpy.getCall(1).args[0]).to.be.equal('Response with status %d in %d ms.');
+      expect(loggerSpy.getCall(1).args[1]).to.be.equal(200);
+    });
+  });
+
+  it('should not log anything when the url path is in the blacklist', function() {
+    var req = {
+      method: 'GET',
+      ip: '10.128.201.134',
+      originalUrl: '/blacklist/test?jwt=xxx',
+      get: function() {
+        return null;
+      }
+    };
+    var res = {
+      statusCode: 200,
+      get: function() {
+        return null;
+      }
+    };
+
+    loggingMiddleware(req, res, function() {
+      expect(loggerSpy.called).to.be.false;
+    });
+  });
+
+});

New alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Fixed alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Improved metrics

Total package byte prevSize

31864

increased by47.08%

Dependency count

1

decreased by-50%

Lines of code

474

increased by123.58%

Number of lines in readme file

100

increased by69.49%

Dependency changes

• - Removednode-uuid@^1.4.2

• - Removednode-uuid@1.4.8(transitive)