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: support traces with TracingStartedInBrowser event #5271

Merged
merged 5 commits into from
Jun 4, 2018
Merged
Show file tree
Hide file tree
Changes from 1 commit
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
39 changes: 30 additions & 9 deletions lighthouse-core/gather/computed/trace-of-tab.js
Original file line number Diff line number Diff line change
Expand Up @@ -42,21 +42,42 @@ class TraceOfTab extends ComputedArtifact {
// *must* be stable to keep events correctly nested.
/** @type Array<LH.TraceEvent> */
const keyEvents = trace.traceEvents
.filter(e => {
return e.cat.includes('blink.user_timing') ||
.filter(e =>
e.cat.includes('blink.user_timing') ||
Copy link
Member

Choose a reason for hiding this comment

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

generally for multi-line arrow function we keep the curly braces/return for clarity. Any reason to drop it here?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

done

e.cat.includes('loading') ||
e.cat.includes('devtools.timeline') ||
e.name === 'TracingStartedInPage';
Copy link
Member

Choose a reason for hiding this comment

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

think you don't want to filter this out to support the legacy case? Or in the fallback case need to search for the first TracingStartedInPage in the original trace.traceEvents

Copy link
Member

Choose a reason for hiding this comment

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

also, does the filter now need to let through e.name === 'TracingStartedInBrowser' events?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Both TracingStartedInPage and TracingStartedInBrowser are in devtools.timeline category which is already allowed.

Copy link
Collaborator

Choose a reason for hiding this comment

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

It seems like it was in toplevel once upon a time based on the fixture change below?

my traces from ~December have it in disabled-by-default-devtools.timeline so I guess it's a question of how far back we want to go

Copy link
Contributor Author

Choose a reason for hiding this comment

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

AFAICT TracingStartedInPage was introduced 4 years ago with devtools.timeline category. See https://codereview.chromium.org/254613002/diff/90001/Source/core/inspector/InspectorTracingAgent.cpp
I wonder where the traces with it being in toplevel come from?

Copy link
Collaborator

Choose a reason for hiding this comment

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

Hm, no clue then 🤷‍♂️ 4 years is plenty good enough for me 😆

})
e.cat === '__metadata')
// @ts-ignore - stableSort added to Array by WebInspector.
.stableSort((event0, event1) => event0.ts - event1.ts);

// The first TracingStartedInPage in the trace is definitely our renderer thread of interest
// Beware: the tracingStartedInPage event can appear slightly after a navigationStart
const startedInPageEvt = keyEvents.find(e => e.name === 'TracingStartedInPage');
// Find out the inspected page frame.
/** @type {LH.TraceEvent|undefined} */
let startedInPageEvt;
const startedInBrowserEvt = keyEvents.find(e => e.name === 'TracingStartedInBrowser');
if (startedInBrowserEvt && startedInBrowserEvt.args.data &&
startedInBrowserEvt.args.data.persistentIds) {
Copy link
Member

Choose a reason for hiding this comment

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

can you add a comment about why persistentIds is significant?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I talked to dgozman, it was added to ensure this is a new version of the event that carries frames. I think we can just check for frames field being there.

const mainFrame = (startedInBrowserEvt.args.data.frames || []).find(frame => !frame.parent);
const pid = mainFrame && mainFrame.processId;
const threadNameEvt = keyEvents.find(e => e.pid === pid && e.ph === 'M' &&
e.cat === '__metadata' && e.name === 'thread_name' &&
// @ts-ignore - property chain exists for 'thread_name' event.
e.args.name === 'CrRendererMain');
Copy link
Member

Choose a reason for hiding this comment

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

since it's just a single level into args, add name?: string to args in externs.d.ts instead of @ts-ignore here?

Copy link
Collaborator

Choose a reason for hiding this comment

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

done

startedInPageEvt = mainFrame && threadNameEvt ?
Object.assign({}, startedInBrowserEvt, {
pid, tid: threadNameEvt.tid, name: 'TracingStartedInPage',
args: {data: {page: mainFrame.frame}}}) :
undefined;
}
// Support legacy browser versions that do not emit TracingStartedInBrowser event.
if (!startedInPageEvt) {
// The first TracingStartedInPage in the trace is definitely our renderer thread of interest
// Beware: the tracingStartedInPage event can appear slightly after a navigationStart
startedInPageEvt = keyEvents.find(e => e.name === 'TracingStartedInPage');
}
if (!startedInPageEvt) throw new LHError(LHError.errors.NO_TRACING_STARTED);
// @ts-ignore - property chain exists for 'TracingStartedInPage' event.
const frameId = startedInPageEvt.args.data.page;
Copy link
Member

Choose a reason for hiding this comment

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

if the casts are annoying, could also do something like

 /** @type {LH.TraceEvent|undefined} */
let possibleStartedInPageEvt;
...

above, and then here

const startedInPageEvt = possibleStartedInPageEvt;

because the compiler will know that possibleStartedInPageEvt is definitely defined at this point, the type for startedInPageEvt will be inferred correctly as LH.TraceEvent, and then it won't need any casts below this.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I considered that, but I didn't want to introduce more code to workaround compiler issues. I'm fine with casts.


// Filter to just events matching the frame ID for sanity
const frameEvents = keyEvents.filter(e => e.args.frame === frameId);

Expand Down Expand Up @@ -106,12 +127,12 @@ class TraceOfTab extends ComputedArtifact {
// stable-sort events to keep them correctly nested.
/** @type Array<LH.TraceEvent> */
const processEvents = trace.traceEvents
.filter(e => e.pid === startedInPageEvt.pid)
.filter(e => e.pid === /** @type {LH.TraceEvent} */ (startedInPageEvt).pid)
// @ts-ignore - stableSort added to Array by WebInspector.
.stableSort((event0, event1) => event0.ts - event1.ts);

const mainThreadEvents = processEvents
.filter(e => e.tid === startedInPageEvt.tid);
.filter(e => e.tid === /** @type {LH.TraceEvent} */ (startedInPageEvt).tid);

const traceEnd = trace.traceEvents.reduce((max, evt) => {
return max.ts > evt.ts ? max : evt;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@
"tid": 1295,
"ts": 900000000000,
"ph": "X",
"cat": "toplevel",
"cat": "devtools.timeline",
"name": "TracingStartedInPage",
"args": {
"data": {
Expand Down
50 changes: 50 additions & 0 deletions lighthouse-core/test/gather/computed/trace-of-tab-test.js
Original file line number Diff line number Diff line change
Expand Up @@ -112,6 +112,56 @@ describe('Trace of Tab computed artifact:', () => {
assert.equal(trace.firstMeaningfulPaintEvt, undefined, 'bad fmp');
});

it('handles traces with TracingStartedInBrowser events', async () => {
const tracingStartedInBrowserTrace = {
'traceEvents': [{
'pid': 69850,
'tid': 69850,
'ts': 2193564729582,
'ph': 'I',
'cat': 'disabled-by-default-devtools.timeline',
'name': 'TracingStartedInBrowser',
'args': {'data': {
'frameTreeNodeId': 1,
'persistentIds': true,
'frames': [{
'frame': 'B192D1F3355A6F961EC8F0B01623C1FB',
'url': 'http://www.example.com/',
'name': '',
'processId': 69920,
}],
}},
'tts': 1085165,
's': 't',
}, {
'pid': 69920,
'tid': 1,
'ts': 2193564790059,
'ph': 'R',
'cat': 'blink.user_timing',
'name': 'navigationStart',
'args': {
'frame': 'B192D1F3355A6F961EC8F0B01623C1FB',
'data': {
'documentLoaderURL': 'http://www.example.com/',
'isLoadingMainFrame': true,
},
},
'tts': 141371,
}, {
'pid': 69920,
'tid': 1,
'ts': 0,
'ph': 'M',
'cat': '__metadata',
'name': 'thread_name',
'args': {'name': 'CrRendererMain'},
}]};
const trace = await traceOfTab.compute_(tracingStartedInBrowserTrace);
assert.equal(trace.startedInPageEvt.ts, 2193564729582);
Copy link
Collaborator

Choose a reason for hiding this comment

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

want to assert the navStart is found and in the trace.mainThreadEvents since I assume that's what the thread_name addition was for?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done

assert.equal(trace.navigationStartEvt.ts, 2193564790059);
});

it('stably sorts events', async () => {
const traceJson = fs.readFileSync(__dirname +
'/../../fixtures/traces/tracingstarted-after-navstart.json', 'utf8');
Expand Down
6 changes: 6 additions & 0 deletions typings/externs.d.ts
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,12 @@ declare global {
cat: string;
args: {
data?: {
persistentIds?: boolean;
frames?: {
frame: string;
parent?: string;
processId?: number;
}[];
page?: string;
readyState?: number;
requestId?: string;
Expand Down