Log the time spent in each elasticsearch query.

service/mget.js

@@ -11,6 +11,9 @@
 
 **/
 
+var peliasLogger = require( 'pelias-logger' ).get( 'service/mget' );
+var microtime = require( 'microtime' );
+
 function service( backend, query, cb ){
 
   // backend command
@@ -20,8 +23,10 @@ function service( backend, query, cb ){
     }
   };
   
+  var startTime = microtime.nowDouble();
   // query new backend
   backend().client.mget( cmd, function( err, data ){
+    peliasLogger.verbose( 'time elasticsearch query took:', microtime.nowDouble() - startTime );
 
     // handle backend errors
     if( err ){ return cb( err ); }
@@ -52,4 +57,4 @@ function service( backend, query, cb ){
 
 }
 
-module.exports = service;
+module.exports = service;

service/search.js

@@ -5,10 +5,15 @@
 
 **/
 
+var peliasLogger = require( 'pelias-logger' ).get( 'service/search' );
+var microtime = require( 'microtime' );
+
 function service( backend, cmd, cb ){
   
+  var startTime = microtime.nowDouble();
   // query new backend
   backend().client.search( cmd, function( err, data ){
+    peliasLogger.verbose( 'time elasticsearch query took:', microtime.nowDouble() - startTime );
 
     // handle backend errors
     if( err ){ return cb( err ); }
@@ -33,4 +38,4 @@ function service( backend, cmd, cb ){
 
 }
 
-module.exports = service;
+module.exports = service;

service/suggest.js

@@ -4,10 +4,15 @@
   cmd can be any valid ES suggest command
 
 **/
+var peliasLogger = require( 'pelias-logger' ).get( 'service/suggest' );
+
+var microtime = require( 'microtime' );
 
 function service( backend, cmd, cb ){
   // query new backend
+  var startTime = microtime.nowDouble();
   backend().client.suggest( cmd, function( err, data ){
+    peliasLogger.verbose( 'time elasticsearch query took:', microtime.nowDouble() - startTime );
     // handle backend errors
     if( err ){ return cb( err ); }
     
@@ -40,4 +45,4 @@ function service( backend, cmd, cb ){
 
 }
 
-module.exports = service;
+module.exports = service;