diff --git a/app.js b/app.js index 824bf33..326e849 100755 --- a/app.js +++ b/app.js @@ -9,7 +9,6 @@ */ 'use strict'; const express = require('express'); -// const logger = require('morgan'); const cookieParser = require('cookie-parser'); const bodyParser = require('body-parser'); const healthcheck = require('topcoder-healthcheck-dropin'); @@ -61,20 +60,16 @@ app.use((err, req, res, next) => { // eslint-disable-line no-unused-vars }); process.on('uncaughtException', (err) => { - // logger.error('Exception: ', err); // Check if error related to Dynamodb conn if (err.code === 'NetworkingError' && err.region) { logger.error('DynamoDB connection failed.'); } logger.logFullError(err, 'system'); - // console.log(err); }); // handle and log unhanled rejection process.on('unhandledRejection', (err) => { - // logger.error('Rejection: ', err); logger.logFullError(err, 'system'); - // console.log(err); }); module.exports = app; diff --git a/package.json b/package.json index 4ceeaed..61669cb 100755 --- a/package.json +++ b/package.json @@ -16,11 +16,12 @@ "debug": "^2.6.9", "dynamoose": "^1.1.0", "express": "^4.17.1", + "get-parameter-names": "^0.3.0", + "global-request-logger": "^0.1.1", "joi": "^11.4.0", - "morgan": "^1.9.1", "no-kafka": "^3.4.3", "topcoder-healthcheck-dropin": "^1.0.3", - "winston": "^2.4.2" + "winston": "^2.4.3" }, "devDependencies": { "eslint-config-topcoder": "^2.0.0", diff --git a/utils/GithubEventDetector.js b/utils/GithubEventDetector.js index 9e64126..7f1b49d 100644 --- a/utils/GithubEventDetector.js +++ b/utils/GithubEventDetector.js @@ -15,6 +15,7 @@ const Joi = require('joi'); const _ = require('lodash'); const models = require('../models'); +const logger = require('./logger'); const EventDetector = require('./EventDetector'); /** @@ -240,3 +241,5 @@ module.exports = new EventDetector('github', [ PullRequestCreatedEvent, PullRequestClosedEvent ]); + +logger.buildService(module.exports); diff --git a/utils/GitlabEventDetector.js b/utils/GitlabEventDetector.js index 44871d7..0ed17b7 100644 --- a/utils/GitlabEventDetector.js +++ b/utils/GitlabEventDetector.js @@ -14,6 +14,7 @@ const Joi = require('joi'); const _ = require('lodash'); const models = require('../models'); +const logger = require('./logger'); const EventDetector = require('./EventDetector'); /** @@ -272,3 +273,5 @@ module.exports = new EventDetector('gitlab', [ PullRequestCreatedEvent, PullRequestClosedEvent ]); + +logger.buildService(module.exports); diff --git a/utils/logger.js b/utils/logger.js index c3f8f39..272f94b 100755 --- a/utils/logger.js +++ b/utils/logger.js @@ -10,7 +10,11 @@ */ 'use strict'; const config = require('config'); +const util = require('util'); +const _ = require('lodash'); const winston = require('winston'); +const getParams = require('get-parameter-names'); +const globalLog = require('global-request-logger'); const logger = new winston.Logger({ transports: [ @@ -33,5 +37,94 @@ logger.logFullError = function logFullError(err, signature) { err.logged = true; }; +/** + * Remove invalid properties from the object and hide long arrays + * @param {Object} obj the object + * @returns {Object} the new object with removed properties + * @private + */ +function sanitizeObject(obj) { + try { + return JSON.parse(JSON.stringify(obj, (name, value) => { + // Array of field names that should not be logged + const removeFields = ['refreshToken', 'accessToken', 'access_token', 'authorization']; + if (_.includes(removeFields, name)) { + return ''; + } + if (_.isArray(value) && value.length > 30) { // eslint-disable-line + return `Array(${value.length}`; + } + return value; + })); + } catch (e) { + return obj; + } +} + +/** + * Convert array with arguments to object + * @param {Array} params the name of parameters + * @param {Array} arr the array with values + * @returns {Object} converted object + * @private + */ +function combineObject(params, arr) { + const ret = {}; + _.forEach(arr, (arg, i) => { + ret[params[i]] = arg; + }); + return ret; +} + +/** + * Decorate all functions of a service and log debug information if DEBUG is enabled + * @param {Object} service the service + */ +logger.decorateWithLogging = function decorateWithLogging(service) { + if (config.LOG_LEVEL !== 'debug') { + return; + } + _.forEach(service, (method, name) => { + const params = method.params || getParams(method); + service[name] = async function serviceMethodWithLogging() { + logger.debug(`ENTER ${name}`); + logger.debug('input arguments'); + const args = Array.prototype.slice.call(arguments); // eslint-disable-line + logger.debug(util.inspect(sanitizeObject(combineObject(params, args)))); + try { + const result = await method.apply(this, arguments); // eslint-disable-line + logger.debug(`EXIT ${name}`); + logger.debug('output arguments'); + logger.debug(util.inspect(sanitizeObject(result))); + return result; + } catch (e) { + logger.logFullError(e, name); + throw e; + } + }; + }); +}; + +/** + * Apply logger and validation decorators + * @param {Object} service the service to wrap + */ +logger.buildService = function buildService(service) { + logger.decorateWithLogging(service); +}; + +// globalLog.initialize(); + +// global any http success request interceptor +globalLog.on('success', (request, response) => { + logger.debug('Request', util.inspect(sanitizeObject(request))); + logger.debug('Response', util.inspect(sanitizeObject(response))); +}); + +// global any http error request interceptor +globalLog.on('error', (request, response) => { + logger.error('Request', util.inspect(sanitizeObject(request))); + logger.error('Response', util.inspect(sanitizeObject(response))); +}); module.exports = logger;