From 097390bc89f09347b3ac5a0b31bf4609077d23bf Mon Sep 17 00:00:00 2001 From: Danny Brain Date: Wed, 2 Nov 2011 15:49:46 +1100 Subject: [PATCH 1/3] Add multiprocess appender, pending tests --- lib/appenders/multiprocess.js | 77 +++++++++++++++++++++++++++++++++++ 1 file changed, 77 insertions(+) create mode 100644 lib/appenders/multiprocess.js diff --git a/lib/appenders/multiprocess.js b/lib/appenders/multiprocess.js new file mode 100644 index 0000000..b57caff --- /dev/null +++ b/lib/appenders/multiprocess.js @@ -0,0 +1,77 @@ +var log4js = require('../log4js'); +var layouts = require('../layouts'); +var net = require('net'); +var util = require('util'); + +var LogServer = function createLogServer(config) { + var actualAppender = config.actualAppender; + var server = net.createServer(function serverCreated(clientSocket) { + clientSocket.on('connect', function clientConnected() { + var logMessage = ''; + clientSocket.on('data', function chunkReceived(chunk) { + logMessage += chunk; + }); + clientSocket.on('end', function gotChunks() { + try { + var loggingEvent = JSON.parse(logMessage); + deserializeLoggingEvent(loggingEvent); + actualAppender(loggingEvent); + } catch (e) { + // JSON.parse failed, just log the contents probably a naughty. + actualAppender(createLoggingEvent('ERROR', 'Unable to parse log: ' + logMessage)); + } + }) + }); + }); + server.listen(config.loggerPort || 5000, config.loggerHost || 'localhost'); +} + +function createLoggingEvent(level, message) { + return { + startTime: new Date(), + categoryName: 'log4js', + level: { toString: function () { + return level; + }}, + data: [ message ] + }; +} + +function deserializeLoggingEvent(loggingEvent) { + loggingEvent.startTime = new Date(loggingEvent.startTime); + loggingEvent.level.toString = function levelToString() { + return loggingEvent.level.levelStr; + }; +} + +function workerAppender(config) { + return function log(loggingEvent) { + var socket = net.createConnection(config.loggerPort || 5000, config.loggerHost || 'localhost'); + socket.on('connect', function socketConnected() { + socket.end(JSON.stringify(loggingEvent), 'utf8'); + }); + }; +} + +function createAppender(config) { + if (config.mode === 'master') { + var server = new LogServer(config); + return config.actualAppender; + } else { + return workerAppender(config); + } +} + +function configure(config) { + var actualAppender; + if (config.appender && config.mode === 'master') { + log4js.loadAppender(config.appender.type); + actualAppender = log4js.appenderMakers[config.appender.type](config.appender); + config.actualAppender = actualAppender; + } + return createAppender(config); +} + +exports.name = 'multiprocess'; +exports.appender = createAppender; +exports.configure = configure; From a95117c0d3912b7b5230d8e4485e5505edb82029 Mon Sep 17 00:00:00 2001 From: Danny Brain Date: Thu, 3 Nov 2011 09:10:02 +1100 Subject: [PATCH 2/3] Add tests for multiprocess file appender --- lib/appenders/multiprocess.js | 2 +- package.json | 3 +- test/multiprocessAppender.js | 173 ++++++++++++++++++++++++++++++++++ 3 files changed, 176 insertions(+), 2 deletions(-) create mode 100644 test/multiprocessAppender.js diff --git a/lib/appenders/multiprocess.js b/lib/appenders/multiprocess.js index b57caff..98d6163 100644 --- a/lib/appenders/multiprocess.js +++ b/lib/appenders/multiprocess.js @@ -20,7 +20,7 @@ var LogServer = function createLogServer(config) { // JSON.parse failed, just log the contents probably a naughty. actualAppender(createLoggingEvent('ERROR', 'Unable to parse log: ' + logMessage)); } - }) + }); }); }); server.listen(config.loggerPort || 5000, config.loggerHost || 'localhost'); diff --git a/package.json b/package.json index fc006e4..2163952 100644 --- a/package.json +++ b/package.json @@ -26,6 +26,7 @@ "devDependencies": { "vows": ">=0.5.2", "sandboxed-module": ">= 0.1.1", - "hook.io": "0.7.7" + "hook.io": "0.7.7", + "underscore": "1.2.1" } } diff --git a/test/multiprocessAppender.js b/test/multiprocessAppender.js new file mode 100644 index 0000000..c1b2e38 --- /dev/null +++ b/test/multiprocessAppender.js @@ -0,0 +1,173 @@ +var vows = require('vows'); +var assert = require('assert'); +var sandbox = require('sandboxed-module'); +var _ = require('underscore'); + +function fancyResultingMultiprocessAppender(opts) { + var result = { clientOns: {}, serverOns: {}, logged: [], ended: [] }; + + var fakeSocket = { + on: function (event, fn) { + result.clientOns[event] = fn; + if (event === 'connect') { + fn(); + } + }, + end: function (data, encoding) { + result.ended.push({ data: data, encoding: encoding }); + } + } + + var fakeServerSocket = { + on: function (event, fn) { + result.serverOns[event] = fn; + if (event === 'connect') { + fn(); + } + } + } + + var fakeServer = { + listen: function (port, host) { + result.listenPort = port; + result.listenHost = host; + } + } + + var fakeNet = { + createServer: function (fn) { + fn(fakeServerSocket); + return fakeServer; + }, + createConnection: function (port, host) { + result.connectPort = port; + result.connectHost = host; + return fakeSocket; + } + } + + var fakeLog4Js = { + appenderMakers: {} + }; + fakeLog4Js.loadAppender = function (appender) { + fakeLog4Js.appenderMakers[appender] = function (config) { + result.actualLoggerConfig = config; + return function log(logEvent) { + result.logged.push(logEvent); + } + }; + }; + + return { theResult: result, + theModule: sandbox.require('../lib/appenders/multiprocess', { + requires: { + '../log4js': fakeLog4Js, + 'net': fakeNet + } + }) + }; +} + +function logMessages(result, logs, raw) { + logs.forEach(function log(item) { + var logItem = { startTime: "Wed, 02 Nov 2011 21:46:39 GMT", level: { levelStr: 'DEBUG' }, data: [ item ] }; + result.serverOns.data(JSON.stringify(logItem)); + result.serverOns.end(); + result.serverOns.connect(); + }); + if (raw) { + raw.forEach(function log(rawItem) { + result.serverOns.data(rawItem); + result.serverOns.end(); + result.serverOns.connect(); + }); + } +} + + +vows.describe('log4js multiprocessAppender').addBatch({ + 'master': { + topic: function() { + var fancy = fancyResultingMultiprocessAppender(); + var logger = fancy.theModule.configure({ mode: 'master', 'loggerPort': 5001, 'loggerHost': 'abba', appender: { type: 'file' } }); + logMessages(fancy.theResult, [ 'ALRIGHTY THEN', 'OH WOW' ]); + return fancy.theResult; + }, + + 'should write to the actual appender': function (result) { + assert.equal(result.listenPort, 5001); + assert.equal(result.listenHost, 'abba'); + assert.equal(result.logged.length, 2); + assert.equal(result.logged[0].data[0], 'ALRIGHTY THEN'); + assert.equal(result.logged[1].data[0], 'OH WOW'); + }, + + 'data written should be formatted correctly': function (result) { + assert.equal(result.logged[0].level.toString(), 'DEBUG'); + assert.equal(result.logged[0].data, 'ALRIGHTY THEN'); + assert.isTrue(typeof(result.logged[0].startTime) === 'object'); + assert.equal(result.logged[1].level.toString(), 'DEBUG'); + assert.equal(result.logged[1].data, 'OH WOW'); + assert.isTrue(typeof(result.logged[1].startTime) === 'object'); + }, + + 'the actual logger should get the right config': function (result) { + assert.equal(result.actualLoggerConfig.type, 'file'); + }, + + 'client should not be called': function (result) { + assert.equal(_.keys(result.clientOns).length, 0); + } + }, + 'master with bad request': { + topic: function() { + var fancy = fancyResultingMultiprocessAppender(); + var logger = fancy.theModule.configure({ mode: 'master', 'loggerPort': 5001, 'loggerHost': 'abba', appender: { type: 'file' } }); + logMessages(fancy.theResult, [], [ 'ALRIGHTY THEN', 'OH WOW' ]); + return fancy.theResult; + }, + + 'should write to the actual appender': function (result) { + assert.equal(result.listenPort, 5001); + assert.equal(result.listenHost, 'abba'); + assert.equal(result.logged.length, 2); + assert.equal(result.logged[0].data[0], 'Unable to parse log: ALRIGHTY THEN'); + assert.equal(result.logged[1].data[0], 'Unable to parse log: OH WOW'); + }, + + 'data written should be formatted correctly': function (result) { + assert.equal(result.logged[0].level.toString(), 'ERROR'); + assert.equal(result.logged[0].data, 'Unable to parse log: ALRIGHTY THEN'); + assert.isTrue(typeof(result.logged[0].startTime) === 'object'); + assert.equal(result.logged[1].level.toString(), 'ERROR'); + assert.equal(result.logged[1].data, 'Unable to parse log: OH WOW'); + assert.isTrue(typeof(result.logged[1].startTime) === 'object'); + } + }, + 'worker': { + 'should emit logging events to the master': { + topic: function() { + var fancy = fancyResultingMultiprocessAppender(); + var logger = fancy.theModule.configure({ loggerHost: 'baba', loggerPort: 1232, name: 'ohno', mode: 'worker', appender: { type: 'file' } }); + logger({ level: { levelStr: 'INFO' }, data: "ALRIGHTY THEN", startTime: '2011-10-27T03:53:16.031Z' }); + logger({ level: { levelStr: 'DEBUG' }, data: "OH WOW", startTime: '2011-10-27T04:53:16.031Z'}); + return fancy.theResult; + }, + + 'client configuration should be correct': function (result) { + assert.equal(result.connectHost, 'baba'); + assert.equal(result.connectPort, 1232); + }, + + 'should not write to the actual appender': function (result) { + assert.equal(result.logged.length, 0); + assert.equal(result.ended.length, 2); + assert.equal(result.ended[0].data, JSON.stringify({ level: { levelStr: 'INFO' }, data: "ALRIGHTY THEN", startTime: '2011-10-27T03:53:16.031Z' })); + assert.equal(result.ended[0].encoding, 'utf8'); + assert.equal(result.ended[1].data, JSON.stringify({ level: { levelStr: 'DEBUG' }, data: "OH WOW", startTime: '2011-10-27T04:53:16.031Z'})); + assert.equal(result.ended[1].encoding, 'utf8'); + assert.equal(_.keys(result.serverOns).length, 0); + } + } + } +}).exportTo(module); From ae8aaa53764212e5f630c2c8eb36f28645a94799 Mon Sep 17 00:00:00 2001 From: Danny Brain Date: Thu, 3 Nov 2011 09:16:38 +1100 Subject: [PATCH 3/3] Add a short description on using multiprocess logger --- README.md | 60 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 60 insertions(+) diff --git a/README.md b/README.md index 7ce5666..9453a70 100644 --- a/README.md +++ b/README.md @@ -160,6 +160,66 @@ This was mainly created for [cluster](https://github.com/LearnBoost/cluster), bu log4js-master/worker.json hookio appender parameters will be passed into the Hook constructor directly, so you can specify hook-port, hook-host etc. *NOTE* hook.io appender will currently (and probably indefinitely) explode if you enable hook.io debug because of the way log4js overrides console.log +## multiprocess (tcp socket) logger + +A multiprocess logger has been added to log4js by [dbrain](https://github.com/dbrain). This allows multiple worker processes to log through a single master process, avoiding issues with rolling etc. in a clustered environment. +This was mainly created for [cluster](https://github.com/LearnBoost/cluster), but you can adapt the example to match your needs, you know, if it fits them. +
+    #### log4js-master.json ####
+    # Will listen for connections on port and host
+    {
+      "appenders": [{
+        "type": "logLevelFilter",
+        "level": "DEBUG",
+        "appender": {
+          "type": "multiprocess",
+          "mode": "master",
+          "loggerPort": 5001,
+          "loggerHost": "simonsaysdie",
+          "appender": {
+            "type": "file",
+            "filename": "muffin.log",
+            "maxLogSize": 104857600,
+            "backups": 10,
+            "pollInterval": 15
+          }
+        }
+      }]
+    }
+
+    #### log4js-worker.json ####
+    # Will connect to master (tcp server) and send stringified log events
+    {
+      "appenders": [{
+        "type": "logLevelFilter",
+        "level": "DEBUG",
+        "appender": {
+          "type": "multiprocess",
+          "mode": "worker",
+          "loggerPort": 5001,
+          "loggerHost": "simonsaysdie"
+        }
+      }]
+    }
+
+    #### ilikebeans.js ####
+    var cluster = require('cluster');
+    var immaCluster = cluster('./doyoulikebeans');
+
+    // Perform the once off configuration depending on type of cluster
+    if (immaCluster.isMaster) {
+      require('log4js').configure('log4js-master.json');
+    } else {
+      require('log4js').configure('log4js-worker.json');
+    }
+
+    // Standard cluster startup
+    immaCluster
+      .use(cluster.logger('run/logs'))
+      .use(cluster.pidfiles('run/pids'))
+      .listen(3000);
+
+ ## author (of this node version) Gareth Jones (csausdev - gareth.jones@sensis.com.au)