Browse Source

feat(log): Use structured logs for place endpoint

pull/1220/head
Julian Simioni 6 years ago
parent
commit
a1add3656e
No known key found for this signature in database
GPG Key ID: B9EEB0C6EE0910A1
  1. 19
      controller/place.js
  2. 7
      service/mget.js
  3. 11
      test/unit/controller/place.js
  4. 5
      test/unit/controller/search.js

19
controller/place.js

@ -47,12 +47,21 @@ function setup( apiConfig, esclient ){
operation.attempt((currentAttempt) => {
const initialTime = debugLog.beginTimer(req);
mgetService( esclient, cmd, function( err, docs ) {
mgetService( esclient, cmd, function( err, docs, data) {
const message = {
controller: 'place',
queryType: 'place',
result_count: _.get(data, 'docs.length'),
response_time: _.get(data, 'response_time', undefined),
params: req.clean,
retries: currentAttempt - 1
};
logger.info('elasticsearch', message);
// returns true if the operation should be attempted again
// (handles bookkeeping of maxRetries)
// only consider for status 408 (request timeout)
if (isRequestTimeout(err) && operation.retry(err)) {
logger.info(`request timed out on attempt ${currentAttempt}, retrying`);
debugLog.stopTimer(req, initialTime, `request timed out on attempt ${currentAttempt}, retrying`);
return;
}
@ -73,12 +82,6 @@ function setup( apiConfig, esclient ){
}
// set response data
else {
// log that a retry was successful
// most requests succeed on first attempt so this declutters log files
if (currentAttempt > 1) {
logger.info(`succeeded on retry ${currentAttempt-1}`);
}
res.data = docs;
}
logger.debug('[ES response]', docs);

7
service/mget.js

@ -22,7 +22,12 @@ function service( esclient, query, cb ){
};
// query elasticsearch
const startTime = new Date();
esclient.mget( cmd, function( err, data ){
if (data) {
data.response_time = new Date() - startTime;
}
// handle elasticsearch errors
if( err ){
logger.error( `elasticsearch error ${err}`);
@ -50,7 +55,7 @@ function service( esclient, query, cb ){
}
// fire callback
return cb( null, docs );
return cb( null, docs, data );
});
}

11
test/unit/controller/place.js

@ -1,3 +1,4 @@
const _ = require('lodash');
const setup = require('../../../controller/place');
const proxyquire = require('proxyquire').noCallThru();
@ -177,8 +178,8 @@ module.exports.tests.timeout = function(test, common) {
get: (service) => {
t.equal(service, 'api');
return {
info: (msg) => {
infoMesssages.push(msg);
info: (msg, json) => {
infoMesssages.push({ msg:msg, json:json});
},
debug: () => {}
};
@ -203,9 +204,9 @@ module.exports.tests.timeout = function(test, common) {
const next = () => {
t.equal(searchServiceCallCount, 3+1);
t.ok(infoMesssages.indexOf('request timed out on attempt 1, retrying') !== -1);
t.ok(infoMesssages.indexOf('request timed out on attempt 2, retrying') !== -1);
t.ok(infoMesssages.indexOf('request timed out on attempt 3, retrying') !== -1);
t.ok(infoMesssages.find(function(msg) {
return _.get(msg, 'json.retries', 2);
}));
t.deepEqual(req.errors, [timeoutError.message]);
t.deepEqual(res, {});

5
test/unit/controller/search.js

@ -268,8 +268,7 @@ module.exports.tests.success = function(test, common) {
t.deepEquals(res.meta, { key: 'value', query_type: 'this is the query type' });
t.ok(infoMesssages.find((msg) => {
console.log(msg);
return _.get(msg, 'json.retries') === 3;
return _.get(msg, 'json.retries') === 2;
}));
t.end();
@ -337,7 +336,7 @@ module.exports.tests.timeout = function(test, common) {
t.equal(searchServiceCallCount, 3+1);
t.ok(infoMesssages.find(function(msg) {
return _.get(msg, 'json.retries') === 3;
return _.get(msg, 'json.retries') === 2;
}));
t.deepEqual(req, {

Loading…
Cancel
Save