chore(trace): include expect steps in a trace (#21199)

package-lock.json

@@ -1945,8 +1945,8 @@
     },
     "node_modules/ansi-to-html": {
       "version": "0.7.2",
-      "dev": true,
-      "license": "MIT",
+      "resolved": "https://registry.npmjs.org/ansi-to-html/-/ansi-to-html-0.7.2.tgz",
+      "integrity": "sha512-v6MqmEpNlxF+POuyhKkidusCHWWkaLcGRURzivcU3I9tv7k4JVhFcnukrM5Rlk2rUywdZuzYAZ+kbZqWCnfN3g==",
       "dependencies": {
         "entities": "^2.2.0"
       },
@@ -2753,7 +2753,6 @@
     },
     "node_modules/entities": {
       "version": "2.2.0",
-      "dev": true,
       "license": "BSD-2-Clause",
       "funding": {
         "url": "https://github.com/fb55/entities?sponsor=1"
@@ -5932,7 +5931,10 @@
       }
     },
     "packages/html-reporter": {
-      "version": "0.0.0"
+      "version": "0.0.0",
+      "dependencies": {
+        "ansi-to-html": "^0.7.2"
+      }
     },
     "packages/playwright": {
       "version": "1.32.0-next",
@@ -6167,7 +6169,10 @@
       "version": "0.0.0"
     },
     "packages/trace-viewer": {
-      "version": "0.0.0"
+      "version": "0.0.0",
+      "dependencies": {
+        "ansi-to-html": "^0.7.2"
+      }
     }
   },
   "dependencies": {
@@ -7421,7 +7426,8 @@
     },
     "ansi-to-html": {
       "version": "0.7.2",
-      "dev": true,
+      "resolved": "https://registry.npmjs.org/ansi-to-html/-/ansi-to-html-0.7.2.tgz",
+      "integrity": "sha512-v6MqmEpNlxF+POuyhKkidusCHWWkaLcGRURzivcU3I9tv7k4JVhFcnukrM5Rlk2rUywdZuzYAZ+kbZqWCnfN3g==",
       "requires": {
         "entities": "^2.2.0"
       }
@@ -7963,8 +7969,7 @@
       }
     },
     "entities": {
-      "version": "2.2.0",
-      "dev": true
+      "version": "2.2.0"
     },
     "env-paths": {
       "version": "2.2.1",
@@ -8640,7 +8645,10 @@
       "integrity": "sha512-c3Ab/url5ksaT0WyleslpBEthOzWhrjQbg75y7XUsfSzi3Dgzt0l8w5e7DylRn15MTlMMD58dTfzddNS2kcAjQ=="
     },
     "html-reporter": {
-      "version": "file:packages/html-reporter"
+      "version": "file:packages/html-reporter",
+      "requires": {
+        "ansi-to-html": "*"
+      }
     },
     "http-cache-semantics": {
       "version": "4.1.1",
@@ -9647,7 +9655,10 @@
       }
     },
     "trace-viewer": {
-      "version": "file:packages/trace-viewer"
+      "version": "file:packages/trace-viewer",
+      "requires": {
+        "ansi-to-html": "^0.7.2"
+      }
     },
     "tree-kill": {
       "version": "1.2.2",

packages/html-reporter/package.json

@@ -6,5 +6,8 @@
     "dev": "vite",
     "build": "vite build && tsc",
     "preview": "vite preview"
+  },
+  "dependencies": {
+    "ansi-to-html": "^0.7.2"
   }
 }

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

@@ -16,10 +16,13 @@
 
 import fs from 'fs';
 import type EventEmitter from 'events';
-import type { ClientSideCallMetadata } from '@protocol/channels';
+import type { ClientSideCallMetadata, StackFrame } from '@protocol/channels';
 import type { SerializedClientSideCallMetadata, SerializedStack, SerializedStackFrame } from '@trace/traceUtils';
 import { yazl, yauzl } from '../zipBundle';
 import { ManualPromise } from './manualPromise';
