fix trimming of long lines, more tests

lib/daemon/daemon.js

@@ -19,6 +19,7 @@ class Daemon extends EventEmitter {
 
         this.rpcServer = new Server();
         this.configCounter = 0;
+        this.idCounter = 0;
         this.listening = false;
         this.waiting = [];
         this.allWaiting = [];
@@ -66,6 +67,11 @@ class Daemon extends EventEmitter {
             }
         }
 
+        if (!Object.prototype.hasOwnProperty.call(options, 'id')) {
+            options = Object.assign({}, options);
+            options.id = this.idCounter++;
+        }
+
         const process = new Process(app, options);
         const logger = this.getLogger(process);
 

lib/daemon/process.js

@@ -6,24 +6,18 @@ const {EventEmitter} = require('events');
 
 const RUNNER = path.resolve(__dirname, 'process-runner.js');
 
-let idCounter = 0;
-
 class Process extends EventEmitter {
     constructor(app, options = {}) {
         super();
 
         this.app = app;
 
-        this.id = options.id || idCounter++;
+        this.id = options.id;
         this.number = options.number || 0;
         this.crashCounter = options.crashCounter || 0;
         this.startDelay = options.startDelay || 0;
         this.pid = -1;
 
-        if (this.number === 'id') {
-            this.number = this.id;
-        }
-
         this.worker = null;
         this.process = null;
 
@@ -165,21 +159,21 @@ class Process extends EventEmitter {
             const total = streamBuffer.bytes + lineData.length;
             const exceeds = total - maxLength;
 
+            index += lineData.length + 1;
+
             if (exceeds > 0) {
                 streamBuffer.truncate += exceeds;
-
-                if (exceeds === lineData.length)
-                    continue;
-
                 lineData = lineData.slice(0, -exceeds);
             }
 
-            index += lineData.length + 1;
-
             if (lineEnd > 0) {
-                const line = Buffer.concat([...streamBuffer.buffers, lineData]).toString();
+                let result = Buffer.concat([...streamBuffer.buffers, lineData]);
+
+                if (result[result.length - 1] === 0x0d) { // trim '\r'
+                    result = result.slice(0, result.length - 1);
+                }
 
-                this.emit('output', stream, line, streamBuffer.truncate);
+                this.emit('output', stream, result.toString(), streamBuffer.truncate);
 
                 streamBuffer.buffers.length = 0;
                 streamBuffer.bytes = 0;
@@ -295,7 +289,14 @@ class Process extends EventEmitter {
 
     send(message, callback) {
         if (this.terminated || !this.process) {
-            setImmediate(callback.bind(new Error("process terminated")));
+            const error = new Error("process terminated");
+
+            if (callback) {
+                setImmediate(callback.bind(null, error));
+            } else {
+                this._onError(error);
+            }
+
             return false;
         }
 

package.json

@@ -1,6 +1,6 @@
 {
   "name": "final-pm",
-  "version": "2.18.0",
+  "version": "2.19.0",
   "author": "laino",
   "description": "The Final Process Manager",
   "main": "index.js",

test/apps/sample-app.js

@@ -8,23 +8,17 @@ const server = require('http').createServer((req, res) => {
 let started = false;
 let shouldStop = false;
 
-process.stdout.write('TWO LINES\r\nAT ONCE\r\n');
-process.stdout.write('A LINE IN');
-setTimeout(() => {
-    process.stdout.write(' TWO PARTS\r\n');
-
-    server.listen(3334, (error) => {
-        if (error) {
-            throw error;
-        }
-        started = true;
-        if (shouldStop) {
-            stop();
-        }
-        process.send('ready');
-        console.log('ready');
-    });
-}, 50);
+server.listen(3334, (error) => {
+    if (error) {
+        throw error;
+    }
+    started = true;
+    if (shouldStop) {
+        stop();
+    }
+    process.send('ready');
+    console.log('ready');
+});
 
 process.on('SIGINT', stop);
 process.on('message', (msg) => {

test/apps/stdout.js

@@ -0,0 +1,6 @@
+process.stdout.write('TWO LINES\r\nAT ONCE\r\n');
+process.stdout.write('A LINE IN');
+setTimeout(() => {
+    process.stdout.write(' TWO PARTS\r\n');
+    process.send('ready');
+}, 100);

test/configs/stdout.js

@@ -0,0 +1,24 @@
+// sample-config.js
+module.exports = {
+    'applications': [{
+        'name': 'app',
+        'ready-on': 'message',
+        'run': './../apps/stdout.js'
+    }, {
+        'name': 'trim',
+        'ready-on': 'message',
+        'run': './../apps/stdout.js',
+        'max-log-line-length': 5,
+    }, {
+        'name': 'expire',
+        'ready-on': 'message',
+        'run': './../apps/stdout.js',
+        'log-retention-timeout': 400,
+    }, {
+        'name': 'spammy',
+        'ready-on': 'message',
+        'stop-signal': 'message',
+        'run': './../apps/spammy-app.js',
+        'max-buffered-log-bytes': 20,
+    }]
+};

test/tests/daemon.js

@@ -105,8 +105,8 @@ describe('daemon', function() {
         await daemon.killDaemon();
     });
 
-    it('discard old log lines in RAM', async function() {
-        const daemon = await common.daemonWithConfig('spammy.js');
+    it('discards old log lines in RAM', async function() {
+        const daemon = await common.daemonWithConfig('stdout.js');
         const client = await common.client(daemon);
 
         await client.invoke('start', 'spammy');
@@ -115,7 +115,7 @@ describe('daemon', function() {
 
         const logs = (await client.invoke('logs', 'spammy', {
             lines: 1000
-        })).lines.filter((line) => line.type === 'STDOUT');
+        })).lines.filter((line) => line.type === 'stdout');
 
         assert.equal(logs.length <= 2, true,
             `two or less log line should fit into RAM`);
@@ -124,6 +124,82 @@ describe('daemon', function() {
         await daemon.killDaemon();
     });
 
+    it('discards logs after some time', async function() {
+        const daemon = await common.daemonWithConfig('stdout.js');
+        const client = await common.client(daemon);
+
+        let result = await client.invoke('start', 'expire');
+        await client.invoke('wait');
+        await client.invoke('stop', result.process.id);
+        await client.invoke('wait');
+
+        // Immediately start a new app, aborting the timeout
+        result = await client.invoke('start', 'expire');
+        await client.invoke('wait');
+
+        await common.wait(500);
+
+        assert.notEqual(
+            (await client.invoke('logs', 'expire')).lines.length, 0,
+            `shouldn't have discarded logs`);
+
+        await client.invoke('stop', result.process.id);
+        await client.invoke('wait');
+
+        await common.wait(500);
+
+        assert.equal(
+            (await client.invoke('logs', 'expire')).lines.length, 0,
+            `should've discarded logs`);
+
+        await client.close();
+        await daemon.killDaemon();
+    });
+
+    it('correctly logs multiple lines received at once or apart', async function() {
+        const daemon = await common.daemonWithConfig('stdout.js');
+        const client = await common.client(daemon);
+
+        await client.invoke('start', 'app');
+        await client.invoke('wait');
+        await client.invoke('stop', 0);
+        await client.invoke('wait');
+
+        const logs = (await client.invoke('logs', 'app'))
+            .lines.filter((line) => line.type === 'stdout');
+
+        assert.equal(logs.length, 3, `logged 3 lines`);
+
+        assert.deepEqual(logs.map((line) => line.text),
+            ['TWO LINES', 'AT ONCE', 'A LINE IN TWO PARTS'],
+            `logged everything and in the right order`);
+
+        await client.close();
+        await daemon.killDaemon();
+    });
+
+    it('trim lines exceded "max-log-line-length"', async function() {
+        const daemon = await common.daemonWithConfig('stdout.js');
+        const client = await common.client(daemon);
+
+        await client.invoke('start', 'trim');
+        await client.invoke('wait');
+        await client.invoke('stop', 0);
+        await client.invoke('wait');
+
+        const logs = (await client.invoke('logs', 'trim'))
+            .lines.filter((line) => line.type === 'stdout');
+
+        assert.equal(logs.length, 3, `logged 3 lines`);
+
+        assert.deepEqual(logs.map((line) => line.text),
+            ['TWO L', 'AT ON', 'A LIN'],
+            `logged everything and in the right order`);
+
+        await client.close();
+        await daemon.killDaemon();
+    });
+
     async function startStopTestSingleApp(client, appName) {
         await client.invoke('all', [
             { name: 'start', args: [appName] },
@@ -166,7 +242,7 @@ describe('daemon', function() {
             ], `should have logged '${appName}' lifecycle in the correct order`);
 
         assert.equal(
-            logsCondensed.filter((t) => t === 'stdout').length, 6,
+            logsCondensed.filter((t) => t === 'stdout').length, 3,
             `should have logged all STDOUT lines of '${appName}'`);
     }