core(fr): add parity logging (#13114)

GoogleChrome · Sep 23, 2021 · b83573b · b83573b
1 parent 472215e
commit b83573b
Show file tree

Hide file tree

Showing 5 changed files with 41 additions and 0 deletions.
diff --git 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<void>} */
   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<void>} */

diff --git 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<LH.IcuMessage>}>}
  */
 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
@@ -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<LH.IcuMessage>}>}
  */
 async function prepareTargetForIndividualNavigation(session, settings, navigation) {
+  const status = {msg: 'Preparing target for navigation', id: 'lh:prepare:navigation'};
+  log.time(status);
+
   /** @type {Array<LH.IcuMessage>} */
   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
@@ -33,6 +33,9 @@ const str_ = i18n.createMessageInstanceIdFn(__filename, UIStrings);
  * @return {Promise<void>}
  */
 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/...m-webtests/webtests/http/tests/devtools/lighthouse/lighthouse-successful-run-expected.txt b/...m-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,18 +149,22 @@ 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
 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