Skip to content

Commit

Permalink
core: refactor tracing processor
Browse files Browse the repository at this point in the history
  • Loading branch information
connorjclark committed Oct 23, 2018
2 parents 9882514 + e151569 commit 35b6693
Show file tree
Hide file tree
Showing 6 changed files with 66 additions and 46 deletions.
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 tracingIds = TracingProcessor.findTracingIds(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 === tracingIds.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 === tracingIds.pid);

const mainThreadEvents = processEvents
.filter(e => e.tid === startedInPageEvt.tid);
.filter(e => e.tid === tracingIds.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,
tracingIds,
navigationStartEvt: navigationStart,
firstPaintEvt: firstPaint,
firstContentfulPaintEvt: firstContentfulPaint,
Expand Down
49 changes: 33 additions & 16 deletions lighthouse-core/lib/traces/tracing-processor.js
Original file line number Diff line number Diff line change
Expand Up @@ -198,39 +198,56 @@ class TraceProcessor {

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

// 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 pid = mainFrame && mainFrame.processId;
frameId = mainFrame && mainFrame.frame;
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;
tid = threadNameEvt && threadNameEvt.tid;

ts = startedInBrowserEvt.ts;
}

// Support legacy browser versions that do not emit TracingStartedInBrowser event.
if (!startedInPageEvt) {
if (!pid || !tid || !frameId || ts === undefined) {
// 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');
const startedInPageEvt = events.find(e => e.name === 'TracingStartedInPage');
if (startedInPageEvt && startedInPageEvt.args && startedInPageEvt.args.data) {
pid = startedInPageEvt.pid;
tid = startedInPageEvt.tid;
frameId = startedInPageEvt.args.data.page;
ts = startedInPageEvt.ts;
}
}

if (!startedInPageEvt) throw new LHError(LHError.errors.NO_TRACING_STARTED);
if (!pid || !tid || !frameId || ts === undefined) {
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};
return {
pid,
tid,
frameId,
ts,
};
}

/**
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.findTracingIds(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.tracingIds.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);
assert.equal(trace.tracingIds.ts, 29343544280);
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.tracingIds.ts, 8885435611);
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.tracingIds.ts, 1805796376829);
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.tracingIds.ts, 2146735802456);
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.tracingIds.ts, 1966813248134);
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.tracingIds.ts, 2193564729582);
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;
/** Various ids for the current trace context. */
tracingIds: {pid: number, tid: number, frameId: string, ts: number};
/** The trace event marking navigationStart. */
navigationStartEvt: TraceEvent;
/** The trace event marking firstPaint, if it was found. */
Expand Down

0 comments on commit 35b6693

Please sign in to comment.