Skip to content

Commit

Permalink
Add ability to set log level by configuration with statuscode
Browse files Browse the repository at this point in the history
  • Loading branch information
Alex Ugol authored and Alex Ugol committed Nov 5, 2018
1 parent a1b37a3 commit ed2f32b
Show file tree
Hide file tree
Showing 7 changed files with 2,013 additions and 180 deletions.
20 changes: 20 additions & 0 deletions README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -118,6 +118,26 @@ Array of strings - pass the header names you wish to exclude from the audit (sen

Array of strings - pass the fields you wish to mask in the headers of the responses (senstitive data like authorization headers etc..).

##### levels

Map of statusCodes to log levels. By default the audit is logged with level 'info'. It is possible to override it by configuration according to the statusCode of the response:

- Key: status code, or status code group: '2xx', '401', etc..
- Value: log level, valid values: 'trace', 'debug', 'info', 'warn', 'error'.
- Configuration errors are ignored and the log is info by default.


Example:
```
levels: {
"2xx":"info", // All 2xx responses are info
"401":"warn", // 401 are warn
"4xx':info", // All 4xx exceprt 401 are info
"503":"warn",
"5xx":"error" // All 5xx except 503 are errors, 503 is warn,
}
```


### Example

Expand Down
30 changes: 17 additions & 13 deletions lib/express-logger.js
View file
Original file line number Diff line number Diff line change
@@ -1,32 +1,32 @@
'use strict';

var _ = require('lodash'),
logger = require('bunyan').createLogger({name: 'ExpressLogger'}),
logger = require('bunyan').createLogger({ name: 'ExpressLogger' }),
loggerHelper = require('./logger-helper'),
setupOptions,
flatten = require('flat');

var audit = function (req, res, next){
var audit = function (req, res, next) {
var oldWrite = res.write;
var oldEnd = res.end;
var chunks = [];

// Log start time of request processing
req.timestamp = new Date();

if (setupOptions.doubleAudit){
if (setupOptions.doubleAudit) {
loggerHelper.auditRequest(req, setupOptions);
}

res.write = function (chunk){
res.write = function (chunk) {
chunks.push(new Buffer(chunk));
oldWrite.apply(res, arguments);
};

// decorate response#end method from express
res.end = function (chunk){
res.end = function (chunk) {
res.timestamp = new Date();
if (chunk){
if (chunk) {
chunks.push(new Buffer(chunk));
}

Expand All @@ -41,7 +41,7 @@ var audit = function (req, res, next){
next();
};

module.exports = function(options){
module.exports = function (options) {
options = options || {};
var defaults = {
logger: logger,
Expand All @@ -61,7 +61,13 @@ module.exports = function(options){
excludeHeaders: []
},
doubleAudit: false,
excludeURLs: []
excludeURLs: [],
levels: {
'2xx': 'info',
'3xx': 'info',
'4xx': 'info',
'5xx': 'info'
}
};

_.defaultsDeep(options, defaults);
Expand All @@ -70,13 +76,11 @@ module.exports = function(options){
};

//convert all options fields that need to be array by default
function validateArrayFields(options, defaults)
{
function validateArrayFields(options, defaults) {
Object.keys(flatten(options)).forEach((key) => {
let optionValue = _.get(options, key);
let defaultValue =_.get(defaults, key)
if(_.isArray(defaultValue) && !_.isArray(optionValue))
{
let defaultValue = _.get(defaults, key)
if (_.isArray(defaultValue) && !_.isArray(optionValue)) {
_.set(options, key, [optionValue]);
}
});
Expand Down
62 changes: 33 additions & 29 deletions lib/logger-helper.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,18 +4,19 @@ var utils = require('./utils');
var _ = require('lodash');
var ALL_FIELDS = '*';
const NA = 'N/A';
const DEFAULT_LOG_LEVEL = 'info';

var auditRequest = function(req, options){
var auditRequest = function (req, options) {
var shouldAudit = utils.shouldAuditURL(options.excludeURLs, req);

if (shouldAudit){
if (shouldAudit) {
var request;

if (options.setupFunc){
if (options.setupFunc) {
options.setupFunc(req, res);
}

if (options.request.audit){
if (options.request.audit) {
request = getRequestAudit(req, options);
}

Expand All @@ -24,29 +25,29 @@ var auditRequest = function(req, options){
};

// Add additional audit fields
if (req && req.additionalAudit){
if (req && req.additionalAudit) {
auditObject = Object.assign(auditObject, req.additionalAudit);
}

options.logger.info(auditObject, 'Inbound Transaction');
}
};

var auditResponse = function(req, res, options){
var auditResponse = function (req, res, options) {
var request;
var response;

var shouldAudit = utils.shouldAuditURL(options.excludeURLs, req);
if (shouldAudit){
if (options.setupFunc){
if (shouldAudit) {
if (options.setupFunc) {
options.setupFunc(req, res);
}

if (options.request.audit){
if (options.request.audit) {
request = getRequestAudit(req, options);
}

if (options.response.audit){
if (options.response.audit) {
response = getResponseAudit(req, res, options);
}

Expand All @@ -56,15 +57,21 @@ var auditResponse = function(req, res, options){
};

// Add additional audit fields
if (req && req.additionalAudit){
if (req && req.additionalAudit) {
auditObject = Object.assign(auditObject, req.additionalAudit);
}

options.logger.info(auditObject, 'Inbound Transaction');
let level = DEFAULT_LOG_LEVEL; // Default
if (res) {
// Make ssure the resolved log level is supported by our logger:
let resolvedLogLevel = utils.getLogLevel(res.statusCode, options.levels);
level = options.logger[resolvedLogLevel] ? resolvedLogLevel : level;
}
options.logger[level](auditObject, 'Inbound Transaction');
}
};

function getRequestAudit(req, options){
function getRequestAudit(req, options) {
var headers = _.get(req, 'headers');
var requestFullURL = utils.getUrl(req);
var requestRoute = utils.getRoute(req);
Expand All @@ -73,7 +80,7 @@ function getRequestAudit(req, options){
var URLParams = req && req.params ? req.params : NA;
var timestamp = req && req.timestamp ? req.timestamp.toISOString() : NA;
var timestamp_ms = req && req.timestamp ? req.timestamp.valueOf() : NA;
var requestBody = _.get(req, 'body'); //handle body clone the original body
var requestBody = _.get(req, 'body'); //handle body clone the original body

requestBody = handleJson(requestBody, options.logger, options.request.excludeBody, options.request.maskBody);

Expand All @@ -87,37 +94,34 @@ function getRequestAudit(req, options){
url: requestFullURL,
url_route: requestRoute,
query: queryParams,
headers: _.isEmpty(headers) ? NA: headers,
headers: _.isEmpty(headers) ? NA : headers,
timestamp: timestamp,
timestamp_ms: timestamp_ms,
body: _.isEmpty(requestBody) ? NA: JSON.stringify(requestBody)
body: _.isEmpty(requestBody) ? NA : JSON.stringify(requestBody)
};

return auditObject;
}

function handleJson(obj, logger, excludeFields, maskFields) {

if(_.includes(excludeFields, ALL_FIELDS))
{
if (_.includes(excludeFields, ALL_FIELDS)) {
obj = undefined;
}
else if(obj)
{
else if (obj) {
try {
//in case obj is string and need to convert to json
if(typeof obj == 'string') {
if (typeof obj == 'string') {
obj = JSON.parse(obj);
}
else if(typeof obj != 'object')
{
else if (typeof obj != 'object') {
throw new Error('only json obj can be exclude/masked');
}

//order is important because body is clone first
obj = utils.maskJson(obj, maskFields);
obj = utils.cleanOmitKeys(obj, excludeFields);
} catch (err){
} catch (err) {
logger.warn('Error parsing json: ' + err);
obj = undefined;
}
Expand All @@ -129,17 +133,17 @@ function handleJson(obj, logger, excludeFields, maskFields) {



function getResponseAudit(req, res, options){
function getResponseAudit(req, res, options) {
var headers = _.get(res, '_headers');
var elapsed = req && res ? res.timestamp - req.timestamp : 0;
var timestamp = res && res.timestamp ? res.timestamp.toISOString() : NA;
var timestamp_ms = res && res.timestamp ? res.timestamp.valueOf() : NA;
var statusCode = res && res.statusCode ? res.statusCode : NA;
var responseBody = _.get(res, '_body'); //no need to clone because its not the original body
var responseBody = _.get(res, '_body'); //no need to clone because its not the original body

if (headers && headers['content-type'] && headers['content-type'].includes('application/json')) {
// Handle JSON only for json responses:
responseBody = handleJson(responseBody, options.logger , options.response.excludeBody, options.response.maskBody);
responseBody = handleJson(responseBody, options.logger, options.response.excludeBody, options.response.maskBody);
}

headers = handleJson(headers, options.logger, options.response.excludeHeaders, options.response.maskHeaders);
Expand All @@ -149,8 +153,8 @@ function getResponseAudit(req, res, options){
timestamp: timestamp,
timestamp_ms: timestamp_ms,
elapsed: elapsed,
headers: _.isEmpty(headers) ? NA: headers,
body: _.isEmpty(responseBody) ? NA: JSON.stringify(responseBody)
headers: _.isEmpty(headers) ? NA : headers,
body: _.isEmpty(responseBody) ? NA : JSON.stringify(responseBody)
};

return auditObject;
Expand Down
39 changes: 29 additions & 10 deletions lib/utils.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,27 +3,29 @@
var _ = require('lodash');
const MASK = 'XXXXX';
const NA = 'N/A';
const VALID_LEVELS = ['trace', 'debug', 'info', 'warn', 'error']
const DEFAULT_LEVEL = 'info';

var getUrl = function(req){
var getUrl = function (req) {
var url = req && req.url || NA;

return url;
};

var getRoute = function(req) {
var getRoute = function (req) {
var url = NA;

if (req){
if (req) {
var route = req.baseUrl;
if (req.route && route){
if (req.route && route) {
url = route + req.route.path;
}
}

return url;
};

function cleanOmitKeys (obj, omitKeys) {
function cleanOmitKeys(obj, omitKeys) {
if (obj && !_.isEmpty(omitKeys)) {
Object.keys(obj).forEach(function (key) {
if (_.some(omitKeys, omitKey => key === omitKey)) {
Expand All @@ -36,15 +38,15 @@ function cleanOmitKeys (obj, omitKeys) {
return obj;
};

var shouldAuditURL = function(excludeURLs, req){
return _.every(excludeURLs, function(path){
var shouldAuditURL = function (excludeURLs, req) {
return _.every(excludeURLs, function (path) {
var url = getUrl(req);
var route = getRoute(req);
return !(url.includes(path) || route.includes(path));
});
};

var maskJson = function(jsonObj, fieldsToMask){
var maskJson = function (jsonObj, fieldsToMask) {
let jsonObjCopy = _.cloneDeepWith(jsonObj, function (value, key) {
if (_.includes(fieldsToMask, key)) {
return MASK
Expand All @@ -53,11 +55,28 @@ var maskJson = function(jsonObj, fieldsToMask){
return jsonObjCopy;
};

var getLogLevel = function (statusCode, levelsMap) {
let level = DEFAULT_LEVEL; // Default

if (levelsMap) {
let status = statusCode.toString();

if (levelsMap[status]) {
level = VALID_LEVELS.includes(levelsMap[status]) ? levelsMap[status] : level;
} else {
let statusGroup = `${status.substring(0, 1)}xx`; // 5xx, 4xx, 2xx, etc..
level = VALID_LEVELS.includes(levelsMap[statusGroup]) ? levelsMap[statusGroup] : level;
}
}

return level;
}

module.exports = {
getRoute: getRoute,
getUrl: getUrl,
shouldAuditURL: shouldAuditURL,
maskJson:maskJson,
cleanOmitKeys:cleanOmitKeys
maskJson: maskJson,
cleanOmitKeys: cleanOmitKeys,
getLogLevel: getLogLevel
};

0 comments on commit ed2f32b

Please sign in to comment.