Parse console.timeStamp payload

The payload now contains the new params the API was called with,
according to go/cpq:console-timestamp. This CL constructs the track data
with this data.

Timestamps for which a duration can be computed (because they have a start and an end) but that do not have an associated track name are stored separately. These events can be added to the timings track, I'd do that in a follow up CL.

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

Author: and-oli

front_end/models/trace/extras/StackTraceForEvent.ts

@@ -120,7 +120,11 @@ function getForExtensionEntry(event: Types.Extensions.SyntheticExtensionEntry, p
   }
   const eventCallTime = Types.Events.isPerformanceMeasureBegin(event.rawSourceEvent) ?
       event.rawSourceEvent.args.callTime :
-      event.rawSourceEvent.args.data?.callTime;
+      Types.Events.isPerformanceMark(event.rawSourceEvent) ?
+      event.rawSourceEvent.args.data?.callTime :
+      // event added with console.timeStamp: take the original event's
+      // ts.
+      event.rawSourceEvent.ts;
   if (eventCallTime === undefined) {
     return null;
   }

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

@@ -8,26 +8,32 @@ import * as Types from '../types/types.js';
 import type {HandlerName} from './types.js';
 import {data as userTimingsData} from './UserTimingsHandler.js';
 
-const extensionFlameChartEntries: Types.Extensions.SyntheticExtensionTrackEntry[] = [];
+const extensionTrackEntries: Types.Extensions.SyntheticExtensionTrackEntry[] = [];
 const extensionTrackData: Types.Extensions.ExtensionTrackData[] = [];
 const extensionMarkers: Types.Extensions.SyntheticExtensionMarker[] = [];
 const entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode> = new Map();
