GoogleChrome · paulirish · Feb 28, 2019 · Jan 18, 2019 · Jan 18, 2019 · Jan 18, 2019
diff --git a/lighthouse-cli/test/fixtures/tricky-main-thread-consumer.js b/lighthouse-cli/test/fixtures/tricky-main-thread-consumer.js
@@ -0,0 +1,20 @@
+/**
+ * @license Copyright 2019 Google Inc. 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';
+
+/* eslint-disable */
+
+if (window.location.search.includes('setTimeout')) {
+  window.library.setTimeout(() => {
+    window.library.stall(3050);
+  }, 0);
+}
+
+if (window.location.search.includes('fetch')) {
+  window.library.fetch('http://localhost:10200/tricky-main-thread.html').then(() => {
+    window.library.stall(3050);
+  });
+}
diff --git a/lighthouse-cli/test/fixtures/tricky-main-thread-library.js b/lighthouse-cli/test/fixtures/tricky-main-thread-library.js
@@ -0,0 +1,37 @@
+/**
+ * @license Copyright 2019 Google Inc. 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';
+
+/* eslint-disable */
+
+window.library = {};
+window.library.setTimeout = (fn, time) => {
+  setTimeout(() => {
+    window.library.stall(50);
+    console.log('Custom timeout hook');
+    fn();
+  }, time);
+};
+
+window.library.fetch = (...args) => {
+  console.log('Custom fetch hook 1');
+  return fetch(...args).then(response => {
+    console.log('Custom fetch hook 2');
+    window.library.stall(50);
+    return response;
+  });
+};
+
+/**
+ * Stalls the main thread for timeInMs
+ */
+window.library.stall = function(timeInMs) {
+  const start = performance.now();
+  while (performance.now() - start < timeInMs) {
+    for (let i = 0; i < 1000000; i++) ;
+  }
+};
+
diff --git a/lighthouse-cli/test/fixtures/tricky-main-thread.html b/lighthouse-cli/test/fixtures/tricky-main-thread.html
@@ -0,0 +1,8 @@
+<html>
+<meta name="viewport" content="width=device-width, initial-scale=1, minimum-scale=1">
+<body>
+  Just try and figure out my scripts
+  <script src="tricky-main-thread-library.js"></script>
+  <script src="tricky-main-thread-consumer.js"></script>
+</body>
+</html>
diff --git a/lighthouse-cli/test/smokehouse/tricky-metrics/expectations.js b/lighthouse-cli/test/smokehouse/tricky-metrics/expectations.js
@@ -6,7 +6,7 @@
 'use strict';
 
 /**
- * Expected Lighthouse audit values for tricky TTI tests
+ * Expected Lighthouse audit values for tricky metrics tests
  */
 module.exports = [
   {
@@ -32,4 +32,37 @@ module.exports = [
       },
     },
   },
+  {
+    requestedUrl: 'http://localhost:10200/tricky-main-thread.html?setTimeout',
+    finalUrl: 'http://localhost:10200/tricky-main-thread.html?setTimeout',
+    audits: {
+      'bootup-time': {
+        details: {
+          items: {
+            0: {
+              url: /main-thread-consumer/,
+              scripting: '>1000',
+            },
+          },
+        },
+      },
+    },
+  },
+  {
+    requestedUrl: 'http://localhost:10200/tricky-main-thread.html?fetch',
+    finalUrl: 'http://localhost:10200/tricky-main-thread.html?fetch',
+    audits: {
+      'bootup-time': {
+        details: {
+          items: {
+            0: {
+              // TODO: requires async stacks, https://github.com/GoogleChrome/lighthouse/pull/5504
+              // url: /main-thread-consumer/,
+              scripting: '>1000',
+            },
+          },
+        },
+      },
+    },
+  },
 ];
