From b83573be5ecb20d996238c961e9a3e70e2f6c72b Mon Sep 17 00:00:00 2001 From: Patrick Hulce Date: Thu, 23 Sep 2021 17:04:04 -0500 Subject: [PATCH] core(fr): add parity logging (#13114) --- lighthouse-core/fraggle-rock/gather/driver.js | 4 ++++ lighthouse-core/gather/driver/navigation.js | 5 +++++ lighthouse-core/gather/driver/prepare.js | 14 ++++++++++++++ lighthouse-core/gather/driver/storage.js | 5 +++++ .../lighthouse-successful-run-expected.txt | 13 +++++++++++++ 5 files changed, 41 insertions(+) diff --git a/lighthouse-core/fraggle-rock/gather/driver.js b/lighthouse-core/fraggle-rock/gather/driver.js index 94d75fb0891e..23f4e20a7985 100644 --- a/lighthouse-core/fraggle-rock/gather/driver.js +++ b/lighthouse-core/fraggle-rock/gather/driver.js @@ -5,6 +5,7 @@ */ 'use strict'; +const log = require('lighthouse-logger'); const ProtocolSession = require('./session.js'); const ExecutionContext = require('../../gather/driver/execution-context.js'); const Fetcher = require('../../gather/fetcher.js'); @@ -68,10 +69,13 @@ class Driver { /** @return {Promise} */ async connect() { if (this._session) return; + const status = {msg: 'Connecting to browser', id: 'lh:driver:connect'}; + log.time(status); const session = await this._page.target().createCDPSession(); this._session = this.defaultSession = new ProtocolSession(session); this._executionContext = new ExecutionContext(this._session); this._fetcher = new Fetcher(this._session, this._executionContext); + log.timeEnd(status); } /** @return {Promise} */ diff --git a/lighthouse-core/gather/driver/navigation.js b/lighthouse-core/gather/driver/navigation.js index 26e5ac22de0f..c8a3cd380d95 100644 --- a/lighthouse-core/gather/driver/navigation.js +++ b/lighthouse-core/gather/driver/navigation.js @@ -5,6 +5,7 @@ */ 'use strict'; +const log = require('lighthouse-logger'); const NetworkMonitor = require('./network-monitor.js'); const {waitForFullyLoaded, waitForFrameNavigated, waitForUserToContinue} = require('./wait-for-condition.js'); // eslint-disable-line max-len const constants = require('../../config/constants.js'); @@ -82,6 +83,9 @@ function resolveWaitForFullyLoadedOptions(options) { * @return {Promise<{finalUrl: string, warnings: Array}>} */ async function gotoURL(driver, url, options) { + const status = {msg: `Navigating to ${url}`, id: 'lh:driver:navigate'}; + log.time(status); + const session = driver.defaultSession; const networkMonitor = new NetworkMonitor(driver.defaultSession); @@ -125,6 +129,7 @@ async function gotoURL(driver, url, options) { await waitForUserToContinue(driver); } + log.timeEnd(status); return { finalUrl, warnings: getNavigationWarnings({timedOut, finalUrl, requestedUrl: url}), diff --git a/lighthouse-core/gather/driver/prepare.js b/lighthouse-core/gather/driver/prepare.js index 64b1e5ef4270..12274c7f563a 100644 --- a/lighthouse-core/gather/driver/prepare.js +++ b/lighthouse-core/gather/driver/prepare.js @@ -142,11 +142,16 @@ async function prepareDeviceEmulationAndAsyncStacks(driver, settings) { * @param {LH.Config.Settings} settings */ async function prepareTargetForTimespanMode(driver, settings) { + const status = {msg: 'Preparing target for timespan mode', id: 'lh:prepare:timespanMode'}; + log.time(status); + await prepareDeviceEmulationAndAsyncStacks(driver, settings); await prepareThrottlingAndNetwork(driver.defaultSession, settings, { disableThrottling: false, blockedUrlPatterns: undefined, }); + + log.timeEnd(status); } /** @@ -159,6 +164,9 @@ async function prepareTargetForTimespanMode(driver, settings) { * @param {LH.Config.Settings} settings */ async function prepareTargetForNavigationMode(driver, settings) { + const status = {msg: 'Preparing target for navigation mode', id: 'lh:prepare:navigationMode'}; + log.time(status); + await prepareDeviceEmulationAndAsyncStacks(driver, settings); // Automatically handle any JavaScript dialogs to prevent a hung renderer. @@ -171,6 +179,8 @@ async function prepareTargetForNavigationMode(driver, settings) { if (settings.throttlingMethod === 'simulate') { await shimRequestIdleCallbackOnNewDocument(driver, settings); } + + log.timeEnd(status); } /** @@ -184,6 +194,9 @@ async function prepareTargetForNavigationMode(driver, settings) { * @return {Promise<{warnings: Array}>} */ async function prepareTargetForIndividualNavigation(session, settings, navigation) { + const status = {msg: 'Preparing target for navigation', id: 'lh:prepare:navigation'}; + log.time(status); + /** @type {Array} */ const warnings = []; @@ -195,6 +208,7 @@ async function prepareTargetForIndividualNavigation(session, settings, navigatio await prepareThrottlingAndNetwork(session, settings, navigation); + log.timeEnd(status); return {warnings}; } diff --git a/lighthouse-core/gather/driver/storage.js b/lighthouse-core/gather/driver/storage.js index 0aa5ac267846..e65bd5b02be2 100644 --- a/lighthouse-core/gather/driver/storage.js +++ b/lighthouse-core/gather/driver/storage.js @@ -33,6 +33,9 @@ const str_ = i18n.createMessageInstanceIdFn(__filename, UIStrings); * @return {Promise} */ async function clearDataForOrigin(session, url) { + const status = {msg: 'Cleaning origin data', id: 'lh:storage:clearDataForOrigin'}; + log.time(status); + const origin = new URL(url).origin; // Clear some types of storage. @@ -63,6 +66,8 @@ async function clearDataForOrigin(session, url) { } else { throw err; } + } finally { + log.timeEnd(status); } } diff --git a/third-party/chromium-webtests/webtests/http/tests/devtools/lighthouse/lighthouse-successful-run-expected.txt b/third-party/chromium-webtests/webtests/http/tests/devtools/lighthouse/lighthouse-successful-run-expected.txt index 1bd3ef9b76b3..2778696f002a 100644 --- a/third-party/chromium-webtests/webtests/http/tests/devtools/lighthouse/lighthouse-successful-run-expected.txt +++ b/third-party/chromium-webtests/webtests/http/tests/devtools/lighthouse/lighthouse-successful-run-expected.txt @@ -20,11 +20,16 @@ Requiring audits Runner setup Connecting to browser Resetting state with about:blank +Navigating to about:blank Getting browser version Benchmarking machine Initializing… +Preparing target for navigation mode Running defaultPass pass Resetting state with about:blank +Navigating to about:blank +Preparing target for navigation +Cleaning origin data Cleaning browser cache Preparing network conditions Running beforePass methods @@ -58,6 +63,7 @@ Gathering setup: SourceMaps Gathering setup: FullPageScreenshot Beginning devtoolsLog and trace Loading page & waiting for onload +Navigating to http://127.0.0.1:8000/devtools/lighthouse/resources/lighthouse-basic.html Running pass methods Gathering in-page: CSSUsage Gathering in-page: JsUsage @@ -127,11 +133,14 @@ Get webapp manifest Collect stacks Running offlinePass pass Resetting state with about:blank +Navigating to about:blank +Preparing target for navigation Preparing network conditions Running beforePass methods Gathering setup: ServiceWorker Beginning devtoolsLog and trace Loading page & waiting for onload +Navigating to http://127.0.0.1:8000/devtools/lighthouse/resources/lighthouse-basic.html Running pass methods Gathering in-page: ServiceWorker Gathering devtoolsLog & network records @@ -140,11 +149,14 @@ Running afterPass methods Gathering: ServiceWorker Running redirectPass pass Resetting state with about:blank +Navigating to about:blank +Preparing target for navigation Preparing network conditions Running beforePass methods Gathering setup: HTTPRedirect Beginning devtoolsLog and trace Loading page & waiting for onload +Navigating to http://127.0.0.1:8000/devtools/lighthouse/resources/lighthouse-basic.html Running pass methods Gathering in-page: HTTPRedirect Gathering devtoolsLog & network records @@ -152,6 +164,7 @@ Computing artifact: NetworkRecords Running afterPass methods Gathering: HTTPRedirect Disconnecting from browser... +Cleaning origin data Analyzing and running audits... Auditing: Uses HTTPS Auditing: Redirects HTTP traffic to HTTPS