Add custom access_log handlers that remove user info

These handlers will remove sensitive query info from the logs when DNT
is enabled

controller/search.js

@@ -2,6 +2,7 @@ var _ = require('lodash');
 
 var service = { search: require('../service/search') };
 var logger = require('pelias-logger').get('api:controller:search');
+var logging = require( '../helper/logging' );
 
 function setup( backend, query ){
 
@@ -16,8 +17,12 @@ function setup( backend, query ){
       return next();
     }
 
+    var cleanOutput = _.cloneDeep(req.clean);
+    if (logging.isDNT(req)) {
+      cleanOutput = logging.removeFields(cleanOutput);
+    }
     // log clean parameters for stats
-    logger.info('[req]', 'endpoint=' + req.path, req.clean);
+    logger.info('[req]', 'endpoint=' + req.path, cleanOutput);
 
     // backend command
     var cmd = {

middleware/access_log.js

@@ -4,11 +4,47 @@
 
 'use strict';
 
+var url = require( 'url' );
+
+var _ = require( 'lodash' );
 var morgan = require( 'morgan' );
 var through = require( 'through2' );
+
 var peliasLogger = require( 'pelias-logger' ).get( 'api' );
+var logging = require( '../helper/logging' );
+
+function customRemoteAddr(req, res) {
+  if (logging.isDNT(req)) {
+    return '[IP removed]';
+  } else {
+    // from morgan default implementation
+    return req.ip ||
+      req._remoteAddress ||
+      (req.connection && req.connection.remoteAddress) ||
+      undefined;
+  }
+}
+
+function customURL(req, res) {
+  var parsedUrl = _.cloneDeep(req._parsedUrl);
+  parsedUrl.query = _.cloneDeep(req.query);
+
+  if (logging.isDNT(req)) {
+    // strip out sensitive fields in the query object
+    parsedUrl.query = logging.removeFields(parsedUrl.query);
+
+    // search will override the query object when formatting the url
+    // see https://nodejs.org/api/all.html#all_url_format_urlobj
+    delete parsedUrl.search;
+  }
+
+  return url.format(parsedUrl);
+}
 
 function createAccessLogger( logFormat ){
+  morgan.token('remote-addr', customRemoteAddr);
+  morgan.token('url', customURL);
+
   return morgan( logFormat, {
     stream: through( function write( ln, _, next ){
       peliasLogger.info( ln.toString().trim() );
@@ -18,5 +54,7 @@ function createAccessLogger( logFormat ){
 }
 
 module.exports = {
+  customRemoteAddr: customRemoteAddr,
+  customURL: customURL,
   createAccessLogger: createAccessLogger
 };

test/unit/middleware/access_log.js

@@ -0,0 +1,83 @@
+var access_log = require('../../../middleware/access_log');
+
+module.exports.tests = {};
+
+module.exports.tests.customRemoteAddress = function(test) {
+  test('non-DNT request shows IP in logs', function(t) {
+    var req = {
+      ip: '8.8.8.8',
+      query: '/v1/search?....'
+    };
+
+    var result = access_log.customRemoteAddr(req, {});
+
+    t.equals(result, '8.8.8.8', 'IP would be sent to logs');
+    t.end();
+  });
+
+  test('DNT request does not show IP in logs', function(t) {
+    var req = {
+      ip: '8.8.8.8',
+      query: '/v1/search?....',
+      headers: {
+        DNT: 1
+      }
+    };
+
+    var result = access_log.customRemoteAddr(req, {});
+
+    t.equals(result, '[IP removed]', 'IP removed from logs');
+    t.end();
+  });
+};
+
+module.exports.tests.customURL = function(test) {
+  test('non-DNT request shows full query in logs', function(t) {
+    var req = {
+      ip: '8.8.8.8',
+      query: {
+        text: 'london'
+      },
+      _parsedUrl: {
+        pathname: '/v1/search',
+        path: '/v1/search?text=london'
+      }
+    };
+
+    var result = access_log.customURL(req, {});
+
+    t.equals(result, '/v1/search?text=london', 'query not removed from logs');
+    t.end();
+  });
+
+  test('DNT request removes sensitive fields from logs', function(t) {
+    var req = {
+      ip: '8.8.8.8',
+      query: {
+        text: 'london'
+      },
+      _parsedUrl: {
+        pathname: '/v1/search',
+        path: '/v1/search?text=london'
+      },
+      headers: {
+        DNT: 1
+      }
+    };
+
+    var result = access_log.customURL(req, {});
+
+    t.equals(result, '/v1/search?text=%5Bremoved%5D', 'query has sensitive fields removed');
+    t.end();
+  });
+};
+
+module.exports.all = function (tape, common) {
+  function test(name, testFunction) {
+    return tape('[middleware] access_log: ' + name, testFunction);
+  }
+
+  for( var testCase in module.exports.tests ){
+    module.exports.tests[testCase](test, common);
+  }
+};

test/unit/run.js

@@ -22,6 +22,7 @@ var tests = [
   require('./helper/logging'),
   require('./helper/type_mapping'),
   require('./helper/sizeCalculator'),
+  require('./middleware/access_log'),
   require('./middleware/confidenceScore'),
   require('./middleware/confidenceScoreReverse'),
   require('./middleware/distance'),