feat(ui): show test trace events live (#26619)

packages/playwright-core/src/utils/traceUtils.ts

@@ -16,13 +16,10 @@
 
 import fs from 'fs';
 import type EventEmitter from 'events';
-import type { ClientSideCallMetadata, SerializedError, StackFrame } from '@protocol/channels';
+import type { ClientSideCallMetadata } from '@protocol/channels';
 import type { SerializedClientSideCallMetadata, SerializedStack, SerializedStackFrame } from './isomorphic/traceUtils';
 import { yazl, yauzl } from '../zipBundle';
 import { ManualPromise } from './manualPromise';
-import type { AfterActionTraceEvent, BeforeActionTraceEvent, TraceEvent } from '@trace/trace';
-import { calculateSha1 } from './crypto';
-import { monotonicTime } from './time';
 
 export function serializeClientSideCallMetadata(metadatas: ClientSideCallMetadata[]): SerializedClientSideCallMetadata {
   const fileNames = new Map<string, number>();
@@ -95,102 +92,3 @@ export async function mergeTraceFiles(fileName: string, temporaryTraceFiles: str
   });
   await mergePromise;
 }
-
-export async function saveTraceFile(fileName: string, traceEvents: TraceEvent[], saveSources: boolean) {
-  const zipFile = new yazl.ZipFile();
-
-  if (saveSources) {
-    const sourceFiles = new Set<string>();
-    for (const event of traceEvents) {
-      if (event.type === 'before') {
-        for (const frame of event.stack || [])
-          sourceFiles.add(frame.file);
-      }
-    }
-    for (const sourceFile of sourceFiles) {
-      await fs.promises.readFile(sourceFile, 'utf8').then(source => {
-        zipFile.addBuffer(Buffer.from(source), 'resources/src@' + calculateSha1(sourceFile) + '.txt');
-      }).catch(() => {});
-    }
-  }
-
-  const sha1s = new Set<string>();
-  for (const event of traceEvents.filter(e => e.type === 'after') as AfterActionTraceEvent[]) {
-    for (const attachment of (event.attachments || [])) {
-      let contentPromise: Promise<Buffer | undefined> | undefined;
-      if (attachment.path)
-        contentPromise = fs.promises.readFile(attachment.path).catch(() => undefined);
-      else if (attachment.base64)
-        contentPromise = Promise.resolve(Buffer.from(attachment.base64, 'base64'));
-
-      const content = await contentPromise;
-      if (content === undefined)
-        continue;
-
-      const sha1 = calculateSha1(content);
-      attachment.sha1 = sha1;
-      delete attachment.path;
-      delete attachment.base64;
-      if (sha1s.has(sha1))
-        continue;
-      sha1s.add(sha1);
-      zipFile.addBuffer(content, 'resources/' + sha1);
-    }
-  }
-
-  const traceContent = Buffer.from(traceEvents.map(e => JSON.stringify(e)).join('\n'));
-  zipFile.addBuffer(traceContent, 'trace.trace');
-
-  await new Promise(f => {
-    zipFile.end(undefined, () => {
-      zipFile.outputStream.pipe(fs.createWriteStream(fileName)).on('close', f);
-    });
-  });
-}
-
-export function createBeforeActionTraceEventForStep(callId: string, parentId: string | undefined, apiName: string, params: Record<string, any> | undefined, wallTime: number, stack: StackFrame[]): BeforeActionTraceEvent {
-  return {
-    type: 'before',
-    callId,
-    parentId,
-    wallTime,
-    startTime: monotonicTime(),
-    class: 'Test',
-    method: 'step',
-    apiName,
-    params: Object.fromEntries(Object.entries(params || {}).map(([name, value]) => [name, generatePreview(value)])),
-    stack,
-  };
-}
-
-export function createAfterActionTraceEventForStep(callId: string, attachments: AfterActionTraceEvent['attachments'], error?: SerializedError['error']): AfterActionTraceEvent {
-  return {
-    type: 'after',
-    callId,
-    endTime: monotonicTime(),
-    log: [],
-    attachments,
-    error,
-  };
-}
-
-function generatePreview(value: any, visited = new Set<any>()): string {
-  if (visited.has(value))
-    return '';
-  visited.add(value);
-  if (typeof value === 'string')
-    return value;
-  if (typeof value === 'number')
-    return value.toString();
-  if (typeof value === 'boolean')
-    return value.toString();
-  if (value === null)
-    return 'null';
-  if (value === undefined)
-    return 'undefined';
-  if (Array.isArray(value))
-    return '[' + value.map(v => generatePreview(v, visited)).join(', ') + ']';
-  if (typeof value === 'object')
-    return 'Object';
-  return String(value);
-}

