fix(trace): do not allow after w/o before (#24106)

Fixes https://github.com/microsoft/playwright/issues/24087,
https://github.com/microsoft/playwright/issues/23802

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

@@ -62,6 +62,7 @@ type RecordingState = {
   networkSha1s: Set<string>,
   traceSha1s: Set<string>,
   recording: boolean;
+  callIds: Set<string>;
 };
 
 const kScreencastOptions = { width: 800, height: 600, quality: 90 };
@@ -146,7 +147,8 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
       chunkOrdinal: 0,
       traceSha1s: new Set(),
       networkSha1s: new Set(),
-      recording: false
+      recording: false,
+      callIds: new Set(),
     };
     const state = this._state;
     this._writeChain = fs.promises.mkdir(state.resourcesDir, { recursive: true }).then(() => fs.promises.writeFile(state.networkFile.file, ''));
@@ -171,6 +173,7 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
       buffer: [],
     };
     state.recording = true;
+    state.callIds.clear();
 
     if (options.name && options.name !== this._state.traceName)
       this._changeTraceName(this._state, options.name);
@@ -352,11 +355,14 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
       return Promise.resolve();
     sdkObject.attribution.page?.temporarlyDisableTracingScreencastThrottling();
     event.beforeSnapshot = `before@${metadata.id}`;
+    this._state?.callIds.add(metadata.id);
     this._appendTraceEvent(event);
     return this._captureSnapshot(event.beforeSnapshot, sdkObject, metadata);
   }
 
   onBeforeInputAction(sdkObject: SdkObject, metadata: CallMetadata, element: ElementHandle) {
+    if (!this._state?.callIds.has(metadata.id))
+      return Promise.resolve();
     // IMPORTANT: no awaits before this._appendTraceEvent in this method.
     const event = createInputActionTraceEvent(metadata);
     if (!event)
@@ -368,9 +374,12 @@ export class Tracing extends SdkObject implements InstrumentationListener, Snaps
   }
 
   async onAfterCall(sdkObject: SdkObject, metadata: CallMetadata) {
+    if (!this._state?.callIds.has(metadata.id))
+      return;
+    this._state?.callIds.delete(metadata.id);
     const event = createAfterActionTraceEvent(metadata);
     if (!event)
-      return Promise.resolve();
+      return;
     sdkObject.attribution.page?.temporarlyDisableTracingScreencastThrottling();
     event.afterSnapshot = `after@${metadata.id}`;
     this._appendTraceEvent(event);

tests/config/utils.ts

@@ -98,7 +98,7 @@ export function suppressCertificateWarning() {
   };
 }
 
