From 38ed8de23d42fcc97e9cf071d6e7984b79d6fd76 Mon Sep 17 00:00:00 2001 From: Dmitry Gozman Date: Thu, 10 Sep 2020 21:42:09 -0700 Subject: [PATCH] feat(tracing): trace actions (#3825) - Fill and click actions pass metadata to Progress. - Progress reports success/failure through instrumentation. - Tracer consumes ActionResult and ActionMetadata and records them. Currently, only click and fill actions pass metadata to contain the size of the change. Everything else should follow. --- src/debug/debugController.ts | 5 +- src/dispatchers/elementHandlerDispatcher.ts | 16 +++- src/dispatchers/frameDispatcher.ts | 16 +++- src/server/dom.ts | 22 +++-- src/server/frames.ts | 55 +++++++------ src/server/instrumentation.ts | 23 +++++- src/server/page.ts | 7 +- src/server/progress.ts | 27 ++++++- src/trace/snapshotter.ts | 14 +--- src/trace/traceTypes.ts | 19 ++++- src/trace/traceViewer.ts | 89 +++++++++++++++------ src/trace/tracer.ts | 88 +++++++++++++++----- 12 files changed, 260 insertions(+), 121 deletions(-) diff --git a/src/debug/debugController.ts b/src/debug/debugController.ts index a4d827805cdff..d85e5edf043d7 100644 --- a/src/debug/debugController.ts +++ b/src/debug/debugController.ts @@ -17,8 +17,7 @@ import { BrowserContext } from '../server/browserContext'; import * as frames from '../server/frames'; import { Page } from '../server/page'; -import { InstrumentingAgent } from '../server/instrumentation'; -import { Progress } from '../server/progress'; +import { ActionMetadata, ActionResult, InstrumentingAgent } from '../server/instrumentation'; import { isDebugMode } from '../utils/utils'; import * as debugScriptSource from '../generated/debugScriptSource'; @@ -43,6 +42,6 @@ export class DebugController implements InstrumentingAgent { async onContextDestroyed(context: BrowserContext): Promise { } - async onBeforePageAction(page: Page, progress: Progress): Promise { + async onAfterAction(result: ActionResult, metadata?: ActionMetadata): Promise { } } diff --git a/src/dispatchers/elementHandlerDispatcher.ts b/src/dispatchers/elementHandlerDispatcher.ts index 34612af1be41a..75ae169f7cc93 100644 --- a/src/dispatchers/elementHandlerDispatcher.ts +++ b/src/dispatchers/elementHandlerDispatcher.ts @@ -20,6 +20,8 @@ import * as channels from '../protocol/channels'; import { DispatcherScope, lookupNullableDispatcher } from './dispatcher'; import { JSHandleDispatcher, serializeResult, parseArgument } from './jsHandleDispatcher'; import { FrameDispatcher } from './frameDispatcher'; +import { runAbortableTask } from '../server/progress'; +import { ActionMetadata } from '../server/instrumentation'; export function createHandle(scope: DispatcherScope, handle: js.JSHandle): JSHandleDispatcher { return handle.asElement() ? new ElementHandleDispatcher(scope, handle.asElement()!) : new JSHandleDispatcher(scope, handle); @@ -77,8 +79,11 @@ export class ElementHandleDispatcher extends JSHandleDispatcher implements chann await this._elementHandle.hover(params); } - async click(params: channels.ElementHandleClickParams): Promise { - await this._elementHandle.click(params); + async click(params: channels.ElementHandleClickParams, metadata?: channels.Metadata): Promise { + const clickMetadata: ActionMetadata = { ...metadata, type: 'click', target: this._elementHandle, page: this._elementHandle._page }; + return runAbortableTask(async progress => { + return await this._elementHandle.click(progress, params); + }, this._elementHandle._page._timeoutSettings.timeout(params), clickMetadata); } async dblclick(params: channels.ElementHandleDblclickParams): Promise { @@ -90,8 +95,11 @@ export class ElementHandleDispatcher extends JSHandleDispatcher implements chann return { values: await this._elementHandle.selectOption(elements, params.options || [], params) }; } - async fill(params: channels.ElementHandleFillParams): Promise { - await this._elementHandle.fill(params.value, params); + async fill(params: channels.ElementHandleFillParams, metadata?: channels.Metadata): Promise { + const fillMetadata: ActionMetadata = { ...metadata, type: 'fill', value: params.value, target: this._elementHandle, page: this._elementHandle._page }; + return runAbortableTask(async progress => { + return await this._elementHandle.fill(progress, params.value, params); + }, this._elementHandle._page._timeoutSettings.timeout(params), fillMetadata); } async selectText(params: channels.ElementHandleSelectTextParams): Promise { diff --git a/src/dispatchers/frameDispatcher.ts b/src/dispatchers/frameDispatcher.ts index 326d1f26741cd..8c562722f1bf5 100644 --- a/src/dispatchers/frameDispatcher.ts +++ b/src/dispatchers/frameDispatcher.ts @@ -20,6 +20,8 @@ import { Dispatcher, DispatcherScope, lookupNullableDispatcher, existingDispatch import { ElementHandleDispatcher, createHandle } from './elementHandlerDispatcher'; import { parseArgument, serializeResult } from './jsHandleDispatcher'; import { ResponseDispatcher, RequestDispatcher } from './networkDispatchers'; +import { ActionMetadata } from '../server/instrumentation'; +import { runAbortableTask } from '../server/progress'; export class FrameDispatcher extends Dispatcher implements channels.FrameChannel { private _frame: Frame; @@ -108,16 +110,22 @@ export class FrameDispatcher extends Dispatcher { - await this._frame.click(params.selector, params); + async click(params: channels.FrameClickParams, metadata?: channels.Metadata): Promise { + const clickMetadata: ActionMetadata = { ...metadata, type: 'click', target: params.selector, page: this._frame._page }; + await runAbortableTask(async progress => { + return await this._frame.click(progress, params.selector, params); + }, this._frame._page._timeoutSettings.timeout(params), clickMetadata); } async dblclick(params: channels.FrameDblclickParams): Promise { await this._frame.dblclick(params.selector, params); } - async fill(params: channels.FrameFillParams): Promise { - await this._frame.fill(params.selector, params.value, params); + async fill(params: channels.FrameFillParams, metadata?: channels.Metadata): Promise { + const fillMetadata: ActionMetadata = { ...metadata, type: 'fill', value: params.value, target: params.selector, page: this._frame._page }; + await runAbortableTask(async progress => { + return await this._frame.fill(progress, params.selector, params.value, params); + }, this._frame._page._timeoutSettings.timeout(params), fillMetadata); } async focus(params: channels.FrameFocusParams): Promise { diff --git a/src/server/dom.ts b/src/server/dom.ts index 766ebdddd46b6..6256485f4b575 100644 --- a/src/server/dom.ts +++ b/src/server/dom.ts @@ -99,18 +99,20 @@ export class ElementHandle extends js.JSHandle { readonly _context: FrameExecutionContext; readonly _page: Page; readonly _objectId: string; + readonly _previewPromise: Promise; constructor(context: FrameExecutionContext, objectId: string) { super(context, 'node', objectId); this._objectId = objectId; this._context = context; this._page = context.frame._page; - this._initializePreview().catch(e => {}); + this._previewPromise = this._initializePreview().catch(e => 'node'); + this._previewPromise.then(preview => this._setPreview('JSHandle@' + preview)); } async _initializePreview() { const utility = await this._context.injectedScript(); - this._setPreview(await utility.evaluate((injected, e) => 'JSHandle@' + injected.previewNode(e), this)); + return utility.evaluate((injected, e) => injected.previewNode(e), this); } asElement(): ElementHandle | null { @@ -367,11 +369,9 @@ export class ElementHandle extends js.JSHandle { return this._retryPointerAction(progress, 'hover', false /* waitForEnabled */, point => this._page.mouse.move(point.x, point.y), options); } - click(options: types.MouseClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions = {}): Promise { - return this._page._runAbortableTask(async progress => { - const result = await this._click(progress, options); - return assertDone(throwRetargetableDOMError(result)); - }, this._page._timeoutSettings.timeout(options)); + async click(progress: Progress, options: types.MouseClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions = {}): Promise { + const result = await this._click(progress, options); + return assertDone(throwRetargetableDOMError(result)); } _click(progress: Progress, options: types.MouseClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions): Promise<'error:notconnected' | 'done'> { @@ -406,11 +406,9 @@ export class ElementHandle extends js.JSHandle { }); } - async fill(value: string, options: types.NavigatingActionWaitOptions = {}): Promise { - return this._page._runAbortableTask(async progress => { - const result = await this._fill(progress, value, options); - assertDone(throwRetargetableDOMError(result)); - }, this._page._timeoutSettings.timeout(options)); + async fill(progress: Progress, value: string, options: types.NavigatingActionWaitOptions = {}): Promise { + const result = await this._fill(progress, value, options); + assertDone(throwRetargetableDOMError(result)); } async _fill(progress: Progress, value: string, options: types.NavigatingActionWaitOptions): Promise<'error:notconnected' | 'done'> { diff --git a/src/server/frames.ts b/src/server/frames.ts index 4dd409e9129c4..17683659ab19f 100644 --- a/src/server/frames.ts +++ b/src/server/frames.ts @@ -770,43 +770,50 @@ export class Frame extends EventEmitter { return result!; } + private async _retryWithProgressIfNotConnected( + progress: Progress, + selector: string, + action: (handle: dom.ElementHandle) => Promise): Promise { + const info = this._page.selectors._parseSelector(selector); + while (progress.isRunning()) { + progress.log(`waiting for selector "${selector}"`); + const task = dom.waitForSelectorTask(info, 'attached'); + const handle = await this._scheduleRerunnableHandleTask(progress, info.world, task); + const element = handle.asElement() as dom.ElementHandle; + progress.cleanupWhenAborted(() => { + // Do not await here to avoid being blocked, either by stalled + // page (e.g. alert) or unresolved navigation in Chromium. + element.dispose(); + }); + const result = await action(element); + element.dispose(); + if (result === 'error:notconnected') { + progress.log('element was detached from the DOM, retrying'); + continue; + } + return result; + } + return undefined as any; + } + private async _retryWithSelectorIfNotConnected( selector: string, options: types.TimeoutOptions, action: (progress: Progress, handle: dom.ElementHandle) => Promise): Promise { - const info = this._page.selectors._parseSelector(selector); return this._page._runAbortableTask(async progress => { - while (progress.isRunning()) { - progress.log(`waiting for selector "${selector}"`); - const task = dom.waitForSelectorTask(info, 'attached'); - const handle = await this._scheduleRerunnableHandleTask(progress, info.world, task); - const element = handle.asElement() as dom.ElementHandle; - progress.cleanupWhenAborted(() => { - // Do not await here to avoid being blocked, either by stalled - // page (e.g. alert) or unresolved navigation in Chromium. - element.dispose(); - }); - const result = await action(progress, element); - element.dispose(); - if (result === 'error:notconnected') { - progress.log('element was detached from the DOM, retrying'); - continue; - } - return result; - } - return undefined as any; + return this._retryWithProgressIfNotConnected(progress, selector, handle => action(progress, handle)); }, this._page._timeoutSettings.timeout(options)); } - async click(selector: string, options: types.MouseClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions = {}) { - await this._retryWithSelectorIfNotConnected(selector, options, (progress, handle) => handle._click(progress, options)); + async click(progress: Progress, selector: string, options: types.MouseClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions) { + return this._retryWithProgressIfNotConnected(progress, selector, handle => handle._click(progress, options)); } async dblclick(selector: string, options: types.MouseMultiClickOptions & types.PointerActionWaitOptions & types.NavigatingActionWaitOptions = {}) { await this._retryWithSelectorIfNotConnected(selector, options, (progress, handle) => handle._dblclick(progress, options)); } - async fill(selector: string, value: string, options: types.NavigatingActionWaitOptions = {}) { - await this._retryWithSelectorIfNotConnected(selector, options, (progress, handle) => handle._fill(progress, value, options)); + async fill(progress: Progress, selector: string, value: string, options: types.NavigatingActionWaitOptions) { + return this._retryWithProgressIfNotConnected(progress, selector, handle => handle._fill(progress, value, options)); } async focus(selector: string, options: types.TimeoutOptions = {}) { diff --git a/src/server/instrumentation.ts b/src/server/instrumentation.ts index 7687e945a17cf..63636a9275ada 100644 --- a/src/server/instrumentation.ts +++ b/src/server/instrumentation.ts @@ -14,14 +14,29 @@ * limitations under the License. */ -import { BrowserContext } from './browserContext'; -import { Page } from './page'; -import { Progress } from './progress'; +import type { BrowserContext } from './browserContext'; +import type { ElementHandle } from './dom'; +import type { Page } from './page'; + +export type ActionMetadata = { + type: 'click' | 'fill', + page: Page, + target: ElementHandle | string, + value?: string, + stack?: string, +}; + +export type ActionResult = { + logs: string[], + startTime: number, + endTime: number, + error?: Error, +}; export interface InstrumentingAgent { onContextCreated(context: BrowserContext): Promise; onContextDestroyed(context: BrowserContext): Promise; - onBeforePageAction(page: Page, progress: Progress): Promise; + onAfterAction(result: ActionResult, metadata?: ActionMetadata): Promise; } export const instrumentingAgents = new Set(); diff --git a/src/server/page.ts b/src/server/page.ts index 6fcc8b9902c8e..50370c4ed5b30 100644 --- a/src/server/page.ts +++ b/src/server/page.ts @@ -32,7 +32,6 @@ import { Progress, runAbortableTask } from './progress'; import { assert, isError } from '../utils/utils'; import { debugLogger } from '../utils/debugLogger'; import { Selectors } from './selectors'; -import { instrumentingAgents } from './instrumentation'; export interface PageDelegate { readonly rawMouse: input.RawMouse; @@ -200,11 +199,7 @@ export class Page extends EventEmitter { } async _runAbortableTask(task: (progress: Progress) => Promise, timeout: number): Promise { - return runAbortableTask(async progress => { - for (const agent of instrumentingAgents) - await agent.onBeforePageAction(this, progress); - return task(progress); - }, timeout); + return runAbortableTask(task, timeout); } async _onFileChooserOpened(handle: dom.ElementHandle) { diff --git a/src/server/progress.ts b/src/server/progress.ts index 9aedfaa20d4fd..ff48369895cab 100644 --- a/src/server/progress.ts +++ b/src/server/progress.ts @@ -18,6 +18,7 @@ import { TimeoutError } from '../utils/errors'; import { assert, monotonicTime } from '../utils/utils'; import { rewriteErrorMessage } from '../utils/stackTrace'; import { debugLogger, LogName } from '../utils/debugLogger'; +import { ActionResult, instrumentingAgents, ActionMetadata } from './instrumentation'; export interface Progress { readonly aborted: Promise; @@ -28,8 +29,8 @@ export interface Progress { throwIfAborted(): void; } -export async function runAbortableTask(task: (progress: Progress) => Promise, timeout: number): Promise { - const controller = new ProgressController(timeout); +export async function runAbortableTask(task: (progress: Progress) => Promise, timeout: number, metadata?: ActionMetadata): Promise { + const controller = new ProgressController(timeout, metadata); return controller.run(task); } @@ -47,15 +48,17 @@ export class ProgressController { // Cleanups to be run only in the case of abort. private _cleanups: (() => any)[] = []; + private _metadata?: ActionMetadata; private _logName: LogName = 'api'; private _state: 'before' | 'running' | 'aborted' | 'finished' = 'before'; private _deadline: number; private _timeout: number; private _logRecordring: string[] = []; - constructor(timeout: number) { + constructor(timeout: number, metadata?: ActionMetadata) { this._timeout = timeout; this._deadline = timeout ? monotonicTime() + timeout : 0; + this._metadata = metadata; this._forceAbortPromise = new Promise((resolve, reject) => this._forceAbort = reject); this._forceAbortPromise.catch(e => null); // Prevent unhandle promsie rejection. @@ -93,11 +96,19 @@ export class ProgressController { const timeoutError = new TimeoutError(`Timeout ${this._timeout}ms exceeded.`); const timer = setTimeout(() => this._forceAbort(timeoutError), progress.timeUntilDeadline()); + const startTime = monotonicTime(); try { const promise = task(progress); const result = await Promise.race([promise, this._forceAbortPromise]); clearTimeout(timer); this._state = 'finished'; + const actionResult: ActionResult = { + startTime, + endTime: monotonicTime(), + logs: this._logRecordring, + }; + for (const agent of instrumentingAgents) + await agent.onAfterAction(actionResult, this._metadata); this._logRecordring = []; return result; } catch (e) { @@ -108,8 +119,16 @@ export class ProgressController { kLoggingNote); clearTimeout(timer); this._state = 'aborted'; - this._logRecordring = []; await Promise.all(this._cleanups.splice(0).map(cleanup => runCleanup(cleanup))); + const actionResult: ActionResult = { + startTime, + endTime: monotonicTime(), + logs: this._logRecordring, + error: e, + }; + for (const agent of instrumentingAgents) + await agent.onAfterAction(actionResult, this._metadata); + this._logRecordring = []; throw e; } } diff --git a/src/trace/snapshotter.ts b/src/trace/snapshotter.ts index 3281bd6a35c89..e72b3bbb3d7fe 100644 --- a/src/trace/snapshotter.ts +++ b/src/trace/snapshotter.ts @@ -45,7 +45,6 @@ export type FrameSnapshot = { resourceOverrides: { url: string, sha1: string }[], }; export type PageSnapshot = { - label: string, viewportSize?: { width: number, height: number }, // First frame is the main frame. frames: FrameSnapshot[], @@ -54,7 +53,6 @@ export type PageSnapshot = { export interface SnapshotterDelegate { onBlob(blob: SnapshotterBlob): void; onResource(resource: SanpshotterResource): void; - onSnapshot(snapshot: PageSnapshot): void; } export class Snapshotter { @@ -74,13 +72,6 @@ export class Snapshotter { helper.removeEventListeners(this._eventListeners); } - async takeSnapshot(progress: Progress, page: Page, label: string): Promise { - assert(page.context() === this._context); - const snapshot = await this._snapshotPage(progress, page, label); - if (snapshot) - this._delegate.onSnapshot(snapshot); - } - private _onPage(page: Page) { this._eventListeners.push(helper.addEventListener(page, Page.Events.Response, (response: network.Response) => { this._saveResource(response).catch(e => debugLogger.log('error', e)); @@ -118,7 +109,9 @@ export class Snapshotter { this._delegate.onBlob({ sha1, buffer: body }); } - private async _snapshotPage(progress: Progress, page: Page, label: string): Promise { + async takeSnapshot(progress: Progress, page: Page): Promise { + assert(page.context() === this._context); + const frames = page.frames(); const promises = frames.map(frame => this._snapshotFrame(progress, frame)); const results = await Promise.all(promises); @@ -169,7 +162,6 @@ export class Snapshotter { } return { - label, viewportSize, frames: [mainFrame.snapshot, ...childFrames], }; diff --git a/src/trace/traceTypes.ts b/src/trace/traceTypes.ts index d9a0700f93926..c016cfa67ab38 100644 --- a/src/trace/traceTypes.ts +++ b/src/trace/traceTypes.ts @@ -38,9 +38,20 @@ export type NetworkResourceTraceEvent = { sha1: string, }; -export type SnapshotTraceEvent = { - type: 'snapshot', +export type ActionTraceEvent = { + type: 'action', contextId: string, - label: string, - sha1: string, + action: string, + target?: string, + label?: string, + value?: string, + startTime?: number, + endTime?: number, + logs?: string[], + snapshot?: { + sha1: string, + duration: number, + }, + stack?: string, + error?: string, }; diff --git a/src/trace/traceViewer.ts b/src/trace/traceViewer.ts index 49cf35e4c4905..29b0eea20de9d 100644 --- a/src/trace/traceViewer.ts +++ b/src/trace/traceViewer.ts @@ -17,7 +17,7 @@ import * as path from 'path'; import * as util from 'util'; import * as fs from 'fs'; -import type { NetworkResourceTraceEvent, SnapshotTraceEvent, ContextCreatedTraceEvent, ContextDestroyedTraceEvent } from './traceTypes'; +import type { NetworkResourceTraceEvent, ActionTraceEvent, ContextCreatedTraceEvent, ContextDestroyedTraceEvent } from './traceTypes'; import type { FrameSnapshot, PageSnapshot } from './snapshotter'; import type { Browser, BrowserContext, Frame, Page, Route } from '../client/api'; import type { Playwright } from '../client/playwright'; @@ -27,7 +27,7 @@ type TraceEvent = ContextCreatedTraceEvent | ContextDestroyedTraceEvent | NetworkResourceTraceEvent | - SnapshotTraceEvent; + ActionTraceEvent; class TraceViewer { private _playwright: Playwright; @@ -71,47 +71,86 @@ class TraceViewer { async show(browserName: string) { const browser = await this._playwright[browserName as ('chromium' | 'firefox' | 'webkit')].launch({ headless: false }); const uiPage = await browser.newPage(); - await uiPage.exposeBinding('renderSnapshot', async (source, event: SnapshotTraceEvent) => { - const snapshot = await fsReadFileAsync(path.join(this._traceStorageDir, event.sha1), 'utf8'); - const context = await this._ensureContext(browser, event.contextId); + await uiPage.exposeBinding('renderSnapshot', async (source, action: ActionTraceEvent) => { + const snapshot = await fsReadFileAsync(path.join(this._traceStorageDir, action.snapshot!.sha1), 'utf8'); + const context = await this._ensureContext(browser, action.contextId); const page = await context.newPage(); - await this._renderSnapshot(page, JSON.parse(snapshot), event.contextId); + await this._renderSnapshot(page, JSON.parse(snapshot), action.contextId); }); - const snapshotsPerContext: { [contextId: string]: { label: string, snapshots: SnapshotTraceEvent[] } } = {}; + const contextData: { [contextId: string]: { label: string, actions: ActionTraceEvent[] } } = {}; for (const trace of this._traces) { let contextId = 0; for (const event of trace.events) { - if (event.type !== 'snapshot') + if (event.type !== 'action') continue; const contextEvent = this._contextEventById.get(event.contextId)!; if (contextEvent.browserName !== browserName) continue; - let contextSnapshots = snapshotsPerContext[contextEvent.contextId]; - if (!contextSnapshots) { - contextSnapshots = { label: trace.traceFile + ' :: context' + (++contextId), snapshots: [] }; - snapshotsPerContext[contextEvent.contextId] = contextSnapshots; + let data = contextData[contextEvent.contextId]; + if (!data) { + data = { label: trace.traceFile + ' :: context' + (++contextId), actions: [] }; + contextData[contextEvent.contextId] = data; } - contextSnapshots.snapshots.push(event); + data.actions.push(event); } } - await uiPage.evaluate(snapshotsPerContext => { - for (const contextSnapshots of Object.values(snapshotsPerContext)) { + await uiPage.evaluate(contextData => { + for (const data of Object.values(contextData)) { const header = document.createElement('div'); - header.textContent = contextSnapshots.label; + header.textContent = data.label; header.style.margin = '10px'; document.body.appendChild(header); - for (const event of contextSnapshots.snapshots) { - const button = document.createElement('button'); - button.style.display = 'block'; - button.textContent = `${event.label}`; - button.addEventListener('click', () => { - (window as any).renderSnapshot(event); - }); - document.body.appendChild(button); + for (const action of data.actions) { + const div = document.createElement('div'); + div.style.whiteSpace = 'pre'; + div.style.borderBottom = '1px solid black'; + const lines = []; + lines.push(`action: ${action.action}`); + if (action.label) + lines.push(`label: ${action.label}`); + if (action.target) + lines.push(`target: ${action.target}`); + if (action.value) + lines.push(`value: ${action.value}`); + if (action.startTime && action.endTime) + lines.push(`duration: ${action.endTime - action.startTime}ms`); + div.textContent = lines.join('\n'); + if (action.error) { + const details = document.createElement('details'); + const summary = document.createElement('summary'); + summary.textContent = 'error'; + details.appendChild(summary); + details.appendChild(document.createTextNode(action.error)); + div.appendChild(details); + } + if (action.stack) { + const details = document.createElement('details'); + const summary = document.createElement('summary'); + summary.textContent = 'callstack'; + details.appendChild(summary); + details.appendChild(document.createTextNode(action.stack)); + div.appendChild(details); + } + if (action.logs && action.logs.length) { + const details = document.createElement('details'); + const summary = document.createElement('summary'); + summary.textContent = 'logs'; + details.appendChild(summary); + details.appendChild(document.createTextNode(action.logs.join('\n'))); + div.appendChild(details); + } + if (action.snapshot) { + const button = document.createElement('button'); + button.style.display = 'block'; + button.textContent = `snapshot after (${action.snapshot.duration}ms)`; + button.addEventListener('click', () => (window as any).renderSnapshot(action)); + div.appendChild(button); + } + document.body.appendChild(div); } } - }, snapshotsPerContext); + }, contextData); } private async _ensureContext(browser: Browser, contextId: string): Promise { diff --git a/src/trace/tracer.ts b/src/trace/tracer.ts index 8cb8bc996d064..7080206aeadcc 100644 --- a/src/trace/tracer.ts +++ b/src/trace/tracer.ts @@ -15,17 +15,18 @@ */ import type { BrowserContext } from '../server/browserContext'; -import type { PageSnapshot, SanpshotterResource, SnapshotterBlob, SnapshotterDelegate } from './snapshotter'; -import { ContextCreatedTraceEvent, ContextDestroyedTraceEvent, NetworkResourceTraceEvent, SnapshotTraceEvent } from './traceTypes'; +import type { SanpshotterResource, SnapshotterBlob, SnapshotterDelegate } from './snapshotter'; +import { ContextCreatedTraceEvent, ContextDestroyedTraceEvent, NetworkResourceTraceEvent, ActionTraceEvent } from './traceTypes'; import * as path from 'path'; import * as util from 'util'; import * as fs from 'fs'; import { calculateSha1, createGuid, mkdirIfNeeded, monotonicTime } from '../utils/utils'; -import { InstrumentingAgent, instrumentingAgents } from '../server/instrumentation'; -import { Page } from '../server/page'; +import { ActionResult, InstrumentingAgent, instrumentingAgents, ActionMetadata } from '../server/instrumentation'; +import type { Page } from '../server/page'; import { Progress, runAbortableTask } from '../server/progress'; import { Snapshotter } from './snapshotter'; import * as types from '../server/types'; +import type { ElementHandle } from '../server/dom'; const fsWriteFileAsync = util.promisify(fs.writeFile.bind(fs)); const fsAppendFileAsync = util.promisify(fs.appendFile.bind(fs)); @@ -48,11 +49,9 @@ export class Tracer implements InstrumentingAgent { } async captureSnapshot(page: Page, options: types.TimeoutOptions & { label?: string } = {}): Promise { - return runAbortableTask(async progress => { - const contextTracer = this._contextTracers.get(page.context()); - if (contextTracer) - await contextTracer._snapshotter.takeSnapshot(progress, page, options.label || 'snapshot'); - }, page._timeoutSettings.timeout(options)); + const contextTracer = this._contextTracers.get(page.context()); + if (contextTracer) + await contextTracer.captureSnapshot(page, options); } async onContextCreated(context: BrowserContext): Promise { @@ -66,10 +65,13 @@ export class Tracer implements InstrumentingAgent { } } - async onBeforePageAction(page: Page, progress: Progress): Promise { - const contextTracer = this._contextTracers.get(page.context()); - if (contextTracer) - await contextTracer._snapshotter.takeSnapshot(progress, page, 'progress'); + async onAfterAction(result: ActionResult, metadata?: ActionMetadata): Promise { + if (!metadata) + return; + const contextTracer = this._contextTracers.get(metadata.page.context()); + if (!contextTracer) + return; + await contextTracer.recordAction(result, metadata); } } @@ -114,17 +116,63 @@ class ContextTracer implements SnapshotterDelegate { this._appendTraceEvent(event); } - onSnapshot(snapshot: PageSnapshot): void { - const buffer = Buffer.from(JSON.stringify(snapshot)); - const sha1 = calculateSha1(buffer); - const event: SnapshotTraceEvent = { - type: 'snapshot', + async captureSnapshot(page: Page, options: types.TimeoutOptions & { label?: string } = {}): Promise { + await runAbortableTask(async progress => { + const label = options.label || 'snapshot'; + const snapshot = await this._takeSnapshot(progress, page); + if (!snapshot) + return; + const event: ActionTraceEvent = { + type: 'action', + contextId: this._contextId, + action: 'snapshot', + label, + snapshot, + }; + this._appendTraceEvent(event); + }, page._timeoutSettings.timeout(options)); + } + + async recordAction(result: ActionResult, metadata: ActionMetadata) { + let snapshot: { sha1: string, duration: number } | undefined; + try { + // Use 20% of the default timeout. + // Never use zero timeout to avoid stalling because of snapshot. + const timeout = (metadata.page._timeoutSettings.timeout({}) / 5) || 6000; + snapshot = await runAbortableTask(progress => this._takeSnapshot(progress, metadata.page), timeout); + } catch (e) { + snapshot = undefined; + } + + const event: ActionTraceEvent = { + type: 'action', contextId: this._contextId, - label: snapshot.label, - sha1, + action: metadata.type, + target: await this._targetToString(metadata.target), + value: metadata.value, + snapshot, + startTime: result.startTime, + endTime: result.endTime, + stack: metadata.stack, + logs: result.logs.slice(), + error: result.error ? result.error.stack : undefined, }; this._appendTraceEvent(event); + } + + private async _targetToString(target: ElementHandle | string): Promise { + return typeof target === 'string' ? target : await target._previewPromise; + } + + private async _takeSnapshot(progress: Progress, page: Page): Promise<{ sha1: string, duration: number } | undefined> { + const startTime = monotonicTime(); + const snapshot = await this._snapshotter.takeSnapshot(progress, page); + if (!snapshot) + return; + const buffer = Buffer.from(JSON.stringify(snapshot)); + const sha1 = calculateSha1(buffer); this._writeArtifact(sha1, buffer); + return { sha1, duration: monotonicTime() - startTime }; } async dispose() {