Skip to content
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
104 changes: 85 additions & 19 deletions core/lib/tracehouse/trace-processor.js
Original file line number Diff line number Diff line change
Expand Up @@ -349,7 +349,7 @@ class TraceProcessor {

const ret = this.getMainThreadTopLevelEventDurations(events, startTime, endTime);
return this._riskPercentiles(ret.durations, totalTime, percentiles,
ret.clippedLength);
ret.clippedLength);
}

/**
Expand Down Expand Up @@ -479,9 +479,9 @@ class TraceProcessor {
const firstResourceSendEvt = events.find(e => e.name === 'ResourceSendRequest');
// We know that these properties exist if we found the events, but TSC doesn't.
if (navStartEvt?.args?.data &&
firstResourceSendEvt &&
firstResourceSendEvt.pid === navStartEvt.pid &&
firstResourceSendEvt.tid === navStartEvt.tid) {
firstResourceSendEvt &&
firstResourceSendEvt.pid === navStartEvt.pid &&
firstResourceSendEvt.tid === navStartEvt.tid) {
const frameId = navStartEvt.args.frame;
if (frameId) {
return {
Expand Down Expand Up @@ -552,9 +552,9 @@ class TraceProcessor {
*/
static isScheduleableTask(evt) {
return evt.name === SCHEDULABLE_TASK_TITLE_LH ||
evt.name === SCHEDULABLE_TASK_TITLE_ALT1 ||
evt.name === SCHEDULABLE_TASK_TITLE_ALT2 ||
evt.name === SCHEDULABLE_TASK_TITLE_ALT3;
evt.name === SCHEDULABLE_TASK_TITLE_ALT1 ||
evt.name === SCHEDULABLE_TASK_TITLE_ALT2 ||
evt.name === SCHEDULABLE_TASK_TITLE_ALT3;
}

/**
Expand All @@ -563,7 +563,7 @@ class TraceProcessor {
*/
static isLCPEvent(evt) {
if (evt.name !== 'largestContentfulPaint::Invalidate' &&
evt.name !== 'largestContentfulPaint::Candidate') return false;
evt.name !== 'largestContentfulPaint::Candidate') return false;
return Boolean(evt.args?.frame);
}

