[RPP] Parse trace event for consoleTask.run

Recently, an event was added as an entrypoint of the task being run
with the console.createTask / run API [1]. This allows us to simplify
our parsing of async js tasks, because now all of these have a single
trace event entry point for the scheduled task. Before, for consoleTask.run we had to assign all the top "run" profile calls as the scheduled task, because of limitations with sampling it's possible that multiple profile calls are made from a single call to the API. With tracing we don't have this limitation, yielding a more simple code.

[1] https://chromium-review.googlesource.com/c/v8/v8/+/6054136

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

Author: and-oli

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

@@ -40,9 +40,8 @@ describe('AsyncJSCallsHandler', function() {
       const allEvents = [...rendererEvents, ...flowEvents];
 
       const asyncCallStacksData = await buildAsyncJSCallsHandlerData(allEvents);
-      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
-      assert.strictEqual(testRunEntryPoints?.length, 1);
-      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+      const testRunEntryPoint = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoint, jsTaskRunEntryPoint);
     });
 
     it('uses the nearest profile call ancestor of a debuggerTaskScheduled as JS task scheduler', async function() {
@@ -63,9 +62,8 @@ describe('AsyncJSCallsHandler', function() {
       const allEvents = [...rendererEvents, ...flowEvents];
 
       const asyncCallStacksData = await buildAsyncJSCallsHandlerData(allEvents);
-      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
-      assert.strictEqual(testRunEntryPoints?.length, 1);
-      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+      const testRunEntryPoint = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoint, jsTaskRunEntryPoint);
     });
 
     it('uses the nearest JS entry point descendant of a debuggerTaskRun as async task run', async function() {
@@ -87,38 +85,9 @@ describe('AsyncJSCallsHandler', function() {
       const allEvents = [...rendererEvents, ...flowEvents];
 
       const asyncCallStacksData = await buildAsyncJSCallsHandlerData(allEvents);
-      const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
-      assert.strictEqual(testRunEntryPoints?.length, 1);
-      assert.strictEqual(testRunEntryPoints?.[0], jsTaskRunEntryPoint);
+      const testRunEntryPoint = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
+      assert.strictEqual(testRunEntryPoint, 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 buildAsyncJSCallsHandlerData(allEvents);
-         const testRunEntryPoints = asyncCallStacksData.schedulerToRunEntryPoints.get(jsTaskScheduler);
-         assert.strictEqual(testRunEntryPoints?.length, 2);
-         assert.strictEqual(testRunEntryPoints?.[0], firstJSTaskRunEntryPoint);
-         assert.strictEqual(testRunEntryPoints?.[1], secondJSTaskRunEntryPoint);
-       });
   });
   describe('Resolving async JS tasks to schedulers', function() {
     it('associates an async JS task to its scheduler', async function() {

front_end/models/trace/handlers/AsyncJSCallsHandler.ts

@@ -7,7 +7,7 @@ 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();
+const schedulerToRunEntryPoints: Map<Types.Events.SyntheticProfileCall, Types.Events.Event> = new Map();
 const asyncCallToScheduler:
     Map<Types.Events.SyntheticProfileCall, {taskName: string, scheduler: Types.Events.SyntheticProfileCall}> =
         new Map();
@@ -40,14 +40,14 @@ export async function finalize(): Promise<void> {
       // Unexpected async call trace data shape, ignore.
       continue;
     }
-    const asyncEntryPoints = findFirstJsInvocationsForAsyncTaskRun(asyncTaskRun, entryToNode);
-    if (!asyncEntryPoints) {
+    const asyncEntryPoint = findFirstJsInvocationForAsyncTaskRun(asyncTaskRun, entryToNode);
+    if (!asyncEntryPoint) {
       // Unexpected async call trace data shape, ignore.
       continue;
     }
     // Set scheduler -> schedulee mapping.
     // The schedulee being the JS entrypoint
-    schedulerToRunEntryPoints.set(asyncCaller, asyncEntryPoints);
+    schedulerToRunEntryPoints.set(asyncCaller, asyncEntryPoint);
 
     // Set schedulee -> scheduler mapping.
     // The schedulees being the JS calls (instead of the entrypoints as
@@ -82,26 +82,23 @@ function findNearestProfileCallAncestor(
  * 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');
+  const eventIsConsoleRunTask = event.name === Types.Events.Name.V8_CONSOLE_RUN_TASK;
+  const eventIsV8EntryPoint = event.name.startsWith('v8') || event.name.startsWith('V8');
+  return Types.Events.isJSInvocationEvent(event) && (eventIsConsoleRunTask || !eventIsV8EntryPoint);
 }
 
 /**
  * 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.
+ * point descendant, which contains the task being scheduled.
  */
-function findFirstJsInvocationsForAsyncTaskRun(
+function findFirstJsInvocationForAsyncTaskRun(
     asyncTaskRun: Types.Events.DebuggerAsyncTaskRun,
-    entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>): Types.Events.Event[] {
+    entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>): Types.Events.Event|undefined {
   // 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);
+             asyncTaskRun, entryToNode, acceptJSInvocationsPredicate, Types.Events.isDebuggerAsyncTaskRun)
+      .at(0);
 }
 
 /**
@@ -137,7 +134,7 @@ function findFirstJSCallsForAsyncTaskRun(
 }
 
 /**
- * Given a root event returns all the top level descendants that meet a
+ * Given a root event returns all the first descendants that meet a
  * predicate condition (predicateAccept) while ignoring subtrees whose
  * top event meets an ignore condition (predicateIgnore).
  */
@@ -166,7 +163,7 @@ function findFirstDescendantsOfType<T extends Types.Events.Event>(
 }
 
 export function data(): {
-  // Given a profile call, returns the JS entrypoints it scheduled (if any).
+  // Given a profile call, returns the JS entrypoint 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).

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

@@ -139,16 +139,11 @@ describeWithEnvironment('InitiatorsHandler', () => {
     if (!schedulerFuntion) {
       throw new Error('Could not find scheduler function call');
     }
-    const taskRunCalls = parsedTrace.Renderer.allTraceEntries.filter(
-        e => Trace.Types.Events.isConsoleTaskRun(e) && e.ts > schedulerFuntion.ts);
-    if (!taskRunCalls!.length) {
-      throw new Error('Could not find task.run call');
-    }
-
-    assert.strictEqual(parsedTrace.Initiators.eventToInitiator.get(taskRunCalls[0]), schedulerFuntion);
-    assert.strictEqual(parsedTrace.Initiators.eventToInitiator.get(taskRunCalls[1]), schedulerFuntion);
-    assert.deepEqual(
-        parsedTrace.Initiators.initiatorToEvents.get(schedulerFuntion), [taskRunCalls[1], taskRunCalls[0]]);
+    const consoleRunTask = parsedTrace.Renderer.allTraceEntries.find(
+        e => Trace.Types.Events.isConsoleRunTask(e) && e.ts > schedulerFuntion.ts);
+    assert.exists(consoleRunTask);
+    assert.strictEqual(parsedTrace.Initiators.eventToInitiator.get(consoleRunTask), schedulerFuntion);
+    assert.deepEqual(parsedTrace.Initiators.initiatorToEvents.get(schedulerFuntion), [consoleRunTask]);
   });
 
   it('for a WebSocketSendHandshakeRequest the initiator is the WebSocketCreate event', async function() {

front_end/models/trace/handlers/InitiatorsHandler.ts

@@ -149,10 +149,8 @@ function createRelationshipsFromFlows(): void {
 
 function createRelationshipsFromAsyncJSCalls(): void {
   const asyncCallPairs = AsyncJSCallsHandlerData().schedulerToRunEntryPoints.entries();
-  for (const [asyncCaller, asyncCallees] of asyncCallPairs) {
-    for (const asyncCallee of asyncCallees) {
-      storeInitiator({event: asyncCallee, initiator: asyncCaller});
-    }
+  for (const [asyncCaller, asyncCallee] of asyncCallPairs) {
+    storeInitiator({event: asyncCallee, initiator: asyncCaller});
   }
 }
 

front_end/models/trace/types/TraceEvents.ts

@@ -2705,22 +2705,24 @@ export function isJSInvocationEvent(event: Event): boolean {
     case Name.EVALUATE_MODULE:
     case Name.EVENT_DISPATCH:
     case Name.V8_EXECUTE:
+    case Name.V8_CONSOLE_RUN_TASK:
       return true;
   }
   // Also consider any new v8 trace events. (eg 'V8.RunMicrotasks' and 'v8.run')
   if (event.name.startsWith('v8') || event.name.startsWith('V8')) {
     return true;
   }
-
-  if (isConsoleTaskRun(event)) {
+  if (isConsoleRunTask(event)) {
     return true;
   }
   return false;
 }
+export interface ConsoleRunTask extends Event {
+  name: Name.V8_CONSOLE_RUN_TASK;
+}
 
-export function isConsoleTaskRun(event: Event): boolean {
-  return isProfileCall(event) && event.callFrame.functionName === 'run' && event.callFrame.columnNumber === -1 &&
-      event.callFrame.lineNumber === -1;
+export function isConsoleRunTask(event: Event): event is ConsoleRunTask {
+  return event.name === Name.V8_CONSOLE_RUN_TASK;
 }
 
 export interface FlowEvent extends Event {
@@ -2805,6 +2807,7 @@ export const enum Name {
   CRYPTO_DO_VERIFY = 'DoVerify',
   CRYPTO_DO_VERIFY_REPLY = 'DoVerifyReply',
   V8_EXECUTE = 'V8.Execute',
+  V8_CONSOLE_RUN_TASK = 'V8Console::runTask',
   SCHEDULE_POST_TASK_CALLBACK = 'SchedulePostTaskCallback',
   RUN_POST_TASK_CALLBACK = 'RunPostTaskCallback',
   ABORT_POST_TASK_CALLBACK = 'AbortPostTaskCallback',

front_end/panels/timeline/fixtures/traces/async-js-calls.json.gz

@@ -47,6 +47,10 @@ const UIStrings = {
    *@description Text in Timeline UIUtils of the Performance panel
    */
   task: 'Task',
+  /**
+   *@description Text in Timeline UIUtils of the Performance panel
+   */
+  consoleTaskRun: 'Run console task',
   /**
    *@description Text for other types of items
    */
@@ -1060,6 +1064,8 @@ export function maybeInitSylesMap(): EventStylesMap {
 
     [Trace.Types.Events.Name.ABORT_POST_TASK_CALLBACK]:
         new TimelineRecordStyle(i18nString(UIStrings.abortPostTaskCallback), defaultCategoryStyles.scripting),
+    [Trace.Types.Events.Name.V8_CONSOLE_RUN_TASK]:
+        new TimelineRecordStyle(i18nString(UIStrings.consoleTaskRun), defaultCategoryStyles.scripting),
   };
   return eventStylesMap;
 }