feat(html reporter): show log for pw:api and expect steps (#8692)

src/client/channelOwner.ts

@@ -21,7 +21,7 @@ import { debugLogger } from '../utils/debugLogger';
 import { captureStackTrace, ParsedStackTrace } from '../utils/stackTrace';
 import { isUnderTest } from '../utils/utils';
 import type { Connection } from './connection';
-import type { ClientSideInstrumentation, Logger } from './types';
+import type { ClientSideInstrumentation, LogContainer, Logger } from './types';
 
 export abstract class ChannelOwner<T extends channels.Channel = channels.Channel, Initializer = {}> extends EventEmitter {
   protected _connection: Connection;
@@ -72,15 +72,15 @@ export abstract class ChannelOwner<T extends channels.Channel = channels.Channel
     };
   }
 
-  private _createChannel(base: Object, stackTrace: ParsedStackTrace | null): T {
+  private _createChannel(base: Object, stackTrace: ParsedStackTrace | null, logContainer?: LogContainer): T {
     const channel = new Proxy(base, {
       get: (obj: any, prop) => {
         if (prop === 'debugScopeState')
-          return (params: any) => this._connection.sendMessageToServer(this, prop, params, stackTrace);
+          return (params: any) => this._connection.sendMessageToServer(this, prop, params, stackTrace, logContainer);
         if (typeof prop === 'string') {
           const validator = scheme[paramsName(this._type, prop)];
           if (validator)
-            return (params: any) => this._connection.sendMessageToServer(this, prop, validator(params, ''), stackTrace);
+            return (params: any) => this._connection.sendMessageToServer(this, prop, validator(params, ''), stackTrace, logContainer);
         }
         return obj[prop];
       },
@@ -93,25 +93,26 @@ export abstract class ChannelOwner<T extends channels.Channel = channels.Channel
     logger = logger || this._logger;
     const stackTrace = captureStackTrace();
     const { apiName, frameTexts } = stackTrace;
-    const channel = this._createChannel({}, stackTrace);
 
     let ancestorWithCSI: ChannelOwner<any> = this;
     while (!ancestorWithCSI._csi && ancestorWithCSI._parent)
       ancestorWithCSI = ancestorWithCSI._parent;
-    let csiCallback: ((e?: Error) => void) | undefined;
+    let csiCallback: ((log: string[], e?: Error) => void) | undefined;
+    const logContainer = { log: [] };
 
     try {
       logApiCall(logger, `=> ${apiName} started`);
       csiCallback = ancestorWithCSI._csi?.onApiCall(stackTrace);
+      const channel = this._createChannel({}, stackTrace, csiCallback ? logContainer : undefined);
       const result = await func(channel as any, stackTrace);
-      csiCallback?.();
+      csiCallback?.(logContainer.log);
       logApiCall(logger, `<= ${apiName} succeeded`);
       return result;
     } catch (e) {
       const innerError = ((process.env.PWDEBUGIMPL || isUnderTest()) && e.stack) ? '\n<inner error>\n' + e.stack : '';
       e.message = apiName + ': ' + e.message;
       e.stack = e.message + '\n' + frameTexts.join('\n') + innerError;
-      csiCallback?.(e);
+      csiCallback?.(logContainer.log, e);
       logApiCall(logger, `<= ${apiName} failed`);
       throw e;
     }

src/client/connection.ts

@@ -39,6 +39,7 @@ import { ParsedStackTrace } from '../utils/stackTrace';
 import { Artifact } from './artifact';
 import { EventEmitter } from 'events';
 import { JsonPipe } from './jsonPipe';
+import type { LogContainer } from './types';
 
 class Root extends ChannelOwner<channels.RootChannel, {}> {
   constructor(connection: Connection) {
@@ -57,7 +58,7 @@ export class Connection extends EventEmitter {
   private _waitingForObject = new Map<string, any>();
   onmessage = (message: object): void => {};
   private _lastId = 0;
-  private _callbacks = new Map<number, { resolve: (a: any) => void, reject: (a: Error) => void, stackTrace: ParsedStackTrace }>();
+  private _callbacks = new Map<number, { resolve: (a: any) => void, reject: (a: Error) => void, stackTrace: ParsedStackTrace, logContainer: LogContainer | undefined }>();
   private _rootObject: Root;
   private _disconnectedErrorMessage: string | undefined;
   private _onClose?: () => void;
@@ -80,7 +81,7 @@ export class Connection extends EventEmitter {
     return this._objects.get(guid)!;
   }
 
-  async sendMessageToServer(object: ChannelOwner, method: string, params: any, maybeStackTrace: ParsedStackTrace | null): Promise<any> {
+  async sendMessageToServer(object: ChannelOwner, method: string, params: any, maybeStackTrace: ParsedStackTrace | null, logContainer?: LogContainer): Promise<any> {
     const guid = object._guid;
     const stackTrace = maybeStackTrace || { frameTexts: [], frames: [], apiName: '' };
     const { frames, apiName } = stackTrace;
@@ -89,12 +90,12 @@ export class Connection extends EventEmitter {
     const converted = { id, guid, method, params };
     // Do not include metadata in debug logs to avoid noise.
     debugLogger.log('channel:command', converted);
-    const metadata: channels.Metadata = { stack: frames, apiName };
+    const metadata: channels.Metadata = { stack: frames, apiName, collectLogs: logContainer ? true : undefined };
     this.onmessage({ ...converted, metadata });
 
     if (this._disconnectedErrorMessage)
       throw new Error(this._disconnectedErrorMessage);
-    return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject, stackTrace }));
+    return await new Promise((resolve, reject) => this._callbacks.set(id, { resolve, reject, stackTrace, logContainer }));
   }
 
   _debugScopeState(): any {
@@ -102,13 +103,15 @@ export class Connection extends EventEmitter {
   }
 
   dispatch(message: object) {
-    const { id, guid, method, params, result, error } = message as any;
+    const { id, guid, method, params, result, error, log } = message as any;
     if (id) {
       debugLogger.log('channel:response', message);
       const callback = this._callbacks.get(id);
       if (!callback)
         throw new Error(`Cannot find command to respond: ${id}`);
       this._callbacks.delete(id);
+      if (log && callback.logContainer)
+        callback.logContainer.log.push(...log);
       if (error)
         callback.reject(parseError(error));
       else

src/client/types.ts

@@ -27,8 +27,11 @@ export interface Logger {
 }
 
 export interface ClientSideInstrumentation {
-  onApiCall(stackTrace: ParsedStackTrace): (error?: Error) => void;
+  onApiCall(stackTrace: ParsedStackTrace): ((log: string[], error?: Error) => void) | undefined;
 }
+export type LogContainer = {
+  log: string[];
+};
 
 export type StrictOptions = { strict?: boolean };
 export type Headers = { [key: string]: string };

src/dispatchers/dispatcher.ts

@@ -222,7 +222,8 @@ export class DispatcherConnection {
     const sdkObject = dispatcher._object instanceof SdkObject ? dispatcher._object : undefined;
     const callMetadata: CallMetadata = {
       id: `call@${id}`,
-      ...validMetadata,
+      stack: validMetadata.stack,
+      apiName: validMetadata.apiName,
       objectId: sdkObject?.guid,
       pageId: sdkObject?.attribution?.page?.guid,
       frameId: sdkObject?.attribution?.frame?.guid,
@@ -277,10 +278,11 @@ export class DispatcherConnection {
       await sdkObject?.instrumentation.onAfterCall(sdkObject, callMetadata);
     }
 
+    const log = validMetadata.collectLogs ? callMetadata.log : undefined;
     if (callMetadata.error)
-      this.onmessage({ id, error: error });
+      this.onmessage({ id, error: error, log });
     else
-      this.onmessage({ id, result: callMetadata.result });
+      this.onmessage({ id, result: callMetadata.result, log });
   }
 
   private _replaceDispatchersWithGuids(payload: any): any {

src/dispatchers/networkDispatchers.ts

@@ -18,6 +18,7 @@ import { Request, Response, Route, WebSocket } from '../server/network';
 import * as channels from '../protocol/channels';
 import { Dispatcher, DispatcherScope, lookupNullableDispatcher, existingDispatcher } from './dispatcher';
 import { FrameDispatcher } from './frameDispatcher';
+import { CallMetadata } from '../server/instrumentation';
 
 export class RequestDispatcher extends Dispatcher<Request, channels.RequestInitializer, channels.RequestEvents> implements channels.RequestChannel {
 
@@ -84,15 +85,15 @@ export class ResponseDispatcher extends Dispatcher<Response, channels.ResponseIn
     return { value: await this._object.serverAddr() || undefined };
   }
 
-  async rawRequestHeaders(params?: channels.ResponseRawRequestHeadersParams, metadata?: channels.Metadata): Promise<channels.ResponseRawRequestHeadersResult> {
+  async rawRequestHeaders(params?: channels.ResponseRawRequestHeadersParams): Promise<channels.ResponseRawRequestHeadersResult> {
     return { headers: await this._object.rawRequestHeaders() };
   }
 
-  async rawResponseHeaders(params?: channels.ResponseRawResponseHeadersParams, metadata?: channels.Metadata): Promise<channels.ResponseRawResponseHeadersResult> {
+  async rawResponseHeaders(params?: channels.ResponseRawResponseHeadersParams): Promise<channels.ResponseRawResponseHeadersResult> {
     return { headers: await this._object.rawResponseHeaders() };
   }
 
-  async sizes(params?: channels.ResponseSizesParams, metadata?: channels.Metadata): Promise<channels.ResponseSizesResult> {
+  async sizes(params?: channels.ResponseSizesParams): Promise<channels.ResponseSizesResult> {
     return { sizes: await this._object.sizes() };
   }
 }
@@ -111,11 +112,11 @@ export class RouteDispatcher extends Dispatcher<Route, channels.RouteInitializer
     });
   }
 
-  async responseBody(params?: channels.RouteResponseBodyParams, metadata?: channels.Metadata): Promise<channels.RouteResponseBodyResult> {
+  async responseBody(params?: channels.RouteResponseBodyParams): Promise<channels.RouteResponseBodyResult> {
     return { binary: (await this._object.responseBody()).toString('base64') };
   }
 
-  async continue(params: channels.RouteContinueParams, metadata?: channels.Metadata): Promise<channels.RouteContinueResult> {
+  async continue(params: channels.RouteContinueParams, metadata: CallMetadata): Promise<channels.RouteContinueResult> {
     const response = await this._object.continue({
       url: params.url,
       method: params.method,

src/dispatchers/playwrightDispatcher.ts

@@ -52,23 +52,23 @@ export class PlaywrightDispatcher extends Dispatcher<Playwright, channels.Playwr
     debugLogger.log('proxy', `Starting socks proxy server on port ${this._object.options.socksProxyPort}`);
   }
 
-  async socksConnected(params: channels.PlaywrightSocksConnectedParams, metadata?: channels.Metadata): Promise<void> {
+  async socksConnected(params: channels.PlaywrightSocksConnectedParams): Promise<void> {
     this._socksProxy?.socketConnected(params);
   }
 
-  async socksFailed(params: channels.PlaywrightSocksFailedParams, metadata?: channels.Metadata): Promise<void> {
+  async socksFailed(params: channels.PlaywrightSocksFailedParams): Promise<void> {
     this._socksProxy?.socketFailed(params);
   }
 
-  async socksData(params: channels.PlaywrightSocksDataParams, metadata?: channels.Metadata): Promise<void> {
+  async socksData(params: channels.PlaywrightSocksDataParams): Promise<void> {
     this._socksProxy?.sendSocketData(params);
   }
 
-  async socksError(params: channels.PlaywrightSocksErrorParams, metadata?: channels.Metadata): Promise<void> {
+  async socksError(params: channels.PlaywrightSocksErrorParams): Promise<void> {
     this._socksProxy?.sendSocketError(params);
   }
 
-  async socksEnd(params: channels.PlaywrightSocksEndParams, metadata?: channels.Metadata): Promise<void> {
+  async socksEnd(params: channels.PlaywrightSocksEndParams): Promise<void> {
     this._socksProxy?.sendSocketEnd(params);
   }
 }

src/protocol/channels.ts

@@ -33,6 +33,7 @@ export type StackFrame = {
 export type Metadata = {
   stack?: StackFrame[],
   apiName?: string,
+  collectLogs?: boolean,
 };
 
 export type Point = {

src/protocol/protocol.yml

@@ -29,6 +29,7 @@ Metadata:
       type: array?
       items: StackFrame
     apiName: string?
+    collectLogs: boolean?
 
 
 Point:

src/protocol/validator.ts

@@ -42,6 +42,7 @@ export function createScheme(tChannel: (name: string) => Validator): Scheme {
   scheme.Metadata = tObject({
     stack: tOptional(tArray(tType('StackFrame'))),
     apiName: tOptional(tString),
+    collectLogs: tOptional(tBoolean),
   });
   scheme.Point = tObject({
     x: tNumber,

src/test/dispatcher.ts

@@ -309,7 +309,7 @@ export class Dispatcher {
         startTime: new Date(params.wallTime),
         duration: 0,
         steps: [],
-        data: params.data,
+        data: {},
       };
       steps.set(params.stepId, step);
       (parentStep || result).steps.push(step);
@@ -331,6 +331,7 @@ export class Dispatcher {
       step.duration = params.wallTime - step.startTime.getTime();
       if (params.error)
         step.error = params.error;
+      step.data = params.data;
       stepStack.delete(step);
       steps.delete(params.stepId);
       this._reporter.onStepEnd?.(test, result, step);

src/test/expect.ts

@@ -77,7 +77,7 @@ function wrap(matcherName: string, matcher: any) {
 
     const INTERNAL_STACK_LENGTH = 3;
     const stackLines = new Error().stack!.split('\n').slice(INTERNAL_STACK_LENGTH + 1);
-    const completeStep = testInfo._addStep('expect', `expect${this.isNot ? '.not' : ''}.${matcherName}`, prepareExpectStepData(stackLines));
+    const step = testInfo._addStep('expect', `expect${this.isNot ? '.not' : ''}.${matcherName}`, prepareExpectStepData(stackLines));
 
     const reportStepEnd = (result: any) => {
       const success = result.pass !== this.isNot;
@@ -86,12 +86,12 @@ function wrap(matcherName: string, matcher: any) {
         const message = result.message();
         error = { message, stack: message + '\n' + stackLines.join('\n') };
       }
-      completeStep?.(error);
+      step.complete(error);
       return result;
     };
 
     const reportStepError = (error: Error) => {
-      completeStep?.(serializeError(error));
+      step.complete(serializeError(error));
       throw error;
     };
 
@@ -119,7 +119,7 @@ function prepareExpectStepData(lines: string[]) {
       column: parsed.column
     };
   }).filter(frame => !!frame);
-  return { stack: frames };
+  return { stack: frames, log: [] };
 }
 
 const wrappedMatchers: any = {};

src/test/fixtures.ts

@@ -16,7 +16,7 @@
 
 import { formatLocation, wrapInPromise } from './util';
 import * as crypto from 'crypto';
-import { FixturesWithLocation, Location, WorkerInfo, TestInfo, CompleteStepCallback } from './types';
+import { FixturesWithLocation, Location, WorkerInfo, TestInfo, TestStepInternal } from './types';
 
 type FixtureScope = 'test' | 'worker';
 type FixtureRegistration = {
@@ -242,7 +242,7 @@ export class FixtureRunner {
       throw error;
   }
 
-  async resolveParametersAndRunHookOrTest(fn: Function, workerInfo: WorkerInfo, testInfo: TestInfo | undefined, paramsStepCallback?: CompleteStepCallback) {
+  async resolveParametersAndRunHookOrTest(fn: Function, workerInfo: WorkerInfo, testInfo: TestInfo | undefined, paramsStepCallback?: TestStepInternal) {
     // Install all automatic fixtures.
     for (const registration of this.pool!.registrations.values()) {
       const shouldSkip = !testInfo && registration.scope === 'test';
@@ -260,7 +260,7 @@ export class FixtureRunner {
     }
 
     // Report fixture hooks step as completed.
-    paramsStepCallback?.();
+    paramsStepCallback?.complete();
 
     return fn(params, testInfo || workerInfo);
   }

src/test/index.ts

@@ -204,9 +204,13 @@ export const test = _baseTest.extend<TestFixtures, WorkerAndFileFixtures>({
       }
       (context as any)._csi = {
         onApiCall: (stackTrace: ParsedStackTrace) => {
-          if ((testInfo as TestInfoImpl)._currentSteps().some(step => step.category === 'pw:api' || step.category === 'expect'))
+          const testInfoImpl = testInfo as TestInfoImpl;
-            return () => {};
+          const existingStep = testInfoImpl._currentSteps().find(step => step.category === 'pw:api' || step.category === 'expect');
-          return (testInfo as TestInfoImpl)._addStep('pw:api', stackTrace.apiName, { stack: stackTrace.frames });
+          const newStep = existingStep ? undefined : testInfoImpl._addStep('pw:api', stackTrace.apiName, { stack: stackTrace.frames, log: [] });
+          return (log: string[], error?: Error) => {
+            (existingStep || newStep)?.data.log?.push(...log);
+            newStep?.complete(error);
+          };
         },
       };
     };

src/test/ipc.ts

@@ -52,7 +52,6 @@ export type StepBeginPayload = {
   title: string;
   category: string;
   wallTime: number;  // milliseconds since unix epoch
-  data: { [key: string]: any };
 };
 
 export type StepEndPayload = {
@@ -60,6 +59,7 @@ export type StepEndPayload = {
   stepId: string;
   wallTime: number;  // milliseconds since unix epoch
   error?: TestError;
+  data: { [key: string]: any };
 };
 
 export type TestEntry = {

src/test/reporters/html.ts

@@ -105,6 +105,7 @@ export type JsonTestStep = {
   steps: JsonTestStep[];
   preview?: string;
   stack?: JsonStackFrame[];
+  log?: string[];
 };
 
 class HtmlReporter {
@@ -221,6 +222,7 @@ class HtmlReporter {
         steps: this._serializeSteps(test, step.steps),
         failureSnippet: step.error ? formatError(step.error, test.location.file) : undefined,
         ...this._sourceProcessor.processStackTrace(step.data.stack),
+        log: step.data.log || undefined,
       };
     });
   }

src/test/testType.ts

@@ -186,12 +186,12 @@ export class TestTypeImpl {
     const testInfo = currentTestInfo();
     if (!testInfo)
       throw errorWithLocation(location, `test.step() can only be called from a test`);
-    const complete = testInfo._addStep('test.step', title);
+    const step = testInfo._addStep('test.step', title);
     try {
       await body();
-      complete();
+      step.complete();
     } catch (e) {
-      complete(serializeError(e));
+      step.complete(serializeError(e));
       throw e;
     }
   }

src/test/types.ts

@@ -25,10 +25,14 @@ export type FixturesWithLocation = {
 };
 export type Annotations = { type: string, description?: string }[];
 
-export type CompleteStepCallback = (error?: Error | TestError) => void;
+export interface TestStepInternal {
+  complete(error?: Error | TestError): void;
+  category: string;
+  data: { [key: string]: any };
+}
 
 export interface TestInfoImpl extends TestInfo {
   _testFinished: Promise<void>;
-  _addStep: (category: string, title: string, data?: { [key: string]: any }) => CompleteStepCallback;
+  _addStep: (category: string, title: string, data?: { [key: string]: any }) => TestStepInternal;
-  _currentSteps(): { category: string }[];
+  _currentSteps(): TestStepInternal[];
 }

src/test/workerRunner.ts

@@ -25,7 +25,7 @@ import { TestBeginPayload, TestEndPayload, RunPayload, TestEntry, DonePayload, W
 import { setCurrentTestInfo } from './globals';
 import { Loader } from './loader';
 import { Modifier, Suite, TestCase } from './test';
-import { Annotations, CompleteStepCallback, TestError, TestInfo, TestInfoImpl, WorkerInfo } from './types';
+import { Annotations, TestError, TestInfo, TestInfoImpl, TestStepInternal, WorkerInfo } from './types';
 import { ProjectImpl } from './project';
 import { FixturePool, FixtureRunner } from './fixtures';
 import { DeadlineRunner, raceAgainstDeadline } from '../utils/async';
@@ -219,7 +219,7 @@ export class WorkerRunner extends EventEmitter {
 
     let testFinishedCallback = () => {};
     let lastStepId = 0;
-    const stepStack = new Set<{ category: string }>();
+    const stepStack = new Set<TestStepInternal>();
     const testInfo: TestInfoImpl = {
       workerIndex: this._params.workerIndex,
       project: this._project.config,
@@ -270,34 +270,39 @@ export class WorkerRunner extends EventEmitter {
       _testFinished: new Promise(f => testFinishedCallback = f),
       _addStep: (category: string, title: string, data: { [key: string]: any } = {}) => {
         const stepId = `${category}@${title}@${++lastStepId}`;
-        const step: StepBeginPayload = {
+        let callbackHandled = false;
+        const step: TestStepInternal = {
+          data,
+          category,
+          complete: (error?: Error | TestError) => {
+            if (callbackHandled)
+              return;
+            callbackHandled = true;
+            if (error instanceof Error)
+              error = serializeError(error);
+            stepStack.delete(step);
+            const payload: StepEndPayload = {
+              testId,
+              stepId,
+              wallTime: Date.now(),
+              error,
+              data,
+            };
+            if (reportEvents)
+              this.emit('stepEnd', payload);
+          }
+        };
+        stepStack.add(step);
+        const payload: StepBeginPayload = {
           testId,
           stepId,
           category,
           title,
           wallTime: Date.now(),
-          data,
         };
-        stepStack.add(step);
         if (reportEvents)
-          this.emit('stepBegin', step);
+          this.emit('stepBegin', payload);
-        let callbackHandled = false;
+        return step;
-        return (error?: Error | TestError) => {
-          if (callbackHandled)
-            return;
-          callbackHandled = true;
-          if (error instanceof Error)
-            error = serializeError(error);
-          stepStack.delete(step);
-          const payload: StepEndPayload = {
-            testId,
-            stepId,
-            wallTime: Date.now(),
-            error
-          };
-          if (reportEvents)
-            this.emit('stepEnd', payload);
-        };
       },
       _currentSteps: () => [...stepStack],
     };
@@ -422,18 +427,18 @@ export class WorkerRunner extends EventEmitter {
   }
 
   private async _runTestWithBeforeHooks(test: TestCase, testInfo: TestInfoImpl) {
-    const completeStep = testInfo._addStep('hook', 'Before Hooks');
+    const step = testInfo._addStep('hook', 'Before Hooks');
     if (test._type === 'test')
       await this._runBeforeHooks(test, testInfo);
 
     // Do not run the test when beforeEach hook fails.
     if (testInfo.status === 'failed' || testInfo.status === 'skipped') {
-      completeStep?.(testInfo.error);
+      step.complete(testInfo.error);
       return;
     }
 
     try {
-      await this._fixtureRunner.resolveParametersAndRunHookOrTest(test.fn, this._workerInfo, testInfo, completeStep);
+      await this._fixtureRunner.resolveParametersAndRunHookOrTest(test.fn, this._workerInfo, testInfo, step);
     } catch (error) {
       if (error instanceof SkipError) {
         if (testInfo.status === 'passed')
@@ -448,15 +453,15 @@ export class WorkerRunner extends EventEmitter {
           testInfo.error = serializeError(error);
       }
     } finally {
-      completeStep?.(testInfo.error);
+      step.complete(testInfo.error);
     }
   }
 
   private async _runAfterHooks(test: TestCase, testInfo: TestInfoImpl) {
-    let completeStep: CompleteStepCallback | undefined;
+    let step: TestStepInternal | undefined;
     let teardownError: TestError | undefined;
     try {
-      completeStep = testInfo._addStep('hook', 'After Hooks');
+      step = testInfo._addStep('hook', 'After Hooks');
       if (test._type === 'test')
         await this._runHooks(test.parent!, 'afterEach', testInfo);
     } catch (error) {
@@ -480,7 +485,7 @@ export class WorkerRunner extends EventEmitter {
         teardownError = testInfo.error;
       }
     }
-    completeStep?.(teardownError);
+    step?.complete(teardownError);
   }
 
   private async _runHooks(suite: Suite, type: 'beforeEach' | 'afterEach', testInfo: TestInfo) {

src/web/htmlReport/htmlReport.css

@@ -181,3 +181,9 @@
 .test-details-column {
   overflow-y: auto;
 }
+
+.step-log {
+  line-height: 20px;
+  white-space: pre;
+  padding: 8px;
+}

src/web/htmlReport/htmlReport.tsx

@@ -272,7 +272,7 @@ const TestStepDetails: React.FC<{
       {
         id: 'log',
         title: 'Log',
-        render: () => <div></div>
+        render: () => <div className='step-log'>{step?.log ? step.log.join('\n') : ''}</div>
       },
       {
         id: 'errors',

tests/config/browserTest.ts

@@ -139,8 +139,9 @@ export const playwrightFixtures: Fixtures<PlaywrightTestOptions & PlaywrightTest
       if (trace)
         await context.tracing.start({ screenshots: true, snapshots: true });
       (context as any)._csi = {
-        onApiCall: (name: string) => {
+        onApiCall: (stackTrace: any) => {
-          return (testInfo as any)._addStep('pw:api', name);
+          const step = (testInfo as any)._addStep('pw:api', stackTrace.apiName);
+          return (log, error) => step.complete(error);
         },
       };
       contexts.push(context);

tests/playwright-test/reporter.spec.ts

@@ -506,20 +506,18 @@ test('should report api step hierarchy', async ({ runInlineTest }) => {
   ]);
 });
 
-test('should report expect and pw:api stacks', async ({ runInlineTest }, testInfo) => {
+test('should report expect and pw:api stacks and logs', async ({ runInlineTest }, testInfo) => {
   const expectReporterJS = `
     class Reporter {
-      stepDetails(step) {
+      stepStack(step) {
         if (!step.data.stack || !step.data.stack[0])
           return step.title + ' <no stack>';
         const frame = step.data.stack[0]
-        return step.title + ' ' + frame.file + ':' + frame.line + ':' + frame.column;
+        return step.title + ' stack: ' + frame.file + ':' + frame.line + ':' + frame.column;
-      }
-      onStepBegin(test, result, step) {
-        console.log('%%%% begin', this.stepDetails(step));
       }
       onStepEnd(test, result, step) {
-        console.log('%%%% end', this.stepDetails(step));
+        console.log('%%%% ' + this.stepStack(step));
+        console.log('%%%% ' + step.title + ' log: ' + (step.data.log || []).join(''));
       }
     }
     module.exports = Reporter;
@@ -535,20 +533,22 @@ test('should report expect and pw:api stacks', async ({ runInlineTest }, testInf
     'a.test.ts': `
       const { test } = pwt;
       test('pass', async ({ page }) => {
-        await page.setContent('<title>hello</title>');
+        await page.setContent('<title>hello</title><body><div>Click me</div></body>');
+        await page.click('text=Click me');
         expect(1).toBe(1);
-        await expect(page).toHaveTitle('hello');
+        await expect(page.locator('div')).toHaveText('Click me');
       });
     `
   }, { reporter: '', workers: 1 });
 
   expect(result.exitCode).toBe(0);
-  expect(result.output).toContain(`%% begin page.setContent ${testInfo.outputPath('a.test.ts:7:20')}`);
+  expect(result.output).toContain(`%% page.setContent stack: ${testInfo.outputPath('a.test.ts:7:20')}`);
-  expect(result.output).toContain(`%% end page.setContent ${testInfo.outputPath('a.test.ts:7:20')}`);
+  expect(result.output).toContain(`%% page.setContent log: setting frame content, waiting until "load"`);
-  expect(result.output).toContain(`%% begin expect.toBe ${testInfo.outputPath('a.test.ts:8:19')}`);
+  expect(result.output).toContain(`%% page.click stack: ${testInfo.outputPath('a.test.ts:8:20')}`);
-  expect(result.output).toContain(`%% end expect.toBe ${testInfo.outputPath('a.test.ts:8:19')}`);
+  expect(result.output).toContain(`%% page.click log: waiting for selector "text=Click me"`);
-  expect(result.output).toContain(`%% begin expect.toHaveTitle ${testInfo.outputPath('a.test.ts:9:28')}`);
+  expect(result.output).toContain(`%% expect.toBe stack: ${testInfo.outputPath('a.test.ts:9:19')}`);
-  expect(result.output).toContain(`%% end expect.toHaveTitle ${testInfo.outputPath('a.test.ts:9:28')}`);
+  expect(result.output).toContain(`%% expect.toHaveText stack: ${testInfo.outputPath('a.test.ts:10:43')}`);
+  expect(result.output).toContain(`%% expect.toHaveText log:   retrieving textContent from "div"`);
 });
 
 function stripEscapedAscii(str: string) {