[Perf] Parse UserTiming::Measure event

The event was added recently [1] and allows us to keep track of the call
to performance.measure, since the event we were dispatching (and
parsing) has it's timestamp and duration overriden to match the values
of the timing measured with the performance.measure API.

The event can be connected to its corresponding performance measure
event with a common traceId.

[1] https://chromium-review.googlesource.com/c/chromium/src/+/6187334

Bug: 395845218
Change-Id: Ie5324100d32928edd1962eb309f730740796a509
Reviewed-on: https://chromium-review.googlesource.com/c/devtools/devtools-frontend/+/6252783
Reviewed-by: Nancy Li <[email protected]>
Auto-Submit: Andres Olivares <[email protected]>
Commit-Queue: Andres Olivares <[email protected]>
Commit-Queue: Nancy Li <[email protected]>

Author: and-oli

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

@@ -3,6 +3,9 @@
 // found in the LICENSE file.
 
 import {describeWithEnvironment} from '../../../testing/EnvironmentHelpers.js';
+import {
+  makeCompleteEvent,
+} from '../../../testing/TraceHelpers.js';
 import {TraceLoader} from '../../../testing/TraceLoader.js';
 import * as Trace from '../trace.js';
 
@@ -180,4 +183,17 @@ describeWithEnvironment('UserTimingsHandler', function() {
       });
     });
   });
+
+  describe('UserTiming::Measure events parsing', function() {
+    it('stores user timing events by trace id', async function() {
+      const userTimingMeasure = makeCompleteEvent(Trace.Types.Events.Name.USER_TIMING_MEASURE, 0, 100, 'cat', 0, 0) as
+          Trace.Types.Events.UserTimingMeasure;
+      userTimingMeasure.args.traceId = 1;
+      Trace.Handlers.ModelHandlers.UserTimings.handleEvent(userTimingMeasure);
+      await Trace.Handlers.ModelHandlers.UserTimings.finalize();
+      const data = Trace.Handlers.ModelHandlers.UserTimings.data();
+      assert.lengthOf(data.measureTraceByTraceId, 1);
+      assert.deepEqual([...data.measureTraceByTraceId.entries()][0], [1, userTimingMeasure]);
+    });
+  });
 });

front_end/models/trace/handlers/UserTimingsHandler.ts

@@ -11,6 +11,18 @@ import * as Types from '../types/types.js';
  * UserTimings and the trace events we parse currently.
  **/
 let syntheticEvents: Types.Events.SyntheticEventPair<Types.Events.PairableAsync>[] = [];
+
+// There are two events dispatched for performance.measure calls: one to
+// represent the measured timing in the tracing clock (which we type as
+// PerformanceMeasure) and another one for the call itself (which we
+// type as UserTimingMeasure). The two events corresponding to the same
+// call are linked together by a common trace_id. The reason two events
+// are dispatched is because the first was originally added with the
+// implementation of the performance.measure API and it uses an
+// overridden timestamp and duration. To prevent breaking potential deps
+// created since then, a second event was added instead of changing the
+// params of the first.
+const measureTraceByTraceId: Map<number, Types.Events.UserTimingMeasure> = new Map();
 const performanceMeasureEvents: Types.Events.PerformanceMeasure[] = [];
 const performanceMarkEvents: Types.Events.PerformanceMark[] = [];
 
@@ -40,6 +52,11 @@ export interface UserTimingsData {
    * https://developer.mozilla.org/en-US/docs/Web/API/console/timeStamp
    */
   timestampEvents: readonly Types.Events.ConsoleTimeStamp[];
+  /**
+   * Events triggered to trace the call to performance.measure itself,
+   * cached by trace_id.
+   */
+  measureTraceByTraceId: Map<number, Types.Events.UserTimingMeasure>;
 }
 
 export function reset(): void {
@@ -48,6 +65,7 @@ export function reset(): void {
   performanceMarkEvents.length = 0;
   consoleTimings.length = 0;
   timestampEvents.length = 0;
+  measureTraceByTraceId.clear();
 }
 
 const resourceTimingNames = [
@@ -142,7 +160,9 @@ export function handleEvent(event: Types.Events.Event): void {
   if (ignoredNames.includes(event.name)) {
     return;
   }
-
+  if (Types.Events.isUserTimingMeasure(event)) {
+    measureTraceByTraceId.set(event.args.traceId, event);
+  }
   if (Types.Events.isPerformanceMeasure(event)) {
     performanceMeasureEvents.push(event);
     return;
@@ -172,5 +192,6 @@ export function data(): UserTimingsData {
     // TODO(crbug/41484172): UserTimingsHandler.test.ts fails if this is not copied.
     performanceMarks: [...performanceMarkEvents],
     timestampEvents: [...timestampEvents],
+    measureTraceByTraceId: new Map(measureTraceByTraceId),
   };
 }

front_end/models/trace/types/TraceEvents.ts

@@ -1387,6 +1387,7 @@ export interface PerformanceMeasureBegin extends PairableUserTiming {
     detail?: string,
     stackTrace?: CallFrame[],
     callTime?: Micro,
+    traceId?: number,
   };
   ph: Phase.ASYNC_NESTABLE_START;
 }
@@ -1439,6 +1440,16 @@ export interface SyntheticConsoleTimeStamp extends Event, SyntheticBased {
   ph: Phase.COMPLETE;
 }
 
+export interface UserTimingMeasure extends Event {
+  cat: 'devtools.timeline';
+  ph: Phase.COMPLETE;
+  name: Name.USER_TIMING_MEASURE;
+  args: Args&{
+    sampleTraceId: number,
+    traceId: number,
+  };
+}
+
 /** 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
  */
@@ -2284,6 +2295,10 @@ export function isConsoleTimeStamp(event: Event): event is ConsoleTimeStamp {
   return event.ph === Phase.COMPLETE && event.name === Name.CONSOLE_TIME_STAMP;
 }
 
+export function isUserTimingMeasure(event: Event): event is UserTimingMeasure {
+  return event.name === Name.USER_TIMING_MEASURE;
+}
+
 export function isParseHTML(event: Event): event is ParseHTML {
   return event.name === 'ParseHTML';
 }
@@ -2998,7 +3013,8 @@ export const enum Name {
   ANIMATION_FRAME = 'AnimationFrame',
   ANIMATION_FRAME_PRESENTATION = 'AnimationFrame::Presentation',
 
-  SYNTHETIC_NETWORK_REQUEST = 'SyntheticNetworkRequest'
+  SYNTHETIC_NETWORK_REQUEST = 'SyntheticNetworkRequest',
+  USER_TIMING_MEASURE = 'UserTiming::Measure',
 }
 
 // NOT AN EXHAUSTIVE LIST: just some categories we use and refer

front_end/testing/TraceHelpers.ts

@@ -690,6 +690,7 @@ export function getBaseTraceParseModelData(overrides: Partial<ParsedTrace> = {})
       performanceMarks: [],
       performanceMeasures: [],
       timestampEvents: [],
+      measureTraceByTraceId: new Map(),
     },
     LargestImagePaint: {lcpRequestByNavigation: new Map()},
     LargestTextPaint: new Map(),