mirror of https://github.com/pelias/api.git
Stephen Hess
8 years ago
3 changed files with 690 additions and 0 deletions
@ -0,0 +1,119 @@
|
||||
'use strict'; |
||||
|
||||
const _ = require('lodash'); |
||||
|
||||
const searchService = require('../service/search'); |
||||
const logger = require('pelias-logger').get('api'); |
||||
const logging = require( '../helper/logging' ); |
||||
const retry = require('retry'); |
||||
|
||||
function isRequestTimeout(err) { |
||||
return _.get(err, 'status') === 408; |
||||
} |
||||
|
||||
function setup( apiConfig, esclient, query, should_execute ){ |
||||
function controller( req, res, next ){ |
||||
if (!should_execute(req, res)) { |
||||
return next(); |
||||
} |
||||
|
||||
let cleanOutput = _.cloneDeep(req.clean); |
||||
if (logging.isDNT(req)) { |
||||
cleanOutput = logging.removeFields(cleanOutput); |
||||
} |
||||
// log clean parameters for stats
|
||||
logger.info('[req]', 'endpoint=' + req.path, cleanOutput); |
||||
|
||||
const renderedQuery = query(req.clean, res); |
||||
// console.log(JSON.stringify(renderedQuery.body, null, 2));
|
||||
|
||||
// if there's no query to call ES with, skip the service
|
||||
if (_.isUndefined(renderedQuery)) { |
||||
return next(); |
||||
} |
||||
|
||||
// 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); |
||||
|
||||
// elasticsearch command
|
||||
const cmd = { |
||||
index: apiConfig.indexName, |
||||
searchType: 'dfs_query_then_fetch', |
||||
body: renderedQuery.body |
||||
}; |
||||
|
||||
logger.debug( '[ES req]', cmd ); |
||||
|
||||
operation.attempt((currentAttempt) => { |
||||
// query elasticsearch
|
||||
searchService( esclient, cmd, function( err, docs, meta ){ |
||||
// 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; |
||||
} |
||||
|
||||
// if execution has gotten this far then one of three things happened:
|
||||
// - the request didn't time out
|
||||
// - maxRetries has been hit so we're giving up
|
||||
// - another error occurred
|
||||
// in either case, handle the error or results
|
||||
|
||||
// error handler
|
||||
if( err ){ |
||||
if (_.isObject(err) && err.message) { |
||||
req.errors.push( err.message ); |
||||
} else { |
||||
req.errors.push( err ); |
||||
} |
||||
} |
||||
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}`); |
||||
} |
||||
|
||||
// because this is used in response to placeholder, there may already
|
||||
// be results. if there are no results from this ES call, don't overwrite
|
||||
// what's already there from placeholder.
|
||||
if (!_.isEmpty(docs)) { |
||||
res.data = docs; |
||||
res.meta = meta || {}; |
||||
// store the query_type for subsequent middleware
|
||||
res.meta.query_type = renderedQuery.type; |
||||
|
||||
const messageParts = [ |
||||
'[controller:search]', |
||||
`[queryType:${renderedQuery.type}]`, |
||||
`[es_result_count:${docs.length}]` |
||||
]; |
||||
|
||||
logger.info(messageParts.join(' ')); |
||||
|
||||
} |
||||
|
||||
} |
||||
logger.debug('[ES response]', docs); |
||||
next(); |
||||
}); |
||||
|
||||
}); |
||||
|
||||
} |
||||
|
||||
return controller; |
||||
} |
||||
|
||||
module.exports = setup; |
@ -0,0 +1,569 @@
|
||||
'use strict'; |
||||
|
||||
const setup = require('../../../controller/search_with_ids'); |
||||
const proxyquire = require('proxyquire').noCallThru(); |
||||
const mocklogger = require('pelias-mock-logger'); |
||||
const _ = require('lodash'); |
||||
|
||||
module.exports.tests = {}; |
||||
|
||||
module.exports.tests.interface = (test, common) => { |
||||
test('valid interface', (t) => { |
||||
t.ok(_.isFunction(setup), 'setup is a function'); |
||||
t.ok(_.isFunction(setup()), 'setup returns a controller'); |
||||
t.end(); |
||||
}); |
||||
}; |
||||
|
||||
module.exports.tests.success = (test, common) => { |
||||
test('successful request to search service should replace data and meta', (t) => { |
||||
t.plan(5); |
||||
|
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
type: 'this is the query type' |
||||
}); |
||||
|
||||
// a controller that validates the esclient and cmd that was passed to the search service
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
t.equal(esclient, 'this is the esclient'); |
||||
t.deepEqual(cmd, { |
||||
index: 'indexName value', |
||||
searchType: 'dfs_query_then_fetch', |
||||
body: 'this is the query body' |
||||
}); |
||||
|
||||
const docs = [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
]; |
||||
const meta = { key: 'replacement meta value' }; |
||||
|
||||
callback(undefined, docs, meta); |
||||
}, |
||||
'pelias-logger': logger |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = { |
||||
data: [ |
||||
{ name: 'original result #1'}, |
||||
{ name: 'original result #2'} |
||||
], |
||||
meta: { |
||||
key: 'original meta value' |
||||
} |
||||
}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [], |
||||
warnings: [] |
||||
}); |
||||
t.deepEquals(res, { |
||||
data: [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
], |
||||
meta: { |
||||
key: 'replacement meta value', |
||||
query_type: 'this is the query type' |
||||
} |
||||
}); |
||||
|
||||
t.ok(logger.isInfoMessage('[controller:search] [queryType:this is the query type] [es_result_count:2]')); |
||||
|
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('undefined meta should set empty object into res', (t) => { |
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
type: 'this is the query type' |
||||
}); |
||||
|
||||
// a controller that validates the esclient and cmd that was passed to the search service
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
const docs = [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
]; |
||||
|
||||
callback(undefined, docs, undefined); |
||||
}, |
||||
'pelias-logger': logger |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = { |
||||
data: [ |
||||
{ name: 'original result #1'}, |
||||
{ name: 'original result #2'} |
||||
], |
||||
meta: { |
||||
key: 'original meta value' |
||||
} |
||||
}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [], |
||||
warnings: [] |
||||
}); |
||||
t.deepEquals(res, { |
||||
data: [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
], |
||||
meta: { |
||||
query_type: 'this is the query type' |
||||
} |
||||
}); |
||||
|
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('undefined docs in response should not overwrite existing results', (t) => { |
||||
t.plan(1+3); // ensures that search service was called, then req+res+logger tests
|
||||
|
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
type: 'this is the query type' |
||||
}); |
||||
|
||||
// a controller that validates the esclient and cmd that was passed to the search service
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
t.pass('search service was called'); |
||||
|
||||
const meta = { key: 'new value' }; |
||||
|
||||
callback(undefined, undefined, meta); |
||||
}, |
||||
'pelias-logger': logger |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = { |
||||
data: [ |
||||
{ id: 1 }, |
||||
{ id: 2 } |
||||
], |
||||
meta: { |
||||
key: 'value' |
||||
} |
||||
}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [], |
||||
warnings: [] |
||||
}); |
||||
t.deepEquals(res, { |
||||
data: [ |
||||
{ id: 1 }, |
||||
{ id: 2 } |
||||
], |
||||
meta: { key: 'value' } |
||||
}); |
||||
|
||||
t.notOk(logger.isInfoMessage(/[controller:search] [queryType:this is the query type] [es_result_count:0]/)); |
||||
|
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('empty docs in response should not overwrite existing results', (t) => { |
||||
t.plan(4); |
||||
|
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
type: 'this is the query type' |
||||
}); |
||||
|
||||
// a controller that validates the esclient and cmd that was passed to the search service
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
t.pass('search service was called'); |
||||
|
||||
const meta = { key: 'value' }; |
||||
|
||||
callback(undefined, [], meta); |
||||
} |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = { |
||||
data: [ |
||||
{ name: 'pre-existing result #1' }, |
||||
{ name: 'pre-existing result #2' } |
||||
], |
||||
meta: { |
||||
key: 'value' |
||||
} |
||||
}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [], |
||||
warnings: [] |
||||
}); |
||||
t.deepEquals(res, { |
||||
data: [ |
||||
{ name: 'pre-existing result #1' }, |
||||
{ name: 'pre-existing result #2' } |
||||
], |
||||
meta: { key: 'value' } |
||||
}); |
||||
|
||||
t.notOk(logger.isInfoMessage(/[controller:search] [queryType:this is the query type] [es_result_count:0]/)); |
||||
|
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('successful request on retry to search service should log info message', (t) => { |
||||
t.plan(3+2+2); // 3 search service calls, 2 log messages, 1 req, 1 res
|
||||
|
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
type: 'this is the query type' |
||||
}); |
||||
|
||||
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/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
t.pass('search service was called'); |
||||
|
||||
if (searchServiceCallCount < 2) { |
||||
// note that the searchService got called
|
||||
searchServiceCallCount++; |
||||
callback(timeoutError); |
||||
} else { |
||||
const docs = [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
]; |
||||
const meta = { key: 'replacement meta value' }; |
||||
|
||||
callback(undefined, docs, meta); |
||||
} |
||||
|
||||
}, |
||||
'pelias-logger': logger |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = { |
||||
data: [ |
||||
{ name: 'original result #1'}, |
||||
{ name: 'original result #2'} |
||||
], |
||||
meta: { |
||||
key: 'original meta value' |
||||
} |
||||
}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [], |
||||
warnings: [] |
||||
}); |
||||
t.deepEquals(res, { |
||||
data: [ |
||||
{ name: 'replacement result #1'}, |
||||
{ name: 'replacement result #2'} |
||||
], |
||||
meta: { |
||||
key: 'replacement meta value', |
||||
query_type: 'this is the query type' |
||||
} |
||||
}); |
||||
|
||||
t.ok(logger.isInfoMessage('[controller:search] [queryType:this is the query type] [es_result_count:2]')); |
||||
t.ok(logger.isInfoMessage('succeeded on retry 2')); |
||||
|
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
}; |
||||
|
||||
module.exports.tests.service_errors = (test, common) => { |
||||
test('default # of request timeout retries should be 3', (t) => { |
||||
// test for 1 initial search service, 3 retries, 1 log messages, 1 req, and 1 res
|
||||
t.plan(1 + 3 + 1 + 2); |
||||
|
||||
const logger = mocklogger(); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ |
||||
body: 'this is the query body', |
||||
}); |
||||
|
||||
const timeoutError = { |
||||
status: 408, |
||||
displayName: 'RequestTimeout', |
||||
message: 'Request Timeout after 17ms' |
||||
}; |
||||
|
||||
// a controller that validates that the search service was called
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
// note that the searchService got called
|
||||
t.pass('search service was called'); |
||||
|
||||
callback(timeoutError); |
||||
}, |
||||
'pelias-logger': logger |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = {}; |
||||
|
||||
const next = () => { |
||||
t.ok(logger.getInfoMessages(), [ |
||||
'request timed out on attempt 1, retrying', |
||||
'request timed out on attempt 2, retrying', |
||||
'request timed out on attempt 3, retrying' |
||||
]); |
||||
|
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [timeoutError.message], |
||||
warnings: [] |
||||
}); |
||||
t.deepEqual(res, {}); |
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('explicit apiConfig.requestRetries should retry that many times', (t) => { |
||||
t.plan(1 + 17); // test for initial search service call and 17 retries
|
||||
|
||||
const config = { |
||||
indexName: 'indexName value', |
||||
requestRetries: 17 |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ }); |
||||
|
||||
const timeoutError = { |
||||
status: 408, |
||||
displayName: 'RequestTimeout', |
||||
message: 'Request Timeout after 17ms' |
||||
}; |
||||
|
||||
// a controller that validates that the search service was called
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
// note that the searchService got called
|
||||
t.pass('search service was called'); |
||||
|
||||
callback(timeoutError); |
||||
} |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = {}; |
||||
|
||||
controller(req, res, () => t.end() ); |
||||
|
||||
}); |
||||
|
||||
test('only status code 408 should be considered a retryable request', (t) => { |
||||
t.plan(2); |
||||
|
||||
const config = { |
||||
indexName: 'indexName value', |
||||
requestRetries: 17 |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ }); |
||||
|
||||
const nonTimeoutError = { |
||||
status: 500, |
||||
displayName: 'InternalServerError', |
||||
message: 'an internal server error occurred' |
||||
}; |
||||
|
||||
// a controller that validates that the search service was called
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
// note that the searchService got called
|
||||
t.pass('search service was called'); |
||||
|
||||
callback(nonTimeoutError); |
||||
} |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = {}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: [nonTimeoutError.message], |
||||
warnings: [] |
||||
}); |
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
test('string error should not retry and be logged as-is', (t) => { |
||||
t.plan(2); // service call + error is in req.errors
|
||||
|
||||
const config = { |
||||
indexName: 'indexName value' |
||||
}; |
||||
const esclient = 'this is the esclient'; |
||||
const query = () => ({ }); |
||||
|
||||
// a controller that validates that the search service was called
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': (esclient, cmd, callback) => { |
||||
// note that the searchService got called
|
||||
t.pass('search service was called'); |
||||
|
||||
callback('this is an error string'); |
||||
} |
||||
})(config, esclient, query, () => true ); |
||||
|
||||
const req = { clean: { }, errors: [], warnings: [] }; |
||||
const res = {}; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(req, { |
||||
clean: {}, |
||||
errors: ['this is an error string'], |
||||
warnings: [] |
||||
}); |
||||
t.end(); |
||||
}; |
||||
|
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
}; |
||||
|
||||
module.exports.tests.should_execute = (test, common) => { |
||||
test('should_execute returning false and empty req.errors should call next', (t) => { |
||||
const esclient = () => t.fail('esclient should not have been called'); |
||||
const query = () => t.fail('query should not have been called'); |
||||
const should_execute = () => false; |
||||
const controller = setup( {}, esclient, query, should_execute ); |
||||
|
||||
const req = { }; |
||||
const res = { }; |
||||
|
||||
const next = () => { |
||||
t.deepEqual(res, { }); |
||||
t.end(); |
||||
}; |
||||
controller(req, res, next); |
||||
|
||||
}); |
||||
|
||||
}; |
||||
|
||||
module.exports.tests.undefined_query = (test, common) => { |
||||
test('query returning undefined should not call service', (t) => { |
||||
t.plan(0, 'test will fail if search service actually gets called'); |
||||
|
||||
// a function that returns undefined
|
||||
const query = () => undefined; |
||||
|
||||
const controller = proxyquire('../../../controller/search_with_ids', { |
||||
'../service/search': () => { |
||||
t.fail('search service should not have been called'); |
||||
} |
||||
})(undefined, undefined, query, () => true ); |
||||
|
||||
const next = () => t.end(); |
||||
|
||||
controller({}, {}, next); |
||||
|
||||
}); |
||||
}; |
||||
|
||||
module.exports.all = (tape, common) => { |
||||
function test(name, testFunction) { |
||||
return tape(`GET /search ${name}`, testFunction); |
||||
} |
||||
|
||||
for( const testCase in module.exports.tests ){ |
||||
module.exports.tests[testCase](test, common); |
||||
} |
||||
}; |
Loading…
Reference in new issue