From ce526251525842b60516044396f7ff215c5303a8 Mon Sep 17 00:00:00 2001
From: Paul Irish <paulirish@google.com>
Date: Thu, 25 Oct 2018 12:45:26 -0700
Subject: [PATCH] docs: add primer on viewing the timing data

---
 docs/hacking-tips.md                    | 15 +++++++++++++++
 lighthouse-core/gather/gather-runner.js |  4 ++--
 lighthouse-core/runner.js               |  3 ++-
 3 files changed, 19 insertions(+), 3 deletions(-)

diff --git a/docs/hacking-tips.md b/docs/hacking-tips.md
index 7546b74758bf..33b0754db9a4 100644
--- a/docs/hacking-tips.md
+++ b/docs/hacking-tips.md
@@ -1,5 +1,20 @@
 A few assorted scripts and tips to make hacking on Lighthouse a bit easier
 
+## Evaluate Lighthouse's runtime performance
+
+Lighthouse has instrumentation to collect timing data for its operations. The data is exposed at `LHR.timing.entries`.  You can generate a trace from this data for closer analysis.
+
+![image](https://user-images.githubusercontent.com/39191/47525915-3c477000-d853-11e8-90a2-27036f93e682.png)
+[View example trace](https://ahead-daughter.surge.sh/paulirish.json.timing.trace.html)
+
+To generate, run `yarn timing-trace` with the LHR json:
+```sh
+lighthouse http://example.com --output=json --output-path=lhr.json
+yarn timing-trace lhr.json
+```
+
+That will generate `lhr.json.timing.trace.json`. Then, drag 'n drop that file into `chrome://tracing`.
+
 ## Unhandled promise rejections
 
 Getting errors like these?
diff --git a/lighthouse-core/gather/gather-runner.js b/lighthouse-core/gather/gather-runner.js
index 2c2c65719b0e..7251e297672d 100644
--- a/lighthouse-core/gather/gather-runner.js
+++ b/lighthouse-core/gather/gather-runner.js
@@ -238,7 +238,7 @@ class GatherRunner {
 
     const status = {
       msg: 'Loading page & waiting for onload',
-      id: 'lh:gather:loadPage',
+      id: `lh:gather:loadPage-${passContext.passConfig.passName}`,
       args: [gatherers.map(g => g.instance.name).join(', ')],
     };
     log.time(status);
@@ -271,8 +271,8 @@ class GatherRunner {
       gathererResult.push(artifactPromise);
       gathererResults[gatherer.name] = gathererResult;
       await artifactPromise.catch(() => {});
-      log.timeEnd(status);
     }
+    log.timeEnd(status);
     log.timeEnd(pStatus);
   }
 
diff --git a/lighthouse-core/runner.js b/lighthouse-core/runner.js
index a363974fd966..83d84b8fb732 100644
--- a/lighthouse-core/runner.js
+++ b/lighthouse-core/runner.js
@@ -175,7 +175,8 @@ class Runner {
     const timingEntriesKeyValues = [
       ...timingEntriesFromArtifacts,
       ...timingEntriesFromRunner,
-    ].map(entry => /** @type {[string, PerformanceEntry]} */ ([entry.name, entry]));
+      // As entries can share a name, dedupe based on the startTime timestamp
+    ].map(entry => /** @type {[number, PerformanceEntry]} */ ([entry.startTime, entry]));
     const timingEntries = Array.from(new Map(timingEntriesKeyValues).values());
     const runnerEntry = timingEntries.find(e => e.name === 'lh:runner:run');
     return {entries: timingEntries, total: runnerEntry && runnerEntry.duration || 0};