[RPP] Add AsyncCallStacksHandler

The handler will generalize async JS calls in the perf panel. Its output
will be the source for the InitiatorHandler's JS scheduling
relationships, so that they don't need to be hardcoded as they are
currently.

The output of this handler will also be the source for async call
stacks that will be shown in the details of JS entries (ProfileCalls)
but this require some reworking on it, which will happen in follow up
CLs.

Bug: 381391955
Change-Id: If1b3a845dccf35bbfd6ae2aa06e7baf4a282d5e0
Reviewed-on: https://chromium-review.googlesource.com/c/devtools/devtools-frontend/+/6055479
Reviewed-by: Jack Franklin <[email protected]>
Commit-Queue: Andres Olivares <[email protected]>

Author: and-oli

config/gni/devtools_grd_files.gni

@@ -1051,6 +1051,7 @@ grd_files_debug_sources = [
   "front_end/models/trace/extras/TraceTree.js",
   "front_end/models/trace/extras/URLForEntry.js",
   "front_end/models/trace/handlers/AnimationHandler.js",
+  "front_end/models/trace/handlers/AsyncCallStacksHandler.js",
   "front_end/models/trace/handlers/AuctionWorkletsHandler.js",
   "front_end/models/trace/handlers/ExtensionTraceDataHandler.js",
   "front_end/models/trace/handlers/FlowsHandler.js",

front_end/models/trace/handlers/AsyncCallStacksHandler.test.ts

@@ -0,0 +1,123 @@
+// Copyright 2024 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+import {
+  makeCompleteEvent,
+  makeFlowEvents,
+  makeProfileCall,
+} from '../../../testing/TraceHelpers.js';
+import * as Trace from '../trace.js';
+const cat = 'mewtwo';
+const pid = 1;
+const tid = 1;
+async function buildAsyncCallStacksHandlerData(events: Trace.Types.Events.Event[]):
+    Promise<ReturnType<typeof Trace.Handlers.ModelHandlers.AsyncCallStacks.data>> {
+  Trace.Handlers.ModelHandlers.Renderer.reset();
+  Trace.Handlers.ModelHandlers.Flows.reset();
+  Trace.Handlers.ModelHandlers.Flows.reset();
+  for (const event of events) {
+    Trace.Handlers.ModelHandlers.Renderer.handleEvent(event);
+    Trace.Handlers.ModelHandlers.Flows.handleEvent(event);
+  }
+  await Trace.Handlers.ModelHandlers.Renderer.finalize();
+  await Trace.Handlers.ModelHandlers.Flows.finalize();
+  await Trace.Handlers.ModelHandlers.AsyncCallStacks.finalize();
+  return Trace.Handlers.ModelHandlers.AsyncCallStacks.data();
+}
+describe('AsyncCallStacksHandler', function() {
+  describe('Resolving JS task schedulers to task run entrypoints', function() {
+    it('associates a JS task scheduler profile call with the corresponding task run entry point', async function() {
+      const jsTaskScheduler = makeProfileCall('setTimeout', 0, 50, pid, tid);
+      const asyncTaskScheduled =
+          makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_SCHEDULED, 0, 0, cat, pid, tid);
+
+      const asyncTaskRun = makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_RUN, 60, 100, cat, tid, pid);
+      const jsTaskRunEntryPoint = makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 70, 20, cat, tid, pid);
+
+      const flowEvents = makeFlowEvents([asyncTaskScheduled, asyncTaskRun]);
+      const rendererEvents = [jsTaskScheduler, asyncTaskScheduled, asyncTaskRun, jsTaskRunEntryPoint];
+      const allEvents = [...rendererEvents, ...flowEvents];
+
+      const asyncCallStacksData = await buildAsyncCallStacksHandlerData(allEvents);
+      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoints?.length, 1);
+      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+    });
+
+    it('uses the nearest profile call ancestor of a debuggerTaskScheduled as JS task scheduler', async function() {
+      // Three profile call ancestors to the debuggerTaskScheduled event.
+      // Test the one closest to the debuggerTaskScheduled in the tree
+      // is picked.
+      const foo = makeProfileCall('foo', 0, 50, pid, tid);
+      const bar = makeProfileCall('bar', 0, 40, pid, tid);
+      const jsTaskScheduler = makeProfileCall('setTimeout', 0, 30, pid, tid);
+      const asyncTaskScheduled =
+          makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_SCHEDULED, 0, 0, cat, pid, tid);
+
+      const asyncTaskRun = makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_RUN, 60, 100, cat, tid, pid);
+      const jsTaskRunEntryPoint = makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 70, 20, cat, tid, pid);
+
+      const flowEvents = makeFlowEvents([asyncTaskScheduled, asyncTaskRun]);
+      const rendererEvents = [foo, bar, jsTaskScheduler, asyncTaskScheduled, asyncTaskRun, jsTaskRunEntryPoint];
+      const allEvents = [...rendererEvents, ...flowEvents];
+
+      const asyncCallStacksData = await buildAsyncCallStacksHandlerData(allEvents);
+      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoints?.length, 1);
+      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+    });
+
+    it('uses the nearest JS entry point descendant of a debuggerTaskRun as async task run', async function() {
+      const jsTaskScheduler = makeProfileCall('setTimeout', 0, 30, pid, tid);
+      const asyncTaskScheduled =
+          makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_SCHEDULED, 0, 0, cat, pid, tid);
+
+      const asyncTaskRun = makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_RUN, 60, 100, cat, tid, pid);
+
+      // Two JS entry points belonging to the same subtree are
+      // descendants to the debuggerTaskRun event. Test the one closest
+      // to the debuggerTaskRun in the global tree is picked.
+      const jsTaskRunEntryPoint = makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 70, 20, cat, tid, pid);
+      const secondFakeEntryPoint = makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 71, 10, cat, tid, pid);
+
+      const flowEvents = makeFlowEvents([asyncTaskScheduled, asyncTaskRun]);
+      const rendererEvents =
+          [jsTaskScheduler, asyncTaskScheduled, asyncTaskRun, jsTaskRunEntryPoint, secondFakeEntryPoint];
+      const allEvents = [...rendererEvents, ...flowEvents];
+
+      const asyncCallStacksData = await buildAsyncCallStacksHandlerData(allEvents);
+      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoints?.length, 1);
+      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+    });
+    it('returns multiple JS entry point descendants of a debuggerTaskRun when they are not in the same subtree',
+       async function() {
+         const jsTaskScheduler = makeProfileCall('setTimeout', 0, 30, pid, tid);
+         const asyncTaskScheduled =
+             makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_SCHEDULED, 0, 0, cat, pid, tid);
+
+         const asyncTaskRun =
+             makeCompleteEvent(Trace.Types.Events.Name.DEBUGGER_ASYNC_TASK_RUN, 60, 100, cat, tid, pid);
+
+         // Two JS entry points belonging to different subtrees are
+         // descendants to the debuggerTaskRun event. Test both are
+         // used.
+         const firstJSTaskRunEntryPoint =
+             makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 70, 20, cat, tid, pid);
+         const secondJSTaskRunEntryPoint =
+             makeCompleteEvent(Trace.Types.Events.Name.FUNCTION_CALL, 90, 10, cat, tid, pid);
+
+         const flowEvents = makeFlowEvents([asyncTaskScheduled, asyncTaskRun]);
+         const rendererEvents =
+             [jsTaskScheduler, asyncTaskScheduled, asyncTaskRun, firstJSTaskRunEntryPoint, secondJSTaskRunEntryPoint];
+         const allEvents = [...rendererEvents, ...flowEvents];
+
+         const asyncCallStacksData = await buildAsyncCallStacksHandlerData(allEvents);
+         const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+         assert.strictEqual(testRunEntryPoints?.length, 2);
+         assert.strictEqual(testRunEntryPoints?.[0], firstJSTaskRunEntryPoint);
+         assert.strictEqual(testRunEntryPoints?.[1], secondJSTaskRunEntryPoint);
+       });
+  });
+});

