core(driver): add run warning on page load timeout (#10538)

lighthouse-core/gather/driver.js

@@ -918,7 +918,7 @@ class Driver {
    * @param {number} cpuQuietThresholdMs
    * @param {number} maxWaitForLoadedMs
    * @param {number=} maxWaitForFcpMs
-   * @return {Promise<void>}
+   * @return {Promise<{timedOut: boolean}>}
    * @private
    */
   async _waitForFullyLoaded(pauseAfterFcpMs, pauseAfterLoadMs, networkQuietThresholdMs,
@@ -939,6 +939,7 @@ class Driver {
 
     // Wait for all initial load promises. Resolves on cleanup function the clears load
     // timeout timer.
+    /** @type {Promise<() => Promise<{timedOut: boolean}>>} */
     const loadPromise = Promise.all([
       waitForFcp.promise,
       waitForLoadEvent.promise,
@@ -947,9 +948,13 @@ class Driver {
       waitForCPUIdle = this._waitForCPUIdle(cpuQuietThresholdMs);
       return waitForCPUIdle.promise;
     }).then(() => {
-      return function() {
+      /** @return {Promise<{timedOut: boolean}>} */
+      const cleanupFn = async function() {
         log.verbose('Driver', 'loadEventFired and network considered idle');
+        return {timedOut: false};
       };
+
+      return cleanupFn;
     }).catch(err => {
       // Throw the error in the cleanupFn so we still cleanup all our handlers.
       return function() {
@@ -959,6 +964,7 @@ class Driver {
 
     // Last resort timeout. Resolves maxWaitForLoadedMs ms from now on
     // cleanup function that removes loadEvent and network idle listeners.
+    /** @type {Promise<() => Promise<{timedOut: boolean}>>} */
     const maxTimeoutPromise = new Promise((resolve, reject) => {
       maxTimeoutHandle = setTimeout(resolve, maxWaitForLoadedMs);
     }).then(_ => {
@@ -970,6 +976,8 @@ class Driver {
           await this.sendCommand('Runtime.terminateExecution');
           throw new LHError(LHError.errors.PAGE_HUNG);
         }
+
+        return {timedOut: true};
       };
     });
 
@@ -985,7 +993,7 @@ class Driver {
     waitForNetworkIdle.cancel();
     waitForCPUIdle.cancel();
 
-    await cleanupFn();
+    return cleanupFn();
   }
 
   /**
@@ -1071,7 +1079,7 @@ class Driver {
    * Resolves on the url of the loaded page, taking into account any redirects.
    * @param {string} url
    * @param {{waitForFcp?: boolean, waitForLoad?: boolean, waitForNavigated?: boolean, passContext?: LH.Gatherer.PassContext}} options
-   * @return {Promise<string>}
+   * @return {Promise<{finalUrl: string, timedOut: boolean}>}
    */
   async gotoURL(url, options = {}) {
     const waitForFcp = options.waitForFcp || false;
@@ -1101,6 +1109,7 @@ class Driver {
     // No timeout needed for Page.navigate. See https://github.com/GoogleChrome/lighthouse/pull/6413.
     const waitforPageNavigateCmd = this._innerSendCommand('Page.navigate', undefined, {url});
 
+    let timedOut = false;
     if (waitForNavigated) {
       await this._waitForFrameNavigated();
     } else if (waitForLoad) {
@@ -1120,14 +1129,18 @@ class Driver {
       /* eslint-enable max-len */
 
       if (!waitForFcp) maxFCPMs = undefined;
-      await this._waitForFullyLoaded(pauseAfterFcpMs, pauseAfterLoadMs, networkQuietThresholdMs,
-        cpuQuietThresholdMs, maxWaitMs, maxFCPMs);
+      const loadResult = await this._waitForFullyLoaded(pauseAfterFcpMs, pauseAfterLoadMs,
+        networkQuietThresholdMs, cpuQuietThresholdMs, maxWaitMs, maxFCPMs);
+      timedOut = loadResult.timedOut;
     }
 
     // Bring `Page.navigate` errors back into the promise chain. See https://github.com/GoogleChrome/lighthouse/pull/6739.
     await waitforPageNavigateCmd;
 
-    return this._endNetworkStatusMonitoring();
+    return {
+      finalUrl: this._endNetworkStatusMonitoring(),
+      timedOut,
+    };
   }
 
   /**

lighthouse-core/gather/gather-runner.js

@@ -24,6 +24,11 @@ const UIStrings = {
   warningRedirected: 'The page may not be loading as expected because your test URL ' +
   `({requested}) was redirected to {final}. ` +
   'Try testing the second URL directly.',
+  /**
+   * @description Warning that Lighthouse timed out while waiting for the page to load.
+   */
+  warningTimeout: 'The page loaded too slowly to finish within the time limit. ' +
+  'Results may be incomplete.',
 };
 
 const str_ = i18n.createMessageInstanceIdFn(__filename, UIStrings);
@@ -76,12 +81,13 @@ class GatherRunner {
     };
     log.time(status);
     try {
-      const finalUrl = await driver.gotoURL(passContext.url, {
+      const {finalUrl, timedOut} = await driver.gotoURL(passContext.url, {
         waitForFcp: passContext.passConfig.recordTrace,
         waitForLoad: true,
         passContext,
       });
       passContext.url = finalUrl;
+      if (timedOut) passContext.LighthouseRunWarnings.push(str_(UIStrings.warningTimeout));
     } catch (err) {
       // If it's one of our loading-based LHErrors, we'll treat it as a page load error.
       if (err.code === 'NO_FCP' || err.code === 'PAGE_HUNG') {

lighthouse-core/lib/i18n/locales/en-US.json

@@ -1418,6 +1418,9 @@
   "lighthouse-core/gather/gather-runner.js | warningRedirected": {
     "message": "The page may not be loading as expected because your test URL ({requested}) was redirected to {final}. Try testing the second URL directly."
   },
+  "lighthouse-core/gather/gather-runner.js | warningTimeout": {
+    "message": "The page loaded too slowly to finish within the time limit. Results may be incomplete."
+  },
   "lighthouse-core/lib/i18n/i18n.js | columnCacheTTL": {
     "message": "Cache TTL"
   },

lighthouse-core/lib/i18n/locales/en-XL.json

@@ -1418,6 +1418,9 @@
   "lighthouse-core/gather/gather-runner.js | warningRedirected": {
     "message": "T̂h́ê ṕâǵê ḿâý n̂ót̂ b́ê ĺôád̂ín̂ǵ âś êx́p̂éĉt́êd́ b̂éĉáûśê ýôúr̂ t́êśt̂ ÚR̂Ĺ ({requested}) ŵáŝ ŕêd́îŕêćt̂éd̂ t́ô {final}. T́r̂ý t̂éŝt́îńĝ t́ĥé ŝéĉón̂d́ ÛŔL̂ d́îŕêćt̂ĺŷ."
   },
+  "lighthouse-core/gather/gather-runner.js | warningTimeout": {
+    "message": "T̂h́ê ṕâǵê ĺôád̂éd̂ t́ôó ŝĺôẃl̂ý t̂ó f̂ín̂íŝh́ ŵít̂h́îń t̂h́ê t́îḿê ĺîḿît́. R̂éŝúl̂t́ŝ ḿâý b̂é îńĉóm̂ṕl̂ét̂é."
+  },
   "lighthouse-core/lib/i18n/i18n.js | columnCacheTTL": {
     "message": "Ĉáĉh́ê T́T̂Ĺ"
   },

lighthouse-core/test/gather/driver-test.js

@@ -514,8 +514,7 @@ describe('.gotoURL', () => {
     const loadPromise = driver.gotoURL(startUrl, loadOptions);
 
     await flushAllTimersAndMicrotasks();
-    const loadedUrl = await loadPromise;
-    expect(loadedUrl).toEqual(finalUrl);
+    expect(await loadPromise).toEqual({finalUrl, timedOut: false});
   });
 
   describe('when waitForNavigated', () => {
@@ -577,7 +576,7 @@ describe('.gotoURL', () => {
         waitForResult.mockResolve();
         await flushAllTimersAndMicrotasks();
         expect(loadPromise).toBeDone(`Did not resolve on ${name}`);
-        await loadPromise;
+        expect(await loadPromise).toMatchObject({timedOut: false});
       });
     });
 
@@ -607,7 +606,7 @@ describe('.gotoURL', () => {
       driver._waitForCPUIdle.mockResolve();
       await flushAllTimersAndMicrotasks();
       expect(loadPromise).toBeDone(`Did not resolve on CPU idle`);
-      await loadPromise;
+      expect(await loadPromise).toMatchObject({timedOut: false});
     });
 
     it('should timeout when not resolved fast enough', async () => {
@@ -638,6 +637,7 @@ describe('.gotoURL', () => {
       expect(driver._waitForLoadEvent.getMockCancelFn()).toHaveBeenCalled();
       expect(driver._waitForNetworkIdle.getMockCancelFn()).toHaveBeenCalled();
       expect(driver._waitForCPUIdle.getMockCancelFn()).toHaveBeenCalled();
+      expect(await loadPromise).toMatchObject({timedOut: true});
     });
 
     it('should cleanup listeners even when waits reject', async () => {

lighthouse-core/test/gather/fake-driver.js

@@ -34,7 +34,7 @@ function makeFakeDriver({protocolGetVersionResponse}) {
     },
     /** @param {string} url */
     gotoURL(url) {
-      return Promise.resolve(url);
+      return Promise.resolve({finalUrl: url, timedOut: false});
     },
     beginEmulation() {
       return Promise.resolve();

lighthouse-core/test/gather/gather-runner-test.js

@@ -143,7 +143,7 @@ describe('GatherRunner', function() {
     const url2 = 'https://example.com/interstitial';
     const driver = {
       gotoURL() {
-        return Promise.resolve(url2);
+        return Promise.resolve({finalUrl: url2, timedOut: false});
       },
     };
 
@@ -216,7 +216,7 @@ describe('GatherRunner', function() {
     const finalUrl = 'https://example.com/interstitial';
     const driver = Object.assign({}, fakeDriver, {
       gotoURL() {
-        return Promise.resolve(finalUrl);
+        return Promise.resolve({finalUrl, timedOut: false});
       },
     });
     const config = makeConfig({passes: [{}]});
@@ -427,7 +427,7 @@ describe('GatherRunner', function() {
     const driver = {
       beginDevtoolsLog: asyncFunc,
       beginTrace: asyncFunc,
-      gotoURL: asyncFunc,
+      gotoURL: async () => ({}),
       cleanBrowserCaches: createCheck('calledCleanBrowserCaches'),
       setThrottling: asyncFunc,
       blockUrlPatterns: asyncFunc,
@@ -534,9 +534,9 @@ describe('GatherRunner', function() {
     // NO_FCP should be ignored because it's a warn pass.
     const navigationError = new LHError(LHError.errors.NO_FCP);
 
-    const gotoUrlForAboutBlank = jest.fn().mockResolvedValue(null);
+    const gotoUrlForAboutBlank = jest.fn().mockResolvedValue({});
     const gotoUrlForRealUrl = jest.fn()
-      .mockResolvedValueOnce(requestedUrl)
+      .mockResolvedValueOnce({finalUrl: requestedUrl, timedOut: false})
       .mockRejectedValueOnce(navigationError);
     const driver = Object.assign({}, fakeDriver, {
       online: true,
@@ -709,7 +709,7 @@ describe('GatherRunner', function() {
         return Promise.resolve();
       },
       gotoURL() {
-        return Promise.resolve();
+        return Promise.resolve({finalUrl: '', timedOut: false});
       },
     };
 
@@ -895,7 +895,7 @@ describe('GatherRunner', function() {
         if (url.includes('blank')) return null;
         if (firstLoad) {
           firstLoad = false;
-          return requestedUrl;
+          return {finalUrl: requestedUrl, timedOut: false};
         } else {
           throw new LHError(LHError.errors.NO_FCP);
         }
@@ -1584,7 +1584,7 @@ describe('GatherRunner', function() {
       const unresolvedDriver = Object.assign({}, fakeDriver, {
         online: true,
         gotoURL() {
-          return Promise.resolve(requestedUrl);
+          return Promise.resolve({finalUrl: requestedUrl, timedOut: false});
         },
         endDevtoolsLog() {
           return unresolvedPerfLog;
@@ -1602,6 +1602,34 @@ describe('GatherRunner', function() {
       });
     });
 
+    it('resolves but warns when page times out', () => {
+      const config = makeConfig({
+        passes: [{
+          recordTrace: true,
+          passName: 'firstPass',
+          gatherers: [],
+        }],
+      });
+
+      const requestedUrl = 'http://www.slow-loading-page.com/';
+      const timedoutDriver = Object.assign({}, fakeDriver, {
+        online: true,
+        gotoURL() {
+          return Promise.resolve({finalUrl: requestedUrl, timedOut: true});
+        },
+      });
+
+      return GatherRunner.run(config.passes, {
+        driver: timedoutDriver,
+        requestedUrl,
+        settings: config.settings,
+      }).then(artifacts => {
+        assert.equal(artifacts.LighthouseRunWarnings.length, 1);
+        expect(artifacts.LighthouseRunWarnings[0])
+          .toBeDisplayString(/too slow/);
+      });
+    });
+
     it('resolves when domain name can\'t be resolved but is offline', () => {
       const config = makeConfig({
         passes: [{
@@ -1616,7 +1644,7 @@ describe('GatherRunner', function() {
       const unresolvedDriver = Object.assign({}, fakeDriver, {
         online: false,
         gotoURL() {
-          return Promise.resolve(requestedUrl);
+          return Promise.resolve({finalUrl: requestedUrl, timedOut: false});
         },
         endDevtoolsLog() {
           return unresolvedPerfLog;

lighthouse-core/test/runner-test.js

@@ -749,10 +749,10 @@ describe('Runner', () => {
         online: true,
         // Loads the page successfully in the first pass, fails with PAGE_HUNG in the second.
         async gotoURL(url) {
-          if (url.includes('blank')) return null;
+          if (url.includes('blank')) return {finalUrl: '', timedOut: false};
           if (firstLoad) {
             firstLoad = false;
-            return url;
+            return {finalUrl: url, timedOut: false};
           } else {
             throw new LHError(LHError.errors.PAGE_HUNG);
           }

readme.md

@@ -273,9 +273,9 @@ yarn build-all
 ```
 
 #### installing protobuf
-If changing audit output, you'll need to have v3.7.1 of the protocol-buffer/protobuf compiler installed. (v3.7.1 is known to be compatible, and 3.11.x is known to be **not** compatible.). 
+If changing audit output, you'll need to have v3.7.1 of the protocol-buffer/protobuf compiler installed. (v3.7.1 is known to be compatible, and 3.11.x is known to be **not** compatible.).
 
-Homebrew should be able to install it correctly: `brew install protobuf@3.7.1`
+Homebrew should be able to install it correctly: `brew install protobuf@3.7`
 
 But if you want to do it manually, these steps that have worked well for us: