From 9e12c650d0540f3ea901f3f54eda9ebbc64bcf00 Mon Sep 17 00:00:00 2001 From: Julian Simioni Date: Thu, 31 Mar 2016 18:34:04 -0400 Subject: [PATCH 1/4] Add logging helper module This module has helper methods for logging. Currently it has methods to: * detect if DNT is enabled * remove sensitive information from input fields for logging --- helper/logging.js | 24 ++++++++++ test/unit/helper/logging.js | 96 +++++++++++++++++++++++++++++++++++++ test/unit/run.js | 1 + 3 files changed, 121 insertions(+) create mode 100644 helper/logging.js create mode 100644 test/unit/helper/logging.js diff --git a/helper/logging.js b/helper/logging.js new file mode 100644 index 00000000..e514ebff --- /dev/null +++ b/helper/logging.js @@ -0,0 +1,24 @@ +var fieldsToRemove = ['text', 'focus.point.lat', 'focus.point.lon', + 'boundary.circle.lat', 'boundary.circle.lon', 'point.lat', 'point.lon']; + +function isDNT(req) { + if (!req.headers) { + return false; + } + return req.headers.DNT || req.headers.dnt || req.headers.do_not_track; +} + +function removeFields(query) { + fieldsToRemove.forEach(function(field) { + if (query[field]) { + query[field] = '[removed]'; + } + }); + + return query; +} + +module.exports = { + isDNT: isDNT, + removeFields: removeFields +}; diff --git a/test/unit/helper/logging.js b/test/unit/helper/logging.js new file mode 100644 index 00000000..90fbfb55 --- /dev/null +++ b/test/unit/helper/logging.js @@ -0,0 +1,96 @@ +var logging = require('../../../helper/logging'); + +module.exports.tests = {}; + +module.exports.tests.dnt = function(test) { + test('DNT=1 triggers DNT detection', function(t) { + var req = { + headers: { + DNT: '1' + } + }; + + t.ok(logging.isDNT(req), 'DNT detected'); + t.end(); + }); + + test('DNT=0 triggers DNT detection', function(t) { + // because this is common apparently, although the spec says to do the opposite + // see https://en.wikipedia.org/wiki/Do_Not_Track + var req = { + headers: { + DNT: '0' + } + }; + + t.ok(logging.isDNT(req), 'DNT detected'); + t.end(); + }); + + test('do_not_track header triggers DNT detection', function(t) { + // according to @riordan, some people use this too + var req = { + headers: { + do_not_track: '1' + } + }; + + t.ok(logging.isDNT(req), 'DNT detected'); + t.end(); + }); + + test('no DNT or do_not_track header does not trigger DNT detection', function(t) { + var req = { + headers: { + 'Accept-Charset': 'utf-8' + } + }; + + t.notOk(logging.isDNT(req), 'DNT detected'); + t.end(); + }); +}; + +module.exports.tests.field_removal = function(test) { + test('removes multiple fields that may have sensitive information', function(t) { + var query = { + text: 'possibly sensitive text', + 'point.lat': 'possibly sensitive location info' + }; + + var cleaned_query = logging.removeFields(query); + + var expected = { + text: '[removed]', + 'point.lat': '[removed]' + }; + + t.deepEquals(cleaned_query, expected, 'multiple sensitive fields removed'); + t.end(); + }); + + test('non-sensitive fields untouched', function(t) { + var query = { + sources: 'wof,gn' + }; + + var cleaned_query = logging.removeFields(query); + + var expected = { + sources: 'wof,gn' + }; + + t.deepEquals(cleaned_query, expected, 'non-sensitive fields are not touched'); + t.end(); + }); +}; + +module.exports.all = function (tape, common) { + function test(name, testFunction) { + return tape('logging: ' + name, testFunction); + } + + for( var testCase in module.exports.tests ){ + module.exports.tests[testCase](test, common); + } +}; diff --git a/test/unit/run.js b/test/unit/run.js index 828d99b5..2debcdcc 100644 --- a/test/unit/run.js +++ b/test/unit/run.js @@ -19,6 +19,7 @@ var tests = [ require('./helper/labelGenerator_GBR'), require('./helper/labelGenerator_USA'), require('./helper/labelSchema'), + require('./helper/logging'), require('./helper/type_mapping'), require('./helper/sizeCalculator'), require('./middleware/confidenceScore'), From ecb28bc3e90160b34833d4673d555060ef52f0fe Mon Sep 17 00:00:00 2001 From: Julian Simioni Date: Thu, 17 Mar 2016 16:49:11 -0400 Subject: [PATCH 2/4] Remove debug statements that print user parameters --- middleware/confidenceScore.js | 4 ---- 1 file changed, 4 deletions(-) diff --git a/middleware/confidenceScore.js b/middleware/confidenceScore.js index df48b2b1..39ea45b2 100644 --- a/middleware/confidenceScore.js +++ b/middleware/confidenceScore.js @@ -77,8 +77,6 @@ function computeConfidenceScore(req, mean, stdev, hit) { hit.confidence /= checkCount; hit.confidence = Number((hit.confidence).toFixed(3)); - logger.debug('[confidence]:', hit.confidence, hit.name.default); - return hit; } @@ -102,8 +100,6 @@ function checkForDealBreakers(req, hit) { if (check.assigned(req.clean.parsed_text.postalcode) && check.assigned(hit.address_parts) && req.clean.parsed_text.postalcode !== hit.address_parts.zip) { - logger.debug('[confidence][deal-breaker]: postalcode !== zip (' + req.clean.parsed_text.postalcode + - ' !== ' + hit.address_parts.zip + ')'); return true; } } From 57d1c8be1e98921aec9e358c5dfa1dc1432f728b Mon Sep 17 00:00:00 2001 From: Julian Simioni Date: Wed, 30 Mar 2016 17:51:31 -0400 Subject: [PATCH 3/4] Return an object from access_log module This allows adding more methods later. --- app.js | 2 +- middleware/access_log.js | 4 +++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/app.js b/app.js index d05e0365..25573573 100644 --- a/app.js +++ b/app.js @@ -5,7 +5,7 @@ var peliasConfig = require( 'pelias-config' ).generate().api; if( peliasConfig.accessLog ){ - app.use( require( './middleware/access_log' )( peliasConfig.accessLog ) ); + app.use( require( './middleware/access_log' ).createAccessLogger( peliasConfig.accessLog ) ); } /** ----------------------- pre-processing-middleware ----------------------- **/ diff --git a/middleware/access_log.js b/middleware/access_log.js index 812a8849..62d99767 100644 --- a/middleware/access_log.js +++ b/middleware/access_log.js @@ -17,4 +17,6 @@ function createAccessLogger( logFormat ){ }); } -module.exports = createAccessLogger; +module.exports = { + createAccessLogger: createAccessLogger +}; From 23ff51fd57dee34ae16744c500ff651d3f1d59d3 Mon Sep 17 00:00:00 2001 From: Julian Simioni Date: Thu, 17 Mar 2016 16:48:23 -0400 Subject: [PATCH 4/4] 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 | 7 ++- middleware/access_log.js | 38 ++++++++++++++ test/unit/middleware/access_log.js | 83 ++++++++++++++++++++++++++++++ test/unit/run.js | 1 + 4 files changed, 128 insertions(+), 1 deletion(-) create mode 100644 test/unit/middleware/access_log.js diff --git a/controller/search.js b/controller/search.js index e2a8acff..7f7ffb68 100644 --- a/controller/search.js +++ b/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 = { diff --git a/middleware/access_log.js b/middleware/access_log.js index 62d99767..d87a2e32 100644 --- a/middleware/access_log.js +++ b/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 }; diff --git a/test/unit/middleware/access_log.js b/test/unit/middleware/access_log.js new file mode 100644 index 00000000..b2926a2d --- /dev/null +++ b/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); + } +}; diff --git a/test/unit/run.js b/test/unit/run.js index 2debcdcc..62516bc9 100644 --- a/test/unit/run.js +++ b/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'),