Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

core: refactor finding of trace start #6370

Merged
merged 6 commits into from
Oct 25, 2018
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 5 additions & 5 deletions lighthouse-core/gather/computed/trace-of-tab.js
Original file line number Diff line number Diff line change
Expand Up @@ -82,10 +82,10 @@ class TraceOfTab {
});

// Find the inspected frame
const {startedInPageEvt, frameId} = TracingProcessor.findTracingStartedEvt(keyEvents);
const mainFrameIds = TracingProcessor.findMainFrameIds(keyEvents);

// Filter to just events matching the frame ID for sanity
const frameEvents = keyEvents.filter(e => e.args.frame === frameId);
const frameEvents = keyEvents.filter(e => e.args.frame === mainFrameIds.frameId);

// Our navStart will be the last frame navigation in the trace
const navigationStart = frameEvents.filter(TraceOfTab.isNavigationStartOfInterest).pop();
Expand Down Expand Up @@ -132,10 +132,10 @@ class TraceOfTab {
// subset all trace events to just our tab's process (incl threads other than main)
// stable-sort events to keep them correctly nested.
const processEvents = TraceOfTab
.filteredStableSort(trace.traceEvents, e => e.pid === startedInPageEvt.pid);
.filteredStableSort(trace.traceEvents, e => e.pid === mainFrameIds.pid);

const mainThreadEvents = processEvents
.filter(e => e.tid === startedInPageEvt.tid);
.filter(e => e.tid === mainFrameIds.tid);

// traceEnd must exist since at least navigationStart event was verified as existing.
const traceEnd = trace.traceEvents.reduce((max, evt) => {
Expand Down Expand Up @@ -177,7 +177,7 @@ class TraceOfTab {
timestamps,
processEvents,
mainThreadEvents,
startedInPageEvt,
mainFrameIds,
navigationStartEvt: navigationStart,
firstPaintEvt: firstPaint,
firstContentfulPaintEvt: firstContentfulPaint,
Expand Down
45 changes: 26 additions & 19 deletions lighthouse-core/lib/traces/tracing-processor.js
Original file line number Diff line number Diff line change
Expand Up @@ -198,39 +198,46 @@ class TraceProcessor {

/**
* @param {LH.TraceEvent[]} events
* @return {{startedInPageEvt: LH.TraceEvent, frameId: string}}
* @return {{pid: number, tid: number, frameId: string}}
*/
static findTracingStartedEvt(events) {
/** @type {LH.TraceEvent|undefined} */
let startedInPageEvt;

static findMainFrameIds(events) {
// Prefer the newer TracingStartedInBrowser event first, if it exists
const startedInBrowserEvt = events.find(e => e.name === 'TracingStartedInBrowser');
if (startedInBrowserEvt && startedInBrowserEvt.args.data &&
startedInBrowserEvt.args.data.frames) {
const mainFrame = startedInBrowserEvt.args.data.frames.find(frame => !frame.parent);
const frameId = mainFrame && mainFrame.frame;
const pid = mainFrame && mainFrame.processId;

const threadNameEvt = events.find(e => e.pid === pid && e.ph === 'M' &&
e.cat === '__metadata' && e.name === 'thread_name' && e.args.name === 'CrRendererMain');
startedInPageEvt = mainFrame && threadNameEvt ?
Object.assign({}, startedInBrowserEvt, {
pid, tid: threadNameEvt.tid, name: 'TracingStartedInPage',
args: {data: {page: mainFrame.frame}}}) :
undefined;
const tid = threadNameEvt && threadNameEvt.tid;

if (pid && tid && frameId) {
return {
pid,
tid,
frameId,
};
}
}

// Support legacy browser versions that do not emit TracingStartedInBrowser event.
if (!startedInPageEvt) {
// The first TracingStartedInPage in the trace is definitely our renderer thread of interest
// Beware: the tracingStartedInPage event can appear slightly after a navigationStart
startedInPageEvt = events.find(e => e.name === 'TracingStartedInPage');
// The first TracingStartedInPage in the trace is definitely our renderer thread of interest
// Beware: the tracingStartedInPage event can appear slightly after a navigationStart
const startedInPageEvt = events.find(e => e.name === 'TracingStartedInPage');
if (startedInPageEvt && startedInPageEvt.args && startedInPageEvt.args.data) {
const frameId = startedInPageEvt.args.data.page;
if (frameId) {
return {
pid: startedInPageEvt.pid,
tid: startedInPageEvt.tid,
frameId,
};
}
}

if (!startedInPageEvt) throw new LHError(LHError.errors.NO_TRACING_STARTED);

// @ts-ignore - property chain exists for 'TracingStartedInPage' event.
const frameId = /** @type {string} */ (startedInPageEvt.args.data.page);
return {startedInPageEvt, frameId};
throw new LHError(LHError.errors.NO_TRACING_STARTED);
}

/**
Expand Down
4 changes: 2 additions & 2 deletions lighthouse-core/scripts/lantern/minify-trace.js
Original file line number Diff line number Diff line change
Expand Up @@ -78,11 +78,11 @@ const traceEventsToKeepInProcess = new Set([
* @param {LH.TraceEvent[]} events
*/
function filterOutUnnecessaryTasksByNameAndDuration(events) {
const {startedInPageEvt} = TracingProcessor.findTracingStartedEvt(events);
const {pid} = TracingProcessor.findMainFrameIds(events);

return events.filter(evt => {
if (toplevelTaskNames.has(evt.name) && evt.dur < 1000) return false;
if (evt.pid === startedInPageEvt.pid && traceEventsToKeepInProcess.has(evt.name)) return true;
if (evt.pid === pid && traceEventsToKeepInProcess.has(evt.name)) return true;
return traceEventsToAlwaysKeep.has(evt.name);
});
}
Expand Down
31 changes: 17 additions & 14 deletions lighthouse-core/test/gather/computed/main-thread-tasks-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -14,15 +14,18 @@ const TracingProcessor = require('../../../lib/traces/tracing-processor.js');
const assert = require('assert');

describe('MainResource computed artifact', () => {
const args = {data: {}};
const pid = 1;
const tid = 2;
const frameId = 'BLAH';
const args = {data: {}, frame: frameId};
const baseTs = 1241250325;
let boilerplateTrace;

beforeEach(() => {
boilerplateTrace = [
{ph: 'I', name: 'TracingStartedInPage', ts: baseTs, args},
{ph: 'I', name: 'navigationStart', ts: baseTs, args},
{ph: 'R', name: 'firstContentfulPaint', ts: baseTs + 1, args},
{ph: 'I', name: 'TracingStartedInPage', pid, tid, ts: baseTs, args: {data: {page: frameId}}},
{ph: 'I', name: 'navigationStart', pid, tid, ts: baseTs, args},
{ph: 'R', name: 'firstContentfulPaint', pid, tid, ts: baseTs + 1, args},
];
});

Expand Down Expand Up @@ -60,13 +63,13 @@ describe('MainResource computed artifact', () => {
*/
const traceEvents = [
...boilerplateTrace,
{ph: 'X', name: 'TaskA', ts: baseTs, dur: 100e3},
{ph: 'B', name: 'TaskB', ts: baseTs + 5e3},
{ph: 'X', name: 'TaskC', ts: baseTs + 10e3, dur: 30e3},
{ph: 'E', name: 'TaskB', ts: baseTs + 55e3},
{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, args},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, args},
{ph: 'X', name: 'TaskC', pid, tid, ts: baseTs + 10e3, dur: 30e3, args},
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 55e3, args},
];

traceEvents.forEach(evt => Object.assign(evt, {cat: 'devtools.timeline', args}));
traceEvents.forEach(evt => Object.assign(evt, {cat: 'devtools.timeline'}));

const context = {computedCache: new Map()};
const tasks = await MainThreadTasks.request({traceEvents}, context);
Expand Down Expand Up @@ -116,11 +119,11 @@ describe('MainResource computed artifact', () => {
*/
const traceEvents = [
...boilerplateTrace,
{ph: 'X', name: 'TaskA', ts: baseTs, dur: 100e3, ...url('about:blank')},
{ph: 'B', name: 'TaskB', ts: baseTs + 5e3, ...stackFrames(['urlB.1', 'urlB.2'])},
{ph: 'X', name: 'EvaluateScript', ts: baseTs + 10e3, dur: 30e3, ...url('urlC')},
{ph: 'X', name: 'TaskD', ts: baseTs + 15e3, dur: 5e3, ...stackFrames(['urlD'])},
{ph: 'E', name: 'TaskB', ts: baseTs + 55e3},
{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, ...url('about:blank')},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, ...stackFrames(['urlB.1', 'urlB.2'])},
{ph: 'X', name: 'EvaluateScript', pid, tid, ts: baseTs + 10e3, dur: 30e3, ...url('urlC')},
{ph: 'X', name: 'TaskD', pid, tid, ts: baseTs + 15e3, dur: 5e3, ...stackFrames(['urlD'])},
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 55e3},
];

traceEvents.forEach(evt => {
Expand Down
14 changes: 7 additions & 7 deletions lighthouse-core/test/gather/computed/trace-of-tab-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ describe('Trace of Tab computed artifact:', () => {
assert.equal(evt.pid, firstEvt.pid, 'A traceEvent is found from another process');
});

assert.ok(firstEvt.pid === trace.startedInPageEvt.pid);
assert.ok(firstEvt.pid === trace.mainFrameIds.pid);
assert.ok(firstEvt.pid === trace.navigationStartEvt.pid);
assert.ok(firstEvt.pid === trace.firstContentfulPaintEvt.pid);
assert.ok(firstEvt.pid === trace.firstMeaningfulPaintEvt.pid);
Expand All @@ -54,7 +54,7 @@ describe('Trace of Tab computed artifact:', () => {
describe('finds correct FMP', () => {
it('if there was a tracingStartedInPage after the frame\'s navStart', async () => {
const trace = await TraceOfTab.compute_(lateTracingStartedTrace);
assert.equal(trace.startedInPageEvt.ts, 29343544280);
brendankenny marked this conversation as resolved.
Show resolved Hide resolved
assert.equal(trace.mainFrameIds.frameId, '0x163736997740');
assert.equal(trace.navigationStartEvt.ts, 29343540951);
assert.equal(trace.firstContentfulPaintEvt.ts, 29343621005);
assert.equal(trace.firstMeaningfulPaintEvt.ts, 29344070867);
Expand All @@ -63,7 +63,7 @@ describe('Trace of Tab computed artifact:', () => {

it('if there was a tracingStartedInPage after the frame\'s navStart #2', async () => {
const trace = await TraceOfTab.compute_(badNavStartTrace);
assert.equal(trace.startedInPageEvt.ts, 8885435611);
assert.equal(trace.mainFrameIds.frameId, '0x89915541e48');
assert.equal(trace.navigationStartEvt.ts, 8885424467);
assert.equal(trace.firstContentfulPaintEvt.ts, 8886056886);
assert.equal(trace.firstMeaningfulPaintEvt.ts, 8886056891);
Expand All @@ -72,7 +72,7 @@ describe('Trace of Tab computed artifact:', () => {

it('if it appears slightly before the fCP', async () => {
const trace = await TraceOfTab.compute_(preactTrace);
assert.equal(trace.startedInPageEvt.ts, 1805796376829);
assert.equal(trace.mainFrameIds.frameId, '0x25edaa521e58');
assert.equal(trace.navigationStartEvt.ts, 1805796384607);
assert.equal(trace.firstContentfulPaintEvt.ts, 1805797263653);
assert.equal(trace.firstMeaningfulPaintEvt.ts, 1805797262960);
Expand All @@ -81,7 +81,7 @@ describe('Trace of Tab computed artifact:', () => {

it('from candidates if no defined FMP exists', async () => {
const trace = await TraceOfTab.compute_(noFMPtrace);
assert.equal(trace.startedInPageEvt.ts, 2146735802456);
assert.equal(trace.mainFrameIds.frameId, '0x150343381dd0');
assert.equal(trace.navigationStartEvt.ts, 2146735807738);
assert.equal(trace.firstContentfulPaintEvt.ts, 2146737302468);
assert.equal(trace.firstMeaningfulPaintEvt.ts, 2146740268666);
Expand All @@ -91,7 +91,7 @@ describe('Trace of Tab computed artifact:', () => {

it('handles traces missing a paints (captured in background tab)', async () => {
const trace = await TraceOfTab.compute_(backgroundTabTrace);
assert.equal(trace.startedInPageEvt.ts, 1966813248134);
assert.equal(trace.mainFrameIds.frameId, '0x53965941e30');
assert.notEqual(trace.navigationStartEvt.ts, 1966813346529, 'picked wrong frame');
assert.notEqual(trace.navigationStartEvt.ts, 1966813520313, 'picked wrong frame');
assert.equal(
Expand Down Expand Up @@ -158,7 +158,7 @@ describe('Trace of Tab computed artifact:', () => {
'args': {'name': 'CrRendererMain'},
}]};
const trace = await TraceOfTab.compute_(tracingStartedInBrowserTrace);
assert.equal(trace.startedInPageEvt.ts, 2193564729582);
assert.equal(trace.mainFrameIds.frameId, 'B192D1F3355A6F961EC8F0B01623C1FB');
assert.equal(trace.navigationStartEvt.ts, 2193564790059);
});

Expand Down
4 changes: 2 additions & 2 deletions typings/artifacts.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -359,8 +359,8 @@ declare global {
processEvents: Array<TraceEvent>;
/** The subset of trace events from the page's main thread, sorted by timestamp. */
mainThreadEvents: Array<TraceEvent>;
/** The event marking the start of tracing in the target browser. */
startedInPageEvt: TraceEvent;
/** IDs for the trace's main frame, process, and thread. */
mainFrameIds: {pid: number, tid: number, frameId: string};
/** The trace event marking navigationStart. */
navigationStartEvt: TraceEvent;
/** The trace event marking firstPaint, if it was found. */
Expand Down
2 changes: 1 addition & 1 deletion yarn.lock
Original file line number Diff line number Diff line change
Expand Up @@ -5948,7 +5948,7 @@ micromatch@^2.3.11, micromatch@^2.3.7:
parse-glob "^3.0.4"
regex-cache "^0.4.2"

micromatch@^3.1.4, micromatch@^3.1.8:
micromatch@^3.1.10, micromatch@^3.1.4, micromatch@^3.1.8:
version "3.1.10"
resolved "https://registry.yarnpkg.com/micromatch/-/micromatch-3.1.10.tgz#70859bc95c9840952f359a068a3fc49f9ecfac23"
integrity sha512-MWikgl9n9M3w+bpsY3He8L+w9eF9338xRl8IAO5viDizwSzziFEyUzo2xrrloB64ADbTf8uA8vRqqttDTOmccg==
Expand Down