front_end/models/trace/handlers/AsyncCallStacksHandler.ts

@@ -0,0 +1,135 @@
+// Copyright 2024 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+import type * as Helpers from '../helpers/helpers.js';
+import * as Types from '../types/types.js';
+
+import {data as flowsHandlerData} from './FlowsHandler.js';
+import {data as rendererHandlerData} from './RendererHandler.js';
+
+const schedulerToRunEntryPoints: Map<Types.Events.SyntheticProfileCall, Types.Events.Event[]> = new Map();
+
+export function reset(): void {
+  schedulerToRunEntryPoints.clear();
+}
+
+export function handleEvent(_: Types.Events.Event): void {
+}
+
+export async function finalize(): Promise<void> {
+  const {flows} = flowsHandlerData();
+  const {entryToNode} = rendererHandlerData();
+  // Process async task flows
+  for (const flow of flows) {
+    const asyncTaskScheduled = flow.at(0);
+    if (!asyncTaskScheduled || !Types.Events.isDebuggerAsyncTaskScheduled(asyncTaskScheduled)) {
+      continue;
+    }
+    const asyncTaskRun = flow.at(1);
+    if (!asyncTaskRun || !Types.Events.isDebuggerAsyncTaskRun(asyncTaskRun)) {
+      // Unexpected flow shape, ignore.
+      continue;
+    }
+    const asyncCaller = findNearestProfileCallAncestor(asyncTaskScheduled, entryToNode);
+    if (!asyncCaller) {
+      // Unexpected async call trace data shape, ignore.
+      continue;
+    }
+    const asyncEntryPoints = findNearestJsInvocationDescendants(asyncTaskRun, entryToNode);
+    if (!asyncEntryPoints) {
+      // Unexpected async call trace data shape, ignore.
+      continue;
+    }
+    schedulerToRunEntryPoints.set(asyncCaller, asyncEntryPoints);
+  }
+}
+/**
+ * Given a DebuggerAsyncTaskScheduled event, returns its closest
+ * ProfileCall ancestor, which represents the JS call that scheduled
+ * the async task.
+ */
+function findNearestProfileCallAncestor(
+    asyncTaskScheduled: Types.Events.DebuggerAsyncTaskScheduled,
+    entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>): Types.Events.SyntheticProfileCall|null {
+  let node = entryToNode.get(asyncTaskScheduled)?.parent;
+  while (node) {
+    if (Types.Events.isProfileCall(node.entry)) {
+      return node.entry;
+    }
+    node = node.parent;
+  }
+  return null;
+}
+/**
+ * Entrypoints to JS execution in the timeline. We ignore those starting
+ * with 'v8' because they aren't shown in the timeline, and ultimately
+ * this function's output results in "initiated" events, so ideally this
+ * returns events that end up in the flame chart.
+ */
+function acceptJSInvocationsPredicate(event: Types.Events.Event): event is Types.Events.Event {
+  return Types.Events.isJSInvocationEvent(event) && !event.name.startsWith('v8') && !event.name.startsWith('V8');
+}
+
+/**
+ * Given a DebuggerAsyncTaskRun event, returns its closest JS entry
+ * point descendants, which represent the task being scheduled.
+ *
+ * We return multiple entry points beacuse some of these are built
+ * from samples (like `consoleTask.run()` ). Because of limitations with
+ * sampling, multiple entry points can mistakenly be made from a single
+ * entry point, so we return all of them to ensure the async stack is
+ * in every event that applies.
+ */
+function findNearestJsInvocationDescendants(
+    asyncTaskRun: Types.Events.DebuggerAsyncTaskRun,
+    entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>): Types.Events.Event[] {
+  // Ignore descendants of other DebuggerAsyncTaskRuns since they
+  // are part of another async task and have to be handled separately
+  return findFirstDescendantsOfType(
+      asyncTaskRun, entryToNode, acceptJSInvocationsPredicate, Types.Events.isDebuggerAsyncTaskRun);
+}
+
+/**
+ * Given a root event returns all the top level descendants that meet a
+ * predicate condition (predicateAccept) while ignoring subtrees whose
+ * top event meets an ignore condition (predicateIgnore).
+ */
+function findFirstDescendantsOfType<T extends Types.Events.Event>(
+    root: Types.Events.Event, entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>,
+    predicateAccept: (event: Types.Events.Event) => event is T,
+    predicateIgnore: (event: Types.Events.Event) => boolean): T[] {
+  const node = entryToNode.get(root);
+  if (!node) {
+    return [];
+  }
+  const childrenGroups = [[...node.children]];
+  const firstDescendants = [];
+  for (let i = 0; i < childrenGroups.length; i++) {
+    const siblings = childrenGroups[i];
+    for (let j = 0; j < siblings.length; j++) {
+      const node = siblings[j];
+      if (predicateAccept(node.entry)) {
+        firstDescendants.push(node.entry);
+      } else if (!predicateIgnore(node.entry)) {
+        childrenGroups.push([...node.children]);
+      }
+    }
+  }
+  return firstDescendants;
+}
+
+export function data(): {
+  // Given a profile call, returns the JS entrypoints it scheduled (if any).
+  // For example, given a setTimeout call, returns the JS entry point
+  // trace event for the timeout callback run event (usually a
+  // FunctionCall event).
+  schedulerToRunEntryPoints: Map<Types.Events.SyntheticProfileCall, Types.Events.Event[]>,
+} {
+  return {
+    schedulerToRunEntryPoints,
+  };
+}
+
+export function deps(): ['Renderer', 'Flows'] {
+  return ['Renderer', 'Flows'];
+}

