feat(log): Remove most unstructured controller logs

These are nose now, the structured logs have much better info

controller/search.js

@@ -22,8 +22,6 @@ function setup( apiConfig, esclient, query, should_execute ){
     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);
 
@@ -113,7 +111,6 @@ function setup( apiConfig, esclient, query, should_execute ){
           };
           logger.info('elasticsearch', message);
 
-          logger.info(messageParts.join(' '));
           debugLog.push(req, {queryType: {
             [renderedQuery.type] : {
               es_result_count: _.get(res, 'data', []).length

controller/search_with_ids.js

@@ -21,8 +21,6 @@ function setup( apiConfig, esclient, query, should_execute ){
     if (logging.isDNT(req)) {
       logging.removeFields(cleanOutput);
     }
-    // log clean parameters for stats
-    logger.info('[req]', `endpoint=${req.path}`, cleanOutput);
 
     const renderedQuery = query(req.clean, res);
 
@@ -112,7 +110,6 @@ function setup( apiConfig, esclient, query, should_execute ){
               `[es_result_count:${docs.length}]`
             ];
 
-            logger.info(messageParts.join(' '));
             debugLog.push(req, {queryType: {
               [renderedQuery.type] : {
                 es_result_count: docs.length

middleware/changeLanguage.js

@@ -36,7 +36,6 @@ function setup(service, should_execute) {
     service(req, res, (err, translations) => {
       // if there's an error, log it and bail
       if (err) {
-        logger.info(`[middleware:language][error]`);
         logger.error(err);
         return next();
       }

query/address_search_using_ids.js

@@ -99,18 +99,14 @@ function generateQuery( clean, res ){
   const vs = new peliasQuery.Vars( defaults );
   const results = _.defaultTo(res.data, []);
 
-  const logParts = ['query:address_search_using_ids', 'parser:libpostal'];
-
   // sources
   if( !_.isEmpty(clean.sources) ) {
     vs.var( 'sources', clean.sources);
-    logParts.push('param:sources');
   }
 
   // size
   if( clean.querySize ) {
     vs.var( 'size', clean.querySize );
-    logParts.push('param:querySize');
   }
 
   if( ! _.isEmpty(clean.parsed_text.number) ){
@@ -179,9 +175,6 @@ function generateQuery( clean, res ){
     });
   }
 
-  // format the log parts into a single coherent string
-  logger.info(logParts.map(part => `[${part}]`).join(' '));
-
   return {
     type: 'fallback',
     body: addressUsingIdsQuery.render(vs)

query/search.js

@@ -114,9 +114,6 @@ function generateQuery( clean ){
 }
 
 function getQuery(vs) {
-
-  logger.info(`[query:search] [search_input_type:${determineQueryType(vs)}]`);
-
   if (hasStreet(vs) || isPostalCodeOnly(vs) || isPostalCodeWithCountry(vs)) {
     return {
       type: 'fallback',

test/unit/controller/search.js

@@ -67,9 +67,6 @@ module.exports.tests.success = function(test, common) {
       t.deepEquals(res.data, [{}, {}]);
       t.deepEquals(res.meta, { key: 'value', query_type: 'this is the query type' });
 
-      t.ok(infoMesssages.find((msg) => {
-        return msg === '[controller:search] [queryType:this is the query type] [es_result_count:2]';
-      }));
       t.end();
     };
 
@@ -131,9 +128,6 @@ module.exports.tests.success = function(test, common) {
       t.deepEquals(res.data, [{}, {}]);
       t.deepEquals(res.meta, { query_type: 'this is the query type' });
 
-      t.ok(infoMesssages.find((msg) => {
-        return msg === '[controller:search] [queryType:this is the query type] [es_result_count:2]';
-      }));
       t.end();
     };
 
@@ -195,9 +189,6 @@ module.exports.tests.success = function(test, common) {
       t.equals(res.data, undefined);
       t.deepEquals(res.meta, { key: 'value', query_type: 'this is the query type' });
 
-      t.ok(infoMesssages.find((msg) => {
-        return msg === '[controller:search] [queryType:this is the query type] [es_result_count:0]';
-      }));
       t.end();
     };
 
@@ -275,10 +266,6 @@ module.exports.tests.success = function(test, common) {
       t.deepEquals(res.data, [{}, {}]);
       t.deepEquals(res.meta, { key: 'value', query_type: 'this is the query type' });
 
-      t.ok(infoMesssages.find((msg) => {
-        return msg === '[controller:search] [queryType:this is the query type] [es_result_count:2]';
-      }));
-
       t.ok(infoMesssages.find((msg) => {
         return msg === 'succeeded on retry 2';
       }));

test/unit/controller/search_with_ids.js

@@ -15,7 +15,7 @@ module.exports.tests.interface = (test, common) => {
 
 module.exports.tests.success = (test, common) => {
   test('successful request to search service should replace data and meta', (t) => {
-    t.plan(5);
+    t.plan(4);
 
     const logger = mocklogger();
 
@@ -77,8 +77,6 @@ module.exports.tests.success = (test, common) => {
         }
       });
 
-      t.ok(logger.isInfoMessage('[controller:search] [queryType:this is the query type] [es_result_count:2]'));
-
       t.end();
     };
 
@@ -146,7 +144,7 @@ module.exports.tests.success = (test, common) => {
   });
 
   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
+    t.plan(1+2); // ensures that search service was called, then req+res+logger tests
 
     const logger = mocklogger();
 
@@ -196,8 +194,6 @@ module.exports.tests.success = (test, common) => {
         meta: { key: 'value' }
       });
 
-      t.notOk(logger.isInfoMessage(/[controller:search] [queryType:this is the query type] [es_result_count:0]/));
-
       t.end();
     };
 
@@ -206,7 +202,7 @@ module.exports.tests.success = (test, common) => {
   });
 
   test('empty docs in response should not overwrite existing results', (t) => {
-    t.plan(4);
+    t.plan(3);
 
     const logger = mocklogger();
 
@@ -255,8 +251,6 @@ module.exports.tests.success = (test, common) => {
         meta: { key: 'value' }
       });
 
-      t.notOk(logger.isInfoMessage(/[controller:search] [queryType:this is the query type] [es_result_count:0]/));
-
       t.end();
     };
 
@@ -265,7 +259,7 @@ module.exports.tests.success = (test, common) => {
   });
 
   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
+    t.plan(3+1+2); // 3 search service calls, 1 log messages, 1 req, 1 res
 
     const logger = mocklogger();
 
@@ -337,7 +331,6 @@ module.exports.tests.success = (test, common) => {
         }
       });
 
-      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();

test/unit/query/address_search_using_ids.js

@@ -67,7 +67,6 @@ module.exports.tests.base_query = (test, common) => {
       'sources view'
     ]);
 
-    t.deepEquals(logger.getInfoMessages(), ['[query:address_search_using_ids] [parser:libpostal]']);
     t.end();
 
   });
@@ -102,7 +101,6 @@ module.exports.tests.other_parameters = (test, common) => {
     const generatedQuery = generateQuery(clean, res);
 
     t.equals(generatedQuery.body.vs.var('size').toString(), 'querySize value');
-    t.deepEquals(logger.getInfoMessages(), ['[query:address_search_using_ids] [parser:libpostal] [param:querySize]']);
     t.end();
 
   });
@@ -135,7 +133,6 @@ module.exports.tests.other_parameters = (test, common) => {
     const generatedQuery = generateQuery(clean, res);
 
     t.deepEquals(generatedQuery.body.vs.var('sources').toString(), ['source 1', 'source 2']);
-    t.deepEquals(logger.getInfoMessages(), ['[query:address_search_using_ids] [parser:libpostal] [param:sources]']);
     t.end();
 
   });