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(tracehouse): allow nested trace events without an end #9785

Merged
merged 4 commits into from
Oct 7, 2019

Conversation

patrickhulce
Copy link
Collaborator

Summary
Addresses one of the 3 remaining cases for Fatal trace logic error - child cannot end after parent error.

Related Issues/PRs
#7764

Copy link
Member

@brendankenny brendankenny left a comment

Choose a reason for hiding this comment

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

LGTM!

lighthouse-core/lib/tracehouse/main-thread-tasks.js Outdated Show resolved Hide resolved
lighthouse-core/lib/tracehouse/main-thread-tasks.js Outdated Show resolved Hide resolved
lighthouse-core/lib/tracehouse/main-thread-tasks.js Outdated Show resolved Hide resolved
{ph: 'I', name: 'MarkerToPushOutTraceEnd', pid, tid, ts: baseTs + 110e3, args},
// TaskB is missing an E event within an X
{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, args},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 10e3, args},
Copy link
Member

Choose a reason for hiding this comment

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

👍

const invalidEventSets = [
[
// TaskA overlaps with TaskB, X first
{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, args},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, args},
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 115e3, args},
{ph: 'I', name: 'MarkerToPushOutTraceEnd', pid, tid, ts: baseTs + 200e3, args},
Copy link
Member

Choose a reason for hiding this comment

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

some of these seem like they won't affect anything, is it just general hygiene so they're all similar?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

they actually do have a noticeable effect though because if the E is the traceEnd then we fall into a different error recovery mode that turns these into valid events which is not what we want to test

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

added a comment to this effect

Copy link
Member

Choose a reason for hiding this comment

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

they actually do have a noticeable effect though because if the E is the traceEnd then we fall into a different error recovery mode that turns these into valid events which is not what we want to test

oh right, because then it would be assumed TaskB didn't have an end event (even though it did) and one was created for it (even though one wasn't), so then it would get trimmed to the length of TaskA.

Doesn't that seem like a problem with using traceEndTs as the signal we were missing an end event? It seems like this case (before the MarkerToPushOutTraceEnd event is added) shouldn't be treated that way (even if it is very unlikely to occur).

Are there downsides to using Infinity for the ts in

taskEndEvent = {ph: 'E', ts: traceEndTs};

?

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Doesn't that seem like a problem with using traceEndTs as the signal we were missing an end event? It seems like this case (before the MarkerToPushOutTraceEnd event is added) shouldn't be treated that way (even if it is very unlikely to occur).

I disagree. In the case where we have just one of the E events and no other events following it at all, the most likely explanation to me is that it just got cutoff emitting the other E event for the exact same time, i.e. the exact case our workaround is targeting.

The fact that other events follow it is what makes it a completely invalid situation.

Copy link
Member

Choose a reason for hiding this comment

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

In the case where we have just one of the E events and no other events following it at all, the most likely explanation to me is that it just got cutoff emitting the other E event for the exact same time, i.e. the exact case our workaround is targeting

Hmm, I don't understand. In the case of

{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, args},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, args},
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 115e3, args},

clearly there was an end event emitted...it seems better to check if other invalid heuristics apply than to just chop off TaskB at baseTs + 100e3.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Oh, oh sorry! Yeah this specific case sounds like it should work without it. 👍

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

alright Infinity has it's own set of problems which is why I avoided it to begin with, so introduced an unbounded boolean to deal with this. LMK if you think it's worth the tradeoff in the latest commit

Copy link
Member

Choose a reason for hiding this comment

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

alright Infinity has it's own set of problems which is why I avoided it to begin with, so introduced an unbounded boolean to deal with this. LMK if you think it's worth the tradeoff in the latest commit

I figured there must be dragons in Infinity, but it was worth a look :) unbounded isn't the most elegant looking, but IMO it's worth it.

@@ -31,6 +31,7 @@ const {taskGroups, taskNameToGroup} = require('./task-groups.js');
* @prop {LH.TraceEvent} event
* @prop {TaskNode[]} children
* @prop {TaskNode|undefined} parent
* @prop {boolean} unbounded
Copy link
Member

Choose a reason for hiding this comment

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

maybe put a note on this one to identify what it means?

const invalidEventSets = [
[
// TaskA overlaps with TaskB, X first
{ph: 'X', name: 'TaskA', pid, tid, ts: baseTs, dur: 100e3, args},
{ph: 'B', name: 'TaskB', pid, tid, ts: baseTs + 5e3, args},
{ph: 'E', name: 'TaskB', pid, tid, ts: baseTs + 115e3, args},
{ph: 'I', name: 'MarkerToPushOutTraceEnd', pid, tid, ts: baseTs + 200e3, args},
Copy link
Member

Choose a reason for hiding this comment

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

alright Infinity has it's own set of problems which is why I avoided it to begin with, so introduced an unbounded boolean to deal with this. LMK if you think it's worth the tradeoff in the latest commit

I figured there must be dragons in Infinity, but it was worth a look :) unbounded isn't the most elegant looking, but IMO it's worth it.

Copy link
Member

@brendankenny brendankenny left a comment

Choose a reason for hiding this comment

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

🔁LGTM

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants