From 3a637e8c39e46125a47aaa32e16993584ef8c37b Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Mon, 7 Jan 2019 12:08:59 -0600 Subject: [PATCH 1/6] core(driver): waitForFCP when tracing --- lighthouse-cli/test/fixtures/delayed-fcp.html | 12 ++++ lighthouse-cli/test/smokehouse/run-smoke.js | 4 +- .../expectations.js | 9 +++ lighthouse-core/gather/driver.js | 66 ++++++++++++++++--- lighthouse-core/gather/gather-runner.js | 1 + 5 files changed, 82 insertions(+), 10 deletions(-) create mode 100644 lighthouse-cli/test/fixtures/delayed-fcp.html rename lighthouse-cli/test/smokehouse/{tricky-tti => tricky-metrics}/expectations.js (79%) diff --git a/lighthouse-cli/test/fixtures/delayed-fcp.html b/lighthouse-cli/test/fixtures/delayed-fcp.html new file mode 100644 index 000000000000..8b8aa76847c5 --- /dev/null +++ b/lighthouse-cli/test/fixtures/delayed-fcp.html @@ -0,0 +1,12 @@ + + + + + + diff --git a/lighthouse-cli/test/smokehouse/run-smoke.js b/lighthouse-cli/test/smokehouse/run-smoke.js index 12f2cb86d7cf..e59e035e8d84 100644 --- a/lighthouse-cli/test/smokehouse/run-smoke.js +++ b/lighthouse-cli/test/smokehouse/run-smoke.js @@ -80,8 +80,8 @@ const SMOKETESTS = [{ config: 'lighthouse-core/config/perf-config.js', batch: 'perf-metric', }, { - id: 'tti', - expectations: 'tricky-tti/expectations.js', + id: 'metrics', + expectations: 'tricky-metrics/expectations.js', config: 'lighthouse-core/config/perf-config.js', batch: 'parallel-second', }]; diff --git a/lighthouse-cli/test/smokehouse/tricky-tti/expectations.js b/lighthouse-cli/test/smokehouse/tricky-metrics/expectations.js similarity index 79% rename from lighthouse-cli/test/smokehouse/tricky-tti/expectations.js rename to lighthouse-cli/test/smokehouse/tricky-metrics/expectations.js index f63c66e6cc97..07d165fcc17b 100644 --- a/lighthouse-cli/test/smokehouse/tricky-tti/expectations.js +++ b/lighthouse-cli/test/smokehouse/tricky-metrics/expectations.js @@ -23,4 +23,13 @@ module.exports = [ }, }, }, + { + requestedUrl: 'http://localhost:10200/delayed-fcp.html', + finalUrl: 'http://localhost:10200/delayed-fcp.html', + audits: { + 'first-contentful-paint': { + rawValue: '>1', // We just want to check that it doesn't error + }, + }, + }, ]; diff --git a/lighthouse-core/gather/driver.js b/lighthouse-core/gather/driver.js index aae4a4339a38..b155adb671cc 100644 --- a/lighthouse-core/gather/driver.js +++ b/lighthouse-core/gather/driver.js @@ -512,6 +512,15 @@ class Driver { }); } + /** + * Returns a promise that resolves immediately. + * Used for placeholder conditions that we don't want to start waiting for just yet, but still want + * to satisfy the same interface. + */ + _waitForNothing() { + return {promise: Promise.resolve(), cancel() {}}; + } + /** * Returns a promise that resolve when a frame has been navigated. * Used for detecting that our about:blank reset has been completed. @@ -522,6 +531,41 @@ class Driver { }); } + /** + * Returns a promise that resolve when a frame has a FCP. + */ + _waitForFCP() { + /** @type {(() => void)} */ + let cancel = () => { + throw new Error('_waitForLoadEvent.cancel() called before it was defined'); + }; + + const promise = (async () => { + await this.sendCommand('Page.setLifecycleEventsEnabled', {enabled: true}); + + return new Promise(resolve => { + /** @param {LH.Crdp.Page.LifecycleEventEvent} e */ + const lifecycleListener = e => { + if (e.name === 'firstContentfulPaint') { + resolve(); + this.off('Page.lifecycleEvent', lifecycleListener); + } + }; + + this.on('Page.lifecycleEvent', lifecycleListener); + + cancel = () => { + this.off('Page.lifecycleEvent', lifecycleListener); + }; + }); + })(); + + return { + promise, + cancel, + }; + } + /** * Returns a promise that resolves when the network has been idle (after DCL) for * `networkQuietThresholdMs` ms and a method to cancel internal network listeners/timeout. @@ -733,25 +777,28 @@ class Driver { * @param {number} networkQuietThresholdMs * @param {number} cpuQuietThresholdMs * @param {number} maxWaitForLoadedMs + * @param {boolean} shouldWaitForFCP * @return {Promise} * @private */ async _waitForFullyLoaded(pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs, - maxWaitForLoadedMs) { + maxWaitForLoadedMs, shouldWaitForFCP) { /** @type {NodeJS.Timer|undefined} */ let maxTimeoutHandle; + // Listener for onload. Resolves on first FCP event. + const waitForFCP = shouldWaitForFCP ? this._waitForFCP() : 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. const waitForNetworkIdle = this._waitForNetworkIdle(networkQuietThresholdMs); // CPU listener. Resolves when the CPU has been idle for cpuQuietThresholdMs after network idle. - /** @type {{promise: Promise, cancel: function(): void}|null} */ - let waitForCPUIdle = null; + let waitForCPUIdle = this._waitForNothing(); // Wait for both load promises. Resolves on cleanup function the clears load // timeout timer. const loadPromise = Promise.all([ + waitForFCP.promise, waitForLoadEvent.promise, waitForNetworkIdle.promise, ]).then(() => { @@ -771,9 +818,10 @@ class Driver { }).then(_ => { return async () => { log.warn('Driver', 'Timed out waiting for page load. Checking if page is hung...'); + waitForFCP.cancel(); waitForLoadEvent.cancel(); waitForNetworkIdle.cancel(); - waitForCPUIdle && waitForCPUIdle.cancel(); + waitForCPUIdle.cancel(); if (await this.isPageHung()) { log.warn('Driver', 'Page appears to be hung, killing JavaScript...'); @@ -874,23 +922,25 @@ class Driver { * possible workaround. * Resolves on the url of the loaded page, taking into account any redirects. * @param {string} url - * @param {{waitForLoad?: boolean, waitForNavigated?: boolean, passContext?: LH.Gatherer.PassContext}} options + * @param {{waitForFCP?: boolean, waitForLoad?: boolean, waitForNavigated?: boolean, passContext?: LH.Gatherer.PassContext}} options * @return {Promise} */ async gotoURL(url, options = {}) { + const waitForFCP = options.waitForFCP || false; const waitForNavigated = options.waitForNavigated || false; const waitForLoad = options.waitForLoad || false; const passContext = /** @type {Partial} */ (options.passContext || {}); const disableJS = passContext.disableJavaScript || false; - if (waitForNavigated && waitForLoad) { - throw new Error('Cannot use both waitForNavigated and waitForLoad, pick just one'); + if (waitForNavigated && (waitForFCP || waitForLoad)) { + throw new Error('Cannot use both waitForNavigated and another event, pick just one'); } await this._beginNetworkStatusMonitoring(url); await this._clearIsolatedContextId(); await this.sendCommand('Page.enable'); + await this.sendCommand('Page.setLifecycleEventsEnabled', {enabled: true}); await this.sendCommand('Emulation.setScriptExecutionDisabled', {value: disableJS}); // No timeout needed for Page.navigate. See #6413. const waitforPageNavigateCmd = this._innerSendCommand('Page.navigate', {url}); @@ -910,7 +960,7 @@ class Driver { /* eslint-enable max-len */ await this._waitForFullyLoaded(pauseAfterLoadMs, networkQuietThresholdMs, cpuQuietThresholdMs, - maxWaitMs); + maxWaitMs, waitForFCP); } // Bring `Page.navigate` errors back into the promise chain. See #6739. diff --git a/lighthouse-core/gather/gather-runner.js b/lighthouse-core/gather/gather-runner.js index 70c2c7a48746..6c02edb44cac 100644 --- a/lighthouse-core/gather/gather-runner.js +++ b/lighthouse-core/gather/gather-runner.js @@ -88,6 +88,7 @@ class GatherRunner { */ static async loadPage(driver, passContext) { const finalUrl = await driver.gotoURL(passContext.url, { + waitForFCP: passContext.passConfig.recordTrace, waitForLoad: true, passContext, }); From ee361aa8e864abbb64b036ac2e8f82ac91c6d9e0 Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Mon, 7 Jan 2019 12:45:31 -0600 Subject: [PATCH 2/6] error msg --- lighthouse-core/gather/driver.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lighthouse-core/gather/driver.js b/lighthouse-core/gather/driver.js index b155adb671cc..2a4c971e8ee9 100644 --- a/lighthouse-core/gather/driver.js +++ b/lighthouse-core/gather/driver.js @@ -537,7 +537,7 @@ class Driver { _waitForFCP() { /** @type {(() => void)} */ let cancel = () => { - throw new Error('_waitForLoadEvent.cancel() called before it was defined'); + throw new Error('_waitForFCP.cancel() called before it was defined'); }; const promise = (async () => { From cee10406b17fe2681ea9c63ba87e113c9428e010 Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Mon, 7 Jan 2019 13:15:57 -0600 Subject: [PATCH 3/6] oops I thought I reverted this already --- lighthouse-core/gather/driver.js | 30 +++++++++++++----------------- 1 file changed, 13 insertions(+), 17 deletions(-) diff --git a/lighthouse-core/gather/driver.js b/lighthouse-core/gather/driver.js index 2a4c971e8ee9..82d274ed75e9 100644 --- a/lighthouse-core/gather/driver.js +++ b/lighthouse-core/gather/driver.js @@ -540,25 +540,21 @@ class Driver { throw new Error('_waitForFCP.cancel() called before it was defined'); }; - const promise = (async () => { - await this.sendCommand('Page.setLifecycleEventsEnabled', {enabled: true}); - - return new Promise(resolve => { - /** @param {LH.Crdp.Page.LifecycleEventEvent} e */ - const lifecycleListener = e => { - if (e.name === 'firstContentfulPaint') { - resolve(); - this.off('Page.lifecycleEvent', lifecycleListener); - } - }; + const promise = new Promise(resolve => { + /** @param {LH.Crdp.Page.LifecycleEventEvent} e */ + const lifecycleListener = e => { + if (e.name === 'firstContentfulPaint') { + resolve(); + this.off('Page.lifecycleEvent', lifecycleListener); + } + }; - this.on('Page.lifecycleEvent', lifecycleListener); + this.on('Page.lifecycleEvent', lifecycleListener); - cancel = () => { - this.off('Page.lifecycleEvent', lifecycleListener); - }; - }); - })(); + cancel = () => { + this.off('Page.lifecycleEvent', lifecycleListener); + }; + }); return { promise, From a276786c938456d9b3be3287917632a8f000a558 Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Mon, 7 Jan 2019 14:40:27 -0600 Subject: [PATCH 4/6] update appveyor invocation --- .appveyor.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.appveyor.yml b/.appveyor.yml index 402b74415371..69de01ad5d79 100644 --- a/.appveyor.yml +++ b/.appveyor.yml @@ -42,7 +42,7 @@ test_script: # FIXME: Exclude Appveyor from running `perf` smoketest until we fix the flake. # https://github.com/GoogleChrome/lighthouse/issues/5053 # - yarn smoke - - yarn smoke ally pwa pwa2 pwa3 dbw redirects seo offline byte tti + - yarn smoke ally pwa pwa2 pwa3 dbw redirects seo offline byte metrics cache: #- chrome-win32 -> appveyor.yml,package.json From f67917d7cbe09e38dd70434fc570598d1a39ffc2 Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Mon, 7 Jan 2019 15:55:50 -0600 Subject: [PATCH 5/6] feedback --- lighthouse-cli/test/fixtures/delayed-fcp.html | 5 +++++ lighthouse-core/gather/driver.js | 1 + 2 files changed, 6 insertions(+) diff --git a/lighthouse-cli/test/fixtures/delayed-fcp.html b/lighthouse-cli/test/fixtures/delayed-fcp.html index 8b8aa76847c5..b369a42e8fdf 100644 --- a/lighthouse-cli/test/fixtures/delayed-fcp.html +++ b/lighthouse-cli/test/fixtures/delayed-fcp.html @@ -1,6 +1,11 @@ +