feat: Merge pull request #1054 from pelias/log-street-count

Log number of streets to be interpolated

middleware/interpolate.js

@@ -57,6 +57,8 @@ function setup(service, should_execute) {
     // perform interpolations asynchronously for all relevant hits
     const start = (new Date()).getTime();
 
+    logger.info(`[interpolation] [street_results] count=${street_results.length}`);
+
     // call the interpolation service asynchronously on every street result
     async.map(street_results, error_intercepting_service(service, req), (err, interpolation_results) => {
 

test/unit/middleware/interpolate.js

@@ -59,6 +59,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, undefined, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/));
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=0/));
       t.end();
 
     });
@@ -87,6 +88,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, res, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/));
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=0/));
 
       t.deepEquals(res, {});
 
@@ -201,6 +203,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, res, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/), 'timing should be info-logged');
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=3/), 'street count should be info-logged');
 
       // test debug messages very vaguely to avoid brittle tests
       t.ok(logger.isDebugMessage(/^\[interpolation\] \[hit\] this is req.clean.parsed_text \{.+?\}$/),
@@ -375,6 +378,7 @@ module.exports.tests.success_conditions = (test, common) => {
         '[middleware:interpolation] id 3 produced an error object'
       ]);
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/), 'timing should be info-logged');
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=4/), 'street count should be info-logged');
 
       // test debug messages very vaguely to avoid brittle tests
       t.ok(logger.isDebugMessage(/^\[interpolation\] \[hit\] this is req.clean.parsed_text \{.+?\}$/),
@@ -491,6 +495,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, res, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/));
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=1/), 'street count should be info-logged');
 
       t.deepEquals(res, {
         data: [
@@ -579,6 +584,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, res, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/));
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=2/), 'street count should be info-logged');
 
       // test debug messages very vaguely to avoid brittle tests
       t.ok(logger.isDebugMessage('[interpolation] [miss] this is req.clean.parsed_text'));
@@ -679,6 +685,7 @@ module.exports.tests.success_conditions = (test, common) => {
     controller(req, res, () => {
       t.notOk(logger.hasErrorMessages(), 'there shouldn\'t be any error messages');
       t.ok(logger.isInfoMessage(/\[interpolation\] \[took\] \d+ ms/));
+      t.ok(logger.isInfoMessage(/\[interpolation\] \[street_results\] count=2/), 'street count should be info-logged');
 
       // test debug messages very vaguely to avoid brittle tests
       t.ok(logger.isDebugMessage('[interpolation] [miss] this is req.clean.parsed_text'));