diff --git a/lighthouse-core/audits/bootup-time.js b/lighthouse-core/audits/bootup-time.js
@@ -22,7 +22,7 @@ const UIStrings = {
     'You may find delivering smaller JS payloads helps with this. [Learn ' +
     'more](https://developers.google.com/web/tools/lighthouse/audits/bootup).',
   /** Label for the total time column in a data table; entries will be the number of milliseconds spent executing per resource loaded by the page. */
-  columnTotal: 'Total',
+  columnTotal: 'Total CPU Time',
   /** Label for a time column in a data table; entries will be the number of milliseconds spent evaluating script for every script loaded by the page. */
   columnScriptEval: 'Script Evaluation',
   /** Label for a time column in a data table; entries will be the number of milliseconds spent parsing script files for every script loaded by the page. */
@@ -89,8 +89,9 @@ class BootupTime extends Audit {
     for (const task of tasks) {
       const jsURL = task.attributableURLs.find(url => jsURLs.has(url));
       const fallbackURL = task.attributableURLs[0];
-      const attributableURL = jsURL || fallbackURL;
-      if (!attributableURL || attributableURL === 'about:blank') continue;
+      let attributableURL = jsURL || fallbackURL;
+      // If we can't find what URL was responsible for this execution, just attribute it to the root page.
+      if (!attributableURL || attributableURL === 'about:blank') attributableURL = 'Other';
 
       const timingByGroupId = result.get(attributableURL) || {};
       const originalTime = timingByGroupId[task.group.id] || 0;
@@ -122,27 +123,27 @@ class BootupTime extends Audit {
     let totalBootupTime = 0;
     const results = Array.from(executionTimings)
       .map(([url, timingByGroupId]) => {
-        // Add up the totalBootupTime for all the taskGroups
-        let bootupTimeForURL = 0;
+        // Add up the totalExecutionTime for all the taskGroups
+        let totalExecutionTimeForURL = 0;
         for (const [groupId, timespanMs] of Object.entries(timingByGroupId)) {
           timingByGroupId[groupId] = timespanMs * multiplier;
-          bootupTimeForURL += timespanMs * multiplier;
-        }
-
-        // Add up all the execution time of shown URLs
-        if (bootupTimeForURL >= context.options.thresholdInMs) {
-          totalBootupTime += bootupTimeForURL;
+          totalExecutionTimeForURL += timespanMs * multiplier;
         }
 
         const scriptingTotal = timingByGroupId[taskGroups.scriptEvaluation.id] || 0;
         const parseCompileTotal = timingByGroupId[taskGroups.scriptParseCompile.id] || 0;
 
+        // Add up all the JavaScript time of shown URLs
+        if (totalExecutionTimeForURL >= context.options.thresholdInMs) {
+          totalBootupTime += scriptingTotal + parseCompileTotal;
+        }
+
         hadExcessiveChromeExtension = hadExcessiveChromeExtension ||
           (url.startsWith('chrome-extension:') && scriptingTotal > 100);
 
         return {
           url: url,
-          total: bootupTimeForURL,
+          total: totalExecutionTimeForURL,
           // Highlight the JavaScript task costs
           scripting: scriptingTotal,
           scriptParseCompile: parseCompileTotal,

diff --git a/lighthouse-core/computed/main-thread-tasks.js b/lighthouse-core/computed/main-thread-tasks.js
@@ -41,6 +41,8 @@ const TraceOfTab = require('./trace-of-tab.js');
  * @prop {TaskGroup} group
  */
 
+/** @typedef {{timers: Map<string, TaskNode>}} PriorTaskData */
+
 class MainThreadTasks {
   /**
    * @param {LH.TraceEvent} event
@@ -71,15 +73,24 @@ class MainThreadTasks {
 
   /**
    * @param {LH.TraceEvent[]} mainThreadEvents
+   * @param {PriorTaskData} priorTaskData
    * @return {TaskNode[]}
    */
-  static _createTasksFromEvents(mainThreadEvents) {
+  static _createTasksFromEvents(mainThreadEvents, priorTaskData) {
     /** @type {TaskNode[]} */
     const tasks = [];
     /** @type {TaskNode|undefined} */
     let currentTask;
 
     for (const event of mainThreadEvents) {
+      // Save the timer data, TimerInstall events are instant events `ph === 'I'` so process them first.
+      if (event.name === 'TimerInstall' && currentTask) {
+        /** @type {string} */
+        // @ts-ignore - timerId exists when name is TimerInstall
+        const timerId = event.args.data.timerId;
+        priorTaskData.timers.set(timerId, currentTask);
+      }
+
       // Only look at X (Complete), B (Begin), and E (End) events as they have most data
       if (event.ph !== 'X' && event.ph !== 'B' && event.ph !== 'E') continue;
 
@@ -141,11 +152,13 @@ class MainThreadTasks {
   /**
    * @param {TaskNode} task
    * @param {string[]} parentURLs
+   * @param {PriorTaskData} priorTaskData
    */
-  static _computeRecursiveAttributableURLs(task, parentURLs) {
+  static _computeRecursiveAttributableURLs(task, parentURLs, priorTaskData) {
     const argsData = task.event.args.data || {};
     const stackFrameURLs = (argsData.stackTrace || []).map(entry => entry.url);
 
+    /** @type {Array<string|undefined>} */
     let taskURLs = [];
     switch (task.event.name) {
       /**
@@ -161,6 +174,15 @@ class MainThreadTasks {
       case 'v8.compileModule':
         taskURLs = [task.event.args.fileName].concat(stackFrameURLs);
         break;
+      case 'TimerFire': {
+        /** @type {string} */
+        // @ts-ignore - timerId exists when name is TimerFire
+        const timerId = task.event.args.data.timerId;
+        const timerInstallerTaskNode = priorTaskData.timers.get(timerId);
+        if (!timerInstallerTaskNode) break;
+        taskURLs = timerInstallerTaskNode.attributableURLs.concat(stackFrameURLs);
+        break;
+      }
       default:
         taskURLs = stackFrameURLs;
         break;
@@ -178,7 +200,7 @@ class MainThreadTasks {
 
     task.attributableURLs = attributableURLs;
     task.children.forEach(child =>
-      MainThreadTasks._computeRecursiveAttributableURLs(child, attributableURLs));
+      MainThreadTasks._computeRecursiveAttributableURLs(child, attributableURLs, priorTaskData));
   }
 
   /**
@@ -196,14 +218,16 @@ class MainThreadTasks {
    * @return {TaskNode[]}
    */
   static getMainThreadTasks(traceEvents) {
-    const tasks = MainThreadTasks._createTasksFromEvents(traceEvents);
+    const timers = new Map();
+    const priorTaskData = {timers};
+    const tasks = MainThreadTasks._createTasksFromEvents(traceEvents, priorTaskData);
 
     // Compute the recursive properties we couldn't compute earlier, starting at the toplevel tasks
     for (const task of tasks) {
       if (task.parent) continue;
 
       MainThreadTasks._computeRecursiveSelfTime(task);
-      MainThreadTasks._computeRecursiveAttributableURLs(task, []);
+      MainThreadTasks._computeRecursiveAttributableURLs(task, [], priorTaskData);
       MainThreadTasks._computeRecursiveTaskGroup(task);
     }
 

diff --git a/lighthouse-core/lib/i18n/en-US.json b/lighthouse-core/lib/i18n/en-US.json
@@ -432,7 +432,7 @@
     "description": "Label for a time column in a data table; entries will be the number of milliseconds spent parsing script files for every script loaded by the page."
   },
   "lighthouse-core/audits/bootup-time.js | columnTotal": {
-    "message": "Total",
+    "message": "Total CPU Time",
     "description": "Label for the total time column in a data table; entries will be the number of milliseconds spent executing per resource loaded by the page."
   },
   "lighthouse-core/audits/bootup-time.js | description": {

diff --git a/lighthouse-core/test/audits/bootup-time-test.js b/lighthouse-core/test/audits/bootup-time-test.js
@@ -32,12 +32,13 @@ describe('Performance: bootup-time audit', () => {
 
     return BootupTime.audit(artifacts, {options: auditOptions, computedCache}).then(output => {
       assert.deepEqual(roundedValueOf(output, 'https://pwa.rocks/script.js'), {scripting: 31.8, scriptParseCompile: 1.3, total: 36.8});
-      assert.deepEqual(roundedValueOf(output, 'https://www.googletagmanager.com/gtm.js?id=GTM-Q5SW'), {scripting: 96.9, scriptParseCompile: 6.5, total: 104.4});
+      assert.deepEqual(roundedValueOf(output, 'https://www.googletagmanager.com/gtm.js?id=GTM-Q5SW'), {scripting: 97.2, scriptParseCompile: 6.5, total: 104.7});
       assert.deepEqual(roundedValueOf(output, 'https://www.google-analytics.com/plugins/ua/linkid.js'), {scripting: 25.2, scriptParseCompile: 1.2, total: 26.4});
       assert.deepEqual(roundedValueOf(output, 'https://www.google-analytics.com/analytics.js'), {scripting: 40.6, scriptParseCompile: 9.6, total: 53.4});
+      assert.deepEqual(roundedValueOf(output, 'Other'), {scripting: 11.7, scriptParseCompile: 0, total: 1123.8}); // eslint-disable-line max-len
 
-      assert.equal(Math.round(output.rawValue), 221);
-      assert.equal(output.details.items.length, 4);
+      assert.equal(Math.round(output.rawValue), 225);
+      assert.equal(output.details.items.length, 5);
       assert.equal(output.score, 1);
     });
   }, 10000);
@@ -55,9 +56,9 @@ describe('Performance: bootup-time audit', () => {
 
     assert.deepEqual(roundedValueOf(output, 'https://pwa.rocks/script.js'), {scripting: 95.3, scriptParseCompile: 3.9, total: 110.5});
 
-    assert.equal(output.details.items.length, 7);
+    assert.equal(output.details.items.length, 8);
     assert.equal(output.score, 0.98);
-    assert.equal(Math.round(output.rawValue), 709);
+    assert.equal(Math.round(output.rawValue), 720);
   });
 
   it('should get no data when no events are present', () => {

diff --git a/lighthouse-core/test/results/sample_v2.json b/lighthouse-core/test/results/sample_v2.json
@@ -689,7 +689,7 @@
       "description": "Consider reducing the time spent parsing, compiling, and executing JS. You may find delivering smaller JS payloads helps with this. [Learn more](https://developers.google.com/web/tools/lighthouse/audits/bootup).",
       "score": 0.92,
       "scoreDisplayMode": "numeric",
-      "rawValue": 1150.932,
+      "rawValue": 1150.573,
       "displayValue": "1.2 s",
       "details": {
         "type": "table",
@@ -703,7 +703,7 @@
             "key": "total",
             "granularity": 1,
             "itemType": "ms",
-            "text": "Total"
+            "text": "Total CPU Time"
           },
           {
             "key": "scripting",
@@ -725,6 +725,12 @@
             "scripting": 957.494,
             "scriptParseCompile": 2.777
           },
+          {
+            "url": "Other",
+            "total": 391.76699999999977,
+            "scripting": 17.790999999999997,
+            "scriptParseCompile": 0.092
+          },
           {
             "url": "http://localhost:10200/zone.js",
             "total": 101.21099999999998,
@@ -739,7 +745,7 @@
           }
         ],
         "summary": {
-          "wastedMs": 1150.932
+          "wastedMs": 1150.573
         }
       }
     },
@@ -4437,7 +4443,7 @@
         },
         {
           "values": {
-            "timeInMs": 1150.932
+            "timeInMs": 1150.573
           },
           "path": "audits[bootup-time].displayValue"
         }

diff --git a/proto/sample_v2_round_trip.json b/proto/sample_v2_round_trip.json
@@ -84,7 +84,7 @@
                         "granularity": 1.0, 
                         "itemType": "ms", 
                         "key": "total", 
-                        "text": "Total"
+                        "text": "Total CPU Time"
                     }, 
                     {
                         "granularity": 1.0, 
@@ -106,6 +106,12 @@
                         "total": 966.9800000000001, 
                         "url": "http://localhost:10200/dobetterweb/dbw_tester.html"
                     }, 
+                    {
+                        "scriptParseCompile": 0.092, 
+                        "scripting": 17.790999999999997, 
+                        "total": 391.76699999999977, 
+                        "url": "Other"
+                    }, 
                     {
                         "scriptParseCompile": 1.674, 
                         "scripting": 89.50799999999998, 
@@ -120,7 +126,7 @@
                     }
                 ], 
                 "summary": {
-                    "wastedMs": 1150.932
+                    "wastedMs": 1150.573
                 }, 
                 "type": "table"
             },