diff --git a/controller/place.js b/controller/place.js index 309702cd..becae8fc 100644 --- a/controller/place.js +++ b/controller/place.js @@ -1,16 +1,39 @@ -var service = { mget: require('../service/mget') }; -var logger = require('pelias-logger').get('api'); +'use strict'; + +const _ = require('lodash'); +const retry = require('retry'); + +const mgetService = require('../service/mget'); +const logger = require('pelias-logger').get('api'); function setup( apiConfig, esclient ){ - function controller( req, res, next ){ + function requestHasErrors(request) { + return _.get(request, 'errors', []).length > 0; + } - // do not run controller when a request - // validation error has occurred. - if( req.errors && req.errors.length ){ + function isRequestTimeout(err) { + return _.get(err, 'status') === 408; + } + + function controller( req, res, next ){ + // do not run controller when a request validation error has occurred. + if (requestHasErrors(req)){ return next(); } - var query = req.clean.ids.map( function(id) { + // options for retry + // maxRetries is from the API config with default of 3 + // factor of 1 means that each retry attempt will esclient requestTimeout + const operationOptions = { + retries: _.get(apiConfig, 'requestRetries', 3), + factor: 1, + minTimeout: _.get(esclient, 'transport.requestTimeout') + }; + + // setup a new operation + const operation = retry.operation(operationOptions); + + const query = req.clean.ids.map( function(id) { return { _index: apiConfig.indexName, _type: id.layers, @@ -20,19 +43,36 @@ function setup( apiConfig, esclient ){ logger.debug( '[ES req]', query ); - service.mget( esclient, query, function( err, docs ) { - // error handler - if( err ){ - req.errors.push( err ); - } - // set response data - else { - res.data = docs; - } - logger.debug('[ES response]', docs); - - next(); + operation.attempt((currentAttempt) => { + mgetService( esclient, query, function( err, docs ) { + // returns true if the operation should be attempted again + // (handles bookkeeping of maxRetries) + // only consider for status 408 (request timeout) + if (isRequestTimeout(err) && operation.retry(err)) { + logger.info(`request timed out on attempt ${currentAttempt}, retrying`); + return; + } + + // error handler + if( err ){ + req.errors.push( err ); + } + // set response data + else { + // log that a retry was successful + // most requests succeed on first attempt so this declutters log files + if (currentAttempt > 1) { + logger.info(`succeeded on retry ${currentAttempt-1}`); + } + + res.data = docs; + } + logger.debug('[ES response]', docs); + + next(); + }); }); + } return controller; diff --git a/test/unit/controller/place.js b/test/unit/controller/place.js index 216b99f3..5f54ba6d 100644 --- a/test/unit/controller/place.js +++ b/test/unit/controller/place.js @@ -1,129 +1,372 @@ -var setup = require('../../../controller/place'), - mockBackend = require('../mock/backend'); +'use strict'; + +const setup = require('../../../controller/search'); +const proxyquire = require('proxyquire').noCallThru(); module.exports.tests = {}; -module.exports.tests.interface = function(test, common) { - test('valid interface', function(t) { +module.exports.tests.interface = (test, common) => { + test('valid interface', (t) => { t.equal(typeof setup, 'function', 'setup is a function'); t.equal(typeof setup(), 'function', 'setup returns a controller'); t.end(); }); }; -// reminder: this is only the api subsection of the full config -var fakeDefaultConfig = { - indexName: 'pelias' +module.exports.tests.success = (test, common) => { + test('successful request to search service should set data and meta', (t) => { + const config = { + indexName: 'indexName value' + }; + const esclient = 'this is the esclient'; + + // request timeout messages willl be written here + const infoMesssages = []; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, query, callback) => { + t.equal(esclient, 'this is the esclient'); + t.deepEqual(query, [ + { + _index: 'indexName value', + _type: 'layer1', + _id: 'id1' + }, + { + _index: 'indexName value', + _type: 'layer2', + _id: 'id2' + } + ]); + + const docs = [{}, {}]; + + callback(undefined, docs); + } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + }, + { + id: 'id2', + layers: 'layer2' + } + ] + }, + errors: [], + warnings: [] + }; + const res = {}; + + const next = () => { + t.deepEqual(req.errors, []); + t.deepEqual(req.warnings, []); + t.deepEquals(res.data, [{}, {}]); + t.end(); + }; + + controller(req, res, next); + + }); + }; -// functionally test controller (backend success) -module.exports.tests.functional_success = function(test, common) { - - // expected geojson features for 'client/place/ok/1' fixture - var expected = [{ - type: 'Feature', - geometry: { - type: 'Point', - coordinates: [ -50.5, 100.1 ] - }, - properties: { - id: 'myid1', - layer: 'mytype1', - text: 'test name1, city1, state1' - } - }, { - type: 'Feature', - geometry: { - type: 'Point', - coordinates: [ -51.5, 100.2 ] - }, - properties: { - id: 'myid2', - layer: 'mytype2', - text: 'test name2, city2, state2' - } - }]; - - test('functional success', function(t) { - var backend = mockBackend( 'client/mget/ok/1', function( cmd ){ - t.deepEqual(cmd, { body: { docs: [ { _id: 123, _index: 'pelias', _type: [ 'a' ] } ] } }, 'correct backend command'); +module.exports.tests.error_conditions = (test, common) => { + test('non-empty req.errors should ', (t) => { + const esclient = () => { + throw new Error('esclient should not have been called'); + }; + const controller = setup( {}, esclient ); + + // the existence of `errors` means that a sanitizer detected an error, + // so don't call the esclient + const req = { + errors: ['error'] + }; + const res = { }; + + t.doesNotThrow(() => { + controller(req, res, () => {}); }); - var controller = setup( fakeDefaultConfig, backend ); - var res = { - status: function( code ){ - t.equal(code, 200, 'status set'); - return res; + t.end(); + + }); + + test('mgetService returning error should add to req.errors and ignore docs', (t) => { + const config = { + indexName: 'indexName value' + }; + const esclient = 'this is the esclient'; + + // request timeout messages willl be written here + const infoMesssages = []; + + const nonTimeoutError = { + status: 500, + displayName: 'InternalServerError', + message: 'an internal server error occurred' + }; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, query, callback) => { + const docs = [{}, {}]; + + callback(nonTimeoutError, docs); + } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + } + ] }, - json: function( json ){ - t.equal(typeof json, 'object', 'returns json'); - t.equal(typeof json.date, 'number', 'date set'); - t.equal(json.type, 'FeatureCollection', 'valid geojson'); - t.true(Array.isArray(json.features), 'features is array'); - t.deepEqual(json.features, expected, 'values correctly mapped'); + errors: [], + warnings: [] + }; + const res = {}; + + const next = () => { + t.deepEqual(req.errors, [nonTimeoutError]); + t.deepEqual(req.warnings, []); + t.deepEquals(res.data, undefined); + t.end(); + }; + + controller(req, res, next); + + }); + +}; + +module.exports.tests.timeout = function(test, common) { + test('default # of request timeout retries should be 3', (t) => { + const config = { + indexName: 'indexName value' + }; + const esclient = 'this is the esclient'; + + let searchServiceCallCount = 0; + + const timeoutError = { + status: 408, + displayName: 'RequestTimeout', + message: 'Request Timeout after 17ms' + }; + + // request timeout messages willl be written here + const infoMesssages = []; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, cmd, callback) => { + // not that the searchService got called + searchServiceCallCount++; + + callback(timeoutError); + }, + 'pelias-logger': { + get: (service) => { + t.equal(service, 'api'); + return { + info: (msg) => { + infoMesssages.push(msg); + }, + debug: () => {} + }; + } } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + } + ] + }, + errors: [], + warnings: [] }; - var req = { clean: { ids: [ {'id' : 123, layers: [ 'a' ] } ] }, errors: [], warnings: [] }; - var next = function next() { - t.equal(req.errors.length, 0, 'next was called without error'); + const res = {}; + + const next = () => { + t.equal(searchServiceCallCount, 3+1); + + t.ok(infoMesssages.indexOf('request timed out on attempt 1, retrying') !== -1); + t.ok(infoMesssages.indexOf('request timed out on attempt 2, retrying') !== -1); + t.ok(infoMesssages.indexOf('request timed out on attempt 3, retrying') !== -1); + + t.deepEqual(req.errors, [timeoutError]); + t.deepEqual(res, {}); t.end(); }; - controller(req, res, next ); + + controller(req, res, next); + }); - test('functional success with custom index name', function(t) { - var fakeCustomizedConfig = { - indexName: 'alternateindexname' + test('explicit apiConfig.requestRetries should retry that many times', (t) => { + const config = { + indexName: 'indexName value', + requestRetries: 17 }; + const esclient = 'this is the esclient'; - var backend = mockBackend( 'client/mget/ok/1', function( cmd ){ - t.deepEqual(cmd, { body: { docs: [ { _id: 123, _index: 'alternateindexname', _type: [ 'a' ] } ] } }, 'correct backend command'); - }); - var controller = setup( fakeCustomizedConfig, backend ); - var res = { - status: function( code ){ - t.equal(code, 200, 'status set'); - return res; + let searchServiceCallCount = 0; + + const timeoutError = { + status: 408, + displayName: 'RequestTimeout', + message: 'Request Timeout after 17ms' + }; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, cmd, callback) => { + // not that the searchService got called + searchServiceCallCount++; + + callback(timeoutError); + } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + } + ] }, - json: function( json ){ - t.equal(typeof json, 'object', 'returns json'); - t.equal(typeof json.date, 'number', 'date set'); - t.equal(json.type, 'FeatureCollection', 'valid geojson'); - t.true(Array.isArray(json.features), 'features is array'); - t.deepEqual(json.features, expected, 'values correctly mapped'); + errors: [], + warnings: [] + }; + const res = {}; + + const next = () => { + t.equal(searchServiceCallCount, 17+1); + t.end(); + }; + + controller(req, res, next); + + }); + + test('only status code 408 should be considered a retryable request', (t) => { + const config = { + indexName: 'indexName value' + }; + const esclient = 'this is the esclient'; + + let searchServiceCallCount = 0; + + const nonTimeoutError = { + status: 500, + displayName: 'InternalServerError', + message: 'an internal server error occurred' + }; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, cmd, callback) => { + // not that the searchService got called + searchServiceCallCount++; + + callback(nonTimeoutError); } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + } + ] + }, + errors: [], + warnings: [] }; - var req = { clean: { ids: [ {'id' : 123, layers: [ 'a' ] } ] }, errors: [], warnings: [] }; - var next = function next() { - t.equal(req.errors.length, 0, 'next was called without error'); + const res = {}; + + const next = () => { + t.equal(searchServiceCallCount, 1); + t.deepEqual(req.errors, [nonTimeoutError]); t.end(); }; - controller(req, res, next ); + + controller(req, res, next); + }); -}; -// functionally test controller (backend failure) -module.exports.tests.functional_failure = function(test, common) { - test('functional failure', function(t) { - var backend = mockBackend( 'client/mget/fail/1', function( cmd ){ - t.deepEqual(cmd, { body: { docs: [ { _id: 123, _index: 'pelias', _type: ['b'] } ] } }, 'correct backend command'); - }); - var controller = setup( fakeDefaultConfig, backend ); - var req = { clean: { ids: [ {'id' : 123, layers: [ 'b' ] } ] }, errors: [], warnings: [] }; - var next = function( message ){ - t.equal(req.errors[0],'an elasticsearch error occurred','error passed to errorHandler'); + test('string error should not retry and be logged as-is', (t) => { + const config = { + indexName: 'indexName value' + }; + const esclient = 'this is the esclient'; + + let searchServiceCallCount = 0; + + const stringTypeError = 'this is an error string'; + + // a controller that validates the esclient and cmd that was passed to the search service + const controller = proxyquire('../../../controller/place', { + '../service/mget': (esclient, cmd, callback) => { + // not that the searchService got called + searchServiceCallCount++; + + callback(stringTypeError); + } + })(config, esclient); + + const req = { + clean: { + ids: [ + { + id: 'id1', + layers: 'layer1' + } + ] + }, + errors: [], + warnings: [] + }; + const res = {}; + + const next = () => { + t.equal(searchServiceCallCount, 1); + t.deepEqual(req.errors, [stringTypeError]); t.end(); }; - controller(req, undefined, next ); + + controller(req, res, next); + }); + }; -module.exports.all = function (tape, common) { +module.exports.all = (tape, common) => { function test(name, testFunction) { return tape('GET /place ' + name, testFunction); } - for( var testCase in module.exports.tests ){ + for( const testCase in module.exports.tests ){ module.exports.tests[testCase](test, common); } };