From bf62a1844b4ba81b8184704b2af5caf7de1cf238 Mon Sep 17 00:00:00 2001
From: Stephen Hess <stephen.k.hess@gmail.com>
Date: Thu, 19 Jan 2017 16:02:10 -0500
Subject: [PATCH] added tests for verifying request retry behavior

limited retry behavior to errors with status 408 (request timeout).  this also reduces reliance on unit/mock/backend and unit/mock/query.
---
 controller/search.js           |   7 +-
 test/unit/controller/search.js | 410 ++++++++++++++++++++++-----------
 test/unit/mock/backend.js      |   8 -
 3 files changed, 284 insertions(+), 141 deletions(-)

diff --git a/controller/search.js b/controller/search.js
index 52b0281a..d1343350 100644
--- a/controller/search.js
+++ b/controller/search.js
@@ -8,6 +8,10 @@ var logging = require( '../helper/logging' );
 const retry = require('retry');
 
 function setup( apiConfig, esclient, query ){
+  function isRequestTimeout(err) {
+    return _.get(err, 'status') === 408;
+  }
+
   function controller( req, res, next ){
     // do not run controller when a request
     // validation error has occurred.
@@ -62,7 +66,8 @@ function setup( apiConfig, esclient, query ){
       searchService( esclient, cmd, function( err, docs, meta ){
         // returns true if the operation should be attempted again
         // (handles bookkeeping of maxRetries)
-        if (operation.retry(err)) {
+        // only consider for status 408 (request timeout)
+        if (isRequestTimeout(err) && operation.retry(err)) {
           logger.info('request timed out, retrying');
           return;
         }
diff --git a/test/unit/controller/search.js b/test/unit/controller/search.js
index 41d32bcd..8652cbb9 100644
--- a/test/unit/controller/search.js
+++ b/test/unit/controller/search.js
@@ -1,3 +1,5 @@
+'use strict';
+
 var setup = require('../../../controller/search'),
     mockBackend = require('../mock/backend'),
     mockQuery = require('../mock/query');
@@ -19,158 +21,302 @@ var fakeDefaultConfig = {
 };
 
 // functionally test controller (backend success)
-module.exports.tests.functional_success = function(test, common) {
-
-  // expected geojson features for 'client/suggest/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'
-    }
-  }];
-
-  var expectedMeta = {
-    scores: [10, 20],
-    query_type: 'mock'
-  };
-
-  var expectedData = [
-    {
-      _id: 'myid1',
-      _score: 10,
-      _type: 'mytype1',
-      _matched_queries: ['query 1', 'query 2'],
-      parent: {
-        country: ['country1'],
-        region: ['state1'],
-        county: ['city1']
-      },
-      center_point: { lat: 100.1, lon: -50.5 },
-      name: { default: 'test name1' },
-      value: 1
-    },
-    {
-      _id: 'myid2',
-      _score: 20,
-      _type: 'mytype2',
-      _matched_queries: ['query 3'],
-      parent: {
-        country: ['country2'],
-        region: ['state2'],
-        county: ['city2']
-      },
-      center_point: { lat: 100.2, lon: -51.5 },
-      name: { default: 'test name2' },
-      value: 2
-    }
-  ];
-
-  test('functional success', function (t) {
-    var backend = mockBackend('client/search/ok/1', function (cmd) {
-      t.deepEqual(cmd, {
-        body: {a: 'b'},
-        index: 'pelias',
-        searchType: 'dfs_query_then_fetch'
-      }, 'correct backend command');
-    });
-    var controller = setup(fakeDefaultConfig, backend, mockQuery());
-    var res = {
-      status: function (code) {
-        t.equal(code, 200, 'status set');
-        return res;
+// module.exports.tests.functional_success = function(test, common) {
+//
+//   // expected geojson features for 'client/suggest/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'
+//     }
+//   }];
+//
+//   var expectedMeta = {
+//     scores: [10, 20],
+//     query_type: 'mock'
+//   };
+//
+//   var expectedData = [
+//     {
+//       _id: 'myid1',
+//       _score: 10,
+//       _type: 'mytype1',
+//       _matched_queries: ['query 1', 'query 2'],
+//       parent: {
+//         country: ['country1'],
+//         region: ['state1'],
+//         county: ['city1']
+//       },
+//       center_point: { lat: 100.1, lon: -50.5 },
+//       name: { default: 'test name1' },
+//       value: 1
+//     },
+//     {
+//       _id: 'myid2',
+//       _score: 20,
+//       _type: 'mytype2',
+//       _matched_queries: ['query 3'],
+//       parent: {
+//         country: ['country2'],
+//         region: ['state2'],
+//         county: ['city2']
+//       },
+//       center_point: { lat: 100.2, lon: -51.5 },
+//       name: { default: 'test name2' },
+//       value: 2
+//     }
+//   ];
+//
+//   test('functional success', function (t) {
+//     var backend = mockBackend('client/search/ok/1', function (cmd) {
+//       t.deepEqual(cmd, {
+//         body: {a: 'b'},
+//         index: 'pelias',
+//         searchType: 'dfs_query_then_fetch'
+//       }, 'correct backend command');
+//     });
+//     var controller = setup(fakeDefaultConfig, backend, mockQuery());
+//     var res = {
+//       status: function (code) {
+//         t.equal(code, 200, 'status set');
+//         return res;
+//       },
+//       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');
+//       }
+//     };
+//     var req = { clean: { a: 'b' }, errors: [], warnings: [] };
+//     var next = function next() {
+//       t.equal(req.errors.length, 0, 'next was called without error');
+//       t.deepEqual(res.meta, expectedMeta, 'meta data was set');
+//       t.deepEqual(res.data, expectedData, 'data was set');
+//       t.end();
+//     };
+//     controller(req, res, next);
+//   });
+//
+//   test('functional success with alternate index name', function(t) {
+//     var fakeCustomizedConfig = {
+//       indexName: 'alternateindexname'
+//     };
+//
+//     var backend = mockBackend('client/search/ok/1', function (cmd) {
+//       t.deepEqual(cmd, {
+//         body: {a: 'b'},
+//         index: 'alternateindexname',
+//         searchType: 'dfs_query_then_fetch'
+//       }, 'correct backend command');
+//     });
+//     var controller = setup(fakeCustomizedConfig, backend, mockQuery());
+//     var res = {
+//       status: function (code) {
+//         t.equal(code, 200, 'status set');
+//         return res;
+//       }
+//     };
+//     var req = { clean: { a: 'b' }, errors: [], warnings: [] };
+//     var next = function next() {
+//       t.equal(req.errors.length, 0, 'next was called without error');
+//       t.end();
+//     };
+//     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/search/fail/1', function( cmd ){
+//       t.deepEqual(cmd, { body: { a: 'b' }, index: 'pelias', searchType: 'dfs_query_then_fetch' }, 'correct backend command');
+//     });
+//     var controller = setup( fakeDefaultConfig, backend, mockQuery() );
+//     var req = { clean: { a: 'b' }, errors: [], warnings: [] };
+//     var next = function(){
+//       t.equal(req.errors[0],'an elasticsearch error occurred');
+//       t.end();
+//     };
+//     controller(req, undefined, 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';
+    const query = () => {
+      return { body: 'this is the query body' };
+    };
+
+    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/search', {
+      '../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'
+        });
+
+        // not that the searchService got called
+        searchServiceCallCount++;
+
+        callback(timeoutError);
       },
-      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');
+      'pelias-logger': {
+        get: (service) => {
+          t.equal(service, 'api');
+          return {
+            info: (msg) => {
+              infoMesssages.push(msg);
+            },
+            debug: () => {}
+          };
+        }
       }
-    };
-    var req = { clean: { a: 'b' }, errors: [], warnings: [] };
-    var next = function next() {
-      t.equal(req.errors.length, 0, 'next was called without error');
-      t.deepEqual(res.meta, expectedMeta, 'meta data was set');
-      t.deepEqual(res.data, expectedData, 'data was set');
+    })(config, esclient, query);
+
+    const req = { clean: { }, errors: [], warnings: [] };
+    const res = {};
+
+    var next = function() {
+      t.equal(searchServiceCallCount, 3+1);
+      t.deepEqual(
+        infoMesssages.filter((msg)=> { return msg === 'request timed out, retrying'; } ).length,
+        3,
+        'there should be 3 request timed out info messages'
+      );
+      t.deepEqual(req, {
+        clean: {},
+        errors: [timeoutError.message],
+        warnings: []
+      });
+      t.deepEqual(res, {});
       t.end();
     };
+
     controller(req, res, next);
+
   });
 
-  test('functional success with alternate 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';
+    const query = () => {
+      return { };
     };
 
-    var backend = mockBackend('client/search/ok/1', function (cmd) {
-      t.deepEqual(cmd, {
-        body: {a: 'b'},
-        index: 'alternateindexname',
-        searchType: 'dfs_query_then_fetch'
-      }, 'correct backend command');
-    });
-    var controller = setup(fakeCustomizedConfig, backend, mockQuery());
-    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'
     };
-    var req = { clean: { a: 'b' }, errors: [], warnings: [] };
-    var next = function next() {
-      t.equal(req.errors.length, 0, 'next was called without error');
+
+    // a controller that validates the esclient and cmd that was passed to the search service
+    const controller = proxyquire('../../../controller/search', {
+      '../service/search': (esclient, cmd, callback) => {
+        // not that the searchService got called
+        searchServiceCallCount++;
+
+        callback(timeoutError);
+      }
+    })(config, esclient, query);
+
+    const req = { clean: { }, errors: [], warnings: [] };
+    const res = {};
+
+    var next = function() {
+      t.equal(searchServiceCallCount, 17+1);
       t.end();
     };
+
     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/search/fail/1', function( cmd ){
-      t.deepEqual(cmd, { body: { a: 'b' }, index: 'pelias', searchType: 'dfs_query_then_fetch' }, 'correct backend command');
-    });
-    var controller = setup( fakeDefaultConfig, backend, mockQuery() );
-    var req = { clean: { a: 'b' }, errors: [], warnings: [] };
-    var next = function(){
-      t.equal(req.errors[0],'an elasticsearch error occurred');
-      t.end();
+  test('only status code 408 should be considered a retryable request', (t) => {
+    const config = {
+      indexName: 'indexName value',
+      requestRetries: 17
+    };
+    const esclient = 'this is the esclient';
+    const query = () => {
+      return { };
     };
-    controller(req, undefined, next );
-  });
-};
 
