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(tracing): handle FrameCommittedInBrowser with processPseudoId #14800

Merged
merged 9 commits into from
Mar 1, 2023
Merged
20 changes: 12 additions & 8 deletions core/lib/tracehouse/trace-processor.js
Original file line number Diff line number Diff line change
Expand Up @@ -488,21 +488,24 @@ class TraceProcessor {
* @return {Map<number, number>} Map where keys are process IDs and their values are thread IDs
*/
static findMainFramePidTids(mainFrameInfo, keyEvents) {
const frameCommittedEvts = keyEvents.filter(evt =>
evt.name === 'FrameCommittedInBrowser' &&
evt.args?.data?.frame === mainFrameInfo.frameId
const frameProcessEvts = keyEvents.filter(evt =>
// ProcessReadyInBrowser is used when a processID isn't available when the FrameCommittedInBrowser trace event is emitted.
// In that case. FrameCommittedInBrowser has no processId, but a processPseudoId. and the ProcessReadyInBrowser event declares the proper processId.
(evt.name === 'FrameCommittedInBrowser' || evt.name === 'ProcessReadyInBrowser') &&
evt.args?.data?.frame === mainFrameInfo.frameId &&
evt?.args?.data?.processId
);

// "Modern" traces with a navigation have a FrameCommittedInBrowser event
const mainFramePids = frameCommittedEvts.length
? frameCommittedEvts.map(e => e?.args?.data?.processId)
const mainFramePids = frameProcessEvts.length
? frameProcessEvts.map(e => e?.args?.data?.processId)
// …But old traces and some timespan traces may not. In these situations, we'll assume the
// primary process ID remains constant (as there were no navigations).
: [mainFrameInfo.startingPid];

const pidToTid = new Map();

mainFramePids.forEach(pid => {
for (const pid of new Set(mainFramePids)) {
// While renderer tids are generally predictable, we'll doublecheck it
const threadNameEvt = keyEvents.find(e =>
e.cat === '__metadata' &&
Expand All @@ -518,7 +521,7 @@ class TraceProcessor {
}

pidToTid.set(pid, tid);
});
}
return pidToTid;
}

Expand Down Expand Up @@ -712,7 +715,8 @@ class TraceProcessor {
}
const frameEvents = keyEvents.filter(e => associatedToMainFrame(e));

// Filter to just events matching the main frame ID or any child frame IDs.
// Filter to just events matching the main frame ID or any child frame IDs. The subframes
// are either in-process (same origin) or, potentially, out-of-process. (OOPIFs)
let frameTreeEvents = [];
if (frameIdToRootFrameId.has(mainFrameInfo.frameId)) {
frameTreeEvents = keyEvents.filter(e => associatedToAllFrames(e));
Expand Down
64 changes: 45 additions & 19 deletions core/test/lib/tracehouse/trace-processor-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@ const lcpTrace = readJson('../../fixtures/traces/lcp-m78.json', import.meta);
const lcpAllFramesTrace = readJson('../../fixtures/traces/frame-metrics-m89.json', import.meta);
const startedAfterNavstartTrace = readJson('../../fixtures/traces/tracingstarted-after-navstart.json', import.meta);
const pidChangeTrace = readJson('../../fixtures/traces/pid-change.json', import.meta);
const decentlyModernTrace = readJson('../../fixtures/traces/frame-metrics-m90.json', import.meta);

describe('TraceProcessor', () => {
describe('_riskPercentiles', () => {
Expand Down Expand Up @@ -933,7 +934,7 @@ Object {
});
});

it('manages cross-process / cross-iframe traces', () => {
describe('manages cross-process / cross-iframe traces', () => {
function summarizeTrace(trace) {
const processed = TraceProcessor.processTrace(trace);
const keyEventsLen = processed._keyEvents.length;
Expand All @@ -943,26 +944,51 @@ Object {
const mainFramePids = new Set();
mainFramePids.add(processed.mainFrameInfo.startingPid);
[...processed._rendererPidToTid.keys()].forEach(pid => mainFramePids.add(pid));

return {processEventsPct, frameEventsPct, mainFramePids};
}

// Single PID trace
const lcpTraceSummarized = summarizeTrace(lcpTrace);
expect(lcpTraceSummarized.mainFramePids.size).toEqual(1);
// The primary process events should make up more than 40% of all key trace events
expect(lcpTraceSummarized.processEventsPct).toBeGreaterThanOrEqual(0.4);
// The main frame's events should make up more than 40% of all key trace events
expect(lcpTraceSummarized.frameEventsPct).toBeGreaterThanOrEqual(0.4);

// Multi PID trace
const pidChangeTraceSummarized = summarizeTrace(pidChangeTrace);
expect(pidChangeTraceSummarized.mainFramePids.size).toEqual(2);
// The primary process events should make up more than 40% of all key trace events
expect(pidChangeTraceSummarized.processEventsPct).toBeGreaterThanOrEqual(0.4);

// The main frame's events should make up more than 40% of all key trace events
// TODO: fix!
// expect(pidChangeTraceSummarized.frameEventsPct).toBeGreaterThanOrEqual(0.4);
it('with a basic single PID trace', () => {
const lcpTraceSummarized = summarizeTrace(lcpTrace);
expect(lcpTraceSummarized.mainFramePids.size).toEqual(1);
// The primary process events should make up more than 40% of all key trace events
expect(lcpTraceSummarized.processEventsPct).toBeGreaterThanOrEqual(0.4);
// The main frame's events should make up more than 40% of all key trace events
expect(lcpTraceSummarized.frameEventsPct).toBeGreaterThanOrEqual(0.4);
});

it('with a multi PID trace', () => {
const pidChangeTraceSummarized = summarizeTrace(pidChangeTrace);
expect(pidChangeTraceSummarized.mainFramePids.size).toEqual(2);
// The primary process events should make up more than 40% of all key trace events
expect(pidChangeTraceSummarized.processEventsPct).toBeGreaterThanOrEqual(0.4);
// The main frame's events should make up more than 40% of all key trace events
// TODO: fix!
// expect(pidChangeTraceSummarized.frameEventsPct).toBeGreaterThanOrEqual(0.4);
});

// FrameCommittedInBrowser w/o processId, but w/ processPsuedoId, and later a ProcessReadyInBrowser
it('with a processPsuedoId navigation', () => {
// A 'normal' FrameCommittedInBrowser's data is:
// {"frame":"FRAME_ID","name":"","processId":72647,"url":"https://memegen.corp.google.com/"}
// But if the processId isn't ready at frame creation, we get this pair:
// {"args":{"data":{"frame":"FRAME_ID","name":"","processPseudoId":"0x7ff70022ca00","url":"https://memegen.com/"}},"cat":"disabled-by-default-devtools.timeline","name":"FrameCommittedInBrowser","ph":"I","pid":744,"s":"t","tid":775,"ts":123265406529,"tts":10824502153},
// {"args":{"data":{"frame":"FRAME_ID","processId":72647,"processPseudoId":"0x7ff70022ca00"}},"cat":"disabled-by-default-devtools.timeline","name":"ProcessReadyInBrowser","ph":"I","pid":744,"s":"t","tid":775,"ts":123265450207,"tts":10824519750},
const psuedoProcTrace = JSON.parse(JSON.stringify(decentlyModernTrace));
const fcibEvt = psuedoProcTrace.traceEvents.find(e => e.name === 'FrameCommittedInBrowser');
const {url, processId, frame} = fcibEvt.args.data;
expect(processId).toBeTruthy();
fcibEvt.args.data = {frame, name: '', url, processPseudoId: '0xbaabaa'};

const procReadyEvt = JSON.parse(JSON.stringify(fcibEvt));
procReadyEvt.name = 'ProcessReadyInBrowser';
procReadyEvt.args.data = {frame, processId, processPseudoId: '0xbaabaa'};
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, do the processPseudoIds match? Almost feels like information we should be using in trace-processor (only look at ProcessReadyInBrowser events that have a processPseudoId that matches a FrameCommittedInBrowser without a proccessId?) but maybe it can never matter

Copy link
Member Author

@paulirish paulirish Mar 1, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yah we definitely could. and I considered it. But I think it's kinda overkill. (tho admittedly OPP does it)
I'm happy to revisit.

procReadyEvt.ts = fcibEvt.ts + 10;
psuedoProcTrace.traceEvents.push(procReadyEvt);

const psuedoProcSummarized = summarizeTrace(psuedoProcTrace);
expect(psuedoProcSummarized.mainFramePids.size).toEqual(1);
// The primary process events should make up more than 40% of all key trace events
expect(psuedoProcSummarized.processEventsPct).toBeGreaterThanOrEqual(0.4);
});
});
});