From 3a68a1eb966d7248f420fda995e84ee7c8343285 Mon Sep 17 00:00:00 2001 From: Gareth Jones Date: Thu, 19 Jul 2018 08:13:59 +1000 Subject: [PATCH] fix: #756 - handle multiple messages better --- lib/appenders/tcp-server.js | 15 +++++++++++++-- lib/appenders/tcp.js | 2 +- test/tap/server-test.js | 31 +++++++++++++++++++++++++++---- test/tap/tcp-appender-test.js | 14 ++++++++++++-- 4 files changed, 53 insertions(+), 9 deletions(-) diff --git a/lib/appenders/tcp-server.js b/lib/appenders/tcp-server.js index 6a9d1fb..0e8ae91 100644 --- a/lib/appenders/tcp-server.js +++ b/lib/appenders/tcp-server.js @@ -3,10 +3,21 @@ const net = require('net'); const clustering = require('../clustering'); const LoggingEvent = require('../LoggingEvent'); +const DELIMITER = '__LOG4JS__'; + +let dataSoFar = ''; const send = (data) => { if (data) { - const event = LoggingEvent.deserialise(data); - clustering.send(event); + dataSoFar += data; + if (dataSoFar.indexOf(DELIMITER)) { + const events = dataSoFar.split(DELIMITER); + if (!dataSoFar.endsWith(DELIMITER)) { + dataSoFar = events.pop(); + } + events.filter(e => e.length).forEach((e) => { + clustering.send(LoggingEvent.deserialise(e)); + }); + } } }; diff --git a/lib/appenders/tcp.js b/lib/appenders/tcp.js index 968f075..201c34a 100644 --- a/lib/appenders/tcp.js +++ b/lib/appenders/tcp.js @@ -11,7 +11,7 @@ function appender(config) { function write(loggingEvent) { debug('Writing log event to socket'); - canWrite = socket.write(loggingEvent.serialise(), 'utf8'); + canWrite = socket.write(`${loggingEvent.serialise()}__LOG4JS__`, 'utf8'); } function emptyBuffer() { diff --git a/test/tap/server-test.js b/test/tap/server-test.js index 3be4f98..ef6dfad 100644 --- a/test/tap/server-test.js +++ b/test/tap/server-test.js @@ -15,33 +15,56 @@ log4js.configure({ } }); +// give the socket a chance to start up test('TCP Server', (batch) => { batch.test('should listen for TCP messages and re-send via process.send', (t) => { - // give the socket a chance to start up setTimeout(() => { const socket = net.connect(5678, () => { socket.write( - (new LoggingEvent('test-category', levels.INFO, ['something'], {})).serialise(), + `${(new LoggingEvent('test-category', levels.INFO, ['something'], {})).serialise() + }__LOG4JS__${ + (new LoggingEvent('test-category', levels.INFO, ['something else'], {})).serialise() + }__LOG4JS__some nonsense__LOG4JS__{"some":"json"}__LOG4JS__`, () => { socket.end(); setTimeout(() => { log4js.shutdown(() => { const logs = vcr.replay(); - t.equal(logs.length, 1); + t.equal(logs.length, 4); t.match(logs[0], { data: ['something'], categoryName: 'test-category', level: { levelStr: 'INFO' }, context: {} }); + t.match(logs[1], { + data: ['something else'], + categoryName: 'test-category', + level: { levelStr: 'INFO' }, + context: {} + }); + t.match(logs[2], { + data: ['Unable to parse log:', 'some nonsense', 'because: ', SyntaxError], + categoryName: 'log4js', + level: { levelStr: 'ERROR' }, + context: {} + }); + t.match(logs[3], { + data: ['Unable to parse log:', '{"some":"json"}', 'because: ', TypeError], + categoryName: 'log4js', + level: { levelStr: 'ERROR' }, + context: {} + }); t.end(); }); }, 100); } ); }); + socket.unref(); }, 100); + + batch.end(); }); - batch.end(); }); diff --git a/test/tap/tcp-appender-test.js b/test/tap/tcp-appender-test.js index 20d4316..4101155 100644 --- a/test/tap/tcp-appender-test.js +++ b/test/tap/tcp-appender-test.js @@ -6,7 +6,10 @@ const messages = []; const server = net.createServer((socket) => { socket.setEncoding('utf8'); socket.on('data', (data) => { - messages.push(JSON.parse(data)); + data + .split('__LOG4JS__') + .filter(s => s.length) + .forEach((s) => { messages.push(JSON.parse(s)); }); }); }); @@ -25,17 +28,24 @@ server.listen(() => { const logger = log4js.getLogger(); logger.info('This should be sent via TCP.'); + logger.info('This should also be sent via TCP and not break things.'); log4js.shutdown(() => { server.close(() => { test('TCP Appender', (batch) => { batch.test('should send log messages as JSON over TCP', (t) => { - t.equal(messages.length, 1); + t.equal(messages.length, 2); t.match(messages[0], { data: ['This should be sent via TCP.'], categoryName: 'default', context: {}, level: { levelStr: 'INFO' } }); + t.match(messages[1], { + data: ['This should also be sent via TCP and not break things.'], + categoryName: 'default', + context: {}, + level: { levelStr: 'INFO' } + }); t.end(); }); batch.end();