Skip to content

Commit 6daf898

Browse files
committed
add slop test to fix notracingstarted trace
1 parent b8e0e81 commit 6daf898

File tree

2 files changed

+69
-1
lines changed

2 files changed

+69
-1
lines changed

lighthouse-core/lib/tracehouse/main-thread-tasks.js

Lines changed: 10 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -222,7 +222,16 @@ class MainThreadTasks {
222222

223223
if (currentTask) {
224224
if (nextTask.endTime > currentTask.endTime) {
225-
throw new Error('Fatal trace logic error - child cannot end after parent');
225+
const timeDelta = nextTask.endTime - currentTask.endTime;
226+
// The child task is taking longer than the parent task, which should be impossible.
227+
// If it's less than 1ms, we'll let it slide.
228+
// If it's more, throw an error.
229+
if (timeDelta < 1000) {
230+
currentTask.endTime = nextTask.endTime;
231+
currentTask.duration += timeDelta;
232+
} else {
233+
throw new Error('Fatal trace logic error - child cannot end after parent');
234+
}
226235
}
227236

228237
// We're currently in the middle of a task, so `nextTask` is a child.

lighthouse-core/test/lib/tracehouse/main-thread-tasks-test.js

Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ const MainThreadTasks = require('../../../lib/tracehouse/main-thread-tasks.js');
1111
const TraceProcessor = require('../../../lib/tracehouse/trace-processor.js');
1212
const taskGroups = require('../../../lib/tracehouse/task-groups.js').taskGroups;
1313
const pwaTrace = require('../../fixtures/traces/progressive-app.json');
14+
const noTracingStartedTrace = require('../../fixtures/traces/no-tracingstarted-m74.json');
1415
const TracingProcessor = require('../../../lib/tracehouse/trace-processor.js');
1516
const assert = require('assert');
1617

@@ -59,6 +60,11 @@ describe('Main Thread Tasks', () => {
5960
assert.equal(Math.round(totalTime), 396);
6061
});
6162

63+
it('should handle slightly trace events that slightly overlap', () => {
64+
const tasks = run(noTracingStartedTrace);
65+
expect(tasks).toHaveLength(425);
66+
});
67+
6268
it('should compute parent/child correctly', () => {
6369
/*
6470
An artistic rendering of the below trace:
@@ -416,6 +422,52 @@ describe('Main Thread Tasks', () => {
416422
]);
417423
});
418424

425+
it('should handle child events that extend <1ms beyond parent event', () => {
426+
/*
427+
An artistic rendering of the below trace:
428+
████████████████TaskA██████████████████
429+
█████████TaskB██████████████████
430+
*/
431+
const traceEvents = [
432+
...boilerplateTrace,
433+
{ph: 'B', name: 'TaskA', pid, tid, ts: baseTs, args},
434+
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 25e3, args},
435+
{ph: 'E', name: 'TaskA', pid, tid, ts: baseTs + 100e3 - 50, args}, // this is invalid, but happens in practice
436+
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 100e3, args},
437+
];
438+
439+
traceEvents.forEach(evt => Object.assign(evt, {cat: 'devtools.timeline'}));
440+
441+
const tasks = run({traceEvents});
442+
const [taskA, taskB] = tasks;
443+
expect(tasks).toEqual([
444+
{
445+
parent: undefined,
446+
attributableURLs: [],
447+
448+
children: [taskB],
449+
event: traceEvents.find(event => event.name === 'TaskA'),
450+
startTime: 0,
451+
endTime: 100,
452+
duration: 100,
453+
selfTime: 25,
454+
group: taskGroups.other,
455+
},
456+
{
457+
parent: taskA,
458+
attributableURLs: [],
459+
460+
children: [],
461+
event: traceEvents.find(event => event.name === 'TaskB' && event.ph === 'B'),
462+
startTime: 25,
463+
endTime: 100,
464+
duration: 75,
465+
selfTime: 75,
466+
group: taskGroups.other,
467+
},
468+
]);
469+
});
470+
419471
const invalidEventSets = [
420472
[
421473
// TaskA overlaps with TaskB, X first
@@ -429,6 +481,13 @@ describe('Main Thread Tasks', () => {
429481
{ph: 'X', name: 'TaskB', pid, tid, ts: baseTs + 5e3, dur: 100e3, args},
430482
{ph: 'E', name: 'TaskA', pid, tid, ts: baseTs + 90e3, args},
431483
],
484+
[
485+
// TaskA overlaps with TaskB, both B/E
486+
{ph: 'B', name: 'TaskA', pid, tid, ts: baseTs, args},
487+
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, args},
488+
{ph: 'E', name: 'TaskA', pid, tid, ts: baseTs + 90e3, args},
489+
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 95e3, args},
490+
],
432491
[
433492
// TaskA is missing a B event
434493
{ph: 'E', name: 'TaskA', pid, tid, ts: baseTs, args},

0 commit comments

Comments
 (0)