diff --git a/examples/example-connect-logger.js b/examples/example-connect-logger.js index b89dc9b..ed7b013 100644 --- a/examples/example-connect-logger.js +++ b/examples/example-connect-logger.js @@ -1,14 +1,46 @@ -var log4js = require('./lib/log4js'); -log4js.addAppender(log4js.fileAppender('cheese.log'), 'cheese'); +//The connect/express logger was added to log4js by danbell. This allows connect/express servers to log using log4js. +//https://github.com/nomiddlename/log4js-node/wiki/Connect-Logger -var logger = log4js.getLogger('cheese'); -logger.setLevel('INFO'); +// load modules +var log4js = require('log4js'); +var express = require("express"); +var app = express(); -var app = require('express').createServer(); +//config +log4js.configure({ + appenders: [ + { type: 'console' }, + { type: 'file', filename: 'logs/log4jsconnect.log', category: 'log4jslog' } + ] +}); + +//define logger +var logger = log4js.getLogger('log4jslog'); + +// set at which time msg is logged print like: only on error & above +// logger.setLevel('ERROR'); + +//express app app.configure(function() { - app.use(log4js.connectLogger(logger, { level: log4js.levels.INFO })); + app.use(express.favicon('')); + // app.use(log4js.connectLogger(logger, { level: log4js.levels.INFO })); + // app.use(log4js.connectLogger(logger, { level: 'auto', format: ':method :url :status' })); + + //### AUTO LEVEL DETECTION + //http responses 3xx, level = WARN + //http responses 4xx & 5xx, level = ERROR + //else.level = INFO + app.use(log4js.connectLogger(logger, { level: 'auto' })); }); -app.get('*', function(req,res) { - res.send('hello world\n cheese\n'); + +//route +app.get('/', function(req,res) { + res.send('hello world'); }); + +//start app app.listen(5000); + +console.log('server runing at localhost:5000'); +console.log('Simulation of normal response: goto localhost:5000'); +console.log('Simulation of error response: goto localhost:5000/xxx'); diff --git a/lib/connect-logger.js b/lib/connect-logger.js index 7758c37..5b8a94a 100644 --- a/lib/connect-logger.js +++ b/lib/connect-logger.js @@ -5,7 +5,7 @@ var levels = require("./levels"); * Options: * * - `format` Format string, see below for tokens - * - `level` A log4js levels instance. + * - `level` A log4js levels instance. Supports also 'auto' * * Tokens: * @@ -26,64 +26,74 @@ var levels = require("./levels"); * @api public */ -function getLogger(logger4js, options) { - if ('object' == typeof options) { - options = options || {}; - } else if (options) { - options = { format: options }; - } else { - options = {}; - } + function getLogger(logger4js, options) { + if ('object' == typeof options) { + options = options || {}; + } else if (options) { + options = { format: options }; + } else { + options = {}; + } - var thislogger = logger4js - , level = levels.toLevel(options.level, levels.INFO) - , fmt = options.format || ':remote-addr - - ":method :url HTTP/:http-version" :status :content-length ":referrer" ":user-agent"' - , nolog = options.nolog ? createNoLogCondition(options.nolog) : null; + var thislogger = logger4js + , level = levels.toLevel(options.level, levels.INFO) + , fmt = options.format || ':remote-addr - - ":method :url HTTP/:http-version" :status :content-length ":referrer" ":user-agent"' + , nolog = options.nolog ? createNoLogCondition(options.nolog) : null; - return function (req, res, next) { + return function (req, res, next) { // mount safety if (req._logging) return next(); - // nologs - if (nolog && nolog.test(req.originalUrl)) return next(); - - if (thislogger.isLevelEnabled(level)) { - - var start = +new Date - , statusCode - , writeHead = res.writeHead - , end = res.end - , url = req.originalUrl; - - // flag as logging - req._logging = true; - - // proxy for statusCode. - res.writeHead = function(code, headers){ - res.writeHead = writeHead; - res.writeHead(code, headers); - res.__statusCode = statusCode = code; - res.__headers = headers || {}; - }; - - // proxy end to output a line to the provided logger. - res.end = function(chunk, encoding) { - res.end = end; - res.end(chunk, encoding); - res.responseTime = +new Date - start; - if ('function' == typeof fmt) { - var line = fmt(req, res, function(str){ return format(str, req, res); }); - if (line) thislogger.log(level, line); - } else { - thislogger.log(level, format(fmt, req, res)); + // nologs + if (nolog && nolog.test(req.originalUrl)) return next(); + if (thislogger.isLevelEnabled(level) || options.level === 'auto') { + + var start = +new Date + , statusCode + , writeHead = res.writeHead + , end = res.end + , url = req.originalUrl; + + // flag as logging + req._logging = true; + + // proxy for statusCode. + res.writeHead = function(code, headers){ + res.writeHead = writeHead; + res.writeHead(code, headers); + res.__statusCode = statusCode = code; + res.__headers = headers || {}; + + //status code response level handling + if(options.level === 'auto'){ + level = levels.INFO; + if(code >= 300) level = levels.WARN; + if(code >= 400) level = levels.ERROR; + } else { + level = levels.toLevel(options.level, levels.INFO) + } + }; + + // proxy end to output a line to the provided logger. + res.end = function(chunk, encoding) { + res.end = end; + res.end(chunk, encoding); + res.responseTime = +new Date - start; + if (thislogger.isLevelEnabled(level)) { + if (typeof fmt === 'function') { + var line = fmt(req, res, function(str){ return format(str, req, res); }); + if (line) thislogger.log(level, line); + } else { + thislogger.log(level, format(fmt, req, res)); + } + } + }; } - }; - } //ensure next gets always called next(); - }; +}; } /** @@ -96,25 +106,25 @@ function getLogger(logger4js, options) { * @api private */ -function format(str, req, res) { - return str - .replace(':url', req.originalUrl) + function format(str, req, res) { + return str + .replace(':url', req.originalUrl) .replace(':method', req.method) - .replace(':status', res.__statusCode || res.statusCode) - .replace(':response-time', res.responseTime) - .replace(':date', new Date().toUTCString()) - .replace(':referrer', req.headers['referer'] || req.headers['referrer'] || '') - .replace(':http-version', req.httpVersionMajor + '.' + req.httpVersionMinor) - .replace(':remote-addr', req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress))) - .replace(':user-agent', req.headers['user-agent'] || '') - .replace(':content-length', (res._headers && res._headers['content-length']) || (res.__headers && res.__headers['Content-Length']) || '-') - .replace(/:req\[([^\]]+)\]/g, function(_, field){ return req.headers[field.toLowerCase()]; }) - .replace(/:res\[([^\]]+)\]/g, function(_, field){ - return res._headers - ? (res._headers[field.toLowerCase()] || res.__headers[field]) - : (res.__headers && res.__headers[field]); - }); -} + .replace(':status', res.__statusCode || res.statusCode) + .replace(':response-time', res.responseTime) + .replace(':date', new Date().toUTCString()) + .replace(':referrer', req.headers['referer'] || req.headers['referrer'] || '') + .replace(':http-version', req.httpVersionMajor + '.' + req.httpVersionMinor) + .replace(':remote-addr', req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress))) + .replace(':user-agent', req.headers['user-agent'] || '') + .replace(':content-length', (res._headers && res._headers['content-length']) || (res.__headers && res.__headers['Content-Length']) || '-') + .replace(/:req\[([^\]]+)\]/g, function(_, field){ return req.headers[field.toLowerCase()]; }) + .replace(/:res\[([^\]]+)\]/g, function(_, field){ + return res._headers + ? (res._headers[field.toLowerCase()] || res.__headers[field]) + : (res.__headers && res.__headers[field]); + }); + } /** * Return RegExp Object about nolog @@ -143,26 +153,26 @@ function format(str, req, res) { * 3.1 ["\\.jpg$", "\\.png", "\\.gif"] * SAME AS "\\.jpg|\\.png|\\.gif" */ -function createNoLogCondition(nolog, type) { - if(!nolog) return null; - type = type || ''; - - if(nolog instanceof RegExp){ - if(type === 'string') - return nolog.source; - return nolog; - } else if(typeof nolog === 'string'){ - if(type === 'string') - return nolog; - try{ - return new RegExp(nolog); - } catch (ex) { - return null; - } - } else if(nolog instanceof Array){ - var regexps = nolog.map(function(o){ return createNoLogCondition(o, 'string')}); - return new RegExp(regexps.join('|')); - } -} + function createNoLogCondition(nolog, type) { + if(!nolog) return null; + type = type || ''; + + if(nolog instanceof RegExp){ + if(type === 'string') + return nolog.source; + return nolog; + } else if(typeof nolog === 'string'){ + if(type === 'string') + return nolog; + try{ + return new RegExp(nolog); + } catch (ex) { + return null; + } + } else if(nolog instanceof Array){ + var regexps = nolog.map(function(o){ return createNoLogCondition(o, 'string')}); + return new RegExp(regexps.join('|')); + } + } -exports.connectLogger = getLogger; + exports.connectLogger = getLogger; diff --git a/lib/streams/DateRollingFileStream.js b/lib/streams/DateRollingFileStream.js index 0fc9394..69d6668 100644 --- a/lib/streams/DateRollingFileStream.js +++ b/lib/streams/DateRollingFileStream.js @@ -24,13 +24,15 @@ function DateRollingFileStream(filename, pattern, options, now) { this.now = now || Date.now; this.lastTimeWeWroteSomething = format.asString(this.pattern, new Date(this.now())); this.baseFilename = filename; + this.alwaysIncludePattern = false; if (options) { if (options.alwaysIncludePattern) { - filename = filename + this.lastTimeWeWroteSomething; + this.alwaysIncludePattern = true; + filename = this.baseFilename + this.lastTimeWeWroteSomething; } delete options.alwaysIncludePattern; - if (options === {}) { + if (Object.keys(options).length === 0) { options = null; } } @@ -53,18 +55,26 @@ DateRollingFileStream.prototype.shouldRoll = function() { }; DateRollingFileStream.prototype.roll = function(filename, callback) { - var that = this, - newFilename = this.baseFilename + this.previousTime; + var that = this; debug("Starting roll"); - async.series([ - this.closeTheStream.bind(this), - deleteAnyExistingFile, - renameTheCurrentFile, - this.openTheStream.bind(this) - ], callback); - + if (this.alwaysIncludePattern) { + this.filename = this.baseFilename + this.lastTimeWeWroteSomething; + async.series([ + this.closeTheStream.bind(this), + this.openTheStream.bind(this) + ], callback); + } else { + var newFilename = this.baseFilename + this.previousTime; + async.series([ + this.closeTheStream.bind(this), + deleteAnyExistingFile, + renameTheCurrentFile, + this.openTheStream.bind(this) + ], callback); + } + function deleteAnyExistingFile(cb) { //on windows, you can get a EEXIST error if you rename a file to an existing file //so, we'll try to delete the file we're renaming to first diff --git a/test/dateFileAppender-test.js b/test/dateFileAppender-test.js index 6b8b047..01433e7 100644 --- a/test/dateFileAppender-test.js +++ b/test/dateFileAppender-test.js @@ -113,6 +113,7 @@ vows.describe('../lib/appenders/dateFile').addBatch({ ] } , thisTime = format.asString(options.appenders[0].pattern, new Date()); + fs.writeFileSync(path.join(__dirname, 'date-file-test' + thisTime), "this is existing data" + require('os').EOL, 'utf8'); log4js.clearAppenders(); log4js.configure(options); logger = log4js.getLogger('tests'); @@ -122,6 +123,9 @@ vows.describe('../lib/appenders/dateFile').addBatch({ }, 'should create file with the correct pattern': function(contents) { assert.include(contents, 'this should be written to the file with the appended date'); + }, + 'should not overwrite the file on open (bug found in issue #132)': function(contents) { + assert.include(contents, 'this is existing data'); } } diff --git a/test/streams/DateRollingFileStream-test.js b/test/streams/DateRollingFileStream-test.js index 69e9ba8..a314170 100644 --- a/test/streams/DateRollingFileStream-test.js +++ b/test/streams/DateRollingFileStream-test.js @@ -125,6 +125,63 @@ vows.describe('DateRollingFileStream').addBatch({ } } } + }, + + 'with alwaysIncludePattern': { + topic: function() { + var that = this, + testTime = new Date(2012, 8, 12, 0, 10, 12), + stream = new DateRollingFileStream(__dirname + '/test-date-rolling-file-stream-pattern', '.yyyy-MM-dd', {alwaysIncludePattern: true}, now); + stream.write("First message\n", 'utf8', function() { + that.callback(null, stream); + }); + }, + teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-12'), + + 'should create a file with the pattern set': { + topic: function(stream) { + fs.readFile(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-12', this.callback); + }, + 'file should contain first message': function(result) { + assert.equal(result.toString(), "First message\n"); + } + }, + + 'when the day changes': { + topic: function(stream) { + testTime = new Date(2012, 8, 13, 0, 10, 12); + stream.write("Second message\n", 'utf8', this.callback); + }, + teardown: cleanUp(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-13'), + + + 'the number of files': { + topic: function() { + fs.readdir(__dirname, this.callback); + }, + 'should be two': function(files) { + assert.equal(files.filter(function(file) { return file.indexOf('test-date-rolling-file-stream-pattern') > -1; }).length, 2); + } + }, + + 'the file with the later date': { + topic: function() { + fs.readFile(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-13', this.callback); + }, + 'should contain the second message': function(contents) { + assert.equal(contents.toString(), "Second message\n"); + } + }, + + 'the file with the date': { + topic: function() { + fs.readFile(__dirname + '/test-date-rolling-file-stream-pattern.2012-09-12', this.callback); + }, + 'should contain the first message': function(contents) { + assert.equal(contents.toString(), "First message\n"); + } + } + } } }).exportTo(module);