Fix ProfileCall nodes being excluded
The filters we apply when generating the tables were incorrectly
removing any ProfileCall events due to them not having a matching record
type. To fix this, we map their RecordType to the RecordType.JSFrame
type, as they are broadly equivalent.
Long term we need to figure out what to do with this RecordType, and how
to reconcile it with the new engine, but this is a fix that enables the
bottom up chart to be correctly populated.
Bug: 1488757
Change-Id: Ic394371e683251c6c77699210bcd70a62be16e3b
Reviewed-on: https://chromium-review.googlesource.com/c/devtools/devtools-frontend/+/4909533
Commit-Queue: Jack Franklin <[email protected]>
Reviewed-by: Andres Olivares <[email protected]>
diff --git a/front_end/models/timeline_model/TimelineModelFilter.ts b/front_end/models/timeline_model/TimelineModelFilter.ts
index 5b3f46b..dede2e04 100644
--- a/front_end/models/timeline_model/TimelineModelFilter.ts
+++ b/front_end/models/timeline_model/TimelineModelFilter.ts
@@ -30,6 +30,12 @@
if (TraceEngine.Legacy.eventHasCategory(event, TimelineModelImpl.Category.UserTiming)) {
return RecordType.UserTiming;
}
+ if (TraceEngine.Legacy.eventIsFromNewEngine(event) && TraceEngine.Types.TraceEvents.isProfileCall(event)) {
+ // ProfileCalls from the new engine are broadly equivalent to JSFrames in
+ // the old engine, so map them as such, as we do not have a RecordType to
+ // represent ProfileCalls.
+ return RecordType.JSFrame;
+ }
return event.name as RecordType;
}
}
diff --git a/front_end/models/timeline_model/TimelineProfileTree.ts b/front_end/models/timeline_model/TimelineProfileTree.ts
index 8c03ea2..d9c5806 100644
--- a/front_end/models/timeline_model/TimelineProfileTree.ts
+++ b/front_end/models/timeline_model/TimelineProfileTree.ts
@@ -105,7 +105,7 @@
const startTime = root.startTime;
const endTime = root.endTime;
const instantEventCallback = root.doNotAggregate ? onInstantEvent : undefined;
- const eventIdCallback = root.doNotAggregate ? undefined : _eventId;
+ const eventIdCallback = root.doNotAggregate ? undefined : generateEventID;
const eventGroupIdCallback = root.getEventGroupIdCallback();
let depth = 0;
// The amount of ancestors found to match this node's ancestors
@@ -346,7 +346,7 @@
const duration = actualEndTime - Math.max(currentStartTime, startTime);
selfTimeStack[selfTimeStack.length - 1] -= duration;
selfTimeStack.push(duration);
- const id = _eventId(e);
+ const id = generateEventID(e);
const noNodeOnStack = !totalTimeById.has(id);
if (noNodeOnStack) {
totalTimeById.set(id, duration);
@@ -355,7 +355,7 @@
}
function onEndEvent(e: TraceEngine.Legacy.CompatibleTraceEvent): void {
- const id = _eventId(e);
+ const id = generateEventID(e);
let node = nodeById.get(id);
if (!node) {
node = new BottomUpNode(root, id, e, false, root);
@@ -476,7 +476,7 @@
}
selfTimeStack[selfTimeStack.length - 1] -= duration;
selfTimeStack.push(duration);
- const id = _eventId(e);
+ const id = generateEventID(e);
eventIdStack.push(id);
eventStack.push(e);
}
@@ -551,11 +551,19 @@
return EventOnTimelineData.forEvent(event).topFrame();
}
-// eslint-disable-next-line @typescript-eslint/naming-convention
-export function _eventId(event: TraceEngine.Legacy.CompatibleTraceEvent): string {
+export function generateEventID(event: TraceEngine.Legacy.CompatibleTraceEvent): string {
+ if (TraceEngine.Legacy.eventIsFromNewEngine(event) && TraceEngine.Types.TraceEvents.isProfileCall(event)) {
+ const name = TimelineJSProfileProcessor.isNativeRuntimeFrame(event.callFrame) ?
+ TimelineJSProfileProcessor.nativeGroup(event.callFrame.functionName) :
+ event.callFrame.functionName;
+ const location = event.callFrame.scriptId || event.callFrame.url || '';
+ return `f:${name}@${location}`;
+ }
+
if (event.name === RecordType.TimeStamp) {
return `${event.name}:${event.args.data.message}`;
}
+
if (!TimelineModelImpl.isJsFrameEvent(event)) {
return event.name;
}
diff --git a/test/unittests/fixtures/traces/BUILD.gn b/test/unittests/fixtures/traces/BUILD.gn
index 319065d0..586c511 100644
--- a/test/unittests/fixtures/traces/BUILD.gn
+++ b/test/unittests/fixtures/traces/BUILD.gn
@@ -29,6 +29,7 @@
"lcp-images.json.gz",
"lcp-web-font.json.gz",
"load-simple.json.gz",
+ "mainWasm_profile.json.gz",
"many-requests.json.gz",
"missing-process-data.json.gz",
"missing-tracing-start.json.gz",
diff --git a/test/unittests/fixtures/traces/mainWasm_profile.json.gz b/test/unittests/fixtures/traces/mainWasm_profile.json.gz
new file mode 100644
index 0000000..b2e6283
--- /dev/null
+++ b/test/unittests/fixtures/traces/mainWasm_profile.json.gz
Binary files differ
diff --git a/test/unittests/front_end/models/timeline_model/TimelineProfileTree_test.ts b/test/unittests/front_end/models/timeline_model/TimelineProfileTree_test.ts
index 118c28f..3dde450 100644
--- a/test/unittests/front_end/models/timeline_model/TimelineProfileTree_test.ts
+++ b/test/unittests/front_end/models/timeline_model/TimelineProfileTree_test.ts
@@ -6,9 +6,12 @@
import * as TimelineModel from '../../../../../front_end/models/timeline_model/timeline_model.js';
import * as TraceEngine from '../../../../../front_end/models/trace/trace.js';
-import {makeCompleteEvent} from '../../helpers/TraceHelpers.js';
+import * as Timeline from '../../../../../front_end/panels/timeline/timeline.js';
+import {describeWithEnvironment} from '../../helpers/EnvironmentHelpers.js';
+import {getMainThread, makeCompleteEvent} from '../../helpers/TraceHelpers.js';
+import {TraceLoader} from '../../helpers/TraceLoader.js';
-describe('TimelineProfileTree', () => {
+describeWithEnvironment('TimelineProfileTree', () => {
describe('TopDownRootNode', () => {
it('builds the root node and its children properly from an event tree', () => {
// This builds the following tree:
@@ -32,6 +35,7 @@
assert.strictEqual(nodesIterator.next().value.event, eventB);
assert.strictEqual(nodesIterator.next().value.event, eventC);
});
+
it('builds a top-down tree from an event tree with multiple levels 1', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -65,6 +69,7 @@
assert.strictEqual(nodeAChildIterator.next().value.event, eventC);
assert.strictEqual(nodeAChildIterator.next().value.event, eventD);
});
+
it('builds a top-down tree from an event tree with multiple levels 2', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -98,6 +103,7 @@
assert.strictEqual(nodeBChildIterator.next().value.event, eventC);
assert.strictEqual(nodeBChildIterator.next().value.event, eventD);
});
+
it('calculates the self time for each node in an event tree correctly', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -149,6 +155,7 @@
assert.strictEqual(nodeE.selfTime, TraceEngine.Helpers.Timing.microSecondsToMilliseconds(eventE.dur));
});
});
+
describe('BottomUpRootNode', () => {
it('builds the root node and its children properly from an event tree', () => {
// This builds the following tree:
@@ -172,6 +179,7 @@
assert.strictEqual(nodesIterator.next().value.event, eventB);
assert.strictEqual(nodesIterator.next().value.event, eventC);
});
+
it('builds a bottom up tree from an event tree with multiple levels 1', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -223,6 +231,7 @@
const nodeBChildren = nodeB.children();
assert.strictEqual(nodeBChildren.size, 0);
});
+
it('builds a tree from an event tree with multiple levels 2', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -275,6 +284,7 @@
const nodeBChildren = nodeB.children();
assert.strictEqual(nodeBChildren.size, 0);
});
+
it('calculates the self time for each node in an event tree correctly', () => {
// This builds the following tree:
// |------------ROOT-----------|
@@ -318,5 +328,68 @@
const nodeBSelfTime = TraceEngine.Types.Timing.MicroSeconds(eventB.dur - eventC.dur - eventD.dur);
assert.strictEqual(nodeB.selfTime, TraceEngine.Helpers.Timing.microSecondsToMilliseconds(nodeBSelfTime));
});
+
+ it('correctly keeps ProfileCall nodes and uses them to build up the tree', async function() {
+ const models = await TraceLoader.allModels(this, 'mainWasm_profile.json.gz');
+ const mainThread = getMainThread(models.traceParsedData.Renderer);
+ const bounds = TraceEngine.Helpers.Timing.traceBoundsMilliseconds(models.traceParsedData.Meta.traceBounds);
+
+ // Replicate the filters as they would be when renderering in the actual panel.
+ const textFilter = new Timeline.TimelineFilters.TimelineRegExp();
+ const modelFilters = [
+ Timeline.TimelineUIUtils.TimelineUIUtils.visibleEventsFilter(),
+ new TimelineModel.TimelineModelFilter.ExclusiveNameFilter(['RunTask']),
+ ];
+ const root = new TimelineModel.TimelineProfileTree.BottomUpRootNode(
+ mainThread.entries, textFilter, modelFilters, bounds.min, bounds.max, null);
+ const rootChildren = root.children();
+ const values = Array.from(rootChildren.values());
+ // Find the list of profile calls that have been calculated as the top level rows in the Bottom Up table.
+ const profileCalls = values
+ .filter(
+ node => TraceEngine.Legacy.eventIsFromNewEngine(node.event) &&
+ TraceEngine.Types.TraceEvents.isProfileCall(node.event) &&
+ node.event.callFrame.functionName.length > 0)
+ .map(n => n.event as TraceEngine.Types.TraceEvents.TraceEventSyntheticProfileCall);
+ const functionNames = profileCalls.map(entry => entry.callFrame.functionName);
+ assert.deepEqual(
+ functionNames, ['fetch', 'getTime', 'wasm-to-js::l-imports.getTime', 'mainWasm', 'js-to-wasm::i']);
+ });
+ });
+
+ describe('generateEventID', () => {
+ it('generates the right ID for new engine profile call events', async function() {
+ const models = await TraceLoader.allModels(this, 'react-hello-world.json.gz');
+ const mainThread = getMainThread(models.traceParsedData.Renderer);
+ const profileCallEntry = mainThread.entries.find(entry => {
+ return TraceEngine.Types.TraceEvents.isProfileCall(entry) &&
+ entry.callFrame.functionName === 'performConcurrentWorkOnRoot';
+ });
+ if (!profileCallEntry) {
+ throw new Error('Could not find a profile call');
+ }
+ const eventId = TimelineModel.TimelineProfileTree.generateEventID(profileCallEntry);
+ assert.strictEqual(eventId, 'f:performConcurrentWorkOnRoot@7');
+ });
+
+ it('generates the right ID for new engine native profile call events', async function() {
+ const traceParsedData = await TraceLoader.traceEngine(this, 'invalid-animation-events.json.gz', {
+ ...TraceEngine.Types.Configuration.DEFAULT,
+ experiments: {
+ ...TraceEngine.Types.Configuration.DEFAULT.experiments,
+ timelineV8RuntimeCallStats: true,
+ },
+ });
+
+ const mainThread = getMainThread(traceParsedData.Renderer);
+ const profileCallEntry = mainThread.entries.find(entry => {
+ return TraceEngine.Types.TraceEvents.isProfileCall(entry) && entry.callFrame.url === 'native V8Runtime';
+ });
+ if (!profileCallEntry) {
+ throw new Error('Could not find a profile call');
+ }
+ const eventId = TimelineModel.TimelineProfileTree.generateEventID(profileCallEntry);
+ assert.strictEqual(eventId, 'f:Compile@0');
+ });
});
});
