Inject Lighthouse metrics back into trace for viewing #1446

paulirish · 2017-01-10T06:57:19Z

Fixes #616

Here's a preview of what this patch gives us:

Live example: https://chromedevtools.github.io/timeline-viewer/?loadTimelineFromURL=https://www.dropbox.com/s/wqzll3jjbdseooe/hypem.com_01-05-2017_7-33-42_PM-0.trace.json?dl=0

In short: the lighthouse metrics like "First meaningful paint", "Time to Interactive", etc are mocked out as User Timing measures, such that they can be viewed in the devtools timeline. The these user timing measures are added right to the trace, so if you saved it with --save-assets, your hostname.datetime.trace.json file has the good stuff.

Additionally, this opens up other tools like pwmetrics to consume the metrics easier without so much reinterpretation of the audit results. cc @denar90

denar90 · 2017-01-10T13:53:42Z

Nice API 😍 , it will make pwmetrics life easier. Do you wanna have it documented?

wardpeet · 2017-01-11T06:02:00Z

this would be so awesome! 🎉

ebidel · 2017-01-11T22:57:14Z

lighthouse-core/lib/traces/metrics-evts.js

@@ -0,0 +1,204 @@
+/**
+ * @license
+ * Copyright 2016 Google Inc. All rights reserved.


ebidel · 2017-01-11T22:57:30Z

lighthouse-core/lib/traces/metrics-evts.js

+
+const log = require('../../../lighthouse-core/lib/log.js');
+
+class Metrics {


throw in a @fileoverview

ebidel · 2017-01-11T23:01:03Z

lighthouse-core/lib/traces/metrics-evts.js

+        name: 'First Contentful Paint',
+        id: 'ttfcp',
+        getTs: auditResults => {
+          const fmpExt = auditResults['first-meaningful-paint'].extendedInfo;


Everything coming from auditResults['first-meaningful-paint'] looks like a mistake. Do we stash several things in auditResults['first-meaningful-paint'].extendedInfo? There are a few others like that, but reading this code is non-obvious.

Essentially we have 3 actual audits in lighthouse that collect these metrics. And yeah we stash several key metrics within the extInfo of each of them.
So, yeah, AFAIK all this is correct and intended... any ideas on how it could look less odd?

was expecting all the first-* stuff to be together, but I guess that makes sense if they're coming from different audits.

ebidel · 2017-01-11T23:03:06Z

lighthouse-core/lib/traces/metrics-evts.js

+        name: 'Visually Complete 85%',
+        id: 'vc85',
+        getTs: auditResults => {
+          const siExt = auditResults['time-to-interactive'].extendedInfo;


auditResults['speed-index-metric']?

Actually, check that all of these are right. Now I'm really confused :)

actually vc85 does actually get delivered on the TTI choo-choo train. :)
that does mean that siExt => ttiExt, so thanks for catching that!

ebidel · 2017-01-11T23:04:08Z

lighthouse-core/lib/traces/metrics-evts.js

+      },
+      {
+        name: 'Visually Complete 100%',
+        id: 'vc',


suggest : id: 'vc100' to be like the other

sounds good.
I had chosen 'vc' origianlly because WebPageTest uses vc for the same thing. OR SO I THOUGHT!. Looking again... i can't see "vc" anywhere, so yeah i'm happy to tweak the id.

ebidel · 2017-01-11T23:12:45Z

lighthouse-core/lib/traces/metrics-evts.js

+    const metricDfns = Metrics.metricsDefinitions;
+    const resolvedMetrics = [];
+    metricDfns.forEach(metric => {
+      // try/catch in case auditResults is missing an audit result


ebidel · 2017-01-11T23:16:40Z

lighthouse-core/lib/traces/metrics-evts.js

+
+
+  /**
+   * Constructs performance.measure trace events, which have start/end events as follows:


is "ph: b", beginning? If so, maybe say being/end events instead of start/end.

actually "b" stands for "nestable start" :D
The trace event phases are kind of insane.

ebidel · 2017-01-11T23:17:24Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

@@ -0,0 +1,85 @@
+/**
+ * @license
+ * Copyright 2016 Google Inc. All rights reserved.


brendankenny

reviewed!

brendankenny · 2017-01-11T23:36:15Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+const assert = require('assert');
+
+const dbwTrace = require('../../fixtures/traces/dbw_tester.json');
+const dbwResults = require('../../fixtures/dbw_tester-perf-results.json');


can we reuse an existing trace? We're already at 26MB of trace fixtures and growing :)

was hoping you'd ask that. :) In this case it's pretty tricky because we need mock results and mock trace from the exact same run. Currently we have no fixtures that satisfy that.

I attempted to update one of our sample.json's (yes we have two) but after 25 minutes i concluded the rabbit hole was a bit too deep for me. :/

brendankenny · 2017-01-11T23:36:38Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+  });
+});
+
+describe('assetSaver prepareAssets', () => {


should probably be in asset-saver-test.js

brendankenny · 2017-01-11T23:38:06Z

lighthouse-core/lib/traces/metrics-evts.js

@@ -0,0 +1,204 @@
+/**


rename to indicate progressive web metrics? pwmetrics-events.js? Or is the intention to keep expanding?

renamed. sg

brendankenny · 2017-01-11T23:56:08Z

lighthouse-core/lib/traces/metrics-evts.js

+   * @param {!Array<!AuditResult>} auditResults
+   * @return {!Array<{ts: number, id: string, name: string}>} metrics to consider
+   */
+  gatherMetrics(auditResults) {


make static? (or can use this._auditResults)

brendankenny · 2017-01-12T00:12:22Z

lighthouse-core/lib/traces/metrics-evts.js

+  /**
+   * Getter for our navigationStart trace event
+   */
+  get navigationStartEvt() {


make just getNavigationStartEvt() or something instead of a getter? Kind of confusing below when this property appears.

Could also be an internal function that the constructor calls, populating the this.navigationStartEvt property so the behavior doesn't change from this

brendankenny · 2017-01-12T00:30:15Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+    evts = new Metrics(dbwTrace.traceEvents, dbwResults.audits).generateFakeEvents();
+
+    const metricsWithoutNavstart = Metrics.metricsDefinitions.length - 1;
+    assert.equal(evts.length, 2 * metricsWithoutNavstart, 'All expected fake events not created');


maybe a comment that the events come in pairs, hence the 2 *?

brendankenny · 2017-01-12T00:32:04Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+    const definitionsWithoutEvents = Metrics.metricsDefinitions
+        .filter(metric => metric.id !== 'navstart')
+        .filter(metric => !evts.find(e => e.name === metric.name));
+    assert.deepEqual(definitionsWithoutEvents, [], 'metrics are missing fake events');


better to do assert.strictEqual(definitionsWithoutEvents.length, 0, 'metrics are missing fake events');?

brendankenny · 2017-01-12T00:34:39Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+
+    const eventsWithoutDefinitions = evts
+        .filter(evt => !Metrics.metricsDefinitions.find(metric => metric.name === evt.name));
+    assert.deepEqual(eventsWithoutDefinitions, [], 'fake events without a metric definition');


same length thing

brendankenny · 2017-01-12T00:40:41Z

lighthouse-core/test/lib/traces/metrics-evts-test.js

+  });
+
+  it('generates fake trace events that are valid', () => {
+    const vizCompleteEvts = evts.filter(e => e.name.includes('Visually Complete 100'));


ideally we could avoid dependence on test ordering like this (I'd like to run our tests in a random order at some point, though we do this sort of thing in a few places in current tests :). Just re-run const evts = new Metrics(dbwTrace.traceEvents, dbwResults.audits).generateFakeEvents()? This test doesn't trigger the > 50ms warning on Travis, so should still be fast.

brendankenny · 2017-01-12T00:49:15Z

lighthouse-core/lib/asset-saver.js

@@ -119,6 +120,10 @@ function prepareAssets(artifacts, results) {
        const traceData = Object.assign({}, trace);
        const html = screenshotDump(screenshots, results);

+        if (results && results.audits) {
+          const evts = new Metrics(traceData.traceEvents, results.audits).generateFakeEvents();
+          traceData.traceEvents.push(...evts);


It seems bad to alter the original trace. Not sure when we did const traceData = Object.assign({}, trace);, but really we should be doing something like traceData.traceEvents = Array.from(traceData.traceEvents) to get a new array. Is that crazy?

On one hand, yeah, it feels bad to alter the trace. It'd be nice to keep the objects separate.

On the other:

I don't think we have a need to keep around the original trace.

We've sorted the trace in-place already (a few times).

The memory consumption is pretty huge for these traces, so there's that advantage to augmenting the solo trace.

We've sorted the trace in-place already (a few times).

very good point :)

denar90 · 2017-01-28T21:40:43Z

@paulirish do you need some help for finishing this?

paulirish · 2017-02-02T20:36:14Z

PTAL

brendankenny

love it

(except

:P)

denar90 · 2017-02-03T07:02:47Z

thanks guys 🎉

Inject Lighthouse metrics back into trace for viewing

9de452e

paulirish force-pushed the exportmetricstotrace branch from c1ff959 to 9de452e Compare January 10, 2017 06:59

ebidel suggested changes Jan 11, 2017

View reviewed changes

brendankenny requested changes Jan 12, 2017

View reviewed changes

paulirish added 2 commits February 2, 2017 12:32

feedback.

0a5bba1

rename files.

b7aefd6

paulirish force-pushed the exportmetricstotrace branch from 864f2cc to b7aefd6 Compare February 2, 2017 20:33

line length.

cb14fe3

ebidel approved these changes Feb 2, 2017

View reviewed changes

brendankenny approved these changes Feb 3, 2017

View reviewed changes

brendankenny merged commit ee8d967 into master Feb 3, 2017

brendankenny deleted the exportmetricstotrace branch February 3, 2017 02:14


		const log = require('../../../lighthouse-core/lib/log.js');

		class Metrics {



		/**
		* Constructs performance.measure trace events, which have start/end events as follows:

Inject Lighthouse metrics back into trace for viewing #1446

Inject Lighthouse metrics back into trace for viewing #1446

Conversation

paulirish commented Jan 10, 2017

denar90 commented Jan 10, 2017

wardpeet commented Jan 11, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

brendankenny left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

denar90 commented Jan 28, 2017

paulirish commented Feb 2, 2017

brendankenny left a comment

Choose a reason for hiding this comment

denar90 commented Feb 3, 2017