From 0a9c0f1e2fd1356f9d946f9ded6dccd7dd044a50 Mon Sep 17 00:00:00 2001 From: Conrado Quilles Gomes Date: Sat, 3 Oct 2015 20:13:19 -0300 Subject: [PATCH] Organizes the Readme.md, puts logging before error logging and separate logging options from error logging options. Add baseMeta and metaField to better control how meta is send to winston, allowing better logging features when using external logger as loggly. Corrects minor typo in test-coverage script command at package.json. Add tests for the metaField option. --- Readme.md | 69 +++++++++++++++++++++-------------- index.js | 36 +++++++++++++++---- package.json | 2 +- test/test.js | 100 ++++++++++++++++++++++++++++++++++++++++++++++++++- 4 files changed, 172 insertions(+), 35 deletions(-) diff --git a/Readme.md b/Readme.md index 475cf67..e5a73fa 100644 --- a/Readme.md +++ b/Readme.md @@ -39,64 +39,81 @@ var winston = require('winston'), expressWinston = require('express-winston'); ``` -### Error Logging +### Request Logging -Use `expressWinston.errorLogger(options)` to create a middleware that log the errors of the pipeline. +Use `expressWinston.logger(options)` to create a middleware to log your HTTP requests. ``` js var router = require('./my-express-router'); - app.use(router); // notice how the router goes first. - app.use(expressWinston.errorLogger({ + app.use(expressWinston.logger({ transports: [ new winston.transports.Console({ json: true, colorize: true }) - ] + ], + meta: true, // optional: control whether you want to log the meta data about the request (default to true) + msg: "HTTP {{req.method}} {{req.url}}", // optional: customize the default logging message. E.g. "{{res.statusCode}} {{req.method}} {{res.responseTime}}ms {{req.url}}" + expressFormat: true, // Use the default Express/morgan request formatting, with the same colors. Enabling this will override any msg and colorStatus if true. Will only output colors on transports with colorize set to true + colorStatus: true, // Color the status code, using the Express/morgan color palette (default green, 3XX cyan, 4XX yellow, 5XX red). Will not be recognized if expressFormat is true + ignoreRoute: function (req, res) { return false; } // optional: allows to skip some log messages based on request and/or response })); -``` -The logger needs to be added AFTER the express router(`app.router)`) and BEFORE any of your custom error handlers(`express.handler`). Since express-winston will just log the errors and not __handle__ them, you can still use your custom error handler like `express.handler`, just be sure to put the logger before any of your handlers. + app.use(router); // notice how the router goes after the logger. +``` -### Options +#### Options ``` js transports: [], // list of all winston transports instances to use. - winstonInstance: , // a winston logger instance. If this is provided the transports option is ignored + winstonInstance: , // a winston logger instance. If this is provided the transports option is ignored. level: String, // log level to use, the default is "info". + msg: String // customize the default logging message. E.g. "{{res.statusCode}} {{req.method}} {{res.responseTime}}ms {{req.url}}", "HTTP {{req.method}} {{req.url}}". + expressFormat: Boolean, // Use the default Express/morgan request formatting, with the same colors. Enabling this will override any msg and colorStatus if true. Will only output colors on transports with colorize set to true + colorStatus: Boolean, // Color the status code, using the Express/morgan color palette (default green, 3XX cyan, 4XX yellow, 5XX red). Will not be recognized if expressFormat is true + meta: Boolean, // control whether you want to log the meta data about the request (default to true). + baseMeta: Object, // default meta data to be added to log, this will be merged with the meta data. + metaField: String, // if defined, the meta data will be added in this field instead of the meta root object. statusLevels: Boolean // different HTTP status codes caused log messages to be logged at different levels (info/warn/error), the default is false - skip: function(req, res) // function to determine if logging is skipped, defaults to false + ignoreRoute: function (req, res) { return false; } // allows to skip some log messages based on request and/or response. + skip: function(req, res) { return false; } // function to determine if logging is skipped, defaults to false. ``` -To use winston's existing transports, set `transports` to the values (as in key-value) of the `winston.default.transports` object. This may be done, for example, by using underscorejs: `transports: _.values(winston.default.transports)`. - -Alternatively, if you're using a winston logger instance elsewhere and have already set up levels and transports, pass the instance into expressWinston with the `winstonInstance` option. The `transports` option is then ignored. - -### Request Logging +### Error Logging -Use `expressWinston.logger(options)` to create a middleware to log your HTTP requests. +Use `expressWinston.errorLogger(options)` to create a middleware that log the errors of the pipeline. ``` js var router = require('./my-express-router'); - app.use(expressWinston.logger({ + app.use(router); // notice how the router goes first. + app.use(expressWinston.errorLogger({ transports: [ new winston.transports.Console({ json: true, colorize: true }) - ], - meta: true, // optional: control whether you want to log the meta data about the request (default to true) - msg: "HTTP {{req.method}} {{req.url}}", // optional: customize the default logging message. E.g. "{{res.statusCode}} {{req.method}} {{res.responseTime}}ms {{req.url}}" - expressFormat: true, // Use the default Express/morgan request formatting, with the same colors. Enabling this will override any msg and colorStatus if true. Will only output colors on transports with colorize set to true - colorStatus: true, // Color the status code, using the Express/morgan color palette (default green, 3XX cyan, 4XX yellow, 5XX red). Will not be recognized if expressFormat is true - ignoreRoute: function (req, res) { return false; } // optional: allows to skip some log messages based on request and/or response + ] })); +``` - app.use(router); // notice how the router goes after the logger. +The logger needs to be added AFTER the express router(`app.router)`) and BEFORE any of your custom error handlers(`express.handler`). Since express-winston will just log the errors and not __handle__ them, you can still use your custom error handler like `express.handler`, just be sure to put the logger before any of your handlers. + +#### Options + +``` js + transports: [], // list of all winston transports instances to use. + winstonInstance: , // a winston logger instance. If this is provided the transports option is ignored + msg: String // customize the default logging message. E.g. "{{res.statusCode}} {{req.method}} {{res.responseTime}}ms {{req.url}}", "HTTP {{req.method}} {{req.url}}". + baseMeta: Object, // default meta data to be added to log, this will be merged with the error data. + metaField: String, // if defined, the meta data will be added in this field instead of the meta root object. ``` +To use winston's existing transports, set `transports` to the values (as in key-value) of the `winston.default.transports` object. This may be done, for example, by using underscorejs: `transports: _.values(winston.default.transports)`. + +Alternatively, if you're using a winston logger instance elsewhere and have already set up levels and transports, pass the instance into expressWinston with the `winstonInstance` option. The `transports` option is then ignored. + ## Examples ``` js @@ -354,11 +371,11 @@ Run the basic Mocha tests: Run the Travis-CI tests (which will fail with < 100% coverage): - npm test-travis + npm run test-travis Generate the `coverage.html` coverage report: - npm test-coverage + npm run test-coverage ## Issues and Collaboration diff --git a/index.js b/index.js index d7f0dff..d2916de 100644 --- a/index.js +++ b/index.js @@ -121,6 +121,8 @@ function errorLogger(options) { options.requestFilter = options.requestFilter || defaultRequestFilter; options.winstonInstance = options.winstonInstance || (new winston.Logger ({ transports: options.transports })); options.msg = options.msg || 'middlewareError'; + options.baseMeta = options.baseMeta || {}; + options.metaField = options.metaField || null; // Using mustache style templating var template = _.template(options.msg, null, { @@ -133,6 +135,14 @@ function errorLogger(options) { var exceptionMeta = winston.exception.getAllInfo(err); exceptionMeta.req = filterObject(req, requestWhitelist, options.requestFilter); + if (options.metaField) { + var newMeta = {}; + newMeta[options.metaField] = exceptionMeta; + exceptionMeta = newMeta; + } + + exceptionMeta = _.extend(exceptionMeta, options.baseMeta); + // This is fire and forget, we don't want logging to hold up the request so don't wait for the callback options.winstonInstance.log('error', template({err: err, req: req, res: res}), exceptionMeta); @@ -157,6 +167,8 @@ function logger(options) { options.level = options.level || "info"; options.statusLevels = options.statusLevels || false; options.msg = options.msg || "HTTP {{req.method}} {{req.url}}"; + options.baseMeta = options.baseMeta || {}; + options.metaField = options.metaField || null; options.colorStatus = options.colorStatus || false; options.expressFormat = options.expressFormat || false; options.ignoreRoute = options.ignoreRoute || function () { return false; }; @@ -212,24 +224,25 @@ function logger(options) { var meta = {}; if(options.meta !== false) { + var logData = {}; var bodyWhitelist, blacklist; requestWhitelist = requestWhitelist.concat(req._routeWhitelists.req || []); responseWhitelist = responseWhitelist.concat(req._routeWhitelists.res || []); - meta.res = res; + logData.res = res; if (_.contains(responseWhitelist, 'body')) { if (chunk) { var isJson = (res._headers && res._headers['content-type'] && res._headers['content-type'].indexOf('json') >= 0); - meta.res.body = isJson ? JSON.parse(chunk) : chunk.toString(); + logData.res.body = isJson ? JSON.parse(chunk) : chunk.toString(); } } - meta.req = filterObject(req, requestWhitelist, options.requestFilter); - meta.res = filterObject(res, responseWhitelist, options.responseFilter); + logData.req = filterObject(req, requestWhitelist, options.requestFilter); + logData.res = filterObject(res, responseWhitelist, options.responseFilter); bodyWhitelist = req._routeWhitelists.body || []; blacklist = _.union(bodyBlacklist, (req._routeBlacklists.body || [])); @@ -244,12 +257,21 @@ function logger(options) { filteredBody = filterObject(req.body, bodyWhitelist, options.requestFilter); } } - - if (filteredBody) meta.req.body = filteredBody; - meta.responseTime = res.responseTime; + if (filteredBody) logData.req.body = filteredBody; + + logData.responseTime = res.responseTime; + + if (options.metaField) { + var newMeta = {} + newMeta[options.metaField] = logData; + logData = newMeta; + } + meta = _.extend(meta, logData); } + meta = _.extend(meta, options.baseMeta); + if(options.expressFormat) { var msg = chalk.grey(req.method + " " + req.url || req.url) + " " + chalk[statusColor](res.statusCode) diff --git a/package.json b/package.json index f7b2069..d310975 100644 --- a/package.json +++ b/package.json @@ -30,7 +30,7 @@ "scripts": { "test": "node_modules/.bin/mocha --reporter spec", "test-travis": "node_modules/.bin/mocha --require blanket --reporter travis-cov", - "test-coverage": "node_modules/.bin/mocha --require blanket --reporter html-cov >| coverage.html || true" + "test-coverage": "node_modules/.bin/mocha --require blanket --reporter html-cov > coverage.html || true" }, "config": { "travis-cov": { diff --git a/test/test.js b/test/test.js index 79b54cc..da2d47f 100644 --- a/test/test.js +++ b/test/test.js @@ -194,6 +194,46 @@ describe('expressWinston', function () { }); }); }); + + describe('log.metaField', function (done) { + var result; + + before(function (done) { + setUp(); + + var originalError = new Error('This is the Error'); + + var test = { + req: req, + res: res, + log: {}, + originalError: originalError, + pipelineError: null + }; + + function next(pipelineError) { + test.pipelineError = pipelineError; + + result = test; + + return done(); + }; + + var middleware = expressWinston.errorLogger({ + transports: [new MockTransport(test)], + metaField: 'metaField' + }); + + middleware(originalError, req, res, next); + }); + + describe('when using custom metaField', function () { + + it('should be logged', function () { + result.log.meta.metaField.req.should.be.ok; + }); + }); + }); }); describe('.logger()', function () { @@ -588,7 +628,7 @@ describe('expressWinston', function () { }); }); }); - + describe('log.skip', function () { var result; @@ -655,6 +695,64 @@ describe('expressWinston', function () { }); }); }); + + describe('log.metaField', function () { + var result; + + function logMetaFieldSetup(url, metaField, done) { + setUp({ + url: url || '/an-url' + }); + + var test = { + req: req, + res: res, + log: {} + }; + + function next(_req, _res, next) { + res.end('{ "message": "Hi! I\'m a chunk!" }'); + + result = test; + + return done(); + }; + + var loggerOptions = { + transports: [new MockTransport(test)] + }; + + if (metaField) { + loggerOptions.metaField = metaField; + } + + var middleware = expressWinston.logger(loggerOptions); + + middleware(req, res, next); + } + + describe('when default', function () { + + before(function (done) { + logMetaFieldSetup('/url-of-sandwich', null, done); + }); + + it('should be logged', function () { + result.log.meta.req.should.be.ok; + }); + }); + + describe('when using custom metaField', function () { + + before(function (done) { + logMetaFieldSetup('/url-of-sandwich', 'metaField', done); + }); + + it('should be logged', function () { + result.log.meta.metaField.req.should.be.ok; + }); + }); + }); }); }); });