From 958ef9fe8fdfce3bf81a81f8a942a51ca5e344c6 Mon Sep 17 00:00:00 2001 From: kirrg001 Date: Sat, 3 Feb 2018 16:20:07 +0100 Subject: [PATCH 1/4] feat(core): Ensure that Ghost was started 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 | 12 +- lib/process-manager.js | 30 ++++ lib/utils/port-polling.js | 104 +++++++++++++ test/unit/commands/run-spec.js | 2 +- test/unit/utils/port-polling-spec.js | 193 ++++++++++++++++++++++++ 7 files changed, 369 insertions(+), 5 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..a33d287ab 100644 --- a/lib/commands/run.js +++ b/lib/commands/run.js @@ -1,5 +1,6 @@ 'use strict'; const spawn = require('child_process').spawn; +const merge = require('lodash/merge'); const Command = require('../command'); class RunCommand extends Command { @@ -54,7 +55,9 @@ class RunCommand extends Command { this.sudo = true; } - useDirect(instance) { + useDirect(instance, options) { + options = merge({delayErrorChaining: true}, options || {}); + this.child = spawn(process.execPath, ['current/index.js'], { cwd: instance.dir, stdio: [0, 1, 2, 'ipc'] @@ -71,7 +74,12 @@ class RunCommand extends Command { return; } - instance.process.error(message.error); + if (!options.delayErrorChaining) { + instance.process.error(message.error); + } else { + // 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..b10409727 100644 --- a/lib/process-manager.js +++ b/lib/process-manager.js @@ -1,5 +1,8 @@ 'use strict'; + const every = require('lodash/every'); +const merge = require('lodash/merge'); +const portPolling = require('./utils/port-polling'); const requiredMethods = [ 'start', 'stop', @@ -60,6 +63,33 @@ class ProcessManager { // Base Implementation } + /** + * General implementation of figuring out if the Ghost blog has started successfully. + * + * @returns {Promise} + */ + ensureStarted(options) { + options = merge({ + 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..c4537acd3 --- /dev/null +++ b/lib/utils/port-polling.js @@ -0,0 +1,104 @@ +'use strict'; + +const net = require('net'); +const merge = require('lodash/merge'); +const errors = require('../errors'); + +module.exports = function portPolling(options) { + options = merge({ + 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..0a5fbfec5 100644 --- a/test/unit/commands/run-spec.js +++ b/test/unit/commands/run-spec.js @@ -166,7 +166,7 @@ describe('Unit: Commands > Run', function () { const errorStub = sinon.stub(); const exitStub = sinon.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'], { 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); + }); + }); +}); From 0073989624be50af173a60283502dd3e83fcdf65 Mon Sep 17 00:00:00 2001 From: Austin Burdine Date: Sun, 4 Feb 2018 16:07:49 +0100 Subject: [PATCH 2/4] fix test workaround --- lib/commands/run.js | 13 ++---- test/unit/commands/run-spec.js | 73 ++++++++++++++++++++-------------- 2 files changed, 46 insertions(+), 40 deletions(-) diff --git a/lib/commands/run.js b/lib/commands/run.js index a33d287ab..ae18236f6 100644 --- a/lib/commands/run.js +++ b/lib/commands/run.js @@ -1,6 +1,5 @@ 'use strict'; const spawn = require('child_process').spawn; -const merge = require('lodash/merge'); const Command = require('../command'); class RunCommand extends Command { @@ -55,9 +54,7 @@ class RunCommand extends Command { this.sudo = true; } - useDirect(instance, options) { - options = merge({delayErrorChaining: true}, options || {}); - + useDirect(instance) { this.child = spawn(process.execPath, ['current/index.js'], { cwd: instance.dir, stdio: [0, 1, 2, 'ipc'] @@ -74,12 +71,8 @@ class RunCommand extends Command { return; } - if (!options.delayErrorChaining) { - instance.process.error(message.error); - } else { - // NOTE: Backwards compatibility of https://github.com/TryGhost/Ghost/pull/9440 - setTimeout(() => {instance.process.error(message.error);}, 1000); - } + // NOTE: Backwards compatibility of https://github.com/TryGhost/Ghost/pull/9440 + setTimeout(() => {instance.process.error(message.error);}, 1000); }); } diff --git a/test/unit/commands/run-spec.js b/test/unit/commands/run-spec.js index 0a5fbfec5..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,17 +158,19 @@ 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}}, {delayErrorChaining: false}); @@ -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; From 40028158dea3fb794ee98a712ebf30cccffcd3bb Mon Sep 17 00:00:00 2001 From: kirrg001 Date: Sun, 4 Feb 2018 17:24:38 +0100 Subject: [PATCH 3/4] Do not require port polling utility on top of the PM --- lib/process-manager.js | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/lib/process-manager.js b/lib/process-manager.js index b10409727..d7773148e 100644 --- a/lib/process-manager.js +++ b/lib/process-manager.js @@ -2,7 +2,6 @@ const every = require('lodash/every'); const merge = require('lodash/merge'); -const portPolling = require('./utils/port-polling'); const requiredMethods = [ 'start', 'stop', @@ -69,6 +68,8 @@ class ProcessManager { * @returns {Promise} */ ensureStarted(options) { + const portPolling = require('./utils/port-polling'); + options = merge({ stopOnError: true, port: this.instance.config.get('server.port') From 36f63404b22fd6e5278ddb014ad4b717c9b2c0fd Mon Sep 17 00:00:00 2001 From: kirrg001 Date: Sun, 4 Feb 2018 17:27:39 +0100 Subject: [PATCH 4/4] use Object.assign instead of _.merge --- lib/process-manager.js | 3 +-- lib/utils/port-polling.js | 3 +-- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/lib/process-manager.js b/lib/process-manager.js index d7773148e..8a33a2986 100644 --- a/lib/process-manager.js +++ b/lib/process-manager.js @@ -1,7 +1,6 @@ 'use strict'; const every = require('lodash/every'); -const merge = require('lodash/merge'); const requiredMethods = [ 'start', 'stop', @@ -70,7 +69,7 @@ class ProcessManager { ensureStarted(options) { const portPolling = require('./utils/port-polling'); - options = merge({ + options = Object.assign({ stopOnError: true, port: this.instance.config.get('server.port') }, options || {}); diff --git a/lib/utils/port-polling.js b/lib/utils/port-polling.js index c4537acd3..d85d556c8 100644 --- a/lib/utils/port-polling.js +++ b/lib/utils/port-polling.js @@ -1,11 +1,10 @@ 'use strict'; const net = require('net'); -const merge = require('lodash/merge'); const errors = require('../errors'); module.exports = function portPolling(options) { - options = merge({ + options = Object.assign({ timeoutInMS: 1000, maxTries: 20, delayOnConnectInMS: 3 * 1000,