Expand Down Expand Up @@ -602,9 +602,10 @@ class TraceProcessor {
*
* @param {LH.TraceEvent[]} events
* @param {LH.TraceEvent} timeOriginEvent
* @param {string|undefined} mainFrameId
* @return {{lcp: LCPEvent | undefined, invalidated: boolean}}
*/
static computeValidLCPAllFrames(events, timeOriginEvent) {
static computeValidLCPAllFrames(events, timeOriginEvent, mainFrameId) {
const lcpEvents = events.filter(this.isLCPEvent).reverse();

/** @type {Map<string, LCPEvent>} */
Expand All @@ -628,6 +629,53 @@ class TraceProcessor {
}
}

// If no standard LCP candidate is found, try the UKM AllFramesEvents.
if (!maxLcpAcrossFrames) {
const ukmEvents = events.filter(
(e) =>
e.name.includes('LargestContentfulPaint') && e.name.includes('UKM')
);

// In the rare cases this whole fallback is necessary, the
// NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM events are missing too.
// As a result, the only useful signal left is the AllFrames invalidates.
// Not ideal since they are 1 paint behind, but.. better than the dreaded
// NO_LCP error
const targetEventName =
'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM';
const ukmInvalidates = ukmEvents.filter((e) => e.name === targetEventName);

if (ukmInvalidates.length > 0) {
ukmInvalidates.sort((a, b) => a.ts - b.ts);
const lastInvalidate = ukmInvalidates[ukmInvalidates.length - 1];
Comment thread
TravenReese marked this conversation as resolved.
Comment on lines +632 to +650
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Suggested change
// If no standard LCP candidate is found, try the UKM AllFramesEvents.
if (!maxLcpAcrossFrames) {
const ukmEvents = events.filter(
(e) =>
e.name.includes('LargestContentfulPaint') && e.name.includes('UKM')
);
// In the rare cases this whole fallback is necessary, the
// NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM events are missing too.
// As a result, the only useful signal left is the AllFrames invalidates.
// Not ideal since they are 1 paint behind, but.. better than the dreaded
// NO_LCP error
const targetEventName =
'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM';
const ukmInvalidates = ukmEvents.filter((e) => e.name === targetEventName);
if (ukmInvalidates.length > 0) {
ukmInvalidates.sort((a, b) => a.ts - b.ts);
const lastInvalidate = ukmInvalidates[ukmInvalidates.length - 1];
// If no standard LCP candidate is found, try the UKM AllFramesEvents.
if (!maxLcpAcrossFrames) {
// In the rare cases this whole fallback is necessary, the
// NavStartToLargestContentfulPaint::Candidate::AllFrames::UKM events are missing too.
// As a result, the only useful signal left is the AllFrames invalidates.
// Not ideal since they are 1 paint behind, but.. better than the dreaded
// NO_LCP error
const targetEventName =
'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM';
const ukmInvalidates = events.filter(e => e.name === targetEventName);
if (ukmInvalidates.length > 0) {
const lastInvalidate = .sort((a, b) => a.ts - b.ts).at(-1);

fwiw this isnt just for code golfing sake :)

the
events.filter(e => e.name.includes(x) && e.name.includes(y)) is pretty expensive (traces often have 5M events+ ) and.. we really only care about this singular name, right?

( also fwiw you can just hit 'commit' here and then pull locally. )


log.warn(
'TraceProcessor',
'LCP candidate missing, falling back to UKM Invalidate event.'
);

// Construct a mock LCP candidate event
maxLcpAcrossFrames = /** @type {LCPCandidateEvent} */ (
/** @type {unknown} */ ({
name: 'largestContentfulPaint::Candidate',
Comment thread
TravenReese marked this conversation as resolved.
cat: 'loading',
ph: lastInvalidate.ph,
ts: lastInvalidate.ts,
pid: lastInvalidate.pid,
tid: lastInvalidate.tid,
args: {
frame: mainFrameId || 'main_frame', // Mocked frame ID
data: {
size: 1, // Don't know the actuall size so we assign it 1
isMainFrame: true,
isOutermostMainFrame: true,
},
},
})
);
}
}

return {
lcp: maxLcpAcrossFrames,
// LCP events were found, but final LCP event of every frame was an invalidate event.
Expand Down Expand Up @@ -669,17 +717,17 @@ class TraceProcessor {
* @param {LH.Trace} trace
* @param {{timeOriginDeterminationMethod?: TimeOriginDeterminationMethod}} [options]
* @return {LH.Artifacts.ProcessedTrace}
*/
*/
static processTrace(trace, options) {
const {timeOriginDeterminationMethod = 'auto'} = options || {};

// Parse the trace for our key events and sort them by timestamp. Note: sort
// *must* be stable to keep events correctly nested.
const keyEvents = this.filteredTraceSort(trace.traceEvents, e => {
return e.cat.includes('blink.user_timing') ||
e.cat.includes('loading') ||
e.cat.includes('devtools.timeline') ||
e.cat === '__metadata';
e.cat.includes('loading') ||
e.cat.includes('devtools.timeline') ||
e.cat === '__metadata';
});

// Find the inspected frame
Expand All @@ -699,7 +747,7 @@ class TraceProcessor {
// Begin collection of frame tree information with TracingStartedInBrowser,
// which should be present even without navigations.
const tracingStartedFrames = keyEvents
.find(e => e.name === 'TracingStartedInBrowser')?.args?.data?.frames;
.find(e => e.name === 'TracingStartedInBrowser')?.args?.data?.frames;
if (tracingStartedFrames) {
for (const frame of tracingStartedFrames) {
framesById.set(frame.frame, {
Expand Down Expand Up @@ -738,12 +786,18 @@ class TraceProcessor {
// Filter to just events matching the main frame ID, just to make sure.
/** @param {LH.TraceEvent} e */
function associatedToMainFrame(e) {
if (e.name === 'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM') {
return true;
}
const frameId = TraceProcessor.getFrameId(e);
return frameId === mainFrameInfo.frameId;
}

/** @param {LH.TraceEvent} e */
function associatedToAllFrames(e) {
if (e.name.includes('LargestContentfulPaint') && e.name.includes('UKM')) {
Comment thread
TravenReese marked this conversation as resolved.
return true;
}
const frameId = TraceProcessor.getFrameId(e);
return frameId ? inspectedTreeFrameIds.includes(frameId) : false;
}
Expand Down Expand Up @@ -805,9 +859,16 @@ class TraceProcessor {
* origin in addition to the standard microsecond monotonic timestamps.
* @param {LH.Artifacts.ProcessedTrace} processedTrace
* @return {LH.Artifacts.ProcessedNavigation}
*/
*/
static processNavigation(processedTrace) {
const {frameEvents, frameTreeEvents, timeOriginEvt, timings, timestamps} = processedTrace;
const {
frameEvents,
frameTreeEvents,
timeOriginEvt,
timings,
timestamps,
mainFrameInfo,
} = processedTrace;

// Compute the key frame timings for the main frame.
const frameTimings = this.computeNavigationTimingsForFrame(frameEvents, {timeOriginEvt});
Expand All @@ -822,7 +883,11 @@ class TraceProcessor {
}

// Compute LCP for all frames.
const lcpAllFramesEvt = this.computeValidLCPAllFrames(frameTreeEvents, timeOriginEvt).lcp;
const lcpAllFramesEvt = this.computeValidLCPAllFrames(
frameTreeEvents,
timeOriginEvt,
mainFrameInfo.frameId
).lcp;

/** @param {number} ts */
const getTiming = ts => (ts - timeOriginEvt.ts) / 1000;
Expand Down Expand Up @@ -950,7 +1015,7 @@ class TraceProcessor {
* in addition to the standard microsecond monotonic timestamps.
* @param {Array<LH.TraceEvent>} frameEvents
* @param {{timeOriginEvt: LH.TraceEvent}} options
*/
*/
static computeNavigationTimingsForFrame(frameEvents, options) {
const {timeOriginEvt} = options;

Expand All @@ -967,7 +1032,8 @@ class TraceProcessor {
}

// This function accepts events spanning multiple frames, but this usage will only provide events from the main frame.
const lcpResult = this.computeValidLCPAllFrames(frameEvents, timeOriginEvt);
const frameId = frameEvents.map(e => TraceProcessor.getFrameId(e)).find(Boolean);
const lcpResult = this.computeValidLCPAllFrames(frameEvents, timeOriginEvt, frameId);

const load = frameEvents.find(e => e.name === 'loadEventEnd' && e.ts > timeOriginEvt.ts);
const domContentLoaded = frameEvents.find(
Expand Down
30 changes: 30 additions & 0 deletions core/test/lib/tracehouse/trace-processor-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -585,6 +585,36 @@ Object {
assert.ok(!navigation.lcpInvalidated);
});


it('falls back to UKM invalidate event if no candidates found', () => {
const testTrace = createTestTrace({timeOrigin: 0, traceEnd: 2000});
const cat = 'loading';
testTrace.traceEvents.push(
{
name: 'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM',
cat,
ph: 'I',
ts: 1500,
args: {
main_frame_tree_node_id: 2,
},
},
{
name: 'NavStartToLargestContentfulPaint::Invalidate::AllFrames::UKM',
cat,
ph: 'I',
ts: 1600,
args: {
main_frame_tree_node_id: 2,
},
}
);
const trace = TraceProcessor.processTrace(testTrace);
const navigation = TraceProcessor.processNavigation(trace);
assert.equal(navigation.timestamps.largestContentfulPaint, 1600);
assert.equal(navigation.largestContentfulPaintEvt.args.data.size, 1);
});

it('invalidates if last event is ::Invalidate', () => {
const testTrace = createTestTrace({timeOrigin: 0, traceEnd: 2000});
const frame = testTrace.traceEvents.find(e => e.name === 'navigationStart').args.frame;
Expand Down
Loading