Merge pull request #759 from log4js-node/tcp-fix

fix: #756 - handle multiple messages better

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));
+      });
+    }
   }
 };
 

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() {

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();
 });

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();