+import type { ActionTraceEvent } from '@trace/trace';
+import { calculateSha1 } from './crypto';
+import { monotonicTime } from './time';
 
 export function serializeClientSideCallMetadata(metadatas: ClientSideCallMetadata[]): SerializedClientSideCallMetadata {
   const fileNames = new Map<string, number>();
@@ -92,3 +95,65 @@ export async function mergeTraceFiles(fileName: string, temporaryTraceFiles: str
   });
   await mergePromise;
 }
+
+export async function saveTraceFile(fileName: string, traceEvents: ActionTraceEvent[], saveSources: boolean) {
+  const lines: string[] = traceEvents.map(e => JSON.stringify(e));
+  const zipFile = new yazl.ZipFile();
+  zipFile.addBuffer(Buffer.from(lines.join('\n')), 'trace.trace');
+
+  if (saveSources) {
+    const sourceFiles = new Set<string>();
+    for (const event of traceEvents) {
+      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(() => {});
+    }
+  }
+  await new Promise(f => {
+    zipFile.end(undefined, () => {
+      zipFile.outputStream.pipe(fs.createWriteStream(fileName)).on('close', f);
+    });
+  });
+}
+
+export function createTraceEventForExpect(apiName: string, expected: any, stack: StackFrame[], wallTime: number): ActionTraceEvent {
+  return {
+    type: 'action',
+    callId: 'expect@' + wallTime,
+    wallTime,
+    startTime: monotonicTime(),
+    endTime: 0,
+    class: 'Test',
+    method: 'step',
+    apiName,
+    params: { expected: generatePreview(expected) },
+    snapshots: [],
+    log: [],
+    stack,
+  };
+}
+
+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, BrowserContextOptions, LaunchOptions, Page, Tracing, Video } from 'playwright-core';
 import * as playwrightLibrary from 'playwright-core';
-import { createGuid, debugMode, removeFolders, addInternalStackPrefix, mergeTraceFiles } from 'playwright-core/lib/utils';
+import { createGuid, debugMode, removeFolders, addInternalStackPrefix, mergeTraceFiles, saveTraceFile } 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';
@@ -426,7 +426,18 @@ const playwrightFixtures: Fixtures<TestFixtures, WorkerFixtures> = ({
       await stopTracing(tracing);
     })));
 
