core(driver): pause after FCP event before resolving load (#10505)

2020-03-27 10:02:16 -05:00 · 2020-03-27 10:02:16 -05:00 · f1216f9b85
--- a/lighthouse-cli/test/cli/snapshots/index-test.js.snap
+++ b/lighthouse-cli/test/cli/snapshots/index-test.js.snap
@ -1294,6 +1294,7 @@ Object {
      "loadFailureMode": "fatal",
      "networkQuietThresholdMs": 1000,
      "passName": "defaultPass",
+      "pauseAfterFcpMs": 1000,
      "pauseAfterLoadMs": 1000,
      "recordTrace": true,
      "useThrottling": true,
@ -1316,6 +1317,7 @@ Object {
      "loadFailureMode": "ignore",
      "networkQuietThresholdMs": 0,
      "passName": "offlinePass",
+      "pauseAfterFcpMs": 0,
      "pauseAfterLoadMs": 0,
      "recordTrace": false,
      "useThrottling": false,
@ -1345,6 +1347,7 @@ Object {
      "loadFailureMode": "warn",
      "networkQuietThresholdMs": 0,
      "passName": "redirectPass",
+      "pauseAfterFcpMs": 0,
      "pauseAfterLoadMs": 0,
      "recordTrace": false,
      "useThrottling": false,
@ -1481,6 +1484,7 @@ Object {
      "loadFailureMode": "fatal",
      "networkQuietThresholdMs": 1000,
      "passName": "defaultPass",
+      "pauseAfterFcpMs": 1000,
      "pauseAfterLoadMs": 1000,
      "recordTrace": true,
      "useThrottling": true,
--- a/lighthouse-cli/test/fixtures/tricky-tti-late-fcp.html
+++ b/lighthouse-cli/test/fixtures/tricky-tti-late-fcp.html
@ -0,0 +1,30 @@
+<!doctype html>
+<!--
+ * Copyright 2020 The Lighthouse Authors. All Rights Reserved.
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at http://www.apache.org/licenses/LICENSE-2.0
+ * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions and limitations under the License.
+-->
+<html>
+<meta name="viewport" content="width=device-width, initial-scale=1, minimum-scale=1">
+<body>
+  <script>
+    /**
+     * Stalls the main thread for timeInMs
+     */
+    function stall(timeInMs) {
+      const start = performance.now();
+      while (performance.now() - start < timeInMs) {
+        for (let i = 0; i < 1000000; i++) ;
+      }
+    }
+
+    setTimeout(() => stall(100), 1000); // stall for 100ms, 1 second out
+    setTimeout(() => stall(100), 3000); // stall for 100ms, 3 seconds out
+
+    // FCP at 5 seconds out, after load, network quiet, and CPU quiet
+    // NOTE: devtools throttling has a bug that makes even this layout become a long task
+    // so must be run with --throttling-method=provided.
+    setTimeout(() => document.body.textContent = 'Hello FCP!', 5000);
+  </script>
+</body>
+</html>
--- a/lighthouse-cli/test/smokehouse/test-definitions/core-tests.js
+++ b/lighthouse-cli/test/smokehouse/test-definitions/core-tests.js
@ -65,7 +65,7 @@ const smokeTests = [{
 }, {
  id: 'metrics',
  expectations: require('./tricky-metrics/expectations.js'),
-  config: require('../../../../lighthouse-core/config/perf-config.js'),
+  config: require('../../../../lighthouse-core/config/no-throttling-config.js'),
 }, {
  id: 'mixed-content',
  expectations: require('./mixed-content/mixed-content-expectations.js'),
--- a/lighthouse-cli/test/smokehouse/test-definitions/tricky-metrics/expectations.js
+++ b/lighthouse-cli/test/smokehouse/test-definitions/tricky-metrics/expectations.js
@ -26,6 +26,22 @@ module.exports = [
      },
    },
  },
+  {
+    lhr: {
+      requestedUrl: 'http://localhost:10200/tricky-tti-late-fcp.html',
+      finalUrl: 'http://localhost:10200/tricky-tti-late-fcp.html',
+      audits: {
+        'first-cpu-idle': {
+          // FCP at ~5 seconds out
+          numericValue: '>4900',
+        },
+        'interactive': {
+          // FCP at ~5 seconds out
+          numericValue: '>4900',
+        },
+      },
+    },
+  },
  {
    lhr: {
      requestedUrl: 'http://localhost:10200/delayed-fcp.html',
--- a/lighthouse-core/config/config.js
+++ b/lighthouse-core/config/config.js
@ -546,6 +546,8 @@ class Config {
    const defaultPass = passes.find(pass => pass.passName === 'defaultPass');
    if (!defaultPass) return;
    const overrides = constants.nonSimulatedPassConfigOverrides;
+    defaultPass.pauseAfterFcpMs =
+      Math.max(overrides.pauseAfterFcpMs, defaultPass.pauseAfterFcpMs);
    defaultPass.pauseAfterLoadMs =
      Math.max(overrides.pauseAfterLoadMs, defaultPass.pauseAfterLoadMs);
    defaultPass.cpuQuietThresholdMs =
--- a/lighthouse-core/config/constants.js
+++ b/lighthouse-core/config/constants.js
@ -83,6 +83,7 @@ const defaultPassConfig = {
  loadFailureMode: 'fatal',
  recordTrace: false,
  useThrottling: false,
+  pauseAfterFcpMs: 0,
  pauseAfterLoadMs: 0,
  networkQuietThresholdMs: 0,
  cpuQuietThresholdMs: 0,
@ -92,6 +93,7 @@ const defaultPassConfig = {
 };

 const nonSimulatedPassConfigOverrides = {
+  pauseAfterFcpMs: 5250,
  pauseAfterLoadMs: 5250,
  networkQuietThresholdMs: 5250,
  cpuQuietThresholdMs: 5250,
--- a/lighthouse-core/config/default-config.js
+++ b/lighthouse-core/config/default-config.js
@ -122,6 +122,7 @@ const defaultConfig = {
    passName: 'defaultPass',
    recordTrace: true,
    useThrottling: true,
+    pauseAfterFcpMs: 1000,
    pauseAfterLoadMs: 1000,
    networkQuietThresholdMs: 1000,
    cpuQuietThresholdMs: 1000,
--- a/lighthouse-core/config/no-throttling-config.js
+++ b/lighthouse-core/config/no-throttling-config.js
@ -0,0 +1,17 @@
+/**
+ * @license Copyright 2020 The Lighthouse Authors. All Rights Reserved.
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at http://www.apache.org/licenses/LICENSE-2.0
+ * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions and limitations under the License.
+ */
+'use strict';
+
+/** @type {LH.Config.Json} */
+const perfConfig = {
+  extends: 'lighthouse:default',
+  settings: {
+    throttlingMethod: 'provided',
+    onlyCategories: ['performance'],
+  },
+};
+
+module.exports = perfConfig;
--- a/lighthouse-core/gather/driver.js
+++ b/lighthouse-core/gather/driver.js
@ -24,6 +24,8 @@ const pageFunctions = require('../lib/page-functions.js');
 // eslint-disable-next-line no-unused-vars
 const Connection = require('./connections/connection.js');

+// Controls how long to wait after FCP before continuing
+const DEFAULT_PAUSE_AFTER_FCP = 0;
 // Controls how long to wait after onLoad before continuing
 const DEFAULT_PAUSE_AFTER_LOAD = 0;
 // Controls how long to wait between network requests before determining the network is quiet
@ -649,10 +651,11 @@ class Driver {

  /**
   * Returns a promise that resolve when a frame has a FCP.
+   * @param {number} pauseAfterFcpMs
   * @param {number} maxWaitForFCPMs
   * @return {{promise: Promise<void>, cancel: function(): void}}
   */
-  _waitForFCP(maxWaitForFCPMs) {
+  _waitForFCP(pauseAfterFcpMs, maxWaitForFCPMs) {
    /** @type {(() => void)} */
    let cancel = () => {
      throw new Error('_waitForFCP.cancel() called before it was defined');
@ -662,12 +665,16 @@ class Driver {
      const maxWaitTimeout = setTimeout(() => {
        reject(new LHError(LHError.errors.NO_FCP));
      }, maxWaitForFCPMs);
+      /** @type {NodeJS.Timeout|undefined} */
+      let loadTimeout;

      /** @param {LH.Crdp.Page.LifecycleEventEvent} e */
      const lifecycleListener = e => {
        if (e.name === 'firstContentfulPaint') {
-          resolve();
-          cancel();
+          loadTimeout = setTimeout(() => {
+            resolve();
+            cancel();
+          }, pauseAfterFcpMs);
        }
      };

@ -679,6 +686,7 @@ class Driver {
        canceled = true;
        this.off('Page.lifecycleEvent', lifecycleListener);
        maxWaitTimeout && clearTimeout(maxWaitTimeout);
+        loadTimeout && clearTimeout(loadTimeout);
        reject(new Error('Wait for FCP canceled'));
      };
    });
@ -904,21 +912,24 @@ class Driver {
   *    - cpuQuietThresholdMs have passed since the last long task after network-2-quiet.
   * - maxWaitForLoadedMs milliseconds have passed.
   * See https://github.com/GoogleChrome/lighthouse/issues/627 for more.
+   * @param {number} pauseAfterFcpMs
   * @param {number} pauseAfterLoadMs
   * @param {number} networkQuietThresholdMs
   * @param {number} cpuQuietThresholdMs
   * @param {number} maxWaitForLoadedMs
-   * @param {number=} maxWaitForFCPMs
+   * @param {number=} maxWaitForFcpMs
   * @return {Promise<void>}
   * @private
   */
-  async _waitForFullyLoaded(pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs,
-      maxWaitForLoadedMs, maxWaitForFCPMs) {
+  async _waitForFullyLoaded(pauseAfterFcpMs, pauseAfterLoadMs, networkQuietThresholdMs,
+      cpuQuietThresholdMs, maxWaitForLoadedMs, maxWaitForFcpMs) {
    /** @type {NodeJS.Timer|undefined} */
    let maxTimeoutHandle;

-    // Listener for onload. Resolves on first FCP event.
-    const waitForFCP = maxWaitForFCPMs ? this._waitForFCP(maxWaitForFCPMs) : this._waitForNothing();
+    // Listener for FCP. Resolves pauseAfterFcpMs ms after first FCP event.
+    const waitForFCP = maxWaitForFcpMs ?
+      this._waitForFCP(pauseAfterFcpMs, maxWaitForFcpMs) :
+      this._waitForNothing();
    // Listener for onload. Resolves pauseAfterLoadMs ms after load.
    const waitForLoadEvent = this._waitForLoadEvent(pauseAfterLoadMs);
    // Network listener. Resolves when the network has been idle for networkQuietThresholdMs.
@ -926,7 +937,7 @@ class Driver {
    // CPU listener. Resolves when the CPU has been idle for cpuQuietThresholdMs after network idle.
    let waitForCPUIdle = this._waitForNothing();

-    // Wait for both load promises. Resolves on cleanup function the clears load
+    // Wait for all initial load promises. Resolves on cleanup function the clears load
    // timeout timer.
    const loadPromise = Promise.all([
      waitForFCP.promise,
@ -1094,11 +1105,13 @@ class Driver {
      await this._waitForFrameNavigated();
    } else if (waitForLoad) {
      const passConfig = /** @type {Partial<LH.Config.Pass>} */ (passContext.passConfig || {});
-      let {pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs} = passConfig;
+
+      /* eslint-disable max-len */
+      let {pauseAfterFcpMs, pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs} = passConfig;
      let maxWaitMs = passContext.settings && passContext.settings.maxWaitForLoad;
      let maxFCPMs = passContext.settings && passContext.settings.maxWaitForFcp;

-      /* eslint-disable max-len */
+      if (typeof pauseAfterFcpMs !== 'number') pauseAfterFcpMs = DEFAULT_PAUSE_AFTER_FCP;
      if (typeof pauseAfterLoadMs !== 'number') pauseAfterLoadMs = DEFAULT_PAUSE_AFTER_LOAD;
      if (typeof networkQuietThresholdMs !== 'number') networkQuietThresholdMs = DEFAULT_NETWORK_QUIET_THRESHOLD;
      if (typeof cpuQuietThresholdMs !== 'number') cpuQuietThresholdMs = DEFAULT_CPU_QUIET_THRESHOLD;
@ -1107,8 +1120,8 @@ class Driver {
      /* eslint-enable max-len */

      if (!waitForFCP) maxFCPMs = undefined;
-      await this._waitForFullyLoaded(pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs,
-          maxWaitMs, maxFCPMs);
+      await this._waitForFullyLoaded(pauseAfterFcpMs, pauseAfterLoadMs, networkQuietThresholdMs,
+        cpuQuietThresholdMs, maxWaitMs, maxFCPMs);
    }

    // Bring `Page.navigate` errors back into the promise chain. See https://github.com/GoogleChrome/lighthouse/pull/6739.
--- a/lighthouse-core/test/config/config-test.js
+++ b/lighthouse-core/test/config/config-test.js
@ -833,6 +833,7 @@ describe('Config', () => {

    assert.equal(config.settings.throttlingMethod, 'devtools');
    assert.equal(config.passes[0].passName, 'defaultPass');
+    assert.ok(config.passes[0].pauseAfterFcpMs >= 5000, 'did not adjust fcp quiet ms');
    assert.ok(config.passes[0].pauseAfterLoadMs >= 5000, 'did not adjust load quiet ms');
    assert.ok(config.passes[0].cpuQuietThresholdMs >= 5000, 'did not adjust cpu quiet ms');
    assert.ok(config.passes[0].networkQuietThresholdMs >= 5000, 'did not adjust network quiet ms');
--- a/lighthouse-core/test/gather/driver-test.js
+++ b/lighthouse-core/test/gather/driver-test.js
@ -659,7 +659,7 @@ describe('._waitForFCP', () => {
  it('should not resolve until FCP fires', async () => {
    driver.on = driver.once = createMockOnceFn();

-    const waitPromise = makePromiseInspectable(driver._waitForFCP(60 * 1000).promise);
+    const waitPromise = makePromiseInspectable(driver._waitForFCP(0, 60 * 1000).promise);
    const listener = driver.on.findListener('Page.lifecycleEvent');

    await flushAllTimersAndMicrotasks();
@ -675,10 +675,30 @@ describe('._waitForFCP', () => {
    await waitPromise;
  });

+  it('should wait for pauseAfterFcpMs after FCP', async () => {
+    driver.on = driver.once = createMockOnceFn();
+
+    const waitPromise = makePromiseInspectable(driver._waitForFCP(5000, 60 * 1000).promise);
+    const listener = driver.on.findListener('Page.lifecycleEvent');
+
+    await flushAllTimersAndMicrotasks();
+    expect(waitPromise).not.toBeDone('Resolved without FCP');
+
+    listener({name: 'firstContentfulPaint'});
+    await flushAllTimersAndMicrotasks();
+    expect(waitPromise).not.toBeDone('Did not wait for pauseAfterFcpMs');
+
+    jest.advanceTimersByTime(5001);
+    await flushAllTimersAndMicrotasks();
+    expect(waitPromise).toBeDone('Did not resolve after pauseAfterFcpMs');
+
+    await waitPromise;
+  });
+
  it('should timeout', async () => {
    driver.on = driver.once = createMockOnceFn();

-    const waitPromise = makePromiseInspectable(driver._waitForFCP(5000).promise);
+    const waitPromise = makePromiseInspectable(driver._waitForFCP(0, 5000).promise);

    await flushAllTimersAndMicrotasks();
    expect(waitPromise).not.toBeDone('Resolved before timeout');
@ -693,7 +713,7 @@ describe('._waitForFCP', () => {
    driver.on = driver.once = createMockOnceFn();
    driver.off = jest.fn();

-    const {promise: rawPromise, cancel} = driver._waitForFCP(5000);
+    const {promise: rawPromise, cancel} = driver._waitForFCP(0, 5000);
    const waitPromise = makePromiseInspectable(rawPromise);

    await flushAllTimersAndMicrotasks();
--- a/types/config.d.ts
+++ b/types/config.d.ts
@ -28,6 +28,7 @@ declare global {
        loadFailureMode?: 'fatal'|'warn'|'ignore';
        recordTrace?: boolean;
        useThrottling?: boolean;
+        pauseAfterFcpMs?: number;
        pauseAfterLoadMs?: number;
        networkQuietThresholdMs?: number;
        cpuQuietThresholdMs?: number;