front_end/models/trace/handlers/BUILD.gn

@@ -10,6 +10,7 @@ import("../../visibility.gni")
 devtools_module("handlers") {
   sources = [
     "AnimationHandler.ts",
+    "AsyncCallStacksHandler.ts",
     "AuctionWorkletsHandler.ts",
     "ExtensionTraceDataHandler.ts",
     "FlowsHandler.ts",
@@ -66,6 +67,7 @@ ts_library("unittests") {
 
   sources = [
     "AnimationHandler.test.ts",
+    "AsyncCallStacksHandler.test.ts",
     "AuctionWorkletsHandler.test.ts",
     "ExtensionTraceDataHandler.test.ts",
     "FlowsHandler.test.ts",

front_end/models/trace/handlers/FlowsHandler.test.ts

@@ -9,13 +9,13 @@ import {
 import * as Trace from '../trace.js';
 
 async function getFlowsHandlerData(events: Trace.Types.Events.Event[]):
-    Promise<ReturnType<typeof Trace.Handlers.ModelHandlers.FlowsHandler.data>> {
-  Trace.Handlers.ModelHandlers.FlowsHandler.reset();
+    Promise<ReturnType<typeof Trace.Handlers.ModelHandlers.Flows.data>> {
+  Trace.Handlers.ModelHandlers.Flows.reset();
   for (const event of events) {
-    Trace.Handlers.ModelHandlers.FlowsHandler.handleEvent(event);
+    Trace.Handlers.ModelHandlers.Flows.handleEvent(event);
   }
-  await Trace.Handlers.ModelHandlers.FlowsHandler.finalize();
-  return Trace.Handlers.ModelHandlers.FlowsHandler.data();
+  await Trace.Handlers.ModelHandlers.Flows.finalize();
+  return Trace.Handlers.ModelHandlers.Flows.data();
 }
 const cat = 'mewtwo';
 const pid = 0;

front_end/models/trace/handlers/InitiatorsHandler.test.ts

@@ -194,10 +194,10 @@ describe('InitiatorsHandler', () => {
   it('for a PostMessage Handler event the initiator is the PostMessage Dispatch event', async function() {
     const traceEvents = await TraceLoader.rawEvents(this, 'postmessage-initiators.json.gz');
     for (const event of traceEvents) {
-      Trace.Handlers.ModelHandlers.FlowsHandler.handleEvent(event);
+      Trace.Handlers.ModelHandlers.Flows.handleEvent(event);
       Trace.Handlers.ModelHandlers.Initiators.handleEvent(event);
     }
-    await Trace.Handlers.ModelHandlers.FlowsHandler.finalize();
+    await Trace.Handlers.ModelHandlers.Flows.finalize();
     await Trace.Handlers.ModelHandlers.Initiators.finalize();
     const data = Trace.Handlers.ModelHandlers.Initiators.data();
 

front_end/models/trace/handlers/InitiatorsHandler.ts

@@ -188,6 +188,6 @@ export function data(): InitiatorsData {
   };
 }
 
-export function deps(): ['FlowsHandler'] {
-  return ['FlowsHandler'];
+export function deps(): ['Flows'] {
+  return ['Flows'];
 }

front_end/models/trace/handlers/ModelHandlers.ts

@@ -3,9 +3,10 @@
 // found in the LICENSE file.
 
 export * as Animations from './AnimationHandler.js';
+export * as AsyncCallStacks from './AsyncCallStacksHandler.js';
 export * as AuctionWorklets from './AuctionWorkletsHandler.js';
 export * as ExtensionTraceData from './ExtensionTraceDataHandler.js';
-export * as FlowsHandler from './FlowsHandler.js';
+export * as Flows from './FlowsHandler.js';
 export * as Frames from './FramesHandler.js';
 export * as GPU from './GPUHandler.js';
 export * as ImagePainting from './ImagePaintingHandler.js';

front_end/models/trace/types/TraceEvents.ts

@@ -1832,6 +1832,22 @@ export function isInvalidateLayout(event: Event): event is InvalidateLayout {
   return event.name === Name.INVALIDATE_LAYOUT;
 }
 
+export interface DebuggerAsyncTaskScheduled extends Event {
+  name: Name.DEBUGGER_ASYNC_TASK_SCHEDULED;
+}
+
+export function isDebuggerAsyncTaskScheduled(event: Event): event is DebuggerAsyncTaskScheduled {
+  return event.name === Name.DEBUGGER_ASYNC_TASK_SCHEDULED;
+}
+
+export interface DebuggerAsyncTaskRun extends Event {
+  name: Name.DEBUGGER_ASYNC_TASK_RUN;
+}
+
+export function isDebuggerAsyncTaskRun(event: Event): event is DebuggerAsyncTaskRun {
+  return event.name === Name.DEBUGGER_ASYNC_TASK_RUN;
+}
+
 class ProfileIdTag {
   readonly #profileIdTag: (symbol|undefined);
 }
@@ -2635,7 +2651,8 @@ export function isAbortPostTaskCallback(event: Event): event is RunPostTaskCallb
 /**
  * Generally, before JS is executed, a trace event is dispatched that
  * parents the JS calls. These we call "invocation" events. This
- * function determines if an event is one of such.
+ * function determines if an event is one of such. Note: these are also
+ * commonly referred to as "JS entry points".
  */
 export function isJSInvocationEvent(event: Event): boolean {
   switch (event.name) {
@@ -2740,6 +2757,8 @@ export const enum Name {
   SCHEDULE_POST_TASK_CALLBACK = 'SchedulePostTaskCallback',
   RUN_POST_TASK_CALLBACK = 'RunPostTaskCallback',
   ABORT_POST_TASK_CALLBACK = 'AbortPostTaskCallback',
+  DEBUGGER_ASYNC_TASK_RUN = 'v8::Debugger::AsyncTaskRun',
+  DEBUGGER_ASYNC_TASK_SCHEDULED = 'v8::Debugger::AsyncTaskScheduled',
 
   /* Gc */
   GC = 'GCEvent',

front_end/panels/timeline/TimelineController.ts

@@ -97,6 +97,7 @@ export class TimelineController implements Trace.TracingManager.TracingManagerCl
       disabledByDefault('devtools.timeline.frame'),
       disabledByDefault('devtools.timeline.stack'),
       disabledByDefault('v8.compile'),
+      disabledByDefault('v8.inspector'),
       disabledByDefault('v8.cpu_profiler.hires'),
       disabledByDefault('lighthouse'),
       'v8.execute',