cherry-pick(#27162): fix(tracing): bump trace version to V5, migrate V4 traces to consoleMessage.args (#27193)

This moves the fix in #27095 from `modernize` to `appendEvent`. The
reason is that `trace V4` is used both for older traces that do not have
`consoleMessage.args` and the new ones with `args`. Since we do not call
`modernize` for traces of the same version, the original fix does not
help in this case.

Fixes #27144.

Author: dgozman

packages/playwright-core/src/server/trace/recorder/tracing.ts

@@ -43,7 +43,7 @@ import { Snapshotter } from './snapshotter';
 import { yazl } from '../../../zipBundle';
 import type { ConsoleMessage } from '../../console';
 
-const version: trace.VERSION = 4;
+const version: trace.VERSION = 5;
 
 export type TracerOptions = {
   name?: string;
@@ -429,24 +429,12 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
   }
 
   private _onConsoleMessage(message: ConsoleMessage) {
-    const object: trace.ConsoleMessageTraceEvent = {
-      type: 'object',
-      class: 'ConsoleMessage',
-      guid: message.guid,
-      initializer: {
-        type: message.type(),
-        text: message.text(),
-        args: message.args().map(a => ({ preview: a.toString(), value: a.rawValue() })),
-        location: message.location(),
-      },
-    };
-    this._appendTraceEvent(object);
-
-    const event: trace.EventTraceEvent = {
-      type: 'event',
-      class: 'BrowserContext',
-      method: 'console',
-      params: { message: { guid: message.guid } },
+    const event: trace.ConsoleMessageTraceEvent = {
+      type: 'console',
+      messageType: message.type(),
+      text: message.text(),
+      args: message.args().map(a => ({ preview: a.toString(), value: a.rawValue() })),
+      location: message.location(),
       time: monotonicTime(),
       pageId: message.page().guid,
     };
@@ -478,7 +466,7 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
   private _appendTraceEvent(event: trace.TraceEvent) {
     const visited = visitTraceEvent(event, this._state!.traceSha1s);
     // Do not flush (console) events, they are too noisy, unless we are in ui mode (live).
-    const flush = this._state!.options.live || (event.type !== 'event' && event.type !== 'object');
+    const flush = this._state!.options.live || (event.type !== 'event' && event.type !== 'console');
     this._fs.appendFile(this._state!.traceFile, JSON.stringify(visited) + '\n', flush);
   }
 

packages/trace-viewer/src/entries.ts

@@ -34,9 +34,8 @@ export type ContextEntry = {
   pages: PageEntry[];
   resources: ResourceSnapshot[];
   actions: trace.ActionTraceEvent[];
-  events: trace.EventTraceEvent[];
+  events: (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[];
   stdio: trace.StdioTraceEvent[];
-  initializers: { [key: string]: trace.ConsoleMessageTraceEvent['initializer'] };
   hasSource: boolean;
 };
 
@@ -65,7 +64,6 @@ export function createEmptyContext(): ContextEntry {
     actions: [],
     events: [],
     stdio: [],
-    initializers: {},
     hasSource: false
   };
 }

packages/trace-viewer/src/traceModel.ts

@@ -16,6 +16,7 @@
 
 import type * as trace from '@trace/trace';
 import type * as traceV3 from './versions/traceV3';
+import type * as traceV4 from './versions/traceV4';
 import { parseClientSideCallMetadata } from '../../../packages/playwright-core/src/utils/isomorphic/traceUtils';
 import type { ContextEntry, PageEntry } from './entries';
 import { createEmptyContext } from './entries';
@@ -39,6 +40,7 @@ export class TraceModel {
   private _attachments = new Map<string, trace.AfterActionTraceEventAttachment>();
   private _resourceToContentType = new Map<string, string>();
   private _jsHandles = new Map<string, { preview: string }>();
+  private _consoleObjects = new Map<string, { type: string, text: string, location: { url: string, lineNumber: number, columnNumber: number }, args?: { preview: string, value: string }[] }>();
 
   constructor() {
   }
@@ -114,6 +116,7 @@ export class TraceModel {
 
     this._snapshotStorage!.finalize();
     this._jsHandles.clear();
+    this._consoleObjects.clear();
   }
 
   async hasEntry(filename: string): Promise<boolean> {
@@ -209,8 +212,8 @@ export class TraceModel {
         contextEntry!.stdio.push(event);
         break;
       }
-      case 'object': {
-        contextEntry!.initializers[event.guid] = event.initializer;
+      case 'console': {
+        contextEntry!.events.push(event);
         break;
       }
       case 'resource-snapshot':
@@ -235,12 +238,15 @@ export class TraceModel {
     }
   }
 
-  private _modernize(event: any): trace.TraceEvent {
+  private _modernize(event: any): trace.TraceEvent | null {
     if (this._version === undefined)
       return event;
-    const lastVersion: trace.VERSION = 4;
-    for (let version = this._version; version < lastVersion; ++version)
+    const lastVersion: trace.VERSION = 5;
+    for (let version = this._version; version < lastVersion; ++version) {
       event = (this as any)[`_modernize_${version}_to_${version + 1}`].call(this, event);
+      if (!event)
+        return null;
+    }
     return event;
   }
 
@@ -286,7 +292,7 @@ export class TraceModel {
     return event;
   }
 
-  _modernize_3_to_4(event: traceV3.TraceEvent): trace.TraceEvent | null {
+  _modernize_3_to_4(event: traceV3.TraceEvent): traceV4.TraceEvent | null {
     if (event.type !== 'action' && event.type !== 'event') {
       return event as traceV3.ContextCreatedTraceEvent |
         traceV3.ScreencastFrameTraceEvent |
@@ -299,23 +305,12 @@ export class TraceModel {
       return null;
 
     if (event.type === 'event') {
-      if (metadata.method === '__create__' && metadata.type === 'JSHandle')
-        this._jsHandles.set(metadata.params.guid, metadata.params.initializer);
       if (metadata.method === '__create__' && metadata.type === 'ConsoleMessage') {
         return {
           type: 'object',
           class: metadata.type,
           guid: metadata.params.guid,
-          initializer: {
-            ...metadata.params.initializer,
-            args: metadata.params.initializer.args?.map((arg: any) => {
-              if (arg.guid) {
-                const handle = this._jsHandles.get(arg.guid);
-                return { preview: handle?.preview || '', value: '' };
-              }
-              return { preview: '', value: '' };
-            })
-          },
+          initializer: metadata.params.initializer,
         };
       }
       return {
@@ -348,6 +343,47 @@ export class TraceModel {
       pageId: metadata.pageId,
     };
   }
+
+  _modernize_4_to_5(event: traceV4.TraceEvent): trace.TraceEvent | null {
+    if (event.type === 'event' && event.method === '__create__' && event.class === 'JSHandle')
+      this._jsHandles.set(event.params.guid, event.params.initializer);
+    if (event.type === 'object') {
+      // We do not expect any other 'object' events.
+      if (event.class !== 'ConsoleMessage')
+        return null;
+      // Older traces might have `args` inherited from the protocol initializer - guid of JSHandle,
+      // but might also have modern `args` with preview and value.
+      const args: { preview: string, value: string }[] = (event.initializer as any).args?.map((arg: any) => {
+        if (arg.guid) {
+          const handle = this._jsHandles.get(arg.guid);
+          return { preview: handle?.preview || '', value: '' };
+        }
+        return { preview: arg.preview || '', value: arg.value || '' };
+      });
+      this._consoleObjects.set(event.guid, {
+        type: event.initializer.type,
+        text: event.initializer.text,
+        location: event.initializer.location,
+        args,
+      });
+      return null;
+    }
+    if (event.type === 'event' && event.method === 'console') {
+      const consoleMessage = this._consoleObjects.get(event.params.message?.guid || '');
+      if (!consoleMessage)
+        return null;
+      return {
+        type: 'console',
+        time: event.time,
+        pageId: event.pageId,
+        messageType: consoleMessage.type,
+        text: consoleMessage.text,
+        args: consoleMessage.args,
+        location: consoleMessage.location,
+      };
+    }
+    return event;
+  }
 }
 
 function stripEncodingFromContentType(contentType: string) {

packages/trace-viewer/src/ui/consoleTab.tsx

@@ -17,7 +17,7 @@
 import type * as channels from '@protocol/channels';
 import * as React from 'react';
 import './consoleTab.css';
-import * as modelUtil from './modelUtil';
+import type * as modelUtil from './modelUtil';
 import { ListView } from '@web/components/listView';
 import type { Boundaries } from '../geometry';
 import { msToString } from '@web/uiUtils';
@@ -51,29 +51,23 @@ export function useConsoleTabModel(model: modelUtil.MultiTraceModel | undefined,
       return { entries: [] };
     const entries: ConsoleEntry[] = [];
     for (const event of model.events) {
-      if (event.method !== 'console' && event.method !== 'pageError')
-        continue;
-      if (event.method === 'console') {
-        const { guid } = event.params.message;
-        const browserMessage = modelUtil.context(event).initializers[guid];
-        if (browserMessage) {
-          const body = browserMessage.args && browserMessage.args.length ? format(browserMessage.args) : formatAnsi(browserMessage.text);
-          const url = browserMessage.location.url;
-          const filename = url ? url.substring(url.lastIndexOf('/') + 1) : '<anonymous>';
-          const location = `${filename}:${browserMessage.location.lineNumber}`;
-
-          entries.push({
-            browserMessage: {
-              body,
-              location,
-            },
-            isError: modelUtil.context(event).initializers[guid]?.type === 'error',
-            isWarning: modelUtil.context(event).initializers[guid]?.type === 'warning',
-            timestamp: event.time,
-          });
-        }
+      if (event.type === 'console') {
+        const body = event.args && event.args.length ? format(event.args) : formatAnsi(event.text);
+        const url = event.location.url;
+        const filename = url ? url.substring(url.lastIndexOf('/') + 1) : '<anonymous>';
+        const location = `${filename}:${event.location.lineNumber}`;
+
+        entries.push({
+          browserMessage: {
+            body,
+            location,
+          },
+          isError: event.messageType === 'error',
+          isWarning: event.messageType === 'warning',
+          timestamp: event.time,
+        });
       }
-      if (event.method === 'pageError') {
+      if (event.type === 'event' && event.method === 'pageError') {
         entries.push({
           browserError: event.params.error,
           isError: true,

packages/trace-viewer/src/ui/modelUtil.ts

@@ -17,7 +17,7 @@
 import type { Language } from '@isomorphic/locatorGenerators';
 import type { ResourceSnapshot } from '@trace/snapshot';
 import type * as trace from '@trace/trace';
-import type { ActionTraceEvent, EventTraceEvent } from '@trace/trace';
+import type { ActionTraceEvent } from '@trace/trace';
 import type { ContextEntry, PageEntry } from '../entries';
 
 const contextSymbol = Symbol('context');
@@ -58,7 +58,7 @@ export class MultiTraceModel {
   readonly options: trace.BrowserContextEventOptions;
   readonly pages: PageEntry[];
   readonly actions: ActionTraceEventInContext[];
-  readonly events: trace.EventTraceEvent[];
+  readonly events: (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[];
   readonly stdio: trace.StdioTraceEvent[];
   readonly hasSource: boolean;
   readonly sdkLanguage: Language | undefined;
@@ -83,7 +83,7 @@ export class MultiTraceModel {
     this.endTime = contexts.map(c => c.endTime).reduce((prev, cur) => Math.max(prev, cur), Number.MIN_VALUE);
     this.pages = ([] as PageEntry[]).concat(...contexts.map(c => c.pages));
     this.actions = mergeActions(contexts);
-    this.events = ([] as EventTraceEvent[]).concat(...contexts.map(c => c.events));
+    this.events = ([] as (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[]).concat(...contexts.map(c => c.events));
     this.stdio = ([] as trace.StdioTraceEvent[]).concat(...contexts.map(c => c.stdio));
     this.hasSource = contexts.some(c => c.hasSource);
     this.resources = [...contexts.map(c => c.resources)].flat();
@@ -203,7 +203,7 @@ export function idForAction(action: ActionTraceEvent) {
   return `${action.pageId || 'none'}:${action.callId}`;
 }
 
-export function context(action: ActionTraceEvent | EventTraceEvent): ContextEntry {
+export function context(action: ActionTraceEvent | trace.EventTraceEvent): ContextEntry {
   return (action as any)[contextSymbol];
 }
 
@@ -218,24 +218,22 @@ export function prevInList(action: ActionTraceEvent): ActionTraceEvent {
 export function stats(action: ActionTraceEvent): { errors: number, warnings: number } {
   let errors = 0;
   let warnings = 0;
-  const c = context(action);
   for (const event of eventsForAction(action)) {
-    if (event.method === 'console') {
-      const { guid } = event.params.message;
-      const type = c.initializers[guid]?.type;
+    if (event.type === 'console') {
+      const type = event.messageType;
       if (type === 'warning')
         ++warnings;
       else if (type === 'error')
         ++errors;
     }
-    if (event.method === 'pageError')
+    if (event.type === 'event' && event.method === 'pageError')
       ++errors;
   }
   return { errors, warnings };
 }
 
-export function eventsForAction(action: ActionTraceEvent): EventTraceEvent[] {
-  let result: EventTraceEvent[] = (action as any)[eventsSymbol];
+export function eventsForAction(action: ActionTraceEvent): (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[] {
+  let result: (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[] = (action as any)[eventsSymbol];
   if (result)
     return result;