diff --git a/lib/LoggingEvent.js b/lib/LoggingEvent.js new file mode 100644 index 0000000..cb7cbd1 --- /dev/null +++ b/lib/LoggingEvent.js @@ -0,0 +1,79 @@ +module.exports = (levels) => { + /** + * @name LoggingEvent + * @namespace Log4js + */ + class LoggingEvent { + /** + * Models a logging event. + * @constructor + * @param {String} categoryName name of category + * @param {Log4js.Level} level level of message + * @param {Array} data objects to log + * @author Seth Chisamore + */ + constructor(categoryName, level, data, context) { + this.startTime = new Date(); + this.categoryName = categoryName; + this.data = data; + this.level = level; + this.context = Object.assign({}, context); + this.pid = process.pid; + // if (cluster && cluster.isWorker) { + // this.cluster = { + // workerId: cluster.worker.id, + // worker: process.pid + // }; + // } + } + + serialise() { + // JSON.stringify(new Error('test')) returns {}, which is not really useful for us. + // The following allows us to serialize errors correctly. + // Validate that we really are in this case + try { + const logData = this.data.map((e) => { + if (e && e.stack && JSON.stringify(e) === '{}') { + e = { message: e.message, stack: e.stack }; + } + return e; + }); + this.data = logData; + return JSON.stringify(this); + } catch (e) { + return new LoggingEvent( + 'log4js', + levels.ERROR, + ['Unable to serialise log event due to :', e] + ).serialise(); + } + } + + static deserialise(serialised) { + let event; + try { + event = JSON.parse(serialised); + event.startTime = new Date(event.startTime); + event.level = levels.getLevel(event.level.levelStr); + event.data = event.data.map((e) => { + if (e && e.stack) { + const fakeError = new Error(e.message); + fakeError.stack = e.stack; + e = fakeError; + } + return e; + }); + } catch (e) { + event = new LoggingEvent( + 'log4js', + levels.ERROR, + ['Unable to parse log:', serialised, 'because: ', e] + ); + } + + return event; + } + } + + return LoggingEvent; +}; diff --git a/lib/clustering.js b/lib/clustering.js new file mode 100644 index 0000000..b046dbf --- /dev/null +++ b/lib/clustering.js @@ -0,0 +1,81 @@ +const debug = require('debug')('log4js:clustering'); + +let cluster; +try { + cluster = require('cluster'); // eslint-disable-line global-require +} catch (e) { + debug('Clustering support disabled because require(cluster) threw an error: ', e); +} + +module.exports = (config) => { + const disabled = config.disableClustering || !cluster; + const pm2 = config.pm2; + const pm2InstanceVar = config.pm2InstanceVar || 'NODE_APP_INSTANCE'; + const listeners = []; + + debug(`clustering disabled ? ${disabled}`); + debug(`cluster.isMaster ? ${cluster && cluster.isMaster}`); + debug(`pm2 enabled ? ${pm2}`); + debug(`pm2InstanceVar = ${pm2InstanceVar}`); + debug(`process.env[${pm2InstanceVar}] = ${process.env[pm2InstanceVar]}`); + + const isPM2Master = () => pm2 && process.env[pm2InstanceVar] === '0'; + const isMaster = () => disabled || cluster.isMaster || isPM2Master(); + const isWorker = () => !isMaster(); + + // in a multi-process node environment, worker loggers will use + // process.send + const receiver = (worker, message) => { + // prior to node v6, the worker parameter was not passed (args were message, handle) + debug('cluster message received from worker ', worker, ': ', message); + if (worker.topic && worker.data) { + message = worker; + worker = undefined; + } + if (message && message.topic && message.topic === 'log4js:message') { + debug('received message: ', message.data); + const logEvent = LoggingEvent.deserialise(message.data); + listeners.forEach(l => l(logEvent)); + } + }; + + // just in case configure is called after shutdown + pm2 && process.removeListener('message', receiver); + cluster.removeListener('message', receiver); + if (config.disableClustering) { + debug('Not listening for cluster messages, because clustering disabled.'); + } else if (isPM2Master()) { + // PM2 cluster support + // PM2 runs everything as workers - install pm2-intercom for this to work. + // we only want one of the app instances to write logs + debug('listening for PM2 broadcast messages'); + process.on('message', receiver); + } else if (cluster.isMaster) { + debug('listening for cluster messages'); + cluster.on('message', receiver); + } else { + debug('not listening for messages, because we are not a master process'); + } + + + return { + onlyOnMaster: (fn) => { + if (isMaster()) { + fn(); + } + }, + onlyOnWorker: (fn) => { + if (isWorker()) { + fn(); + } + }, + isMaster: isMaster, + isWorker: isWorker, + send: (msg) => { + + }, + onMessage: (listener) => { + listeners.push(listener); + } + }; +}; diff --git a/lib/configuration.js b/lib/configuration.js index b471d9d..d59a2ce 100644 --- a/lib/configuration.js +++ b/lib/configuration.js @@ -4,15 +4,9 @@ const util = require('util'); const path = require('path'); const levels = require('./levels'); const layouts = require('./layouts'); +const clustering = require('./clustering'); const debug = require('debug')('log4js:configuration'); -let cluster; -try { - cluster = require('cluster'); // eslint-disable-line global-require -} catch (e) { - debug('Clustering support disabled because require(cluster) threw an error: ', e); -} - const validColours = [ 'white', 'grey', 'black', 'blue', 'cyan', 'green', @@ -80,18 +74,12 @@ class Configuration { debug(`DEPRECATION: Appender ${config.type} exports a shutdown function.`); } - if (this.disableClustering || cluster.isMaster || (this.pm2 && process.env[this.pm2InstanceVar] === '0')) { - debug(`cluster.isMaster ? ${cluster.isMaster}`); - debug(`pm2 enabled ? ${this.pm2}`); - debug(`pm2InstanceVar = ${this.pm2InstanceVar}`); - debug(`process.env[${this.pm2InstanceVar}] = ${process.env[this.pm2InstanceVar]}`); - return appenderModule.configure( - config, - layouts, - this.configuredAppenders.get.bind(this.configuredAppenders), - this.configuredLevels - ); - } + this.clustering.onlyOnMaster(() => appenderModule.configure( + config, + layouts, + this.configuredAppenders.get.bind(this.configuredAppenders), + this.configuredLevels + )); return () => {}; } @@ -203,12 +191,8 @@ class Configuration { this.throwExceptionIf(not(anObject(candidate.appenders)), 'must have a property "appenders" of type object.'); this.throwExceptionIf(not(anObject(candidate.categories)), 'must have a property "categories" of type object.'); - this.disableClustering = this.candidate.disableClustering || !cluster; - - this.pm2 = this.candidate.pm2; - this.pm2InstanceVar = this.candidate.pm2InstanceVar || 'NODE_APP_INSTANCE'; - this.levels = candidate.levels; + this.clustering = clustering(this.candidate); this.appenders = candidate.appenders; this.categories = candidate.categories; } diff --git a/lib/log4js.js b/lib/log4js.js index c8484b6..c4b79aa 100644 --- a/lib/log4js.js +++ b/lib/log4js.js @@ -29,12 +29,6 @@ const connectModule = require('./connect-logger'); const logger = require('./logger'); const layouts = require('./layouts'); -let cluster; -try { - cluster = require('cluster'); // eslint-disable-line global-require -} catch (e) { - debug('Clustering support disabled because require(cluster) threw an error: ', e); -} const defaultConfig = { appenders: { @@ -49,6 +43,7 @@ let Logger; let LoggingEvent; let config; let connectLogger; +let clustering; let enabled = false; function configForCategory(category) { @@ -101,14 +96,6 @@ function workerDispatch(logEvent) { process.send({ topic: 'log4js:message', data: logEvent.serialise() }); } -function isPM2Master() { - return config.pm2 && process.env[config.pm2InstanceVar] === '0'; -} - -function isMaster() { - return config.disableClustering || cluster.isMaster || isPM2Master(); -} - /** * Get a logger instance. * @static @@ -129,21 +116,6 @@ function loadConfigurationFile(filename) { return filename; } -// in a multi-process node environment, worker loggers will use -// process.send -const receiver = (worker, message) => { - // prior to node v6, the worker parameter was not passed (args were message, handle) - debug('cluster message received from worker ', worker, ': ', message); - if (worker.topic && worker.data) { - message = worker; - worker = undefined; - } - if (message && message.topic && message.topic === 'log4js:message') { - debug('received message: ', message.data); - sendLogEventToAppender(LoggingEvent.deserialise(message.data)); - } -}; - function configure(configurationFileOrObject) { let configObject = configurationFileOrObject; @@ -152,29 +124,14 @@ function configure(configurationFileOrObject) { } debug(`Configuration is ${configObject}`); config = new Configuration(configObject); + clustering = config.clustering; module.exports.levels = config.levels; const loggerModule = logger(config.levels, levelForCategory, setLevelForCategory); Logger = loggerModule.Logger; LoggingEvent = loggerModule.LoggingEvent; module.exports.connectLogger = connectModule(config.levels).connectLogger; - // just in case configure is called after shutdown - process.removeListener('message', receiver); - cluster.removeListener('message', receiver); - if (config.disableClustering) { - debug('Not listening for cluster messages, because clustering disabled.'); - } else if (isPM2Master()) { - // PM2 cluster support - // PM2 runs everything as workers - install pm2-intercom for this to work. - // we only want one of the app instances to write logs - debug('listening for PM2 broadcast messages'); - process.on('message', receiver); - } else if (cluster.isMaster) { - debug('listening for cluster messages'); - cluster.on('message', receiver); - } else { - debug('not listening for messages, because we are not a master process'); - } + clustering.onMessage(sendLogEventToAppender); enabled = true; } diff --git a/lib/logger.js b/lib/logger.js index 0da1182..9bdd010 100644 --- a/lib/logger.js +++ b/lib/logger.js @@ -3,90 +3,10 @@ 'use strict'; const debug = require('debug')('log4js:logger'); - -let cluster; -try { - cluster = require('cluster'); // eslint-disable-line global-require -} catch (e) { - debug('Clustering support disabled because require(cluster) threw an error: ', e); -} +const loggingEventModule = require('./LoggingEvent'); module.exports = function (levels, getLevelForCategory, setLevelForCategory) { - /** - * @name LoggingEvent - * @namespace Log4js - */ - class LoggingEvent { - /** - * Models a logging event. - * @constructor - * @param {String} categoryName name of category - * @param {Log4js.Level} level level of message - * @param {Array} data objects to log - * @author Seth Chisamore - */ - constructor(categoryName, level, data, context) { - this.startTime = new Date(); - this.categoryName = categoryName; - this.data = data; - this.level = level; - this.context = Object.assign({}, context); - this.pid = process.pid; - if (cluster && cluster.isWorker) { - this.cluster = { - workerId: cluster.worker.id, - worker: process.pid - }; - } - } - - serialise() { - // JSON.stringify(new Error('test')) returns {}, which is not really useful for us. - // The following allows us to serialize errors correctly. - // Validate that we really are in this case - try { - const logData = this.data.map((e) => { - if (e && e.stack && JSON.stringify(e) === '{}') { - e = { message: e.message, stack: e.stack }; - } - return e; - }); - this.data = logData; - return JSON.stringify(this); - } catch (e) { - return new LoggingEvent( - 'log4js', - levels.ERROR, - ['Unable to serialise log event due to :', e] - ).serialise(); - } - } - - static deserialise(serialised) { - let event; - try { - event = JSON.parse(serialised); - event.startTime = new Date(event.startTime); - event.level = levels.getLevel(event.level.levelStr); - event.data = event.data.map((e) => { - if (e && e.stack) { - const fakeError = new Error(e.message); - fakeError.stack = e.stack; - e = fakeError; - } - return e; - }); - } catch (e) { - event = new LoggingEvent( - 'log4js', - levels.ERROR, - ['Unable to parse log:', serialised, 'because: ', e] - ); - } - - return event; - } - } + const LoggingEvent = loggingEventModule(levels); /** * Logger to log messages. diff --git a/lib/server.js b/lib/server.js new file mode 100644 index 0000000..32cd555 --- /dev/null +++ b/lib/server.js @@ -0,0 +1,24 @@ +const net = require('net'); + +module.exports = (config, clustering) => { + // dummy shutdown if we're not master + let shutdown = (cb) => { cb(); }; + + clustering.onlyOnMaster(() => { + const server = net.createServer((socket) => { + socket.setEncoding('utf8'); + socket.on('data', clustering.send); + socket.on('end', clustering.send); + }); + + server.listen(config.port || 5000, config.host || 'localhost', () => { + server.unref(); + }); + + shutdown = (cb) => { + server.close(cb); + }; + }); + + return shutdown; +}; diff --git a/test/tap/server-test.js b/test/tap/server-test.js index a713e47..77c2c9b 100644 --- a/test/tap/server-test.js +++ b/test/tap/server-test.js @@ -1,6 +1,44 @@ const test = require('tap').test; +const net = require('net'); +const log4js = require('../../lib/log4js'); +const vcr = require('../../lib/appenders/recording'); +const levels = require('../../lib/levels')(); +const LoggingEvent = (require('../../lib/logger')(levels)).LoggingEvent; + +log4js.configure({ + appenders: { + vcr: { type: 'recording' } + }, + categories: { + default: { appenders: ['vcr'], level: 'debug' } + }, + listen: { + port: 5678 + } +}); test('TCP Server', (batch) => { - batch.test('should listen for TCP messages and re-send via process.send'); + batch.test('should listen for TCP messages and re-send via process.send', (t) => { + const socket = net.connect(5678, () => { + socket.write( + (new LoggingEvent('test-category', levels.INFO, ['something'], {})).serialise(), + () => { + socket.end(); + log4js.shutdown(() => { + const logs = vcr.replay(); + t.equal(logs.length, 1); + t.match(logs[0], { + data: ['something'], + categoryName: 'test-category', + level: { levelStr: 'INFO' }, + context: {} + }); + t.end(); + }); + } + ); + }); + socket.unref(); + }); batch.end(); });