packages/playwright-test/src/index.ts

@@ -18,7 +18,7 @@ import * as fs from 'fs';
 import * as path from 'path';
 import type { APIRequestContext, BrowserContext, Browser, BrowserContextOptions, LaunchOptions, Page, Tracing, Video } from 'playwright-core';
 import * as playwrightLibrary from 'playwright-core';
-import { createGuid, debugMode, addInternalStackPrefix, mergeTraceFiles, saveTraceFile, isString, asLocator, jsonStringifyForceASCII } from 'playwright-core/lib/utils';
+import { createGuid, debugMode, addInternalStackPrefix, mergeTraceFiles, isString, asLocator, jsonStringifyForceASCII } from 'playwright-core/lib/utils';
 import type { Fixtures, PlaywrightTestArgs, PlaywrightTestOptions, PlaywrightWorkerArgs, PlaywrightWorkerOptions, ScreenshotMode, TestInfo, TestType, TraceMode, VideoMode } from '../types/test';
 import type { TestInfoImpl } from './worker/testInfo';
 import { rootTestType } from './common/testType';
@@ -541,6 +541,8 @@ class ArtifactsRecorder {
     this._testInfo = testInfo;
     testInfo._onDidFinishTestFunction = () => this.didFinishTestFunction();
     this._captureTrace = shouldCaptureTrace(this._traceMode, testInfo) && !process.env.PW_TEST_DISABLE_TRACING;
+    if (this._captureTrace)
+      this._testInfo._tracing.start(path.join(this._artifactsDir, 'traces', `${this._testInfo.testId}-test.trace`), this._traceOptions);
 
     // Since beforeAll(s), test and afterAll(s) reuse the same TestInfo, make sure we do not
     // overwrite previous screenshots.
@@ -644,18 +646,9 @@ class ArtifactsRecorder {
 
     // Collect test trace.
     if (this._preserveTrace()) {
-      const events = this._testInfo._traceEvents;
+      const tracePath = path.join(this._artifactsDir, createGuid() + '.zip');
-      if (events.length) {
+      this._temporaryTraceFiles.push(tracePath);
-        if (!this._traceOptions.attachments) {
+      await this._testInfo._tracing.stop(tracePath);
-          for (const event of events) {
-            if (event.type === 'after')
-              delete event.attachments;
-          }
-        }
-        const tracePath = path.join(this._artifactsDir, createGuid() + '.zip');
-        this._temporaryTraceFiles.push(tracePath);
-        await saveTraceFile(tracePath, events, this._traceOptions.sources);
-      }
     }
 
     // Either remove or attach temporary traces for contexts closed before the

packages/playwright-test/src/worker/testInfo.ts

@@ -16,7 +16,7 @@
 
 import fs from 'fs';
 import path from 'path';
-import { MaxTime, captureRawStack, createAfterActionTraceEventForStep, createBeforeActionTraceEventForStep, monotonicTime, zones, sanitizeForFilePath } from 'playwright-core/lib/utils';
+import { MaxTime, captureRawStack, monotonicTime, zones, sanitizeForFilePath } from 'playwright-core/lib/utils';
 import type { TestInfoError, TestInfo, TestStatus, FullProject, FullConfig } from '../../types/test';
 import type { AttachmentPayload, StepBeginPayload, StepEndPayload, WorkerInitParams } from '../common/ipc';
 import type { TestCase } from '../common/test';
@@ -24,7 +24,7 @@ import { TimeoutManager } from './timeoutManager';
 import type { Annotation, FullConfigInternal, FullProjectInternal } from '../common/config';
 import type { Location } from '../../types/testReporter';
 import { getContainedPath, normalizeAndSaveAttachment, serializeError, trimLongString } from '../util';
-import type * as trace from '@trace/trace';
+import { TestTracing } from './testTracing';
 
 export interface TestStepInternal {
   complete(result: { error?: Error | TestInfoError }): void;
@@ -51,7 +51,8 @@ export class TestInfoImpl implements TestInfo {
   readonly _startTime: number;
   readonly _startWallTime: number;
   private _hasHardError: boolean = false;
-  readonly _traceEvents: trace.TraceEvent[] = [];
+  readonly _tracing = new TestTracing();
+
   _didTimeout = false;
   _wasInterrupted = false;
   _lastStepId = 0;
@@ -87,7 +88,7 @@ export class TestInfoImpl implements TestInfo {
   readonly outputDir: string;
   readonly snapshotDir: string;
   errors: TestInfoError[] = [];
-  private _attachmentsPush: (...items: TestInfo['attachments']) => number;
+  readonly _attachmentsPush: (...items: TestInfo['attachments']) => number;
 
   get error(): TestInfoError | undefined {
     return this.errors[0];
@@ -303,7 +304,7 @@ export class TestInfoImpl implements TestInfo {
         };
         this._onStepEnd(payload);
         const errorForTrace = error ? { name: '', message: error.message || '', stack: error.stack } : undefined;
-        this._traceEvents.push(createAfterActionTraceEventForStep(stepId, serializeAttachments(this.attachments, initialAttachments), errorForTrace));
+        this._tracing.appendAfterActionForStep(stepId, this.attachments, initialAttachments, errorForTrace);
       }
     };
     const parentStepList = parentStep ? parentStep.steps : this._steps;
@@ -321,19 +322,10 @@ export class TestInfoImpl implements TestInfo {
       location,
     };
     this._onStepBegin(payload);
-    this._traceEvents.push(createBeforeActionTraceEventForStep(stepId, parentStep?.stepId, data.apiName || data.title, data.params, data.wallTime, data.location ? [data.location] : []));
+    this._tracing.appendBeforeActionForStep(stepId, parentStep?.stepId, data.apiName || data.title, data.params, data.wallTime, data.location ? [data.location] : []);
     return step;
   }
 
-  _appendStdioToTrace(type: 'stdout' | 'stderr', chunk: string | Buffer) {
-    this._traceEvents.push({
-      type,
-      timestamp: monotonicTime(),
-      text: typeof chunk === 'string' ? chunk : undefined,
-      base64: typeof chunk === 'string' ? undefined : chunk.toString('base64'),
-    });
-  }
-
   _interrupt() {
     // Mark as interrupted so we can ignore TimeoutError thrown by interrupt() call.
     this._wasInterrupted = true;
@@ -466,16 +458,5 @@ export class TestInfoImpl implements TestInfo {
   }
 }
 
-function serializeAttachments(attachments: TestInfo['attachments'], initialAttachments: Set<TestInfo['attachments'][0]>): trace.AfterActionTraceEvent['attachments'] {
-  return attachments.filter(a => a.name !== 'trace' && !initialAttachments.has(a)).map(a => {
-    return {
-      name: a.name,
-      contentType: a.contentType,
-      path: a.path,
-      base64: a.body?.toString('base64'),
-    };
-  });
-}
-
 class SkipError extends Error {
 }

packages/playwright-test/src/worker/testTracing.ts

@@ -0,0 +1,173 @@
+/**
+ * Copyright Microsoft Corporation. All rights reserved.
+ *
+ * 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 fs from 'fs';
+import path from 'path';
+import type { SerializedError, StackFrame } from '@protocol/channels';
+import type * as trace from '@trace/trace';
+import { calculateSha1, monotonicTime } from 'playwright-core/lib/utils';
+import type { TestInfo } from '../../types/test';
+import { yazl } from 'playwright-core/lib/zipBundle';
+
+type Attachment = TestInfo['attachments'][0];
+
+export class TestTracing {
+  private _liveTraceFile: string | undefined;
+  private _traceEvents: trace.TraceEvent[] = [];
+  private _options: { sources: boolean; attachments: boolean; _live: boolean; } | undefined;
+
+  start(liveFileName: string, options: { sources: boolean, attachments: boolean, _live: boolean }) {
+    this._options = options;
+    if (options._live) {
+      this._liveTraceFile = liveFileName;
+      fs.mkdirSync(path.dirname(this._liveTraceFile), { recursive: true });
+      const data = this._traceEvents.map(e => JSON.stringify(e)).join('\n') + '\n';
+      fs.writeFileSync(this._liveTraceFile, data);
+    }
+  }
+
+  async stop(fileName: string) {
+    const zipFile = new yazl.ZipFile();
+
+    if (!this._options?.attachments) {
+      for (const event of this._traceEvents) {
+        if (event.type === 'after')
+          delete event.attachments;
+      }
+    }
+
+    if (this._options?.sources) {
+      const sourceFiles = new Set<string>();
+      for (const event of this._traceEvents) {
+        if (event.type === 'before') {
+          for (const frame of event.stack || [])
+            sourceFiles.add(frame.file);
+        }
+      }
+      for (const sourceFile of sourceFiles) {
+        await fs.promises.readFile(sourceFile, 'utf8').then(source => {
+          zipFile.addBuffer(Buffer.from(source), 'resources/src@' + calculateSha1(sourceFile) + '.txt');
+        }).catch(() => {});
+      }
+    }
+
+    const sha1s = new Set<string>();
+    for (const event of this._traceEvents.filter(e => e.type === 'after') as trace.AfterActionTraceEvent[]) {
+      for (const attachment of (event.attachments || [])) {
+        let contentPromise: Promise<Buffer | undefined> | undefined;
+        if (attachment.path)
+          contentPromise = fs.promises.readFile(attachment.path).catch(() => undefined);
+        else if (attachment.base64)
+          contentPromise = Promise.resolve(Buffer.from(attachment.base64, 'base64'));
+
+        const content = await contentPromise;
+        if (content === undefined)
+          continue;
+
+        const sha1 = calculateSha1(content);
+        attachment.sha1 = sha1;
+        delete attachment.path;
+        delete attachment.base64;
+        if (sha1s.has(sha1))
+          continue;
+        sha1s.add(sha1);
+        zipFile.addBuffer(content, 'resources/' + sha1);
+      }
+    }
+
+    const traceContent = Buffer.from(this._traceEvents.map(e => JSON.stringify(e)).join('\n'));
+    zipFile.addBuffer(traceContent, 'trace.trace');
+
+    await new Promise(f => {
+      zipFile.end(undefined, () => {
+        zipFile.outputStream.pipe(fs.createWriteStream(fileName)).on('close', f);
+      });
+    });
+  }
+
+  appendStdioToTrace(type: 'stdout' | 'stderr', chunk: string | Buffer) {
+    this._appendTraceEvent({
+      type,
+      timestamp: monotonicTime(),
+      text: typeof chunk === 'string' ? chunk : undefined,
+      base64: typeof chunk === 'string' ? undefined : chunk.toString('base64'),
+    });
+  }
+
+  appendBeforeActionForStep(callId: string, parentId: string | undefined, apiName: string, params: Record<string, any> | undefined, wallTime: number, stack: StackFrame[]) {
+    this._appendTraceEvent({
+      type: 'before',
+      callId,
+      parentId,
+      wallTime,
+      startTime: monotonicTime(),
+      class: 'Test',
+      method: 'step',
+      apiName,
+      params: Object.fromEntries(Object.entries(params || {}).map(([name, value]) => [name, generatePreview(value)])),
+      stack,
+    });
+  }
+
+  appendAfterActionForStep(callId: string, attachments: Attachment[], initialAttachments: Set<Attachment>, error?: SerializedError['error']) {
+    this._appendTraceEvent({
+      type: 'after',
+      callId,
+      endTime: monotonicTime(),
+      log: [],
+      attachments: serializeAttachments(attachments, initialAttachments),
+      error,
+    });
+  }
+
+  private _appendTraceEvent(event: trace.TraceEvent) {
+    this._traceEvents.push(event);
+    if (this._liveTraceFile)
+      fs.appendFileSync(this._liveTraceFile, JSON.stringify(event) + '\n');
+  }
+}
+
+function serializeAttachments(attachments: Attachment[], initialAttachments: Set<Attachment>): trace.AfterActionTraceEvent['attachments'] {
+  return attachments.filter(a => a.name !== 'trace' && !initialAttachments.has(a)).map(a => {
+    return {
+      name: a.name,
+      contentType: a.contentType,
+      path: a.path,
+      base64: a.body?.toString('base64'),
+    };
+  });
+}
+
+function generatePreview(value: any, visited = new Set<any>()): string {
+  if (visited.has(value))
+    return '';
+  visited.add(value);
+  if (typeof value === 'string')
+    return value;
+  if (typeof value === 'number')
+    return value.toString();
+  if (typeof value === 'boolean')
+    return value.toString();
+  if (value === null)
+    return 'null';
+  if (value === undefined)
+    return 'undefined';
+  if (Array.isArray(value))
+    return '[' + value.map(v => generatePreview(v, visited)).join(', ') + ']';
+  if (typeof value === 'object')
+    return 'Object';
+  return String(value);
+}

packages/playwright-test/src/worker/workerMain.ts

@@ -80,7 +80,7 @@ export class WorkerMain extends ProcessRunner {
         ...chunkToParams(chunk)
       };
       this.dispatchEvent('stdOut', outPayload);
-      this._currentTest?._appendStdioToTrace('stdout', chunk);
+      this._currentTest?._tracing.appendStdioToTrace('stdout', chunk);
       return true;
     };
 
@@ -90,7 +90,7 @@ export class WorkerMain extends ProcessRunner {
           ...chunkToParams(chunk)
         };
         this.dispatchEvent('stdErr', outPayload);
-        this._currentTest?._appendStdioToTrace('stderr', chunk);
+        this._currentTest?._tracing.appendStdioToTrace('stderr', chunk);
         return true;
       };
     }

packages/trace-viewer/src/ui/filmStrip.css

@@ -28,7 +28,8 @@
   position: relative;
   min-height: 50px;
   max-height: 200px;
-  overflow: auto;
+  overflow-x: hidden;
+  overflow-y: auto;
 }
 
 .film-strip-lane {

packages/trace-viewer/src/ui/snapshotTab.css

@@ -20,7 +20,7 @@
   flex-direction: column;
   align-items: stretch;
   outline: none;
-  --window-header-height: 40px;
+  --browser-frame-header-height: 40px;
   overflow: hidden;
 }
 
@@ -78,7 +78,7 @@
 
 .snapshot-switcher {
   width: 100%;
-  height: calc(100% - var(--window-header-height));
+  height: calc(100% - var(--browser-frame-header-height));
   position: relative;
 }
 

tests/playwright-test/ui-mode-test-output.spec.ts

@@ -164,6 +164,7 @@ test('should stream console messages live', async ({ runUITest }, testInfo) => {
         await button.evaluate(node => node.addEventListener('click', () => {
           setTimeout(() => { console.log('I was clicked'); }, 1000);
         }));
+        console.log('I was logged');
         await button.click();
         await page.locator('#not-there').waitFor();
       });
@@ -174,6 +175,7 @@ test('should stream console messages live', async ({ runUITest }, testInfo) => {
   await page.getByText('print').click();
 
   await expect(page.locator('.console-tab .console-line-message')).toHaveText([
+    'I was logged',
     'I was clicked',
   ]);
   await page.getByTitle('Stop').click();

tests/playwright-test/ui-mode-test-progress.spec.ts

@@ -52,7 +52,7 @@ test('should update trace live', async ({ runUITest, server }) => {
       listItem,
       'action list'
   ).toHaveText([
-    /browserContext.newPage[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
     /page.gotohttp:\/\/localhost:\d+\/one.html/
   ]);
 
@@ -78,7 +78,7 @@ test('should update trace live', async ({ runUITest, server }) => {
       'verify snapshot'
   ).toHaveText('One');
   await expect(listItem).toHaveText([
-    /browserContext.newPage[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
     /page.gotohttp:\/\/localhost:\d+\/one.html[\d.]+m?s/,
     /page.gotohttp:\/\/localhost:\d+\/two.html/
   ]);
@@ -139,7 +139,7 @@ test('should preserve action list selection upon live trace update', async ({ ru
       listItem,
       'action list'
   ).toHaveText([
-    /browserContext.newPage[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
     /page.gotoabout:blank[\d.]+m?s/,
     /page.setContent[\d.]+m?s/,
   ]);
@@ -153,7 +153,7 @@ test('should preserve action list selection upon live trace update', async ({ ru
       listItem,
       'action list'
   ).toHaveText([
-    /browserContext.newPage[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
     /page.gotoabout:blank[\d.]+m?s/,
     /page.setContent[\d.]+m?s/,
     /page.setContent[\d.]+m?s/,
@@ -200,7 +200,7 @@ test('should update tracing network live', async ({ runUITest, server }) => {
       listItem,
       'action list'
   ).toHaveText([
-    /browserContext.newPage[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
     /page.gotohttp:\/\/localhost:\d+\/one.html[\d.]+m?s/,
     /page.setContent[\d.]+m?s/,
   ]);
@@ -240,15 +240,13 @@ test('should show trace w/ multiple contexts', async ({ runUITest, server, creat
       listItem,
       'action list'
   ).toHaveText([
-    /apiRequestContext.get[\d.]+m?s/,
+    /Before Hooks[\d.]+m?s/,
-    /browserContext.newPage[\d.]+m?s/,
     /page.gotoabout:blank[\d.]+m?s/,
   ]);
 
   latch.open();
 });
 
-
 test('should show live trace for serial', async ({ runUITest, server, createLatch }) => {
   const latch = createLatch();
 
@@ -287,6 +285,7 @@ test('should show live trace for serial', async ({ runUITest, server, createLatc
       listItem,
       'action list'
   ).toHaveText([
+    /Before Hooks[\d.]+m?s/,
     /locator.unchecklocator\('input'\)[\d.]+m?s/,
     /expect.not.toBeCheckedlocator\('input'\)[\d.]/,
   ]);