-    // 6. Either remove or attach temporary traces and screenshots for contexts closed
+
+    // 6. Save test trace.
+    if (preserveTrace) {
+      const events = (testInfo as any)._traceEvents;
+      if (events.length) {
+        const tracePath = path.join(_artifactsDir(), createGuid() + '.zip');
+        temporaryTraceFiles.push(tracePath);
+        await saveTraceFile(tracePath, events, traceOptions.sources);
+      }
+    }
+
+    // 7. Either remove or attach temporary traces and screenshots for contexts closed
     // before the test has finished.
     if (preserveTrace && temporaryTraceFiles.length) {
       const tracePath = testInfo.outputPath(`trace.zip`);

packages/playwright-test/src/matchers/expect.ts

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-import { captureRawStack, pollAgainstTimeout } from 'playwright-core/lib/utils';
+import { captureRawStack, createTraceEventForExpect, monotonicTime, pollAgainstTimeout } from 'playwright-core/lib/utils';
 import type { ExpectZone } from 'playwright-core/lib/utils';
 import {
   toBeChecked,
@@ -214,6 +214,11 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler<any> {
       });
       testInfo.currentStep = step;
 
+      const generateTraceEvent = matcherName !== 'poll' && matcherName !== 'toPass';
+      const traceEvent = generateTraceEvent ? createTraceEventForExpect(defaultTitle, args[0], stackFrames, wallTime) : undefined;
+      if (traceEvent)
+        testInfo._traceEvents.push(traceEvent);
+
       const reportStepError = (jestError: Error) => {
         const message = jestError.message;
         if (customMessage) {
@@ -238,22 +243,32 @@ class ExpectMetaInfoProxyHandler implements ProxyHandler<any> {
         }
 
         const serializerError = serializeError(jestError);
-        step.complete({ error: serializerError });
+        if (traceEvent) {
+          traceEvent.error = { name: jestError.name, message: jestError.message, stack: jestError.stack };
+          traceEvent.endTime = monotonicTime();
+          step.complete({ error: serializerError });
+        }
         if (this._info.isSoft)
           testInfo._failWithError(serializerError, false /* isHardError */);
         else
           throw jestError;
       };
 
+      const finalizer = () => {
+        if (traceEvent)
+          traceEvent.endTime = monotonicTime();
+        step.complete({});
+      };
+
       try {
         const expectZone: ExpectZone = { title: defaultTitle, wallTime };
         const result = zones.run<ExpectZone, any>('expectZone', expectZone, () => {
           return matcher.call(target, ...args);
         });
         if (result instanceof Promise)
-          return result.then(() => step.complete({})).catch(reportStepError);
+          return result.then(() => finalizer()).catch(reportStepError);
         else
-          step.complete({});
+          finalizer();
       } catch (e) {
         reportStepError(e);
       }

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

@@ -23,6 +23,7 @@ import type { TestCase } from '../common/test';
 import { TimeoutManager } from './timeoutManager';
 import type { Annotation, FullConfigInternal, FullProjectInternal, Location } from '../common/types';
 import { getContainedPath, normalizeAndSaveAttachment, sanitizeForFilePath, serializeError, trimLongString } from '../util';
+import type * as trace from '@trace/trace';
 
 export type TestInfoErrorState = {
   status: TestStatus,
@@ -49,6 +50,7 @@ export class TestInfoImpl implements TestInfo {
   readonly _startTime: number;
   readonly _startWallTime: number;
   private _hasHardError: boolean = false;
+  readonly _traceEvents: trace.TraceEvent[] = [];
   readonly _onTestFailureImmediateCallbacks = new Map<() => Promise<void>, string>(); // fn -> title
   _didTimeout = false;
   _lastStepId = 0;

packages/trace-viewer/package.json

@@ -7,5 +7,8 @@
     "build": "vite build && tsc",
     "build-sw": "vite --config vite.sw.config.ts build && tsc",
     "preview": "vite preview"
+  },
+  "dependencies": {
+    "ansi-to-html": "^0.7.2"
   }
 }

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

@@ -14,6 +14,7 @@
  * limitations under the License.
  */
 
+import ansi2html from 'ansi-to-html';
 import type { SerializedValue } from '@protocol/channels';
 import type { ActionTraceEvent } from '@trace/trace';
 import { msToString } from '@web/uiUtils';
@@ -38,10 +39,8 @@ export const CallTab: React.FunctionComponent<{
   const wallTime = action.wallTime ? new Date(action.wallTime).toLocaleString() : null;
   const duration = action.endTime ? msToString(action.endTime - action.startTime) : 'Timed Out';
   return <div className='call-tab'>
-    <div className='call-error' key='error' hidden={!error}>
-      <div className='codicon codicon-issues'/>
-      {error}
-    </div>
+    {!!error && <ErrorMessage error={error}></ErrorMessage>}
+    {!!error && <div className='call-section'>Call</div>}
     <div className='call-line'>{action.apiName}</div>
     {<>
       <div className='call-section'>Time</div>
@@ -145,3 +144,40 @@ function parseSerializedValue(value: SerializedValue, handles: any[] | undefined
   }
   return '<object>';
 }
+
+const ErrorMessage: React.FC<{
+  error: string;
+}> = ({ error }) => {
+  const html = React.useMemo(() => {
+    const config: any = {
+      bg: 'var(--vscode-panel-background)',
+      fg: 'var(--vscode-foreground)',
+    };
+    config.colors = ansiColors;
+    return new ansi2html(config).toHtml(escapeHTML(error));
+  }, [error]);
+  return <div className='call-error-message' dangerouslySetInnerHTML={{ __html: html || '' }}></div>;
+};
+
+const ansiColors = {
+  0: '#000',
+  1: '#C00',
+  2: '#0C0',
+  3: '#C50',
+  4: '#00C',
+  5: '#C0C',
+  6: '#0CC',
+  7: '#CCC',
+  8: '#555',
+  9: '#F55',
+  10: '#5F5',
+  11: '#FF5',
+  12: '#55F',
+  13: '#F5F',
+  14: '#5FF',
+  15: '#FFF'
+};
+
+function escapeHTML(text: string): string {
+  return text.replace(/[&"<>]/g, c => ({ '&': '&amp;', '"': '&quot;', '<': '&lt;', '>': '&gt;' }[c]!));
+}

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

@@ -59,6 +59,7 @@ export class MultiTraceModel {
 
     this.actions.sort((a1, a2) => a1.startTime - a2.startTime);
     this.events.sort((a1, a2) => a1.time - a2.time);
+    this.actions = dedupeActions(this.actions);
   }
 }
 
@@ -74,6 +75,39 @@ function indexModel(context: ContextEntry) {
     (event as any)[contextSymbol] = context;
 }
 
+function dedupeActions(actions: ActionTraceEvent[]) {
+  const callActions = actions.filter(a => a.callId.startsWith('call@'));
+  const expectActions = actions.filter(a => a.callId.startsWith('expect@'));
+
+  // Call startTime/endTime are server-side times.
+  // Expect startTime/endTime are client-side times.
+  // If there are call times, adjust expect startTime/endTime to align with callTime.
+  if (callActions.length && expectActions.length) {
+    const offset = callActions[0].startTime - callActions[0].wallTime!;
+    for (const expectAction of expectActions) {
+      const duration = expectAction.endTime - expectAction.startTime;
+      expectAction.startTime = expectAction.wallTime! + offset;
+      expectAction.endTime = expectAction.startTime + duration;
+    }
+  }
+  const callActionsByKey = new Map<string, ActionTraceEvent>();
+  for (const action of callActions)
+    callActionsByKey.set(action.apiName + '@' + action.wallTime, action);
+
+  const result = [...callActions];
+  for (const expectAction of expectActions) {
+    const callAction = callActionsByKey.get(expectAction.apiName + '@' + expectAction.wallTime);
+    if (callAction) {
+      if (expectAction.error)
+        callAction.error = expectAction.error;
+      continue;
+    }
+    result.push(expectAction);
+  }
+
+  return result.sort((a1, a2) => a1.startTime - a2.startTime);
+}
+
 export function context(action: ActionTraceEvent): ContextEntry {
   return (action as any)[contextSymbol];
 }

tests/playwright-test/playwright.reuse.spec.ts

@@ -154,12 +154,12 @@ test('should reuse context with trace if mode=when-possible', async ({ runInline
 
   const trace2 = await parseTrace(testInfo.outputPath('test-results', 'reuse-two', 'trace.zip'));
   expect(trace2.actions).toEqual([
+    'expect.toBe',
     'page.setContent',
     'page.fill',
     'locator.click',
   ]);
   expect(trace2.events.some(e => e.type === 'frame-snapshot')).toBe(true);
-  expect(fs.existsSync(testInfo.outputPath('test-results', 'reuse-two', 'trace-1.zip'))).toBe(false);
 });
 
 test('should work with manually closed pages', async ({ runInlineTest }) => {

tests/playwright-test/playwright.trace.spec.ts

@@ -89,7 +89,7 @@ test('should record api trace', async ({ runInlineTest, server }, testInfo) => {
   const trace2 = await parseTrace(testInfo.outputPath('test-results', 'a-api-pass', 'trace.zip'));
   expect(trace2.actions).toEqual(['apiRequestContext.get']);
   const trace3 = await parseTrace(testInfo.outputPath('test-results', 'a-fail', 'trace.zip'));
-  expect(trace3.actions).toEqual(['browserContext.newPage', 'page.goto', 'apiRequestContext.get']);
+  expect(trace3.actions).toEqual(['browserContext.newPage', 'page.goto', 'apiRequestContext.get', 'expect.toBe']);
 });