From 8c68889b0c1bde4be675f69928d75df04f16046c Mon Sep 17 00:00:00 2001 From: Katharina Irrgang Date: Sun, 4 Feb 2018 17:48:39 +0100 Subject: [PATCH] feat(process): ensure that Ghost is started (#612) closes #472 - added port polling utility - general process manager class offers `ensureStarted` function - systemd extension makes use of `ensureStarted` --- extensions/systemd/systemd.js | 30 +++- extensions/systemd/test/systemd-spec.js | 3 + lib/commands/run.js | 3 +- lib/process-manager.js | 30 ++++ lib/utils/port-polling.js | 103 +++++++++++++ test/unit/commands/run-spec.js | 75 +++++---- test/unit/utils/port-polling-spec.js | 193 ++++++++++++++++++++++++ 7 files changed, 403 insertions(+), 34 deletions(-) create mode 100644 lib/utils/port-polling.js create mode 100644 test/unit/utils/port-polling-spec.js diff --git a/extensions/systemd/systemd.js b/extensions/systemd/systemd.js index f20eac74f..dcbd0f7e4 100644 --- a/extensions/systemd/systemd.js +++ b/extensions/systemd/systemd.js @@ -10,11 +10,26 @@ class SystemdProcessManager extends cli.ProcessManager { return `ghost_${this.instance.name}`; } + get logSuggestion() { + return `journalctl -u ${this.systemdName} -n 50`; + } + start() { this._precheck(); return this.ui.sudo(`systemctl start ${this.systemdName}`) - .catch((error) => Promise.reject(new cli.errors.ProcessError(error))); + .then(() => { + return this.ensureStarted({ + logSuggestion: this.logSuggestion + }); + }) + .catch((error) => { + if (error instanceof cli.errors.CliError) { + throw error; + } + + throw new cli.errors.ProcessError(error); + }); } stop() { @@ -28,7 +43,18 @@ class SystemdProcessManager extends cli.ProcessManager { this._precheck(); return this.ui.sudo(`systemctl restart ${this.systemdName}`) - .catch((error) => Promise.reject(new cli.errors.ProcessError(error))); + .then(() => { + return this.ensureStarted({ + logSuggestion: this.logSuggestion + }); + }) + .catch((error) => { + if (error instanceof cli.errors.CliError) { + throw error; + } + + throw new cli.errors.ProcessError(error); + }); } isEnabled() { diff --git a/extensions/systemd/test/systemd-spec.js b/extensions/systemd/test/systemd-spec.js index 326d88b60..96c228db9 100644 --- a/extensions/systemd/test/systemd-spec.js +++ b/extensions/systemd/test/systemd-spec.js @@ -32,6 +32,7 @@ describe('Unit: Systemd > Process Manager', function () { beforeEach(function () { ui = {sudo: sinon.stub().resolves()}, ext = new Systemd(ui, null, instance); + ext.ensureStarted = sinon.stub().resolves(); ext._precheck = () => true; }); @@ -68,6 +69,7 @@ describe('Unit: Systemd > Process Manager', function () { beforeEach(function () { ui = {sudo: sinon.stub().resolves()}, ext = new Systemd(ui, null, instance); + ext.ensureStarted = sinon.stub().resolves(); ext._precheck = () => true; }); @@ -104,6 +106,7 @@ describe('Unit: Systemd > Process Manager', function () { beforeEach(function () { ui = {sudo: sinon.stub().resolves()}, ext = new Systemd(ui, null, instance); + ext.ensureStarted = sinon.stub().resolves(); ext._precheck = () => true; }); diff --git a/lib/commands/run.js b/lib/commands/run.js index 485e7235c..ae18236f6 100644 --- a/lib/commands/run.js +++ b/lib/commands/run.js @@ -71,7 +71,8 @@ class RunCommand extends Command { return; } - instance.process.error(message.error); + // NOTE: Backwards compatibility of https://github.com/TryGhost/Ghost/pull/9440 + setTimeout(() => {instance.process.error(message.error);}, 1000); }); } diff --git a/lib/process-manager.js b/lib/process-manager.js index a9abab0a2..8a33a2986 100644 --- a/lib/process-manager.js +++ b/lib/process-manager.js @@ -1,4 +1,5 @@ 'use strict'; + const every = require('lodash/every'); const requiredMethods = [ 'start', @@ -60,6 +61,35 @@ class ProcessManager { // Base Implementation } + /** + * General implementation of figuring out if the Ghost blog has started successfully. + * + * @returns {Promise} + */ + ensureStarted(options) { + const portPolling = require('./utils/port-polling'); + + options = Object.assign({ + stopOnError: true, + port: this.instance.config.get('server.port') + }, options || {}); + + return portPolling(options) + .catch((err) => { + if (options.stopOnError) { + return this.stop() + .then(() => { + throw err; + }) + .catch(() => { + throw err; + }); + } + + throw err; + }); + } + /** * This function checks if this process manager can be used on this system * diff --git a/lib/utils/port-polling.js b/lib/utils/port-polling.js new file mode 100644 index 000000000..d85d556c8 --- /dev/null +++ b/lib/utils/port-polling.js @@ -0,0 +1,103 @@ +'use strict'; + +const net = require('net'); +const errors = require('../errors'); + +module.exports = function portPolling(options) { + options = Object.assign({ + timeoutInMS: 1000, + maxTries: 20, + delayOnConnectInMS: 3 * 1000, + logSuggestion: 'ghost log', + socketTimeoutInMS: 1000 * 30 + }, options || {}); + + if (!options.port) { + return Promise.reject(new errors.CliError({ + message: 'Port is required.' + })); + } + + const connectToGhostSocket = (() => { + return new Promise((resolve, reject) => { + const ghostSocket = net.connect(options.port); + let delayOnConnectTimeout; + + // inactivity timeout + ghostSocket.setTimeout(options.socketTimeoutInMS); + ghostSocket.on('timeout', (() => { + if (delayOnConnectTimeout) { + clearTimeout(delayOnConnectTimeout); + } + + ghostSocket.destroy(); + + // force retry + const err = new Error(); + err.retry = true; + reject(err); + })); + + ghostSocket.on('connect', (() => { + if (options.delayOnConnectInMS) { + let ghostDied = false; + + // CASE: client closes socket + ghostSocket.on('close', (() => { + ghostDied = true; + })); + + delayOnConnectTimeout = setTimeout(() => { + ghostSocket.destroy(); + + if (ghostDied) { + reject(new Error('Ghost died.')); + } else { + resolve(); + } + }, options.delayOnConnectInMS); + + return; + } + + ghostSocket.destroy(); + resolve(); + })); + + ghostSocket.on('error', ((err) => { + ghostSocket.destroy(); + + err.retry = true; + reject(err); + })); + }); + }); + + const startPolling = (() => { + return new Promise((resolve, reject) => { + let tries = 0; + + (function retry() { + connectToGhostSocket() + .then(() => { + resolve(); + }) + .catch((err) => { + if (err.retry && tries < options.maxTries) { + tries = tries + 1; + setTimeout(retry, options.timeoutInMS); + return; + } + + reject(new errors.GhostError({ + message: 'Ghost did not start.', + suggestion: options.logSuggestion, + err: err + })); + }); + }()); + }); + }); + + return startPolling(); +}; diff --git a/test/unit/commands/run-spec.js b/test/unit/commands/run-spec.js index 77c6cc857..992259688 100644 --- a/test/unit/commands/run-spec.js +++ b/test/unit/commands/run-spec.js @@ -9,9 +9,15 @@ const modulePath = '../../../lib/commands/run'; const errors = require('../../../lib/errors'); describe('Unit: Commands > Run', function () { + const sandbox = sinon.sandbox.create(); + + afterEach(() => { + sandbox.restore(); + }); + describe('run', function () { it('logs if stdin is tty', function () { - const logStub = sinon.stub().throws(new Error('throw me')); + const logStub = sandbox.stub().throws(new Error('throw me')); const RunCommand = require(modulePath); const instance = new RunCommand({log: logStub}, {}); const oldIsTTY = process.stdin.isTTY; @@ -30,18 +36,18 @@ describe('Unit: Commands > Run', function () { }); it('sets paths.contentPath if it is not already set in config, and calls useDirect if useGhostUser returns false', function () { - const logStub = sinon.stub(); - const useGhostUserStub = sinon.stub().returns(false); + const logStub = sandbox.stub(); + const useGhostUserStub = sandbox.stub().returns(false); const config = configStub(); config.has.returns(false); const fakeInstance = {config: config, dir: '/var/www/ghost'}; - const getInstanceStub = sinon.stub().returns(fakeInstance); + const getInstanceStub = sandbox.stub().returns(fakeInstance); const RunCommand = proxyquire(modulePath, { '../utils/use-ghost-user': useGhostUserStub }); const instance = new RunCommand({log: logStub}, {getInstance: getInstanceStub}); - const useGhostUser = sinon.stub(instance, 'useGhostUser').resolves(); - const useDirect = sinon.stub(instance, 'useDirect').resolves(); + const useGhostUser = sandbox.stub(instance, 'useGhostUser').resolves(); + const useDirect = sandbox.stub(instance, 'useDirect').resolves(); const oldIsTTY = process.stdin.isTTY; process.stdin.isTTY = false; @@ -63,18 +69,18 @@ describe('Unit: Commands > Run', function () { }); it('doesn\'t set paths.contentPath if it is set in cofig, and calls useGhostUser if useGhostUser util returns false', function () { - const logStub = sinon.stub(); - const useGhostUserStub = sinon.stub().returns(true); + const logStub = sandbox.stub(); + const useGhostUserStub = sandbox.stub().returns(true); const config = configStub(); config.has.returns(true); const fakeInstance = {config: config, dir: '/var/www/ghost'}; - const getInstanceStub = sinon.stub().returns(fakeInstance); + const getInstanceStub = sandbox.stub().returns(fakeInstance); const RunCommand = proxyquire(modulePath, { '../utils/use-ghost-user': useGhostUserStub }); const instance = new RunCommand({log: logStub}, {getInstance: getInstanceStub}); - const useGhostUser = sinon.stub(instance, 'useGhostUser').resolves(); - const useDirect = sinon.stub(instance, 'useDirect').resolves(); + const useGhostUser = sandbox.stub(instance, 'useGhostUser').resolves(); + const useDirect = sandbox.stub(instance, 'useDirect').resolves(); const oldIsTTY = process.stdin.isTTY; process.stdin.isTTY = false; @@ -97,14 +103,14 @@ describe('Unit: Commands > Run', function () { it('useGhostUser spawns child process and handles events correctly', function () { const childStub = new EventEmitter(); - const spawnStub = sinon.stub().returns(childStub); + const spawnStub = sandbox.stub().returns(childStub); const RunCommand = proxyquire(modulePath, { child_process: {spawn: spawnStub} }); - const failStub = sinon.stub(); - const logStub = sinon.stub() + const failStub = sandbox.stub(); + const logStub = sandbox.stub() const instance = new RunCommand({fail: failStub, log: logStub}, {}); - const exitStub = sinon.stub(process, 'exit'); + const exitStub = sandbox.stub(process, 'exit'); instance.useGhostUser({dir: '/var/www/ghost'}); @@ -139,8 +145,6 @@ describe('Unit: Commands > Run', function () { expect(exitStub.calledOnce).to.be.true; expect(exitStub.calledWithExactly(1)).to.be.true; - exitStub.restore(); - // Check that it does nothing on success message childStub.emit('message', {started: true}); // nothing should happen @@ -154,19 +158,21 @@ describe('Unit: Commands > Run', function () { } }); - it('useDirect spawns child process and handles events correctly', function () { + it('useDirect spawns child process and handles events correctly', function (done) { + this.timeout(5000); + const childStub = new EventEmitter(); - const spawnStub = sinon.stub().returns(childStub); + const spawnStub = sandbox.stub().returns(childStub); const RunCommand = proxyquire(modulePath, { child_process: {spawn: spawnStub} }); - const failStub = sinon.stub(); + const failStub = sandbox.stub(); const instance = new RunCommand({fail: failStub}, {}); - const successStub = sinon.stub(); - const errorStub = sinon.stub(); - const exitStub = sinon.stub(process, 'exit'); + const successStub = sandbox.stub(); + const errorStub = sandbox.stub(); + const exitStub = sandbox.stub(process, 'exit'); - instance.useDirect({dir: '/var/www/ghost', process: {success: successStub, error: errorStub}}); + instance.useDirect({dir: '/var/www/ghost', process: {success: successStub, error: errorStub}}, {delayErrorChaining: false}); expect(spawnStub.calledOnce).to.be.true; expect(spawnStub.calledWithExactly(process.execPath, ['current/index.js'], { @@ -193,13 +199,20 @@ describe('Unit: Commands > Run', function () { successStub.reset(); errorStub.reset(); + // check message handler with error childStub.emit('message', {error: 'oops I did it again'}); - expect(successStub.called).to.be.false; - expect(errorStub.calledOnce).to.be.true; - expect(errorStub.calledWithExactly('oops I did it again')).to.be.true; - exitStub.restore(); + setTimeout(() => { + try { + expect(successStub.called).to.be.false; + expect(errorStub.calledOnce).to.be.true; + expect(errorStub.calledWithExactly('oops I did it again')).to.be.true; + done(); + } catch (e) { + done(e); + } + }, 2000); }); describe('cleanup handler', function () { @@ -216,7 +229,7 @@ describe('Unit: Commands > Run', function () { const instance = new RunCommand({}, {}); const err = new Error(); err.code = 'EPERM'; - const killStub = sinon.stub().throws(err); + const killStub = sandbox.stub().throws(err); instance.child = {kill: killStub}; instance.sudo = true; @@ -228,7 +241,7 @@ describe('Unit: Commands > Run', function () { const instance = new RunCommand({}, {}); const err = new Error(); err.code = 'EPERM'; - const killStub = sinon.stub().throws(err); + const killStub = sandbox.stub().throws(err); instance.child = {kill: killStub}; instance.sudo = false; @@ -246,7 +259,7 @@ describe('Unit: Commands > Run', function () { const instance = new RunCommand({}, {}); const err = new Error('yikes'); err.code = 'ENOTFOUND'; - const killStub = sinon.stub().throws(err); + const killStub = sandbox.stub().throws(err); instance.child = {kill: killStub}; instance.sudo = true; diff --git a/test/unit/utils/port-polling-spec.js b/test/unit/utils/port-polling-spec.js new file mode 100644 index 000000000..7dbf0bb14 --- /dev/null +++ b/test/unit/utils/port-polling-spec.js @@ -0,0 +1,193 @@ +'use strict'; +const expect = require('chai').expect; +const sinon = require('sinon'); +const net = require('net'); + +const portPolling = require('../../../lib/utils/port-polling'); +const sandbox = sinon.sandbox.create(); + +describe('Unit: Utils > portPolling', function () { + afterEach(function () { + sandbox.restore(); + }); + + it('port is missing', function () { + return portPolling() + .then(() => { + throw new Error('Expected error'); + }) + .catch((err) => { + expect(err.message).to.eql('Port is required.'); + }); + }); + + + it('Ghost does never start', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + netStub.on = function (event, cb) { + if (event === 'error') { + cb(new Error('whoops')); + } + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 3, timeoutInMS: 100}) + .then(() => { + throw new Error('Expected error'); + }) + .catch((err) => { + expect(err.options.suggestion).to.exist; + expect(err.message).to.eql('Ghost did not start.'); + expect(err.err.message).to.eql('whoops'); + expect(netStub.destroy.callCount).to.eql(4); + }); + }); + + it('Ghost does start, but falls over', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + + let i = 0; + netStub.on = function (event, cb) { + i = i + 1; + + if (event === 'close') { + cb(); + } else if (event === 'error' && i === 3) { + cb(new Error()); + } else if (event === 'connect' && i === 5) { + cb(); + } + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 3, timeoutInMS: 100, delayOnConnectInMS: 150}) + .then(() => { + throw new Error('Expected error'); + }) + .catch((err) => { + expect(err.options.suggestion).to.exist; + expect(err.message).to.eql('Ghost did not start.'); + expect(netStub.destroy.callCount).to.eql(2); + }); + }); + + it('Ghost does start', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + + let i = 0; + netStub.on = function (event, cb) { + i = i + 1; + + if (i === 6) { + expect(event).to.eql('close'); + } else if (i === 5 && event === 'connect') { + cb(); + } else if (i === 3 && event === 'error') { + cb(new Error()); + } + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 3, timeoutInMS: 100, delayOnConnectInMS: 150}) + .then(() => { + expect(netStub.destroy.callCount).to.eql(2); + }) + .catch((err) => { + throw err; + }); + }); + + it('Ghost does start, skip delay on connect', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + + netStub.on = function (event, cb) { + expect(event).to.not.eql('close'); + + if (event === 'connect') { + cb(); + } + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 3, timeoutInMS: 100, delayOnConnectInMS: false}) + .then(() => { + expect(netStub.destroy.callCount).to.eql(1); + }) + .catch((err) => { + throw err; + }); + }); + + it('socket times out', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + + netStub.on = function (event, cb) { + if (event === 'timeout') { + cb(); + } + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 3, timeoutInMS: 100, socketTimeoutInMS: 300}) + .then(() => { + throw new Error('Expected error'); + }) + .catch((err) => { + expect(err.options.suggestion).to.exist; + expect(err.message).to.eql('Ghost did not start.'); + expect(netStub.destroy.callCount).to.eql(4); + }); + }); + + it('Ghost connects, but socket times out kicks in', function () { + const netStub = sandbox.stub(); + + netStub.setTimeout = sandbox.stub(); + netStub.destroy = sandbox.stub(); + + const events = {}; + netStub.on = function (event, cb) { + if (event === 'connect') { + cb(); + + setTimeout(() => { + events.timeout(); + }, 100); + } + + events[event] = cb; + }; + + sandbox.stub(net, 'connect').returns(netStub); + + return portPolling({port: 1111, maxTries: 2, timeoutInMS: 100, socketTimeoutInMS: 300}) + .then(() => { + throw new Error('Expected error'); + }) + .catch((err) => { + expect(err.options.suggestion).to.exist; + expect(err.message).to.eql('Ghost did not start.'); + expect(netStub.destroy.callCount).to.eql(3); + }); + }); +});