Added a timeout to the get helper

- The get helper can sometimes take a long time, and in themes that have many get helpers, the request can take far too long to respond
- This adds a timeout to the get helper, so that the page render doesn't block forever
- This won't abort the request to the DB, but instead just means the page will render sooner, and without the get block

ghost/core/core/frontend/helpers/get.js

@@ -117,9 +117,59 @@ function parseOptions(globals, data, options) {
     return options;
 }
 
+/**
+ *
+ * @param {String} resource
+ * @param {String} controllerName
+ * @param {String} action
+ * @param {Object} apiOptions
+ * @returns {Promise<Object>}
+ */
+async function makeAPICall(resource, controllerName, action, apiOptions) {
+    const controller = api[controllerName];
+
+    let timer;
+
+    try {
+        let response;
+
+        if (config.get('optimization:getHelper:timeout:threshold')) {
+            const logLevel = config.get('optimization:getHelper:timeout:level') || 'error';
+            const threshold = config.get('optimization:getHelper:timeout:threshold');
+
+            const apiResponse = controller[action](apiOptions);
+
+            const timeout = new Promise((resolve) => {
+                timer = setTimeout(() => {
+                    logging[logLevel](new errors.HelperWarning({
+                        message: `{{#get}} took longer than ${threshold}ms and was aborted`,
+                        code: 'ABORTED_GET_HELPER',
+                        errorDetails: {
+                            api: `${controllerName}.${action}`,
+                            apiOptions
+                        }
+                    }));
+
+                    resolve({[resource]: []});
+                }, threshold);
+            });
+
+            response = await Promise.race([apiResponse, timeout]);
+            clearTimeout(timer);
+        } else {
+            response = await controller[action](apiOptions);
+        }
+
+        return response;
+    } catch (err) {
+        clearTimeout(timer);
+        throw err;
+    }
+}
+
 /**
  * ## Get
- * @param {Object} resource
+ * @param {String} resource
  * @param {Object} options
  * @returns {Promise<any>}
  */
@@ -149,7 +199,6 @@ module.exports = async function get(resource, options) {
     }
 
     const controllerName = RESOURCES[resource].alias;
-    const controller = api[controllerName];
     const action = isBrowse(apiOptions) ? 'browse' : 'read';
 
     // Parse the options we're going to pass to the API
@@ -157,7 +206,7 @@ module.exports = async function get(resource, options) {
     apiOptions.context = {member: data.member};
 
     try {
-        const response = await controller[action](apiOptions);
+        const response = await makeAPICall(resource, controllerName, action, apiOptions);
 
         // prepare data properties for use with handlebars
         if (response[resource] && response[resource].length) {
@@ -185,9 +234,10 @@ module.exports = async function get(resource, options) {
         data.error = error.message;
         return options.inverse(self, {data: data});
     } finally {
+        if (config.get('optimization:getHelper:notify:threshold')) {
             const totalMs = Date.now() - start;
-        const logLevel = config.get('logging:slowHelper:level');
+            const logLevel = config.get('optimization:getHelper:notify:level') || 'warn';
-        const threshold = config.get('logging:slowHelper:threshold');
+            const threshold = config.get('optimization:getHelper:notify:threshold');
             if (totalMs > threshold) {
                 logging[logLevel](new errors.HelperWarning({
                     message: `{{#get}} helper took ${totalMs}ms to complete`,
@@ -200,6 +250,7 @@ module.exports = async function get(resource, options) {
                 }));
             }
         }
+    }
 };
 
 module.exports.async = true;

ghost/core/core/shared/config/defaults.json

@@ -58,11 +58,7 @@
         },
         "transports": [
             "stdout"
-        ],
+        ]
-        "slowHelper": {
-            "level": "warn",
-            "threshold": 200
-        }
     },
     "spam": {
         "user_login": {
@@ -145,6 +141,18 @@
             "maxAge": 0
         }
     },
+    "optimization": {
+        "getHelper": {
+            "timeout": {
+                "threshold": 5000,
+                "level": "error"
+            },
+            "notify": {
+                "threshold": 200,
+                "level": "warn"
+            }
+        }
+    },
     "imageOptimization": {
         "resize": true,
         "srcsets": true

ghost/core/test/unit/frontend/helpers/get.test.js

@@ -2,6 +2,8 @@ const should = require('should');
 const sinon = require('sinon');
 const Promise = require('bluebird');
 const {SafeString} = require('../../../../core/frontend/services/handlebars');
+const configUtils = require('../../../utils/configUtils');
+const logging = require('@tryghost/logging');
 
 // Stuff we are testing
 const get = require('../../../../core/frontend/helpers/get');
@@ -319,4 +321,60 @@ describe('{{#get}} helper', function () {
             browseStub.firstCall.args[0].context.member.should.eql(member);
         });
     });
+
+    describe('optimization', function () {
+        beforeEach(function () {
+            sinon.spy(logging, 'error');
+            sinon.spy(logging, 'warn');
+
+            sinon.stub(api, 'postsPublic').get(() => {
+                return {
+                    browse: () => {
+                        return new Promise((resolve) => {
+                            setTimeout(() => {
+                                resolve({posts: [{id: 'abcd1234'}]});
+                            }, 5);
+                        });
+                    }
+                };
+            });
+        });
+        afterEach(function () {
+            configUtils.restore();
+        });
+
+        it('should log a warning if it hits the notify threshold', async function () {
+            configUtils.set('optimization:getHelper:notify:threshold', 1);
+
+            await get.call(
+                {},
+                'posts',
+                {hash: {}, data: locals, fn: fn, inverse: inverse}
+            );
+
+            // A log message will be output
+            logging.warn.calledOnce.should.be.true();
+            // The get helper will return as per usual
+            fn.calledOnce.should.be.true();
+            fn.firstCall.args[0].should.be.an.Object().with.property('posts');
+            fn.firstCall.args[0].posts.should.be.an.Array().with.lengthOf(1);
+        });
+
+        it('should log an error and return safely if it hits the timeout threshold', async function () {
+            configUtils.set('optimization:getHelper:timeout:threshold', 1);
+
+            await get.call(
+                {},
+                'posts',
+                {hash: {}, data: locals, fn: fn, inverse: inverse}
+            );
+
+            // A log message will be output
+            logging.error.calledOnce.should.be.true();
+            // The get helper gets called with an empty array of results
+            fn.calledOnce.should.be.true();
+            fn.firstCall.args[0].should.be.an.Object().with.property('posts');
+            fn.firstCall.args[0].posts.should.be.an.Array().with.lengthOf(0);
+        });
+    });
 });