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(trace-processor): correct overlapping tasks #15921

Merged
merged 3 commits into from
Apr 4, 2024
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
17 changes: 15 additions & 2 deletions core/lib/tracehouse/trace-processor.js
Original file line number Diff line number Diff line change
Expand Up @@ -403,6 +403,9 @@ class TraceProcessor {
*/
static getMainThreadTopLevelEvents(trace, startTime = 0, endTime = Infinity) {
const topLevelEvents = [];
/** @type {ToplevelEvent|undefined} */
let prevToplevel = undefined;

// note: mainThreadEvents is already sorted by event start
for (const event of trace.mainThreadEvents) {
if (!this.isScheduleableTask(event) || !event.dur) continue;
Expand All @@ -411,11 +414,21 @@ class TraceProcessor {
const end = (event.ts + event.dur - trace.timeOriginEvt.ts) / 1000;
if (start > endTime || end < startTime) continue;

topLevelEvents.push({
// Temporary fix for a Chrome bug where some RunTask events can be overlapping.
// We correct that here be ensuring each RunTask ends at least 1 microsecond before the next
// https://github.com/GoogleChrome/lighthouse/issues/15896
// https://issues.chromium.org/issues/329678173
if (prevToplevel && start < prevToplevel.end) {
prevToplevel.end = start - 0.001;
}

prevToplevel = {
start,
end,
duration: event.dur / 1000,
});
};

topLevelEvents.push(prevToplevel);
}

return topLevelEvents;
Expand Down
2 changes: 1 addition & 1 deletion core/test/audits/long-tasks-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -304,7 +304,7 @@ describe('Long tasks audit', () => {
}],
},
});
expect(result.metricSavings.TBT).toBeApproximately(353.53);
expect(result.metricSavings.TBT).toBeApproximately(171.95);
Copy link
Member Author

Choose a reason for hiding this comment

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

I checked, this trace does have overlapping events: https://trace.cafe/t/ETHMnpFcQx


const debugData = result.details.debugData;
expect(debugData).toStrictEqual({
Expand Down
2 changes: 1 addition & 1 deletion core/test/audits/mainthread-work-breakdown-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -120,7 +120,7 @@ Object {
expect(Math.round(output.numericValue)).toMatchInlineSnapshot(`979`);
assert.equal(output.details.items.length, 7);
assert.equal(output.score, 1);
expect(output.metricSavings.TBT).toBeCloseTo(353.5, 0.1);
expect(output.metricSavings.TBT).toBeCloseTo(171.95, 0.1);
});

it('should compute the correct values for the load trace (legacy)', async () => {
Expand Down
41 changes: 41 additions & 0 deletions core/test/lib/tracehouse/trace-processor-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -331,6 +331,47 @@ describe('TraceProcessor', () => {
assert.equal(ret[1].end, 2000);
assert.equal(ret[1].duration, 1000);
});

it('corrects overlapping tasks', () => {
const baseTime = 20_000_000;
const name = 'RunTask';
const processedTrace = {
timeOriginEvt: {ts: baseTime},
mainThreadEvents: [
// 10ms to 100ms
{ts: baseTime + 10_000, dur: 90_000, name},
// 40ms to 60ms
{ts: baseTime + 40_000, dur: 20_000, name},
// 70ms to 90ms
{ts: baseTime + 70_000, dur: 20_000, name},
// 100ms to 120ms
{ts: baseTime + 100_000, dur: 20_000, name},
],
};

const ret = TraceProcessor.getMainThreadTopLevelEvents(
processedTrace,
0,
2000
);
assert.equal(ret.length, 4);

assert.equal(ret[0].start, 10);
assert.equal(ret[0].end, 39.999);
assert.equal(ret[0].duration, 90);

assert.equal(ret[1].start, 40);
assert.equal(ret[1].end, 60);
assert.equal(ret[1].duration, 20);

assert.equal(ret[2].start, 70);
assert.equal(ret[2].end, 90);
assert.equal(ret[2].duration, 20);

assert.equal(ret[3].start, 100);
assert.equal(ret[3].end, 120);
assert.equal(ret[3].duration, 20);
});
});

describe('getMainThreadTopLevelEventDurations', () => {
Expand Down
Loading