diff --git a/lib/appenders/categoryFilter.js b/lib/appenders/categoryFilter.js new file mode 100644 index 0000000..f854f65 --- /dev/null +++ b/lib/appenders/categoryFilter.js @@ -0,0 +1,20 @@ +"use strict"; +var log4js = require('../log4js'); + +function categoryFilter (excludes, appender) { + if (typeof(excludes) === 'string') excludes = [excludes]; + return function(logEvent) { + if (excludes.indexOf(logEvent.categoryName) === -1) { + appender(logEvent); + } + }; +} + +function configure(config) { + log4js.loadAppender(config.appender.type); + var appender = log4js.appenderMakers[config.appender.type](config.appender); + return categoryFilter(config.exclude, appender); +} + +exports.appender = categoryFilter; +exports.configure = configure; diff --git a/lib/appenders/clustered.js b/lib/appenders/clustered.js new file mode 100755 index 0000000..f56e89a --- /dev/null +++ b/lib/appenders/clustered.js @@ -0,0 +1,118 @@ +"use strict"; + +var cluster = require('cluster'); +var log4js = require('../log4js'); + +/** + * Takes a loggingEvent object, returns string representation of it. + */ +function serializeLoggingEvent(loggingEvent) { + return JSON.stringify(loggingEvent); +} + +/** + * Takes a string, returns an object with + * the correct log properties. + * + * This method has been "borrowed" from the `multiprocess` appender + * by `nomiddlename` (https://github.com/nomiddlename/log4js-node/blob/master/lib/appenders/multiprocess.js) + * + * Apparently, node.js serializes everything to strings when using `process.send()`, + * so we need smart deserialization that will recreate log date and level for further processing by log4js internals. + */ +function deserializeLoggingEvent(loggingEventString) { + + var loggingEvent; + + try { + + loggingEvent = JSON.parse(loggingEventString); + loggingEvent.startTime = new Date(loggingEvent.startTime); + loggingEvent.level = log4js.levels.toLevel(loggingEvent.level.levelStr); + + } catch (e) { + + // JSON.parse failed, just log the contents probably a naughty. + loggingEvent = { + startTime: new Date(), + categoryName: 'log4js', + level: log4js.levels.ERROR, + data: [ 'Unable to parse log:', loggingEventString ] + }; + } + return loggingEvent; +} + +/** + * Creates an appender. + * + * If the current process is a master (`cluster.isMaster`), then this will be a "master appender". + * Otherwise this will be a worker appender, that just sends loggingEvents to the master process. + * + * If you are using this method directly, make sure to provide it with `config.actualAppenders` array + * of actual appender instances. + * + * Or better use `configure(config, options)` + */ +function createAppender(config) { + + if (cluster.isMaster) { + + var masterAppender = function(loggingEvent) { + + if (config.actualAppenders) { + var size = config.actualAppenders.length; + for(var i = 0; i < size; i++) { + config.actualAppenders[i](loggingEvent); + } + } + } + + // Listen on new workers + cluster.on('fork', function(worker) { + + worker.on('message', function(message) { + if (message.type && message.type === '::log-message') { + // console.log("master : " + cluster.isMaster + " received message: " + JSON.stringify(message.event)); + + var loggingEvent = deserializeLoggingEvent(message.event); + masterAppender(loggingEvent); + } + }); + + }); + + return masterAppender; + + } else { + + return function(loggingEvent) { + // If inside the worker process, then send the logger event to master. + if (cluster.isWorker) { + // console.log("worker " + cluster.worker.id + " is sending message"); + process.send({ type: '::log-message', event: serializeLoggingEvent(loggingEvent)}); + } + } + } +} + +function configure(config, options) { + + if (config.appenders && cluster.isMaster) { + + var size = config.appenders.length; + config.actualAppenders = new Array(size); + + for(var i = 0; i < size; i++) { + + log4js.loadAppender(config.appenders[i].type); + config.actualAppenders[i] = log4js.appenderMakers[config.appenders[i].type](config.appenders[i], options); + + } + } + + return createAppender(config); +} + +exports.appender = createAppender; +exports.configure = configure; \ No newline at end of file diff --git a/lib/date_format.js b/lib/date_format.js index bf36318..d75ce20 100644 --- a/lib/date_format.js +++ b/lib/date_format.js @@ -45,7 +45,7 @@ exports.asString = function(/*format,*/ date) { var vDay = addZero(date.getDate()); var vMonth = addZero(date.getMonth()+1); var vYearLong = addZero(date.getFullYear()); - var vYearShort = addZero(date.getFullYear().toString().substring(3,4)); + var vYearShort = addZero(date.getFullYear().toString().substring(2,4)); var vYear = (format.indexOf("yyyy") > -1 ? vYearLong : vYearShort); var vHour = addZero(date.getHours()); var vMinute = addZero(date.getMinutes()); diff --git a/lib/layouts.js b/lib/layouts.js index b171cee..9cfd035 100644 --- a/lib/layouts.js +++ b/lib/layouts.js @@ -120,6 +120,7 @@ function messagePassThroughLayout (loggingEvent) { * - %r time in toLocaleTimeString format * - %p log level * - %c log category + * - %h hostname * - %m log data * - %d date in various formats * - %% % @@ -143,7 +144,7 @@ function messagePassThroughLayout (loggingEvent) { */ function patternLayout (pattern, tokens) { var TTCC_CONVERSION_PATTERN = "%r %p %c - %m%n"; - var regex = /%(-?[0-9]+)?(\.?[0-9]+)?([\[\]cdmnprx%])(\{([^\}]+)\})?|([^%]+)/; + var regex = /%(-?[0-9]+)?(\.?[0-9]+)?([\[\]cdhmnprx%])(\{([^\}]+)\})?|([^%]+)/; pattern = pattern || TTCC_CONVERSION_PATTERN; @@ -166,6 +167,8 @@ function patternLayout (pattern, tokens) { // Pick up special cases if (format == "ISO8601") { format = dateFormat.ISO8601_FORMAT; + } else if (format == "ISO8601_WITH_TZ_OFFSET") { + format = dateFormat.ISO8601_WITH_TZ_OFFSET_FORMAT; } else if (format == "ABSOLUTE") { format = dateFormat.ABSOLUTETIME_FORMAT; } else if (format == "DATE") { @@ -175,6 +178,10 @@ function patternLayout (pattern, tokens) { // Format the date return dateFormat.asString(format, loggingEvent.startTime); } + + function hostname() { + return os.hostname().toString(); + } function formatMessage(loggingEvent) { return formatLogData(loggingEvent.data); @@ -218,6 +225,7 @@ function patternLayout (pattern, tokens) { var replacers = { 'c': categoryName, 'd': formatAsDate, + 'h': hostname, 'm': formatMessage, 'n': endOfLine, 'p': logLevel, diff --git a/package.json b/package.json index 68b7984..1835408 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "log4js", - "version": "0.6.6", + "version": "0.6.8", "description": "Port of Log4js to work with node.", "keywords": [ "logging", @@ -21,7 +21,7 @@ "node": ">=0.8" }, "scripts": { - "test": "vows" + "test": "mocha" }, "directories": { "test": "test", @@ -29,17 +29,16 @@ }, "dependencies": { "async": "0.1.15", - "dequeue": "1.0.3", "semver": "~1.1.4", "readable-stream": "~1.0.2", - "weak": "~0.2.2" }, "devDependencies": { - "vows": "0.7.0", "sandboxed-module": "0.1.3", - "hook.io": "0.8.10", "underscore": "1.2.1", "mocha": "~1.12.0", "should": "~1.2.2" + }, + "browser": { + "os": false } } diff --git a/test/categoryFilter-test.js b/test/categoryFilter-test.js new file mode 100644 index 0000000..1ad10a0 --- /dev/null +++ b/test/categoryFilter-test.js @@ -0,0 +1,83 @@ +'use strict'; + +var vows = require('vows') +, fs = require('fs') +, assert = require('assert'); + +function remove(filename) { + try { + fs.unlinkSync(filename); + } catch (e) { + //doesn't really matter if it failed + } +} + +vows.describe('log4js categoryFilter').addBatch({ + 'appender': { + topic: function() { + + var log4js = require('../lib/log4js'), logEvents = [], webLogger, appLogger; + log4js.clearAppenders(); + var appender = require('../lib/appenders/categoryFilter') + .appender( + ['app'], + function(evt) { logEvents.push(evt); } + ); + log4js.addAppender(appender, ["app","web"]); + + webLogger = log4js.getLogger("web"); + appLogger = log4js.getLogger("app"); + + webLogger.debug('This should get logged'); + appLogger.debug('This should not'); + webLogger.debug('Hello again'); + log4js.getLogger('db').debug('This shouldn\'t be included by the appender anyway'); + + return logEvents; + }, + 'should only pass matching category' : function(logEvents) { + assert.equal(logEvents.length, 2); + assert.equal(logEvents[0].data[0], 'This should get logged'); + assert.equal(logEvents[1].data[0], 'Hello again'); + } + }, + + 'configure': { + topic: function() { + var log4js = require('../lib/log4js') + , logger, weblogger; + + remove(__dirname + '/categoryFilter-web.log'); + remove(__dirname + '/categoryFilter-noweb.log'); + + log4js.configure('test/with-categoryFilter.json'); + logger = log4js.getLogger("app"); + weblogger = log4js.getLogger("web"); + + logger.info('Loading app'); + logger.debug('Initialising indexes'); + weblogger.info('00:00:00 GET / 200'); + weblogger.warn('00:00:00 GET / 500'); + //wait for the file system to catch up + setTimeout(this.callback, 100); + }, + 'tmp-tests.log': { + topic: function() { + fs.readFile(__dirname + '/categoryFilter-noweb.log', 'utf8', this.callback); + }, + 'should contain all log messages': function(contents) { + var messages = contents.trim().split('\n'); + assert.deepEqual(messages, ['Loading app','Initialising indexes']); + } + }, + 'tmp-tests-web.log': { + topic: function() { + fs.readFile(__dirname + '/categoryFilter-web.log','utf8',this.callback); + }, + 'should contain only error and warning log messages': function(contents) { + var messages = contents.trim().split('\n'); + assert.deepEqual(messages, ['00:00:00 GET / 200','00:00:00 GET / 500']); + } + } + } +}).export(module); diff --git a/test/clusteredAppender-test.js b/test/clusteredAppender-test.js new file mode 100755 index 0000000..a0dd5fb --- /dev/null +++ b/test/clusteredAppender-test.js @@ -0,0 +1,116 @@ +"use strict"; +var assert = require('assert'); +var vows = require('vows'); +var layouts = require('../lib/layouts'); +var sandbox = require('sandboxed-module'); +var LoggingEvent = require('../lib/logger').LoggingEvent; +var cluster = require('cluster'); + +vows.describe('log4js cluster appender').addBatch({ + 'when in master mode': { + topic: function() { + + var registeredClusterEvents = []; + var loggingEvents = []; + + // Fake cluster module, so no cluster listeners be really added + var fakeCluster = { + + on: function(event, callback) { + registeredClusterEvents.push(event); + }, + + isMaster: true, + isWorker: false, + + }; + + var fakeActualAppender = function(loggingEvent) { + loggingEvents.push(loggingEvent); + } + + // Load appender and fake modules in it + var appenderModule = sandbox.require('../lib/appenders/clustered', { + requires: { + 'cluster': fakeCluster, + } + }); + + var masterAppender = appenderModule.appender({ + actualAppenders: [ fakeActualAppender ] + }); + + // Actual test - log message using masterAppender + masterAppender(new LoggingEvent('wovs', 'Info', ['masterAppender test'])); + + var returnValue = { + registeredClusterEvents: registeredClusterEvents, + loggingEvents: loggingEvents, + }; + + return returnValue; + }, + + "should register 'fork' event listener on 'cluster'": function(topic) { + assert.equal(topic.registeredClusterEvents[0], 'fork'); + }, + + "should log using actual appender": function(topic) { + assert.equal(topic.loggingEvents[0].data[0], 'masterAppender test'); + }, + + }, + + 'when in worker mode': { + + topic: function() { + + var registeredProcessEvents = []; + + // Fake cluster module, to fake we're inside a worker process + var fakeCluster = { + + isMaster: false, + isWorker: true, + + }; + + var fakeProcess = { + + send: function(data) { + registeredProcessEvents.push(data); + }, + + }; + + // Load appender and fake modules in it + var appenderModule = sandbox.require('../lib/appenders/clustered', { + requires: { + 'cluster': fakeCluster, + }, + globals: { + 'process': fakeProcess, + } + }); + + var workerAppender = appenderModule.appender(); + + // Actual test - log message using masterAppender + workerAppender(new LoggingEvent('wovs', 'Info', ['workerAppender test'])); + + var returnValue = { + registeredProcessEvents: registeredProcessEvents, + }; + + return returnValue; + + }, + + "worker appender should call process.send" : function(topic) { + assert.equal(topic.registeredProcessEvents[0].type, '::log-message'); + assert.equal(JSON.parse(topic.registeredProcessEvents[0].event).data[0], "workerAppender test"); + } + + } + +}).exportTo(module); diff --git a/test/date_format-test.js b/test/date_format-test.js index d4a5cb5..6085843 100644 --- a/test/date_format-test.js +++ b/test/date_format-test.js @@ -39,6 +39,13 @@ vows.describe('date_format').addBatch({ dateFormat.asString(dateFormat.ABSOLUTETIME_FORMAT, date), '14:31:30.005' ); + }, + 'should provide a custom format': function(date) { + date.getTimezoneOffset = function() { return 120; }; + assert.equal( + dateFormat.asString("O.SSS.ss.mm.hh.dd.MM.yy", date), + '-0200.005.30.31.14.11.01.10' + ); } } }).export(module); diff --git a/test/fileAppender-test.js b/test/fileAppender-test.js index cb4692a..9476ad6 100644 --- a/test/fileAppender-test.js +++ b/test/fileAppender-test.js @@ -222,7 +222,7 @@ vows.describe('log4js fileAppender').addBatch({ , logger; //this config file defines one file appender (to ./tmp-tests.log) //and sets the log level for "tests" to WARN - log4js.configure('test/log4js.json'); + log4js.configure('./test/log4js.json'); logger = log4js.getLogger('tests'); logger.info('this should not be written to the file'); logger.warn('this should be written to the file'); diff --git a/test/layouts-test.js b/test/layouts-test.js index 9af1242..c355bdd 100644 --- a/test/layouts-test.js +++ b/test/layouts-test.js @@ -209,6 +209,9 @@ vows.describe('log4js layouts').addBatch({ '%n should output a new line': function(args) { test(args, '%n', '\n'); }, + '%h should output hostname' : function(args) { + test(args, '%h', require('os').hostname().toString()); + }, '%c should handle category names like java-style package names': function(args) { test(args, '%c{1}', 'tests'); test(args, '%c{2}', 'of.tests'); @@ -221,9 +224,11 @@ vows.describe('log4js layouts').addBatch({ test(args, '%d', '2010-12-05 14:18:30.045'); }, '%d should allow for format specification': function(args) { + test(args, '%d{ISO8601_WITH_TZ_OFFSET}', '2010-12-05T14:18:30-0000'); test(args, '%d{ISO8601}', '2010-12-05 14:18:30.045'); test(args, '%d{ABSOLUTE}', '14:18:30.045'); test(args, '%d{DATE}', '05 12 2010 14:18:30.045'); + test(args, '%d{yy MM dd hh mm ss}', '10 12 05 14 18 30'); test(args, '%d{yyyy MM dd}', '2010 12 05'); test(args, '%d{yyyy MM dd hh mm ss SSS}', '2010 12 05 14 18 30 045'); }, diff --git a/test/with-categoryFilter.json b/test/with-categoryFilter.json new file mode 100644 index 0000000..7998cc8 --- /dev/null +++ b/test/with-categoryFilter.json @@ -0,0 +1,23 @@ +{ + "appenders": [ + { + "type": "categoryFilter", + "exclude": "web", + "appender": { + "type": "file", + "filename": "test/categoryFilter-noweb.log", + "layout": { + "type": "messagePassThrough" + } + } + }, + { + "category": "web", + "type": "file", + "filename": "test/categoryFilter-web.log", + "layout": { + "type": "messagePassThrough" + } + } + ] +}