feat: Merge pull request #751 from pelias/improved_logging

Improved logging

controller/place.js

@@ -1,5 +1,5 @@
 var service = { mget: require('../service/mget') };
-var logger = require('pelias-logger').get('api:controller:place');
+var logger = require('pelias-logger').get('api');
 
 function setup( config, backend ){
 

controller/search.js

@@ -1,7 +1,7 @@
 var _ = require('lodash');
 
 var service = { search: require('../service/search') };
-var logger = require('pelias-logger').get('api:controller:search');
+var logger = require('pelias-logger').get('api');
 var logging = require( '../helper/logging' );
 
 function setup( config, backend, query ){

middleware/500.js

@@ -1,13 +1,19 @@
-var logger = require( 'pelias-logger' ).get( 'middleware-500' );
+var check = require('check-types'),
+    logger = require( 'pelias-logger' ).get( 'api' );
 
 // handle application errors
 function middleware(err, req, res, next) {
+
   logger.error( 'Error: `%s`. Stack trace: `%s`.', err, err.stack );
-  res.header('Cache-Control','public');
-  var error = (err && err.message) ? err.message : err;
 
-  if( res.statusCode < 400 ){ res.status(500); }
-  res.json({ error: typeof error === 'string' ? error : 'internal server error' });
+  if( res.statusCode < 400 ){
+    logger.info( 'status code changed from', res.statusCode, 'to 500' );
+    res.status(500);
+  }
+
+  var error = ( err && err.message ) ? err.message : err;
+  res.header('Cache-Control','public');
+  res.json({ error: check.nonEmptyString( error ) ? error : 'internal server error' });
 }
 
 module.exports = middleware;

middleware/confidenceScoreFallback.js

@@ -10,7 +10,7 @@
  */
 
 var check = require('check-types');
-var logger = require('pelias-logger').get('api-confidence');
+var logger = require('pelias-logger').get('api');
 
 function setup() {
   return computeScores;

middleware/sendJSON.js

@@ -1,5 +1,6 @@
 var check = require('check-types'),
     es = require('elasticsearch'),
+    logger = require( 'pelias-logger' ).get( 'api' ),
     exceptions = require('elasticsearch-exceptions/lib/exceptions/SupportedExceptions');
 
 // create a list of regular expressions to match against.
@@ -42,7 +43,10 @@ function sendJSONResponse(req, res, next) {
         if( err instanceof es.errors.RequestTimeout ){ statusCode = Math.max( statusCode, 408 ); }
         else if( err instanceof es.errors.NoConnections ){ statusCode = Math.max( statusCode, 502 ); }
         else if( err instanceof es.errors.ConnectionFault ){ statusCode = Math.max( statusCode, 502 ); }
-        else { statusCode = Math.max( statusCode, 500 ); }
+        else {
+          logger.warn( 'unknown geocoding error object:', err.constructor.name, err );
+          statusCode = Math.max( statusCode, 500 );
+        }
 
       /*
         some elasticsearch errors are only returned as strings (not instances of Error).
@@ -55,7 +59,10 @@ function sendJSONResponse(req, res, next) {
             statusCode = Math.max( statusCode, 500 );
             break; // break on first match
           }
+          logger.warn( 'unknown geocoding error string:', err );
         }
+      } else {
+        logger.warn( 'unknown geocoding error type:', typeof err, err );
       }
     });
   }

sanitizer/search_fallback.js

@@ -4,7 +4,7 @@ var sanitizeAll = require('../sanitizer/sanitizeAll'),
     };
 
 var sanitize = function(req, cb) { sanitizeAll(req, sanitizers, cb); };
-var logger = require('pelias-logger').get('api:controller:search_fallback');
+var logger = require('pelias-logger').get('api');
 var logging = require( '../helper/logging' );
 
 // middleware

service/mget.js

@@ -11,7 +11,7 @@
 
 **/
 
-var peliasLogger = require( 'pelias-logger' ).get( 'service/mget' );
+var logger = require( 'pelias-logger' ).get( 'api' );
 
 function service( backend, query, cb ){
 
@@ -24,8 +24,17 @@ function service( backend, query, cb ){
 
   // query new backend
   backend().client.mget( cmd, function( err, data ){
+
+    // log total ms elasticsearch reported the query took to execute
+    if( data && data.took ){
+      logger.verbose( 'time elasticsearch reported:', data.took / 1000 );
+    }
+
     // handle backend errors
-    if( err ){ return cb( err ); }
+    if( err ){
+      logger.error( 'backend error', err );
+      return cb( err );
+    }
 
     // map returned documents
     var docs = [];

service/search.js

@@ -5,18 +5,23 @@
 
 **/
 
-var peliasLogger = require( 'pelias-logger' ).get( 'service/search' );
+var logger = require( 'pelias-logger' ).get( 'api' );
 
 function service( backend, cmd, cb ){
 
   // query new backend
   backend().client.search( cmd, function( err, data ){
 
-    // handle backend errors
-    if( err ){ return cb( err ); }
-
     // log total ms elasticsearch reported the query took to execute
-    peliasLogger.verbose( 'time elasticsearch reported:', data.took / 1000 );
+    if( data && data.took ){
+      logger.verbose( 'time elasticsearch reported:', data.took / 1000 );
+    }
+
+    // handle backend errors
+    if( err ){
+      logger.error( 'backend error', err );
+      return cb( err );
+    }
 
     // map returned documents
     var docs = [];