From 61beac28d39ee59ddf27286368a131f5ccdeb28f Mon Sep 17 00:00:00 2001 From: Marcin Kielar Date: Fri, 9 Aug 2013 00:04:25 +0200 Subject: [PATCH] Clustered appender for log4js. + lib/appenders/clustered.js + test/clusteredAppender-test.js Instead os using sockets (like multiprocess) or dead and unmaintained hook.io, Clustered appender uses process.send(message) / worker.on('message', callback) mechanisms for transporting data between worker processes and master logger. Master logger takes an "appenders" array of actual appenders that are triggered when worker appenders send some data. This guarantees sequential writes to appenders, so the log messages are not mixed in single lines of log. --- lib/appenders/clustered.js | 118 +++++++++++++++++++++++++++++++++ test/clusteredAppender-test.js | 116 ++++++++++++++++++++++++++++++++ 2 files changed, 234 insertions(+) create mode 100755 lib/appenders/clustered.js create mode 100755 test/clusteredAppender-test.js 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/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);