+const timeStampByName: Map<string, Types.Events.ConsoleTimeStamp> = new Map();
+
+const syntheticConsoleEntriesForTimingsTrack: Types.Events.SyntheticConsoleTimeStamp[] = [];
 
 export interface ExtensionTraceData {
   extensionTrackData: readonly Types.Extensions.ExtensionTrackData[];
   extensionMarkers: readonly Types.Extensions.SyntheticExtensionMarker[];
   entryToNode: Map<Types.Events.Event, Helpers.TreeHelpers.TraceEntryNode>;
+  syntheticConsoleEntriesForTimingsTrack: Types.Events.SyntheticConsoleTimeStamp[];
 }
 
 export function handleEvent(_event: Types.Events.Event): void {
   // Implementation not needed because data is sourced from UserTimingsHandler
 }
 
 export function reset(): void {
-  extensionFlameChartEntries.length = 0;
+  extensionTrackEntries.length = 0;
+  syntheticConsoleEntriesForTimingsTrack.length = 0;
   extensionTrackData.length = 0;
   extensionMarkers.length = 0;
   entryToNode.clear();
+  timeStampByName.clear();
 }
 
 export async function finalize(): Promise<void> {
@@ -39,14 +45,127 @@ function createExtensionFlameChartEntries(): void {
   const marks: readonly Types.Events.PerformanceMark[] = userTimingsData().performanceMarks;
   const mergedRawExtensionEvents = Helpers.Trace.mergeEventsInOrder(pairedMeasures, marks);
 
-  extractExtensionEntries(mergedRawExtensionEvents);
-  Helpers.Extensions.buildTrackDataFromExtensionEntries(extensionFlameChartEntries, extensionTrackData, entryToNode);
+  extractPerformanceAPIExtensionEntries(mergedRawExtensionEvents);
+  extractConsoleAPIExtensionEntries();
+  // extensionTrackEntries is filled by the above two calls.
+  Helpers.Trace.sortTraceEventsInPlace(extensionTrackEntries);
+  Helpers.Extensions.buildTrackDataFromExtensionEntries(extensionTrackEntries, extensionTrackData, entryToNode);
+}
+
+/**
+ * Extracts extension entries from console.timeStamp events.
+ *
+ * Entries are built by pairing `console.timeStamp` events based on
+ * their names. When a `console.timeStamp` event includes a `start`
+ * argument (and optionally an `end` argument), it attempts to find
+ * previously recorded `console.timeStamp` events with names matching
+ * the `start` and `end` values. These matching events are then used to
+ * determine the start and end times of the new entry.
+ *
+ * If a `console.timeStamp` event includes data for a custom track
+ * (specified by the `track` argument), an extension track entry is
+ * created and added to the `extensionTrackEntries` array. These entries
+ * are used to visualize custom tracks in the Performance panel.
+ *
+ * If a `console.timeStamp` event includes data for a custom track
+ * (specified by the `track` argument), an extension track entry is
+ * created and added to the `extensionTrackEntries` array. These entries
+ * are used to visualize custom tracks in the Performance panel.
+ *
+ * If a `console.timeStamp` event does not specify a custom track but
+ * includes a start and/or end time (referencing other
+ * `console.timeStamp` names), a synthetic console time stamp entry is
+ * created and added to the `syntheticConsoleEntriesForTimingsTrack`
+ * array. These entries are displayed in the "Timings" track.
+ */
+export function extractConsoleAPIExtensionEntries(): void {
+  const consoleTimeStamps: readonly Types.Events.ConsoleTimeStamp[] = userTimingsData().timestampEvents;
+  for (const currentTimeStamp of consoleTimeStamps) {
+    const timeStampName = String(currentTimeStamp.args.data.name);
+    timeStampByName.set(timeStampName, currentTimeStamp);
+    const extensionData = extensionDataInConsoleTimeStamp(currentTimeStamp);
+    const startName = currentTimeStamp.args.data.start;
+    const endName = currentTimeStamp.args.data.end;
+    if (!extensionData && !startName && !endName) {
+      continue;
+    }
+    const startTimeStamp = startName ? timeStampByName.get(String(startName)) : undefined;
+    const endTimeStamp = endName ? timeStampByName.get(String(endName)) : undefined;
+    if (endTimeStamp && !startTimeStamp) {
+      // Invalid data
+      continue;
+    }
+    const entryStartTime = startTimeStamp?.ts ?? currentTimeStamp.ts;
+    const entryEndTime = endTimeStamp?.ts ?? currentTimeStamp.ts;
+    if (extensionData) {
+      const unregisteredExtensionEntry: Omit<Types.Extensions.SyntheticExtensionTrackEntry, '_tag'> = {
+        ...currentTimeStamp,
+        name: timeStampName,
+        cat: 'devtools.extension',
+        args: extensionData,
+        rawSourceEvent: currentTimeStamp,
+        dur: Types.Timing.MicroSeconds(entryEndTime - entryStartTime),
+        ts: entryStartTime,
+      };
+      const extensionEntry =
+          Helpers.SyntheticEvents.SyntheticEventsManager.getActiveManager()
+              .registerSyntheticEvent<Types.Extensions.SyntheticExtensionTrackEntry>(unregisteredExtensionEntry);
+      extensionTrackEntries.push(extensionEntry);
+      continue;
+    }
+    // If no extension data is found in the entry (no custom track name
+    // was passed), but the entry has a duration. we still save it here
+    // to be added in the timings track. Note that timings w/o duration
+    // and extension data are already handled by the UserTimingsHandler.
+    const unregisteredSyntheticTimeStamp: Omit<Types.Events.SyntheticConsoleTimeStamp, '_tag'> = {
+      ...currentTimeStamp,
+      name: timeStampName,
+      cat: 'disabled-by-default-v8.inspector',
+      ph: Types.Events.Phase.COMPLETE,
+      ts: entryStartTime,
+      dur: Types.Timing.MicroSeconds(entryEndTime - entryStartTime),
+      rawSourceEvent: currentTimeStamp
+    };
+    const syntheticTimeStamp =
+        Helpers.SyntheticEvents.SyntheticEventsManager.getActiveManager()
+            .registerSyntheticEvent<Types.Events.SyntheticConsoleTimeStamp>(unregisteredSyntheticTimeStamp);
+    syntheticConsoleEntriesForTimingsTrack.push(syntheticTimeStamp);
+  }
 }
 
-export function extractExtensionEntries(timings: (Types.Events.SyntheticUserTimingPair|Types.Events.PerformanceMark)[]):
-    void {
+/**
+ * Extracts extension entries from Performance API events (marks and
+ * measures).
+ * It specifically looks for events that contain extension-specific data
+ * within their `detail` property.
+ *
+ * If an event's `detail` property can be parsed as a JSON object and
+ * contains a `devtools` field with a valid extension payload, a
+ * synthetic extension entry is created. The type of extension entry
+ * created depends on the payload:
+ *
+ * - If the payload conforms to `ExtensionPayloadMarker`, a
+ *   `SyntheticExtensionMarker` is created and added to the
+ *   `extensionMarkers` array. These markers represent single points in
+ *   time.
+ * - If the payload conforms to `ExtensionPayloadTrackEntry`, a
+ *   `SyntheticExtensionTrackEntry` is created and added to the
+ *   `extensionTrackEntries` array. These entries represent events with
+ *   a duration and are displayed on custom tracks in the Performance
+ *   panel.
+ *
+ * **Note:** Only events with a `detail` property that contains valid
+ * extension data are processed. Other `performance.mark` and
+ * `performance.measure` events are ignored.
+ *
+ * @param timings An array of `SyntheticUserTimingPair` or
+ *                `PerformanceMark` events, typically obtained from the
+ *                `UserTimingsHandler`.
+ */
+export function extractPerformanceAPIExtensionEntries(
+    timings: (Types.Events.SyntheticUserTimingPair|Types.Events.PerformanceMark)[]): void {
   for (const timing of timings) {
-    const extensionPayload = extensionDataInTiming(timing);
+    const extensionPayload = extensionDataInPerformanceTiming(timing);
     if (!extensionPayload) {
       // Not an extension user timing.
       continue;
@@ -78,14 +197,15 @@ export function extractExtensionEntries(timings: (Types.Events.SyntheticUserTimi
           Helpers.SyntheticEvents.SyntheticEventsManager.getActiveManager()
               .registerSyntheticEvent<Types.Extensions.SyntheticExtensionTrackEntry>(
                   extensionSyntheticEntry as Omit<Types.Extensions.SyntheticExtensionTrackEntry, '_tag'>);
-      extensionFlameChartEntries.push(extensionTrackEntry);
+      extensionTrackEntries.push(extensionTrackEntry);
       continue;
     }
   }
 }
 
-export function extensionDataInTiming(timing: Types.Events.SyntheticUserTimingPair|
-                                      Types.Events.PerformanceMark): Types.Extensions.ExtensionDataPayload|null {
+export function extensionDataInPerformanceTiming(timing: Types.Events.SyntheticUserTimingPair|
+                                                 Types.Events.PerformanceMark): Types.Extensions.ExtensionDataPayload|
+    null {
   const timingDetail =
       Types.Events.isPerformanceMark(timing) ? timing.args.data?.detail : timing.args.data.beginEvent.args.detail;
   if (!timingDetail) {
@@ -112,12 +232,49 @@ export function extensionDataInTiming(timing: Types.Events.SyntheticUserTimingPa
     return null;
   }
 }
+/**
+ * Extracts extension data from a `console.timeStamp` event.
+ *
+ * Checks if a `console.timeStamp` event contains data intended for
+ * creating a custom track entry in the DevTools Performance panel. It
+ * specifically looks for a `track` argument within the event's data.
+ *
+ * If a `track` argument is present (and not an empty string), the
+ * function constructs an `ExtensionTrackEntryPayload` object containing
+ * the track name, an optional color, an optional track group. This
+ * payload is then used to create a `SyntheticExtensionTrackEntry`.
+ *
+ * **Note:** The `color` argument is optional and its type is validated
+ * against a predefined palette (see
+ * `ExtensionUI::extensionEntryColor`).
+ *
+ * @param timeStamp The `ConsoleTimeStamp` event to extract data from.
+ * @return An `ExtensionTrackEntryPayload` object if the event contains
+ *         valid extension data for a track entry, or `null` otherwise.
+ */
+export function extensionDataInConsoleTimeStamp(timeStamp: Types.Events.ConsoleTimeStamp):
+    Types.Extensions.ExtensionTrackEntryPayload|null {
+  const trackName = timeStamp.args.data.track;
+  if (trackName === '' || trackName === undefined) {
+    return null;
+  }
+  return {
+    // the color is defaulted to primary if it's value isn't one from
+    // the defined palette (see ExtensionUI::extensionEntryColor) so
+    // we don't need to check the value is valid here.
+    color: String(timeStamp.args.data.color) as Types.Extensions.ExtensionTrackEntryPayload['color'],
+    track: String(trackName),
+    dataType: 'track-entry',
+    trackGroup: timeStamp.args.data.trackGroup !== undefined ? String(timeStamp.args.data.trackGroup) : undefined
+  };
+}
 
 export function data(): ExtensionTraceData {
   return {
     entryToNode,
-    extensionTrackData: [...extensionTrackData],
-    extensionMarkers: [...extensionMarkers],
+    extensionTrackData,
+    extensionMarkers,
+    syntheticConsoleEntriesForTimingsTrack,
   };
 }
 

front_end/models/trace/handlers/ExtensionTraceDataHandler.ts

@@ -2,7 +2,9 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
-import type {Args, Event, PerformanceMark, PerformanceMeasureBegin, Phase, SyntheticBased} from './TraceEvents.js';
+import type {
+  Args, ConsoleTimeStamp, Event, PerformanceMark, PerformanceMeasureBegin, Phase, SyntheticBased} from
+  './TraceEvents.js';
 
 export type ExtensionEntryType = 'track-entry'|'marker';
 
@@ -58,7 +60,7 @@ export interface ExtensionMarkerPayload extends ExtensionDataPayloadBase {
  * Synthetic events created for extension tracks.
  */
 export interface SyntheticExtensionTrackEntry extends
-    SyntheticBased<Phase.COMPLETE, PerformanceMeasureBegin|PerformanceMark> {
+    SyntheticBased<Phase.COMPLETE, PerformanceMeasureBegin|PerformanceMark|ConsoleTimeStamp> {
   args: Args&ExtensionTrackEntryPayload;
 }
 

front_end/models/trace/types/Extensions.ts

@@ -1394,16 +1394,23 @@ export interface ConsoleTimeStamp extends Event {
   ph: Phase.COMPLETE;
   args: Args&{
     data: ArgsData & {
+      // The console.timeStamp allows to pass integers as values as well
+      // as strings
       name: string | number,
       start?: string|number,
       end?: string|number,
-      trackName?: string|number,
+      track?: string|number,
       trackGroup?: string|number,
       color?: string|number,
     },
   };
 }
 
+export interface SyntheticConsoleTimeStamp extends Event, SyntheticBased {
+  cat: 'disabled-by-default-v8.inspector';
+  ph: Phase.COMPLETE;
+}
+
 /** ChromeFrameReporter args for PipelineReporter event.
     Matching proto: https://source.chromium.org/chromium/chromium/src/+/main:third_party/perfetto/protos/perfetto/trace/track_event/chrome_frame_reporter.proto
  */

front_end/models/trace/types/TraceEvents.ts

@@ -72,9 +72,9 @@ export class TimingsTrackAppender implements TrackAppender {
   appendTrackAtLevel(trackStartLevel: number, expanded?: boolean): number {
     const extensionMarkersAreEmpty = this.#extensionMarkers.length === 0;
     const performanceMarks = this.#parsedTrace.UserTimings.performanceMarks.filter(
-        m => !Trace.Handlers.ModelHandlers.ExtensionTraceData.extensionDataInTiming(m));
+        m => !Trace.Handlers.ModelHandlers.ExtensionTraceData.extensionDataInPerformanceTiming(m));
     const performanceMeasures = this.#parsedTrace.UserTimings.performanceMeasures.filter(
-        m => !Trace.Handlers.ModelHandlers.ExtensionTraceData.extensionDataInTiming(m));
+        m => !Trace.Handlers.ModelHandlers.ExtensionTraceData.extensionDataInPerformanceTiming(m));
     const timestampEvents = this.#parsedTrace.UserTimings.timestampEvents;
     const consoleTimings = this.#parsedTrace.UserTimings.consoleTimings;
 

front_end/panels/timeline/TimingsTrackAppender.ts

@@ -3,8 +3,8 @@
 // found in the LICENSE file.
 
 import { // eslint-disable-line rulesdir/es-modules-import
-  createTraceExtensionDataFromTestInput,
-  type ExtensionTestData,
+  createTraceExtensionDataFromPerformanceAPITestInput,
+  type PerformanceAPIExtensionTestData,
 } from '../../../models/trace/handlers/ExtensionTraceDataHandler.test.js';
 import * as Trace from '../../../models/trace/trace.js';
 import {describeWithEnvironment} from '../../../testing/EnvironmentHelpers.js';
@@ -112,8 +112,8 @@ describeWithEnvironment('ExtensionTrackAppender', function() {
              ts: 100,
              dur: 100,
            },
-         ] as ExtensionTestData[];
-         const traceExtensionData = await createTraceExtensionDataFromTestInput(extensionData);
+         ] as PerformanceAPIExtensionTestData[];
+         const traceExtensionData = await createTraceExtensionDataFromPerformanceAPITestInput(extensionData);
          const testParsedTrace = getBaseTraceParseModelData({ExtensionTraceData: traceExtensionData});
          entryData = [];
          flameChartData = PerfUI.FlameChart.FlameChartTimelineData.createEmpty();

front_end/panels/timeline/track_appenders/ExtensionTrackAppender.test.ts

@@ -707,6 +707,7 @@ export function getBaseTraceParseModelData(overrides: Partial<ParsedTrace> = {})
       entryToNode: new Map(),
       extensionMarkers: [],
       extensionTrackData: [],
+      syntheticConsoleEntriesForTimingsTrack: [],
     },
     Frames: {
       frames: [],