-export async function parseTraceRaw(file: string): Promise<{ events: any[], resources: Map<string, Buffer>, actions: string[], stacks: Map<string, StackFrame[]> }> {
+export async function parseTraceRaw(file: string): Promise<{ events: any[], resources: Map<string, Buffer>, actions: string[], actionObjects: ActionTraceEvent[], stacks: Map<string, StackFrame[]> }> {
   const zipFS = new ZipFile(file);
   const resources = new Map<string, Buffer>();
   for (const entry of await zipFS.entries())
@@ -111,6 +111,8 @@ export async function parseTraceRaw(file: string): Promise<{ events: any[], reso
     for (const line of resources.get(traceFile)!.toString().split('\n')) {
       if (line) {
         const event = JSON.parse(line) as TraceEvent;
+        events.push(event);
+
         if (event.type === 'before') {
           const action: ActionTraceEvent = {
             ...event,
@@ -118,7 +120,6 @@ export async function parseTraceRaw(file: string): Promise<{ events: any[], reso
             endTime: 0,
             log: []
           };
-          events.push(action);
           actionMap.set(event.callId, action);
         } else if (event.type === 'input') {
           const existing = actionMap.get(event.callId);
@@ -131,8 +132,6 @@ export async function parseTraceRaw(file: string): Promise<{ events: any[], reso
           existing.log = event.log;
           existing.error = event.error;
           existing.result = event.result;
-        } else {
-          events.push(event);
         }
       }
     }
@@ -151,21 +150,17 @@ export async function parseTraceRaw(file: string): Promise<{ events: any[], reso
       stacks.set(key, value);
   }
 
+  const actionObjects = [...actionMap.values()];
+  actionObjects.sort((a, b) => a.startTime - b.startTime);
   return {
     events,
     resources,
-    actions: eventsToActions(events),
+    actions: actionObjects.map(a => a.apiName),
+    actionObjects,
     stacks,
   };
 }
 
-function eventsToActions(events: ActionTraceEvent[]): string[] {
-  // Trace viewer only shows non-internal non-tracing actions.
-  return events.filter(e => e.type === 'action')
-      .sort((a, b) => a.startTime - b.startTime)
-      .map(e => e.apiName);
-}
-
 export async function parseTrace(file: string): Promise<{ resources: Map<string, Buffer>, events: EventTraceEvent[], actions: ActionTraceEvent[], apiNames: string[], traceModel: TraceModel, model: MultiTraceModel, actionTree: string[] }> {
   const backend = new TraceBackend(file);
   const traceModel = new TraceModel();

tests/library/tracing.spec.ts

@@ -112,8 +112,8 @@ test('should not include buffers in the trace', async ({ context, page, server,
   await page.goto(server.PREFIX + '/empty.html');
   await page.screenshot();
   await context.tracing.stop({ path: testInfo.outputPath('trace.zip') });
-  const { events } = await parseTraceRaw(testInfo.outputPath('trace.zip'));
+  const { actionObjects } = await parseTraceRaw(testInfo.outputPath('trace.zip'));
-  const screenshotEvent = events.find(e => e.type === 'action' && e.apiName === 'page.screenshot');
+  const screenshotEvent = actionObjects.find(a => a.apiName === 'page.screenshot');
   expect(screenshotEvent.beforeSnapshot).toBeTruthy();
   expect(screenshotEvent.afterSnapshot).toBeTruthy();
   expect(screenshotEvent.result).toEqual({});
@@ -526,7 +526,7 @@ test('should hide internal stack frames', async ({ context, page }, testInfo) =>
   await context.tracing.stop({ path: tracePath });
 
   const trace = await parseTraceRaw(tracePath);
-  const actions = trace.events.filter(e => e.type === 'action' && !e.apiName.startsWith('tracing.'));
+  const actions = trace.actionObjects.filter(a => !a.apiName.startsWith('tracing.'));
   expect(actions).toHaveLength(4);
   for (const action of actions)
     expect(relativeStack(action, trace.stacks)).toEqual(['tracing.spec.ts']);
@@ -547,7 +547,7 @@ test('should hide internal stack frames in expect', async ({ context, page }, te
   await context.tracing.stop({ path: tracePath });
 
   const trace = await parseTraceRaw(tracePath);
-  const actions = trace.events.filter(e => e.type === 'action' && !e.apiName.startsWith('tracing.'));
+  const actions = trace.actionObjects.filter(a => !a.apiName.startsWith('tracing.'));
   expect(actions).toHaveLength(5);
   for (const action of actions)
     expect(relativeStack(action, trace.stacks)).toEqual(['tracing.spec.ts']);
@@ -703,6 +703,66 @@ test('should flush console events on tracing stop', async ({ context, page }, te
   expect(events).toHaveLength(100);
 });
 
+test('should not emit after w/o before', async ({ browserType, mode }, testInfo) => {
+  test.skip(mode === 'service', 'Service ignores tracesDir');
+
+  const tracesDir = testInfo.outputPath('traces');
+  const browser = await browserType.launch({ tracesDir });
+  const context = await browser.newContext();
+  const page = await context.newPage();
+
+  await context.tracing.start({ name: 'name1', snapshots: true });
+  const evaluatePromise = page.evaluate(() => new Promise(f => (window as any).callback = f)).catch(() => {});
+  await context.tracing.stopChunk({ path: testInfo.outputPath('trace1.zip') });
+  expect(fs.existsSync(path.join(tracesDir, 'name1.trace'))).toBe(true);
+
+  await context.tracing.startChunk({ name: 'name2' });
+  await page.evaluateHandle(() => (window as any).callback());
+  await evaluatePromise;
+  await context.tracing.stop({ path: testInfo.outputPath('trace2.zip') });
+  expect(fs.existsSync(path.join(tracesDir, 'name2.trace'))).toBe(true);
+
+  await browser.close();
+  let minCallId = 100000;
+  const sanitize = (e: any) => {
+    if (e.type === 'after' || e.type === 'before') {
+      minCallId = Math.min(minCallId, +e.callId.split('@')[1]);
+      return {
+        type: e.type,
+        callId: +e.callId.split('@')[1] - minCallId,
+        apiName: e.apiName,
+      };
+    }
+  };
+
+  {
+    const { events } = await parseTraceRaw(testInfo.outputPath('trace1.zip'));
+    expect(events.map(sanitize).filter(Boolean)).toEqual([
+      {
+        type: 'before',
+        callId: 0,
+        apiName: 'page.evaluate'
+      }
+    ]);
+  }
+
+  {
+    const { events } = await parseTraceRaw(testInfo.outputPath('trace2.zip'));
+    expect(events.map(sanitize).filter(Boolean)).toEqual([
+      {
+        type: 'before',
+        callId: 6,
+        apiName: 'page.evaluateHandle'
+      },
+      {
+        type: 'after',
+        callId: 6,
+        apiName: undefined
+      }
+    ]);
+  }
+});
+
 function expectRed(pixels: Buffer, offset: number) {
   const r = pixels.readUInt8(offset);
   const g = pixels.readUInt8(offset + 1);