-module.exports.tests.timeout = function(test, common) {
-  test('timeout', function(t) {
-    var backend = mockBackend( 'client/search/timeout/1', function( cmd ){
-      t.deepEqual(cmd, { body: { a: 'b' }, index: 'pelias', searchType: 'dfs_query_then_fetch' }, 'correct backend command');
-    });
-    var controller = setup( fakeDefaultConfig, backend, mockQuery() );
-    var req = { clean: { a: 'b' }, errors: [], warnings: [] };
-    var next = function(){
-      t.equal(req.errors[0],'Request Timeout after 5000ms');
+    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/search', {
+      '../service/search': (esclient, cmd, callback) => {
+        // not that the searchService got called
+        searchServiceCallCount++;
+
+        callback(nonTimeoutError);
+      }
+    })(config, esclient, query);
+
+    const req = { clean: { }, errors: [], warnings: [] };
+    const res = {};
+
+    var next = function() {
+      t.equal(searchServiceCallCount, 1);
+      t.deepEqual(req, {
+        clean: {},
+        errors: [nonTimeoutError.message],
+        warnings: []
+      });
       t.end();
     };
-    controller(req, undefined, next );
+
+    controller(req, res, next);
+
   });
+
 };
 
 module.exports.tests.existing_errors = function(test, common) {
diff --git a/test/unit/mock/backend.js b/test/unit/mock/backend.js
index 104f84dc..53df354f 100644
--- a/test/unit/mock/backend.js
+++ b/test/unit/mock/backend.js
@@ -35,14 +35,6 @@ responses['client/search/fail/1'] = function( cmd, cb ){
   return cb( 'an elasticsearch error occurred' );
 };
 
-responses['client/search/timeout/1'] = function( cmd, cb) {
-  // timeout errors are objects
-  return cb({
-    status: 408,
-    message: 'Request Timeout after 5000ms'
-  });
-};
-
 responses['client/mget/ok/1'] = function( cmd, cb ){
   return cb( undefined, mgetEnvelope([{
     _id: 'myid1',