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

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.

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 = {
+    const event: trace.ConsoleMessageTraceEvent = {
-      type: 'object',
+      type: 'console',
-      class: 'ConsoleMessage',
+      messageType: message.type(),
-      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 } },
       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': {
+      case 'console': {
-        contextEntry!.initializers[event.guid] = event.initializer;
+        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;
+    const lastVersion: trace.VERSION = 5;
-    for (let version = this._version; version < lastVersion; ++version)
+    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: {
+          initializer: metadata.params.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: '' };
-            })
-          },
         };
       }
       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')
+      if (event.type === 'console') {
-        continue;
+        const body = event.args && event.args.length ? format(event.args) : formatAnsi(event.text);
-      if (event.method === 'console') {
+        const url = event.location.url;
-        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}`;
+        const location = `${filename}:${event.location.lineNumber}`;
 
         entries.push({
           browserMessage: {
             body,
             location,
           },
-            isError: modelUtil.context(event).initializers[guid]?.type === 'error',
+          isError: event.messageType === 'error',
-            isWarning: modelUtil.context(event).initializers[guid]?.type === 'warning',
+          isWarning: event.messageType === 'warning',
           timestamp: event.time,
         });
       }
-      }
+      if (event.type === 'event' && event.method === 'pageError') {
-      if (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') {
+    if (event.type === 'console') {
-      const { guid } = event.params.message;
+      const type = event.messageType;
-      const type = c.initializers[guid]?.type;
       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[] {
+export function eventsForAction(action: ActionTraceEvent): (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[] {
-  let result: EventTraceEvent[] = (action as any)[eventsSymbol];
+  let result: (trace.EventTraceEvent | trace.ConsoleMessageTraceEvent)[] = (action as any)[eventsSymbol];
   if (result)
     return result;
 

packages/trace-viewer/src/versions/traceV4.ts

@@ -0,0 +1,225 @@
+/**
+ * Copyright (c) Microsoft Corporation.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import type { Entry as ResourceSnapshot } from '../../../trace/src/har';
+
+type Language = 'javascript' | 'python' | 'java' | 'csharp' | 'jsonl';
+type Point = { x: number, y: number };
+type Size = { width: number, height: number };
+
+type StackFrame = {
+  file: string,
+  line: number,
+  column: number,
+  function?: string,
+};
+
+type SerializedValue = {
+  n?: number,
+  b?: boolean,
+  s?: string,
+  v?: 'null' | 'undefined' | 'NaN' | 'Infinity' | '-Infinity' | '-0',
+  d?: string,
+  u?: string,
+  bi?: string,
+  m?: SerializedValue,
+  se?: SerializedValue,
+  r?: {
+    p: string,
+    f: string,
+  },
+  a?: SerializedValue[],
+  o?: {
+    k: string,
+    v: SerializedValue,
+  }[],
+  h?: number,
+  id?: number,
+  ref?: number,
+};
+
+type SerializedError = {
+  error?: {
+    message: string,
+    name: string,
+    stack?: string,
+  },
+  value?: SerializedValue,
+};
+
+type NodeSnapshot =
+  // Text node.
+  string |
+  // Subtree reference, "x snapshots ago, node #y". Could point to a text node.
+  // Only nodes that are not references are counted, starting from zero, using post-order traversal.
+  [ [number, number] ] |
+  // Just node name.
+  [ string ] |
+  // Node name, attributes, child nodes.
+  // Unfortunately, we cannot make this type definition recursive, therefore "any".
+  [ string, { [attr: string]: string }, ...any ];
+
+
+type ResourceOverride = {
+  url: string,
+  sha1?: string,
+  ref?: number
+};
+
+type FrameSnapshot = {
+  snapshotName?: string,
+  callId: string,
+  pageId: string,
+  frameId: string,
+  frameUrl: string,
+  timestamp: number,
+  collectionTime: number,
+  doctype?: string,
+  html: NodeSnapshot,
+  resourceOverrides: ResourceOverride[],
+  viewport: { width: number, height: number },
+  isMainFrame: boolean,
+};
+
+type BrowserContextEventOptions = {
+  viewport?: Size,
+  deviceScaleFactor?: number,
+  isMobile?: boolean,
+  userAgent?: string,
+};
+
+type ContextCreatedTraceEvent = {
+  version: number,
+  type: 'context-options',
+  browserName: string,
+  channel?: string,
+  platform: string,
+  wallTime: number,
+  title?: string,
+  options: BrowserContextEventOptions,
+  sdkLanguage?: Language,
+  testIdAttributeName?: string,
+};
+
+type ScreencastFrameTraceEvent = {
+  type: 'screencast-frame',
+  pageId: string,
+  sha1: string,
+  width: number,
+  height: number,
+  timestamp: number,
+};
+
+type BeforeActionTraceEvent = {
+  type: 'before',
+  callId: string;
+  startTime: number;
+  apiName: string;
+  class: string;
+  method: string;
+  params: Record<string, any>;
+  wallTime: number;
+  beforeSnapshot?: string;
+  stack?: StackFrame[];
+  pageId?: string;
+  parentId?: string;
+};
+
+type InputActionTraceEvent = {
+  type: 'input',
+  callId: string;
+  inputSnapshot?: string;
+  point?: Point;
+};
+
+type AfterActionTraceEventAttachment = {
+  name: string;
+  contentType: string;
+  path?: string;
+  sha1?: string;
+  base64?: string;
+};
+
+type AfterActionTraceEvent = {
+  type: 'after',
+  callId: string;
+  endTime: number;
+  afterSnapshot?: string;
+  log: string[];
+  error?: SerializedError['error'];
+  attachments?: AfterActionTraceEventAttachment[];
+  result?: any;
+};
+
+type EventTraceEvent = {
+  type: 'event',
+  time: number;
+  class: string;
+  method: string;
+  params: any;
+  pageId?: string;
+};
+
+type ConsoleMessageTraceEvent = {
+  type: 'object';
+  class: string;
+  initializer: {
+    type: string,
+    text: string,
+    location: {
+      url: string,
+      lineNumber: number,
+      columnNumber: number,
+    },
+  };
+  guid: string;
+};
+
+type ResourceSnapshotTraceEvent = {
+  type: 'resource-snapshot',
+  snapshot: ResourceSnapshot,
+};
+
+type FrameSnapshotTraceEvent = {
+  type: 'frame-snapshot',
+  snapshot: FrameSnapshot,
+};
+
+type ActionTraceEvent = {
+  type: 'action',
+} & Omit<BeforeActionTraceEvent, 'type'>
+  & Omit<AfterActionTraceEvent, 'type'>
+  & Omit<InputActionTraceEvent, 'type'>;
+
+type StdioTraceEvent = {
+  type: 'stdout' | 'stderr';
+  timestamp: number;
+  text?: string;
+  base64?: string;
+};
+
+export type TraceEvent =
+    ContextCreatedTraceEvent |
+    ScreencastFrameTraceEvent |
+    ActionTraceEvent |
+    BeforeActionTraceEvent |
+    InputActionTraceEvent |
+    AfterActionTraceEvent |
+    EventTraceEvent |
+    ConsoleMessageTraceEvent |
+    ResourceSnapshotTraceEvent |
+    FrameSnapshotTraceEvent |
+    StdioTraceEvent;

packages/trace/src/trace.ts

@@ -21,7 +21,7 @@ import type { FrameSnapshot, ResourceSnapshot } from './snapshot';
 export type Size = { width: number, height: number };
 
 // Make sure you add _modernize_N_to_N1(event: any) to traceModel.ts.
-export type VERSION = 4;
+export type VERSION = 5;
 
 export type BrowserContextEventOptions = {
   viewport?: Size,
@@ -103,10 +103,10 @@ export type EventTraceEvent = {
 };
 
 export type ConsoleMessageTraceEvent = {
-  type: 'object';
+  type: 'console';
-  class: string;
+  time: number;
-  initializer: {
+  pageId?: string;
-    type: string,
+  messageType: string,
   text: string,
   args?: { preview: string, value: any }[],
   location: {
@@ -114,8 +114,6 @@ export type ConsoleMessageTraceEvent = {
     lineNumber: number,
     columnNumber: number,
   },
-  };
-  guid: string;
 };
 
 export type ResourceSnapshotTraceEvent = {

tests/config/utils.ts

@@ -22,7 +22,7 @@ import { parseClientSideCallMetadata } from '../../packages/playwright-core/lib/
 import { TraceModel } from '../../packages/trace-viewer/src/traceModel';
 import type { ActionTreeItem } from '../../packages/trace-viewer/src/ui/modelUtil';
 import { buildActionTree, MultiTraceModel } from '../../packages/trace-viewer/src/ui/modelUtil';
-import type { ActionTraceEvent, EventTraceEvent, TraceEvent } from '@trace/trace';
+import type { ActionTraceEvent, ConsoleMessageTraceEvent, EventTraceEvent, TraceEvent } from '@trace/trace';
 
 export async function attachFrame(page: Page, frameId: string, url: string): Promise<Frame> {
   const handle = await page.evaluateHandle(async ({ frameId, url }) => {
@@ -158,7 +158,7 @@ export async function parseTraceRaw(file: string): Promise<{ events: any[], reso
   };
 }
 
-export async function parseTrace(file: string): Promise<{ resources: Map<string, Buffer>, events: EventTraceEvent[], actions: ActionTraceEvent[], apiNames: string[], traceModel: TraceModel, model: MultiTraceModel, actionTree: string[] }> {
+export async function parseTrace(file: string): Promise<{ resources: Map<string, Buffer>, events: (EventTraceEvent | ConsoleMessageTraceEvent)[], actions: ActionTraceEvent[], apiNames: string[], traceModel: TraceModel, model: MultiTraceModel, actionTree: string[] }> {
   const backend = new TraceBackend(file);
   const traceModel = new TraceModel();
   await traceModel.load(backend, () => {});

tests/library/trace-viewer.spec.ts

@@ -911,6 +911,18 @@ test('should open trace-1.31', async ({ showTraceViewer }) => {
   await expect(snapshot.locator('[__playwright_target__]')).toHaveText(['Submit']);
 });
 
+test('should open trace-1.37', async ({ showTraceViewer }) => {
+  const traceViewer = await showTraceViewer([path.join(__dirname, '../assets/trace-1.37.zip')]);
+  const snapshot = await traceViewer.snapshotFrame('page.goto');
+  await expect(snapshot.locator('div')).toHaveCSS('background-color', 'rgb(255, 0, 0)');
+
+  await traceViewer.showConsoleTab();
+  await expect(traceViewer.consoleLineMessages).toHaveText(['hello {foo: bar}']);
+
+  await traceViewer.showNetworkTab();
+  await expect(traceViewer.networkRequests).toContainText([/200GET\/index.htmltext\/html/, /200GET\/style.cssx-unknown/]);
+});
+
 test('should prefer later resource request with the same method', async ({ page, server, runAndTrace }) => {
   const html = `
     <body>

tests/library/tracing.spec.ts

@@ -739,7 +739,7 @@ test('should flush console events on tracing stop', async ({ context, page }, te
   const tracePath = testInfo.outputPath('trace.zip');
   await context.tracing.stop({ path: tracePath });
   const trace = await parseTraceRaw(tracePath);
-  const events = trace.events.filter(e => e.method === 'console');
+  const events = trace.events.filter(e => e.type === 'console');
   expect(events).toHaveLength(100);
 });