diff --git a/ARCHITECTURE.md b/ARCHITECTURE.md index fd11018f..3776e8f4 100644 --- a/ARCHITECTURE.md +++ b/ARCHITECTURE.md @@ -192,7 +192,7 @@ The DOM-walking scripts run in the page via `browser.execute`, so — like `scri Per-framework demo projects used for manual verification. -- `examples/wdio/` — WebdriverIO, split into `cucumber/` and `mocha/` (shared page objects in `pageobjects/`). Run via `pnpm demo:wdio` (Cucumber) or `pnpm demo:wdio:mocha`. +- `examples/wdio/` — WebdriverIO, split into `cucumber/` and `mocha/` (shared page objects in `pageobjects/`). Run via `pnpm demo:wdio` (Cucumber), `pnpm demo:wdio:mocha`, or `pnpm demo:wdio:native` (Appium native app — needs a running Appium server and a device, see the README's Mobile testing section). - `examples/nightwatch/` — Nightwatch (both vanilla and Cucumber). Run via `pnpm demo:nightwatch`. - `examples/selenium/` — Selenium with subdirs for `mocha-test/`, `jest-test/`, `cucumber-test/`, `jasmine-test/`, `vitest-test/`. `pnpm demo:selenium` runs mocha; `pnpm --filter @wdio/selenium-devtools example:` runs the others. diff --git a/CLAUDE.md b/CLAUDE.md index 9196819f..2e6346fd 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -81,6 +81,10 @@ The split is not aesthetic. **`backend` may not import `core`** (it would pull f The test for a new helper: *would the backend ever need this to build a zip?* If yes, `trace`. If it needs a driver, a framework hook, or a capture session, `core`. +### One DOM snapshot per action, taken before it + +The per-action trace snapshot is captured in `beforeCommand`, stamped at the previous action's end, so an action's result IS the next action's "before" and every row resolves to a state the driver was idle for. `afterCommand` captures nothing in trace mode. An eager post-action capture — added and removed twice — lands while the screen is still moving, which is the only reason `waitForActionResult` and the `__wdioSnapMark` document tag existed; both are deleted, and both should stay that way. The last action has no successor, so `#finalizePerScenario` supplies it and names its capture after that action — `lastRenderedScreenshot` skips a capture named `__final__`, which is reserved for a session that ran no action at all. What that one capture waits on is `settleAfterLastAction`, and the wait is **gated, not timed**: the drain that runs immediately before it (`captureTrace(browser, true)`) anchors each document once, so `SessionCapturer.replacedDocumentInLastDrain` says whether the last action navigated to a document the session had not seen. No → return at once (the app has been at rest since the last action, so the test's own teardown is the gap that let the paint land). Yes → `waitUntil(document.readyState === 'complete')`, which is only meaningful once you know the document being described is the incoming one: ungated, the OUTGOING document already reports 'complete' right after a click, so a blind poll returns instantly and captures the page the test just left, and the old `body.childElementCount > 0` clause that papered over that made a legitimately blank destination a guaranteed 8 s timeout per test. Native pauses 250 ms instead (no document to poll; a capture at a 0 s gap measures 359–476 KB against 1.87 MB settled on Appium). Residual: a navigation that has not *committed* when the anchor is read still reads as "no navigation" — the same blind spot the deleted document tag had. Don't reintroduce a poll without a gate, or a tag. + ### Adapters are thin and isolated Adapter packages own only: @@ -308,7 +312,7 @@ Documented divergences from the conventions above. They exist today as debt to b - **A Nightwatch command failure arrives as a callback RESULT, not a throw.** Only a synchronous failure reaches the `try/catch` around the wrapped method; an async one (a command that times out waiting for an element) invokes the capture callback with an error-shaped object, and the driver response nests it one level down under the W3C `value` wrapper. `browserProxy.ts` `callbackError` unwraps that and promotes it to the row's `error`. Left in `result`, the row kept `error: undefined` and rendered as a success — no red row, nothing in the Errors tab, the failure readable only as raw text in the result pane. A result carrying `passed` is an assertion outcome and is deliberately not reinterpreted, since those have their own pass/fail path. - **Row order comes from issue order (`CommandLog.sequence`), not from the millisecond clock.** `browser.assert.*` calls are enqueued synchronously and the next command is invoked in the same millisecond, so their `startTime`s tie; because assert rows are appended in the test-end batch while driver rows are appended at completion, the tie resolved in insertion order and put an assert *after* the command it preceded (measured: `assert.textContains` landing below the logout click it ran before). Nightwatch stamps `sequence` when the test issues a row — a driver command at invocation, an assert at enqueue — and `buildActionEvents` uses it as the sort tiebreak. Adapters that emit no deferred rows leave it unset and keep insertion order. - Nightwatch's own per-assertion execution windows are unavailable here: `results.commands` is **empty** for the BDD interface, so `assertCommandTimings` always returns nulls and the rows keep their enqueue timestamp. That is why issue order, not reported timing, has to carry the ordering. -- **Actions that only read the page inherit the preceding action's capture** (`core/trace-frame-snapshots.ts` `claimAfter`). It is non-consuming and falls back to the most recent earlier capture instead of returning nothing, because several actions legitimately share one page state — Nightwatch emits its native assertion rows in a batch whose execution windows collapse onto one instant, and handing the capture to whichever claimed first left the rest of the batch with no DOM, no a11y tree and no screenshot. Nightwatch correspondingly takes **no** capture for an assertion row (`captureAssertCommand`): those rows are emitted at test-end but positioned back on their real execution window, so probing there recorded the page as it was *then* under a timestamp seconds earlier (an assert that ran on `/secure` rendered the `/login` page the test later logged out to). +- **Actions that only read the page inherit the preceding action's capture** (`packages/trace/src/trace-frame-snapshots.ts` `claimAfter`). It is non-consuming and falls back to the most recent earlier capture instead of returning nothing, because several actions legitimately share one page state — Nightwatch emits its native assertion rows in a batch whose execution windows collapse onto one instant, and handing the capture to whichever claimed first left the rest of the batch with no DOM, no a11y tree and no screenshot. Nightwatch correspondingly takes **no** capture for an assertion row (`captureAssertCommand`): those rows are emitted at test-end but positioned back on their real execution window, so probing there recorded the page as it was *then* under a timestamp seconds earlier (an assert that ran on `/secure` rendered the `/login` page the test later logged out to). - **Every per-action snapshot probe is timeout-guarded** (`core/action-snapshot.ts` `probe`, `SNAPSHOT_DRIVER_PROBE_TIMEOUT_MS`), not just the in-page scripts. Nightwatch's `browser.getCurrentUrl()`/`getTitle()` are QUEUED commands: called from inside the plugin's own command hook they enqueue behind the command still running and never resolve, and one unguarded probe in the capture's `Promise.all` stranded the whole snapshot — 10 of 14 captures never settled, so those actions reached the trace with no DOM, no a11y tree and no element rects. Nightwatch now runs all four probes (url/title/screenshot/script) over the raw WebDriver HTTP transport in `nightwatch-devtools/src/helpers/webdriverHttp.ts`, bypassing the queue entirely — the pattern `takeScreenshotViaHttp` already used. Relatedly, `runWith` treats a `null` script result as its fallback: a driver that answers `null` instead of rejecting (no-such-session, transport-swallowed script error) otherwise handed the serializers a non-array and lost the entire snapshot, screenshot and all. - The per-test `screenshot` and `video` options live on the **WDIO `ServiceOptions` only** — not `BaseDevToolsOptions` — because only the service implements them (an option belongs on an adapter until a second adapter consumes it, mirroring the core-helper rule; putting them on the shared base made them appear available in Selenium/Nightwatch and broke those adapters' `Required<>` option types). The policy *types* (`TraceScreenshotPolicy`/`TraceVideoPolicy`) and the capture/slice/encode logic (`core/screenshot-artifact.ts`, `core/video-slice.ts`) are framework-agnostic, so Selenium/Nightwatch adoption was wiring-only — now done (Selenium adds the options on its own `DevToolsOptions` with full inline attach; Nightwatch adds them produce-only — see the Allure-attach entry below). All are gated to `traceGranularity:'test'` (per-test inline Allure); coarser granularities keep artifacts in the manifest. Video records the screencast continuously and slices per-test by wall-time — the session frame buffer is bounded by `maxBufferFrames` (default 2000; decimates keeping first/last), and on non-Chrome the polling recorder issues many `takeScreenshot`s that flood `@wdio/allure-reporter` (pair with `disableWebdriverStepsReporting`). - The `filmstrip` option (dense screencast into the trace) is on **`BaseDevToolsOptions`** — the counterexample to the screenshot/video entry above — because all three adapters implement it (the "second consumer → base" rule realized). Core owns the work (`core/screencast-trace.ts` `thinScreencastFrames`/`buildDenseScreencast`; slice windowing in `spec-trace-helpers.ts`); adapters only default the option, un-gate the recorder in trace mode when it's set, and feed `recorder.frames` into the finalize context. Each adapter captures frames while the recorder is still alive (service `onReload` → `#filmstripFrames`; Selenium `onDriverEnd` drain before nulling; Nightwatch `#finalizeCurrentScreencast` snapshot before delegating), and each finalize context spreads `[...accumulated, ...(live recorder frames)]` so a **mid-run** per-spec/per-test slice flush (which fires before the recorder is drained) isn't blank. When dense frames are present they **supersede** the sparse per-action filmstrip (the per-action DOM `elements`/`snapshot` are carried independently by the `frame-snapshot` events, so no DOM data is lost); a run without dense frames keeps the sparse filmstrip, byte-stable with before. Thinning is applied at export; the live session frame buffer is bounded by `maxBufferFrames` (default 2000; see the screenshot/video entry above). Per-test filmstrip slicing follows the same per-test-hook availability as `traceGranularity:'test'` (works for WDIO mocha/cucumber, Selenium mocha, Nightwatch exports-object/cucumber; Nightwatch BDD `describe/it` degrades to session scope per the entry below), and non-Chrome polling carries the same reporter-noise caveat. @@ -330,11 +334,18 @@ Documented divergences from the conventions above. They exist today as debt to b - **Two mechanisms resolve a command's target selector, and the WDIO one is wrong for interleaved handles.** Selenium keys a `WeakMap` on handle identity (`WebElement.id_` is a promise, so no id is readable when a command is invoked); the service uses a mutable last-selector in `service/src/command-selectors.ts`, which stamps the wrong locator for `const a = await $('#a'); const b = await $('#b'); await a.click()` (the Selenium side is covered in `selenium-devtools/tests/element-locators.test.ts`; the WDIO failure itself has **no** test — it is an unverified reading of `command-selectors.ts`). They cannot share a registry — WDIO's hook sees a *serialized* handle carrying an id string and never the live object, Selenium has the object and no readable id. Unifying would need the policy parameterized rather than the storage shared; until then the WDIO path is knowingly wrong in that case. Nightwatch is a third mechanism: it reads arg 0 through a per-kind allowlist (`assertTarget.ts`) rather than tracking handles at all, because its classic API takes selector strings. The allowlists are deliberately **not** derived from shared's `ACTION_MAP` — that table says how a command *renders* (its `Element` entries include WDIO commands called on a handle, with no selector argument), not whether arg 0 is an element definition. - Service renders expect-webdriverio matchers as single `expect.` rows by **folding**, not stack/depth suppression (the old `#assertionDepth`/`#matcherStarted`/self-heal machinery is gone). The matcher's value-read (`toHaveText`→`getText`, `toExist`→`isExisting`, …) is captured as a normal command; `afterAssertion` then coalesces the synthesized `expect.*` row into that read in place — inheriting its callSource, screenshot, and timeline position — and the fold replaces **by timestamp, never a public `id`**: `id` is the per-worker `commandCounter`, which resets per spec, so stamping one lets the app's id-first `replaceCommand` swap a same-id row from another spec (duplicate rows + a fold from another spec vanishing, in multi-spec live mode). `beforeAssertion` arms the pending matcher (depth-counted so aliases like `toBeChecked`→`toBeSelected` fold once); a matcher that **hard-throws** — element never resolves, so expect-webdriverio's `waitUntil` rethrows and `afterAssertion` never fires — is synthesized at `afterTest`/`afterStep` from the throwing read, so a failing assertion renders as `expect.` whether or not the element existed. Two limits: its error is then the read's (`Can't call getText on … element wasn't found`), not an assertion-phrased message; and `MATCHER_READ_COMMANDS` is a hand-maintained allowlist, so a matcher whose read isn't listed leaves its raw read visible alongside the `expect.*` row. Plain-value jest matchers (`expect(x).toBe(y)`) don't fire the ewdio hooks, so they aren't captured as rows. +### What a per-action trace capture costs + +- **One capture per action means two driver round trips per action, and the platform decides which half is expensive.** Measured on Appium 3.7.0 / UiAutomator2 (emulator-5554, Android API 37, 1080×2424): `GET /screenshot` 1.18–2.22 s (steady ~1.20 s) at 1.86 MB, `GET /source` (page-source XML) 0.09–0.53 s at 40 KB, `window/rect` 0.015 s — the screenshot dominates by ~10× on Android. **iOS is unmeasured**; the issue claims the split inverts there, and the native example (`examples/wdio/mocha/wdio.native.conf.ts`) is what makes it measurable. Measured per action: two captures 2.41 s against one capture 1.19 s; end-to-end on the native example 19.1 s against 12.4 s, with live mode (no per-action capture) at 5.9 s. That is the case for the `beforeCommand` capture, and the reason an eager post-action capture is not worth re-adding: it cost a second capture per action and existed only to be patched by a `readyState` poll that could not tell a document that had not navigated yet from one that was loading. +- A filmstrip poll against a native session stacks requests: `setInterval` never waits for its async handler, a native screenshot takes ~1.2 s against the 200 ms default, and a serialised driver serves that queue ahead of the test's own commands — measured, a **15 ms command took 4.5–7.8 s**. `ScreencastRecorderBase`'s `#pollInFlight` latch bounds it to one outstanding shot, and `#pollGeneration` stops a shot orphaned by `stop()` from appending into the next recording or clearing its successor's latch. +- Residual: **a polling matcher fires one capture per poll** — each poll is a top-level mapped read — so "one capture per action" undercounts a real suite. Pre-existing in `d924a02`, unmeasured on a device, and the likeliest next lever. +- The next test's first pre-capture used to be stamped at the previous test's last-action timestamp — the log it scans is run-long, so a test boundary was invisible to it. That slot already holds the previous test's finalize capture, and the richer-screenshot merge could replace it: with a `reloadSession` between the tests the row replayed the post-reload page. The capture now stamps `Date.now()` when the scanned timestamp predates `#currentTestStartWallTime` (0 without per-test hooks, so the standalone path is unchanged) — the same rule that makes a session's first capture its initial frame. Per-test slices were never affected: `flushTest` runs inside `afterTest`, before the next test's commands. + ### File-size (raw line counts; soft cap is 500 logic lines) Most entries below don't trigger the `max-lines` lint rule after `skipBlankLines`/`skipComments`; they're documented because their raw line count is over 500, and the next substantive change to any of them should still look for an extraction opportunity. The service plugin is the exception — it's now over the *logic*-line cap. -- `packages/service/src/index.ts` (602 logic / 843 raw, was 729/1043). Still over the 500-logic cap. The screencast and trace-slice seams are extracted: `screencast-lifecycle.ts` (139 logic / 217 raw) owns every read and write of recorder frames — start, reload, finalize, the cross-`reloadSession` filmstrip buffer and the per-test video slice, two invariants that were previously produced and consumed 400 lines apart — and `trace-slices.ts` (58 logic / 87 raw) owns boundary recording plus the eager per-test flush beside the flush I/O it already held. The only remaining cluster large enough to close the gap is the command-hook family (`beforeCommand`/`afterCommand`/`#commandStack`/`#markDocument`/`#drainAfterLiveCommand`, ~120 logic lines); `before()` is still over the function cap at 62 logic lines. +- `packages/service/src/index.ts` (599 logic / 856 raw, was 729/1043). Still over the 500-logic cap. The screencast and trace-slice seams are extracted: `screencast-lifecycle.ts` (139 logic / 217 raw) owns every read and write of recorder frames — start, reload, finalize, the cross-`reloadSession` filmstrip buffer and the per-test video slice, two invariants that were previously produced and consumed 400 lines apart — and `trace-slices.ts` (58 logic / 87 raw) owns boundary recording plus the eager per-test flush beside the flush I/O it already held. The only remaining cluster large enough to close the gap is the command-hook family (`beforeCommand`/`afterCommand`/`#commandStack`/`#drainAfterLiveCommand`, ~120 logic lines); `before()` is still over the function cap at 62 logic lines. - `packages/nightwatch-devtools/src/index.ts` (783 raw / 676 logic). Cucumber/test/run-lifecycle, session-init, event-hub and now the screencast seam (`plugin-screencast.ts`, 105 raw / 60 logic) are extracted; the remainder is the `PluginInternals` accessor bag plus per-method delegators plus the factory. The bag is deliberately declarative — accept as-is. - `packages/selenium-devtools/src/index.ts` (~644 raw, down from ~758 — the dead `scriptInjected` accessor pair and setter are gone). Session/test-lifecycle **and** the per-test-artifact seam are now extracted: the sink cache + input snapshot + produce/attach flow live in `selenium-devtools/src/test-artifacts.ts` as `SeleniumTestArtifacts` (mirrors Nightwatch's twin — a typed input bag threading the Allure sink + flushed-trace promise), and the plugin keeps only a thin bag-building delegator. Remainder is the `PluginInternals` accessor bag plus onCommand/onDriverCreated wiring. Still over the 500 **raw** soft cap (under the logic-line cap after `skipBlankLines`/`skipComments`); the accessor bag / command wiring is the next extraction candidate if it grows. - `packages/nightwatch-devtools/src/session.ts` (519 raw, under the logic-line cap after `skipBlankLines`/`skipComments`). `captureNetworkFromPerformanceLogs` + `captureBrowserLogs` + `drainCollector` are tightly coupled to NightwatchBrowser state. Coverage at 78% after recent backfill; further extraction would need rewriting the browser-coupling. diff --git a/README.md b/README.md index 9cec10dc..deefa1a5 100644 --- a/README.md +++ b/README.md @@ -202,7 +202,7 @@ services: [[DevToolsHookService, { Adapters detect mobile sessions via `platformName: 'android' | 'ios'` (case-insensitive) and adjust the per-action snapshot to extract elements from the mobile XML tree instead of the DOM. The trace's `context-options` records `title: 'android' — ` / `'ios' — ` so the viewer labels frames correctly. -A reference WDIO config is at [examples/wdio/cucumber/wdio.mobile.conf.ts](examples/wdio/cucumber/wdio.mobile.conf.ts). Prereqs to run it end-to-end with a local emulator: +A reference WDIO config is at [examples/wdio/cucumber/wdio.mobile.conf.ts](examples/wdio/cucumber/wdio.mobile.conf.ts) — that one drives Chrome *on* the device. For a native app (no document at all, so the snapshot reads the page-source XML) there is [examples/wdio/mocha/wdio.native.conf.ts](examples/wdio/mocha/wdio.native.conf.ts), run via `pnpm demo:wdio:native`: it needs no APK, launches a preinstalled app, and reads its Appium endpoint from `APPIUM_HOST` / `APPIUM_PORT` / `APPIUM_DEVICE` (plus `APPIUM_APP` to install a bundle instead). No Chromedriver is involved. Prereqs to run either end-to-end with a local emulator: 1. **Java JDK** — `brew install --cask temurin` 2. **Android SDK** — `brew install --cask android-commandlinetools` then `yes | sdkmanager --licenses && sdkmanager "platform-tools" "emulator" "system-images;android-34;google_apis_playstore;arm64-v8a"`. The brew cask installs sdkmanager under `/opt/homebrew/share/android-commandlinetools/`, and sdkmanager downloads other SDK pieces alongside it — set `ANDROID_HOME` to that path (not `~/Library/Android/sdk/`). diff --git a/examples/wdio/mocha/native/clock.e2e.ts b/examples/wdio/mocha/native/clock.e2e.ts new file mode 100644 index 00000000..9c513ec6 --- /dev/null +++ b/examples/wdio/mocha/native/clock.e2e.ts @@ -0,0 +1,42 @@ +// A native Android spec: no document, no URL, no DOM — the capture path a +// browser session never exercises. Drives Clock, which ships with every Android +// system image, so the example needs no APK and no app upload. +// +// Every selector below was read off an emulator (API 37, Clock from +// com.google.android.deskclock); resource-ids are used over text because the +// countdown text changes every second. +import { expect } from '@wdio/globals' + +const APP_ID = 'com.google.android.deskclock' + +const byId = (id: string) => + $(`android=new UiSelector().resourceId("com.google.android.deskclock:id/${id}")`) + +describe('Clock (native)', () => { + it('starts a preset timer, pauses it, and clears it', async () => { + console.log('[TEST] launching the Clock app') + // `mobile: activateApp` rather than an `appium:app`/`appActivity` + // capability: the activity name is build-specific and this needs no + // adb_shell, which Appium does not enable by default. + await browser.execute('mobile: activateApp', { appId: APP_ID }) + + console.log('[TEST] opening the Timers tab') + await byId('tab_menu_timer').click() + + console.log('[TEST] starting the 5 minute preset') + // This build starts the timer straight from the preset — verified on the + // device — so the running countdown is the evidence the tap landed. + await byId('timer_preset_2').click() + await expect(byId('timer_text')).toHaveText(/^\d{2}:\d{2}$/) + + console.log('[TEST] pausing the timer') + await byId('play_pause_button').click() + // The button's accessibility label flips with the timer's state; asserting + // on it keeps this step off the countdown's own clock. + await expect($(`~Start 5 minutes timer`)).toBeDisplayed() + + console.log('[TEST] clearing the timer') + await byId('delete_button').click() + await expect(byId('timer_text')).not.toBeDisplayed() + }) +}) diff --git a/examples/wdio/mocha/wdio.native.conf.ts b/examples/wdio/mocha/wdio.native.conf.ts new file mode 100644 index 00000000..c43ed5bb --- /dev/null +++ b/examples/wdio/mocha/wdio.native.conf.ts @@ -0,0 +1,80 @@ +// Native-app variant of wdio.trace.conf.ts: drives a preinstalled Android app +// over Appium, so a trace can be produced from a session that has NO document — +// the path where the per-action snapshot reads page-source XML instead of +// running page scripts. The mobile-WEB variant lives in +// cucumber/wdio.mobile.conf.ts; that one drives Chrome on the device and takes +// the web capture path, so the two are not interchangeable. +// +// Prerequisites: an Appium server with the UiAutomator2 driver +// (`appium driver install uiautomator2`) and an emulator or device attached. +// The endpoint and device come from the environment, so a remote host works: +// +// APPIUM_HOST=100.69.254.5 APPIUM_PORT=4723 pnpm native +// +// No APK is needed — the spec launches a preinstalled app itself. Set +// APPIUM_APP to a bundle path or URL to install one instead. +export const config: WebdriverIO.Config = { + runner: 'local', + + // Native specs live in their own folder so the web configs' `./specs/**` + // glob can't pick them up — they drive Appium, not a browser. + specs: ['./native/**/*.e2e.ts'], + exclude: [], + + hostname: process.env.APPIUM_HOST ?? '127.0.0.1', + port: Number(process.env.APPIUM_PORT ?? 4723), + path: '/', + + maxInstances: 1, + capabilities: [ + { + platformName: 'Android', + 'appium:automationName': 'UiAutomator2', + 'appium:deviceName': process.env.APPIUM_DEVICE ?? 'emulator-5554', + // Keep whatever the app already has on the device — this example drives + // an app it did not install. + 'appium:noReset': true, + ...(process.env.APPIUM_APP ? { 'appium:app': process.env.APPIUM_APP } : {}), + // Appium's BiDi shim for UiAutomator2 doesn't implement every BiDi + // command (e.g. script.addPreloadScript), so keep WDIO on classic. + 'wdio:enforceWebDriverClassic': true + } + // eslint-disable-next-line @typescript-eslint/no-explicit-any + ] as any, + + logLevel: 'warn', + bail: 0, + waitforTimeout: 15000, + connectionRetryTimeout: 120000, + connectionRetryCount: 3, + services: [ + [ + 'devtools', + { + // Trace by default; DEVTOOLS_MODE=live gives the same spec a baseline to + // measure the capture cost against. + mode: (process.env.DEVTOOLS_MODE === 'live' ? 'live' : 'trace') as + | 'live' + | 'trace', + traceGranularity: (process.env.DEVTOOLS_TRACE_GRANULARITY ?? + 'session') as 'session' | 'spec' | 'test', + tracePolicy: (process.env.DEVTOOLS_TRACE_POLICY ?? 'on') as + | 'on' + | 'retain-on-failure' + | 'retain-on-first-failure', + // Off by default because a native session has no CDP: the recorder + // falls back to polling `takeScreenshot` on an interval, which against a + // phone is a second, competing source of driver round trips. Set + // DEVTOOLS_FILMSTRIP=on to record one anyway. + filmstrip: process.env.DEVTOOLS_FILMSTRIP === 'on', + emitArtifactsManifest: true + } + ] + ], + framework: 'mocha', + reporters: ['spec'], + mochaOpts: { + ui: 'bdd', + timeout: 120000 + } +} diff --git a/examples/wdio/mocha/wdio.trace.conf.ts b/examples/wdio/mocha/wdio.trace.conf.ts index b50b9961..3994b419 100644 --- a/examples/wdio/mocha/wdio.trace.conf.ts +++ b/examples/wdio/mocha/wdio.trace.conf.ts @@ -46,6 +46,10 @@ export const config: WebdriverIO.Config = { | 'on-first-retry' | 'on-all-retries' | 'retain-on-failure-and-retries', + // Dense screencast frames written into the trace; on by default, and the + // heaviest part of a session's teardown. DEVTOOLS_FILMSTRIP=off measures + // the trace without them. + filmstrip: process.env.DEVTOOLS_FILMSTRIP !== 'off', // Always emit the manifest so the artifact set is inspectable per run. emitArtifactsManifest: true } diff --git a/examples/wdio/package.json b/examples/wdio/package.json index f2a13edd..30c3e369 100644 --- a/examples/wdio/package.json +++ b/examples/wdio/package.json @@ -22,6 +22,7 @@ "cucumber": "wdio run ./cucumber/wdio.conf.ts", "mocha": "wdio run ./mocha/wdio.conf.ts", "mobile": "wdio run ./cucumber/wdio.mobile.conf.ts", + "native": "wdio run ./mocha/wdio.native.conf.ts", "trace": "wdio run ./cucumber/wdio.trace.conf.ts", "retention": "wdio run ./cucumber/wdio.retention.conf.ts" } diff --git a/package.json b/package.json index 0fd9355a..9c6d2bd2 100644 --- a/package.json +++ b/package.json @@ -10,6 +10,7 @@ "demo:wdio": "wdio run ./examples/wdio/cucumber/wdio.conf.ts", "demo:wdio:mocha": "wdio run ./examples/wdio/mocha/wdio.conf.ts", "demo:wdio:retry": "wdio run ./examples/wdio/mocha/wdio.retry.conf.ts", + "demo:wdio:native": "wdio run ./examples/wdio/mocha/wdio.native.conf.ts", "demo:nightwatch": "pnpm --filter @wdio/nightwatch-devtools example", "demo:nightwatch:retry": "pnpm --filter @wdio/nightwatch-devtools example:retry", "demo:selenium": "pnpm --filter @wdio/selenium-devtools example", diff --git a/packages/backend/src/trace-reader-utils.ts b/packages/backend/src/trace-reader-utils.ts index 0026dce0..7e23b1ed 100644 --- a/packages/backend/src/trace-reader-utils.ts +++ b/packages/backend/src/trace-reader-utils.ts @@ -290,20 +290,27 @@ export function buildSources( return sources } +/** The frame that shows a command's state: the latest capture at or before it, + * since a capture is stamped when the document was read. Falling back to the + * next later frame only when nothing precedes keeps a row without a capture of + * its own from replaying the state its SUCCESSOR produced, which is what an + * absolute-nearest rule does when the successor's frame is the closer one. */ export function nearestFrame( frames: TracePlayerFrame[], timestamp: number ): TracePlayerFrame | undefined { - let best: TracePlayerFrame | undefined - let bestDelta = Infinity + let preceding: TracePlayerFrame | undefined + let following: TracePlayerFrame | undefined for (const frame of frames) { - const delta = Math.abs(frame.timestamp - timestamp) - if (delta < bestDelta) { - bestDelta = delta - best = frame + if (frame.timestamp <= timestamp) { + if (!preceding || frame.timestamp > preceding.timestamp) { + preceding = frame + } + } else if (!following || frame.timestamp < following.timestamp) { + following = frame } } - return best + return preceding ?? following } export function buildMetadata(ctx: ContextOptionsEvent | undefined): Metadata { diff --git a/packages/backend/tests/trace-reader.test.ts b/packages/backend/tests/trace-reader.test.ts index a414ac56..6aae8008 100644 --- a/packages/backend/tests/trace-reader.test.ts +++ b/packages/backend/tests/trace-reader.test.ts @@ -6,7 +6,11 @@ import type { TraceActionGroupNode } from '@wdio/devtools-shared' import { parseTraceZip } from '../src/trace-reader.js' -import { buildSources, stackToCallSource } from '../src/trace-reader-utils.js' +import { + buildSources, + nearestFrame, + stackToCallSource +} from '../src/trace-reader-utils.js' import type { BeforeEvent } from '../src/trace-reader-types.js' function allGroups(children: TraceActionChild[]): TraceActionGroupNode[] { @@ -858,3 +862,26 @@ describe('glued callSource recovery from older zips', () => { expect(sources).toEqual({ [clean]: 'glued source' }) }) }) + +describe('nearestFrame', () => { + const frame = (timestamp: number) => ({ timestamp, screenshot: 'x' }) + + it('shows a row the state it observed, not the one its successor produced', () => { + // One capture per action means a row without one of its own (an assert row, + // an internal command) sits BETWEEN two captures. The later one is the + // successor's result, so the earlier is the state this row actually saw. + const frames = [frame(100), frame(300)] + expect(nearestFrame(frames, 220)).toEqual(frame(100)) + expect(nearestFrame(frames, 260)).toEqual(frame(100)) + }) + + it('takes the next frame when nothing precedes the row', () => { + expect(nearestFrame([frame(300)], 220)).toEqual(frame(300)) + }) + + it('prefers the frame at the row own timestamp', () => { + const frames = [frame(100), frame(300)] + expect(nearestFrame(frames, 300)).toEqual(frame(300)) + expect(nearestFrame(frames, 100)).toEqual(frame(100)) + }) +}) diff --git a/packages/core/src/allure-artifacts.ts b/packages/core/src/allure-artifacts.ts index 88c80c34..a4779753 100644 --- a/packages/core/src/allure-artifacts.ts +++ b/packages/core/src/allure-artifacts.ts @@ -81,13 +81,21 @@ export async function attachTraceArtifact( } } +/** A snapshot's command for a session that ran no action at all, so the frame + * carries no result to show and may be a blank post-teardown page. Written by + * the service's per-scenario finalize, skipped by `lastRenderedScreenshot`. + * Shared rather than repeated: a rename on one side would silently stop the + * skip from matching and start attaching those frames as test screenshots. */ +export const FINAL_SNAPSHOT_COMMAND = '__final__' + /** * The base64 of the last rendered action snapshot for the current test, skipping - * the end-of-scenario `__final__` frame (captured post-teardown, often blank when - * a reloadSession runs before the after-hook). Scoped to `>= startWallTime` so a - * test that captured nothing doesn't borrow the previous test's frame. Reused as - * the per-test screenshot — reload-immune and one fewer WebDriver command than a - * fresh end-of-test capture. + * a `FINAL_SNAPSHOT_COMMAND` frame — which a session that ran no action at all + * produces, so it carries no result to show and may be a blank post-teardown + * page. Scoped to `>= startWallTime` so a test that captured nothing doesn't + * borrow the previous test's frame. Reused as the per-test screenshot — + * reload-immune and one fewer WebDriver command than a fresh end-of-test + * capture. */ export function lastRenderedScreenshot( snapshots: readonly ActionSnapshot[], @@ -98,7 +106,7 @@ export function lastRenderedScreenshot( if (snap.timestamp < startWallTime) { return undefined } - if (snap.command !== '__final__' && snap.screenshot) { + if (snap.command !== FINAL_SNAPSHOT_COMMAND && snap.screenshot) { return snap.screenshot } } diff --git a/packages/core/src/screencast.ts b/packages/core/src/screencast.ts index e5d3b8f9..44afc2e1 100644 --- a/packages/core/src/screencast.ts +++ b/packages/core/src/screencast.ts @@ -22,6 +22,11 @@ export abstract class ScreencastRecorderBase { protected options: Required protected driver?: TDriver #pollTimer: ReturnType | undefined + #pollInFlight = false + /** Bumped by start and stop alike. A shot that outlives its loop compares + * against this: its frame belongs to the old recording, and the latch it + * holds is not the successor's to clear. */ + #pollGeneration = 0 #isRecording = false #cdpActive = false #startIndex = 0 @@ -41,14 +46,22 @@ export abstract class ScreencastRecorderBase { if (this.#isRecording) { return } + // Claimed before the first await, because a stop() arriving during any of + // them has nothing else to invalidate: nothing is armed, and #isRecording is + // still false, so without this the loop would be armed after the caller + // stopped it. A native session's first screenshot runs ~1.2 s. + const generation = ++this.#pollGeneration this.driver = driver const cdpOk = await this.tryStartCdp() + if (generation !== this.#pollGeneration) { + return + } if (cdpOk) { this.#cdpActive = true this.#isRecording = true return } - await this.#startPolling() + await this.#startPolling(generation) } /** @@ -56,6 +69,10 @@ export abstract class ScreencastRecorderBase { * never called or failed. */ async stop(): Promise { + // Bumped before the early return: a stop() that lands while start() is still + // awaiting its first screenshot finds nothing armed and #isRecording still + // false, so returning above would let start() arm the loop afterwards. + this.#pollGeneration++ if (!this.#isRecording) { return } @@ -209,9 +226,12 @@ export abstract class ScreencastRecorderBase { // ─── Polling implementation ───────────────────────────────────────────── - async #startPolling(): Promise { + async #startPolling(generation: number): Promise { try { const first = await this.takeScreenshot() + if (generation !== this.#pollGeneration) { + return + } if (first === null) { this.onUnavailable(new Error('first screenshot returned null')) return @@ -227,14 +247,28 @@ export abstract class ScreencastRecorderBase { if (isInputDispatchInFlight()) { return } + // setInterval does not wait for this handler. A screenshot slower than + // the interval stacks requests that a serialised driver then serves + // ahead of the test's own commands (a native session's screenshot runs + // ~1.2 s against a 200 ms default) — keep at most one outstanding. + if (this.#pollInFlight) { + return + } + this.#pollInFlight = true try { const data = await this.takeScreenshot() - if (data !== null) { + if (data !== null && generation === this.#pollGeneration) { this.#appendFrame({ data, timestamp: Date.now() }) } } catch { // Session ended mid-interval — stop polling gracefully. - this.#stopPolling() + if (generation === this.#pollGeneration) { + this.#stopPolling() + } + } finally { + if (generation === this.#pollGeneration) { + this.#pollInFlight = false + } } }, intervalMs) @@ -249,6 +283,12 @@ export abstract class ScreencastRecorderBase { if (this.#pollTimer !== undefined) { clearInterval(this.#pollTimer) this.#pollTimer = undefined + // A shot issued just before the stop outlives it. Bumping the generation + // keeps that orphan from appending into a later recording or clearing the + // successor's latch, and clearing the latch here lets a restart tick + // without waiting on it. + this.#pollGeneration++ + this.#pollInFlight = false this.onPollingStopped(this.buffer.length) } } diff --git a/packages/core/tests/allure-artifacts.test.ts b/packages/core/tests/allure-artifacts.test.ts index 7ce26252..39bffc9f 100644 --- a/packages/core/tests/allure-artifacts.test.ts +++ b/packages/core/tests/allure-artifacts.test.ts @@ -106,6 +106,14 @@ describe('lastRenderedScreenshot', () => { expect(lastRenderedScreenshot(snaps, 100)).toBe('BB') }) + it('returns a last-action frame that carries the action name', () => { + // The service captures the FINAL action's result in its own finalize, named + // after that action — the marker is only for a session with no action at + // all, so the screenshot a failing test is judged on is the failure's. + const snaps = [snap('setValue', 200, 'BB'), snap('click', 300, 'CC')] + expect(lastRenderedScreenshot(snaps, 100)).toBe('CC') + }) + it('returns undefined when the only snapshots predate the test start', () => { expect( lastRenderedScreenshot([snap('click', 50, 'AA')], 100) diff --git a/packages/core/tests/screencast.test.ts b/packages/core/tests/screencast.test.ts index 663a7693..b58eb207 100644 --- a/packages/core/tests/screencast.test.ts +++ b/packages/core/tests/screencast.test.ts @@ -54,6 +54,32 @@ describe('ScreencastRecorderBase — polling path', () => { expect(throwR.isRecording).toBe(false) }) + it('does not arm a loop that a stop() during the first shot has cancelled', async () => { + vi.useFakeTimers() + let release: ((value: string) => void) | undefined + class SlowFirst extends TestRecorder { + protected override takeScreenshot(): Promise { + this.shotsTaken++ + return new Promise((resolve) => { + release = resolve + }) + } + } + const r = new SlowFirst({ pollIntervalMs: 50 }) + const starting = r.start({ name: 'driver' }) + // Nothing is armed yet and `isRecording` is still false, so this stop() has + // no timer to clear — without the generation it would return as a no-op and + // the interval would arm underneath it. + await r.stop() + release?.('late-shot') + await starting + await vi.advanceTimersByTimeAsync(500) + + expect(r.isRecording).toBe(false) + expect(r.bufferLength).toBe(0) + vi.useRealTimers() + }) + it('captures multiple frames at the configured interval', async () => { vi.useFakeTimers() const r = new TestRecorder({ pollIntervalMs: 50 }) @@ -144,6 +170,113 @@ describe('ScreencastRecorderBase — input-dispatch gate', () => { }) }) +describe('ScreencastRecorderBase — in-flight latch', () => { + it('keeps at most one screenshot outstanding when a shot outruns the interval', async () => { + vi.useFakeTimers() + let shots = 0 + class SlowRecorder extends TestRecorder { + protected override takeScreenshot(): Promise { + shots++ + // The first shot (before the interval starts) resolves, so recording + // begins; every later one stays in flight, standing in for a native + // session's ~1.2 s screenshot against a 200 ms interval. setInterval + // does not wait, so without the latch ten ticks stack ten requests that + // a serialised driver then serves ahead of the test's own commands. + return shots === 1 ? Promise.resolve('initial') : new Promise(() => {}) + } + } + const r = new SlowRecorder({ pollIntervalMs: 50 }) + await r.start({ name: 'driver' }) + expect(shots).toBe(1) + + await vi.advanceTimersByTimeAsync(500) // 10 ticks + expect(shots).toBe(2) // one outstanding; the other nine dropped + + await r.stop() + vi.useRealTimers() + }) + + it('restarts polling without waiting for a shot orphaned by stop()', async () => { + vi.useFakeTimers() + let hanging = true + let shots = 0 + class Orphaned extends TestRecorder { + protected override takeScreenshot(): Promise { + shots++ + return hanging && shots > 1 + ? new Promise(() => {}) + : Promise.resolve(`f-${shots}`) + } + } + const r = new Orphaned({ pollIntervalMs: 50 }) + await r.start({ name: 'driver' }) // shot 1 resolves + await vi.advanceTimersByTimeAsync(50) // shot 2 hangs + expect(shots).toBe(2) + + await r.stop() // shot 2 is still outstanding + hanging = false + await r.start({ name: 'driver' }) // shot 3 resolves, recording resumes + const started = r.bufferLength + await vi.advanceTimersByTimeAsync(150) + + // The latch has to clear with the timer, or the restarted loop drops every + // tick until the orphan from the previous recording settles. + expect(r.bufferLength).toBeGreaterThan(started) + await r.stop() + vi.useRealTimers() + }) + + it('discards a shot that outlived the loop it was issued from', async () => { + vi.useFakeTimers() + let release: ((value: string) => void) | undefined + class Orphan extends TestRecorder { + protected override takeScreenshot(): Promise { + this.shotsTaken++ + return this.shotsTaken === 1 + ? Promise.resolve('initial') + : new Promise((resolve) => { + release = resolve + }) + } + } + const r = new Orphan({ pollIntervalMs: 50 }) + await r.start({ name: 'driver' }) + await vi.advanceTimersByTimeAsync(50) // tick → its shot hangs + expect(r.bufferLength).toBe(1) + + await r.stop() + release?.('late-frame') + await vi.advanceTimersByTimeAsync(60) + + // The frame belongs to the recording that ended — appending it would put a + // post-stop screenshot into the export. + expect(r.bufferLength).toBe(1) + vi.useRealTimers() + }) + + it('releases the latch when a shot settles, so polling continues', async () => { + vi.useFakeTimers() + class Bumpy extends TestRecorder { + protected override async takeScreenshot(): Promise { + this.shotsTaken++ + if (this.shotsTaken === 2) { + await new Promise((resolve) => setTimeout(resolve, 300)) + } + return `f-${this.shotsTaken}` + } + } + const r = new Bumpy({ pollIntervalMs: 50 }) + await r.start({ name: 'driver' }) + const initial = r.bufferLength + await vi.advanceTimersByTimeAsync(50) // tick → slow shot starts + await vi.advanceTimersByTimeAsync(300) // slow shot settles, ticks resume + await vi.advanceTimersByTimeAsync(200) + expect(r.bufferLength).toBeGreaterThan(initial + 1) + await r.stop() + vi.useRealTimers() + }) +}) + describe('ScreencastRecorderBase — frames / setStartMarker / duration', () => { it('setStartMarker trims preceding frames from the public getter', async () => { class CdpFlavor extends ScreencastRecorderBase<{ name: string }> { diff --git a/packages/service/src/action-snapshot.ts b/packages/service/src/action-snapshot.ts index 9391c916..44e1286e 100644 --- a/packages/service/src/action-snapshot.ts +++ b/packages/service/src/action-snapshot.ts @@ -10,12 +10,10 @@ import { captureActionSnapshot as coreCapture, - mapCommandToAction, upsertRichestSnapshot } from '@wdio/devtools-core' import type { ActionSnapshot } from '@wdio/devtools-shared' import { isNativeAppSession, mobilePlatform } from './mobile.js' -import { INTERNAL_COMMANDS } from './constants.js' import { wdioRunnerId } from './wdio-runner-id.js' function reviveScript(src: string): () => unknown { @@ -25,74 +23,65 @@ function reviveScript(src: string): () => unknown { return new Function(`return (${src})`) as () => unknown } +/** Bound on the end-of-test wait for a document the last action navigated to. */ +const FINAL_SETTLE_TIMEOUT_MS = 8000 +/** Time to let a paint land, so the final capture is not a transitional frame — + * measured on Appium, where a mid-paint screenshot runs 359-476 KB against a + * settled 1.87 MB. */ +const FINAL_SETTLE_PAUSE_MS = 250 + /** - * After a mapped action, wait for the resulting page to settle before the - * post-action screenshot. readyState alone is unreliable — right after a click - * the OLD document still reports 'complete'. beforeCommand tags the document; - * if the tag is gone the action navigated, so we wait for the NEW document to - * finish loading AND render content before the destination is screenshotted. + * Settle the page after the LAST action, before its capture. Every other + * capture is taken in `beforeCommand`, at a moment the driver is idle and the + * previous action's effect has had the test's own gap to land; the last action + * has no successor, so this is the one place a settle earns its cost. + * + * `navigated` says the drain immediately before this brought a document the + * session had not seen — the only condition under which `readyState` is worth + * asking about. Ungated it is unreliable: right after a click the OUTGOING + * document already reports 'complete', so a blind poll returns instantly and + * captures the page the test just left. Gated, the document it describes is the + * incoming one. Never throws. */ -export async function waitForActionResult( - browser: WebdriverIO.Browser -): Promise { - const navigated = await browser - .execute( - () => !(window as Window & { __wdioSnapMark?: boolean }).__wdioSnapMark - ) - .catch(() => true) - if (!navigated) { - return - } - await browser - .waitUntil( - async () => - (await browser - .execute( - () => - document.readyState === 'complete' && - !!document.body && - document.body.childElementCount > 0 - ) - .catch(() => false)) === true, - { timeout: 8000, interval: 150 } - ) - .catch(() => undefined) - // Headless renderers can return a blank shot right after load; let it paint. - await browser.pause(250).catch(() => undefined) -} - -/** Post-action capture: settle the resulting page, screenshot it, and push the - * snapshot stamped at the latest logged action. No-op for internal/non-mapped - * commands. Skipped by the caller outside trace mode. */ -export async function captureActionResult( +export async function settleAfterLastAction( browser: WebdriverIO.Browser, - command: string, - actionSnapshots: ActionSnapshot[], - stampTimestamp: () => number + navigated: boolean ): Promise { - if (!mapCommandToAction(command) || INTERNAL_COMMANDS.includes(command)) { - return - } - // Keyed on having a document, matching `#markDocument`, which writes the tag - // this reads — split, a session tags a document nothing settles on. - if (!isNativeAppSession(browser)) { - await waitForActionResult(browser) - } - // Stamped before the capture, not after: a snapshot probe can never enter - // commandsLog (beforeCommand requires an empty command stack), so the latest - // logged action is the same either way — and reading it up front keeps the - // stamp a capture input rather than a post-hoc mutation. - const snap = await captureActionSnapshot(browser, command, stampTimestamp()) - if (snap) { - upsertRichestSnapshot(actionSnapshots, snap) + // A test double or a driver without `pause`/`waitUntil` must not fail a + // capture that has nothing to do with it, so the whole settle is best-effort. + try { + if (isNativeAppSession(browser)) { + await browser.pause(FINAL_SETTLE_PAUSE_MS) + return + } + // Not navigated: the app has been at rest since the last action, so the + // test's own teardown is the gap that lets the paint land. Waiting costs + // every test for nothing. + if (!navigated) { + return + } + // Caught separately from the outer handler: a slow load that blows the + // timeout still leaves a page mid-paint, and that is exactly the frame the + // pause exists to avoid capturing. + await browser + .waitUntil( + async () => + (await browser + .execute(() => document.readyState === 'complete') + .catch(() => false)) === true, + { timeout: FINAL_SETTLE_TIMEOUT_MS, interval: 150 } + ) + .catch(() => undefined) + await browser.pause(FINAL_SETTLE_PAUSE_MS) + } catch { + // The capture is worth taking regardless of why the settle could not run. } } /** Capture a DOM snapshot for a synthesized action row (e.g. an `expect.*` * assertion) and push it stamped at the row's OWN timestamp — the trace * player's Snapshot tab claims it by timestamp the same way it claims a - * regular command's post-action snapshot (see FrameSnapshotIndex.claimAfter). - * Mirrors the tail of `captureActionResult` for a command with no page-settle. */ + * command's own snapshot (see FrameSnapshotIndex.claimAfter). */ export async function pushActionSnapshotAt( browser: WebdriverIO.Browser, command: string, diff --git a/packages/service/src/index.ts b/packages/service/src/index.ts index 107bda92..a8f11875 100644 --- a/packages/service/src/index.ts +++ b/packages/service/src/index.ts @@ -5,6 +5,7 @@ import { beginInputDispatch, captureAndAttachScreenshot, errorMessage, + FINAL_SNAPSHOT_COMMAND, finalizeTraceExport, lastRenderedScreenshot, mapCommandToAction, @@ -30,8 +31,8 @@ import { import { resolveCallSourceFromFrame } from './call-source.js' import { TraceSliceTracker } from './trace-slices.js' import { - captureActionResult, - captureActionSnapshot + captureActionSnapshot, + settleAfterLastAction } from './action-snapshot.js' import type { ActionSnapshot, TestMetadataMap } from '@wdio/devtools-shared' import { SevereServiceError } from 'webdriverio' @@ -56,7 +57,7 @@ import { LOCATOR_COMMANDS, PAGE_TRANSITION_COMMANDS } from './constants.js' -import { isAppiumSession, isNativeAppSession } from './mobile.js' +import { isAppiumSession } from './mobile.js' import { resolveSessionMetadata } from './session-metadata.js' import { stampRunnerMetadata } from './wdio-runner-id.js' import { detectInvocationConfigPath } from './standalone.js' @@ -553,28 +554,73 @@ export default class DevToolsHookService implements Services.ServiceInstance { // otherwise never be captured before teardown. forceAnchor: the destination's // async initial anchor may not have run yet, so anchor it synchronously here. await this.#sessionCapturer.captureTrace(this.#browser, true) - const snap = await captureActionSnapshot( - this.#browser, - '__final__', - this.#lastActionTimestamp() - ) - if (snap) { - // The last action's post-capture shares this timestamp and resources are - // named by timestamp, so keep only the richer screenshot — a blank - // end-of-scenario frame must not clobber the action's real result. - upsertRichestSnapshot(this.#actionSnapshots, snap) + // Named after the action it captures, because that is what it is: every + // other row's result comes from the NEXT action's pre-capture, so the last + // action's has no successor and this is the only capture of it. A session + // that ran no action names it FINAL_SNAPSHOT_COMMAND, which the per-test + // screenshot reads as "post-teardown frame, do not use". + const lastAction = this.#lastAction() + // A session with no action has no timestamp of its own to key on, so its + // frame is recognised by the marker instead — otherwise `Date.now()` differs + // between the per-test finalize and `after()` and both capture. + const alreadyCaptured = lastAction + ? this.#actionSnapshots.some( + (snap) => snap.timestamp === lastAction.timestamp + ) + : this.#actionSnapshots.some( + (snap) => snap.command === FINAL_SNAPSHOT_COMMAND + ) + // `after()` finalizes once more at session end, for the standalone path that + // has no per-test hook. On a framework run the test that just ended has + // already recorded this slot, and the driver would return the same page a + // second time — capture only when it is still empty. + if (!alreadyCaptured) { + await settleAfterLastAction( + this.#browser, + this.#sessionCapturer.replacedDocumentInLastDrain + ) + const snap = await captureActionSnapshot( + this.#browser, + lastAction?.command ?? FINAL_SNAPSHOT_COMMAND, + lastAction?.timestamp ?? Date.now() + ) + if (snap) { + // Stamped at the last action's own timestamp, where an assertion row can + // have captured too, and resources are named by timestamp — keep only the + // richer screenshot so a blank end-of-scenario frame cannot clobber it. + upsertRichestSnapshot(this.#actionSnapshots, snap) + } } } - #lastActionTimestamp(): number { + /** A command a snapshot can be attributed to: mapped (so it has a row to + * render on) and not internal (several of those ARE mapped — getTitle, + * getUrl, execute — and a snapshot stamped at one would sit at a timestamp + * no row owns). Both the capture gate and `#lastAction` ask this. */ + #isActionCommand(command: string): boolean { + return ( + Boolean(mapCommandToAction(command)) && + !INTERNAL_COMMANDS.includes(command) + ) + } + + /** The last action a capture can be attributed to. Scans rather than tracks a + * pointer: the log is run-long and never reset per test, so the scan + * self-scopes, and a slot already filled at its own boundary converges on + * `alreadyCaptured`. */ + #lastAction(): { command: string; timestamp: number } | undefined { const commands = this.#sessionCapturer.commandsLog for (let i = commands.length - 1; i >= 0; i--) { const cmd = commands[i]! - if (mapCommandToAction(cmd.command)) { - return cmd.timestamp + if (this.#isActionCommand(cmd.command)) { + return cmd } } - return Date.now() + return undefined + } + + #lastActionTimestamp(): number { + return this.#lastAction()?.timestamp ?? Date.now() } private resetStack() { @@ -647,42 +693,37 @@ export default class DevToolsHookService implements Services.ServiceInstance { if (PAGE_TRANSITION_COMMANDS.includes(command)) { await this.#sessionCapturer.captureTrace(this.#browser) } - // Pre-action capture: state BEFORE this action executes. Stamped at the - // previous action's end time (or 0 for the first). Trace mode only. + // Pre-action capture: the state this action runs against, which is the state + // the previous action left behind. Taken HERE, before the command is issued, + // because that is the one moment the driver is guaranteed idle and the app + // at rest — a capture taken the instant a command returns catches whatever + // transition it started. Stamped at the previous action's end (or now, for + // the first, which makes it the initial frame). Trace mode only. if ( topLevelUserCommand && this.#options.mode === 'trace' && this.#browser && - mapCommandToAction(command) && - !INTERNAL_COMMANDS.includes(command) + this.#isActionCommand(command) ) { + // Stamped at the previous action's end so this capture IS that action's + // result — except across a test boundary, where that slot already holds + // its own finalize capture and a second frame at the same timestamp lets + // the richer-screenshot merge replace it (with a reloadSession between + // the tests, the row then replays the post-reload page). The first + // capture of a test stamps now instead, the same rule the session's first + // capture uses to become the initial frame. + const previousEnd = this.#lastActionTimestamp() const snap = await captureActionSnapshot( this.#browser, command, - this.#lastActionTimestamp() + previousEnd >= this.#currentTestStartWallTime ? previousEnd : Date.now() ) if (snap) { upsertRichestSnapshot(this.#actionSnapshots, snap) } - // Tag the current document so the post-action capture can tell whether - // this action navigated (a new document drops the tag). - await this.#markDocument() } } - #markDocument(): Promise { - // Keyed on having a document: `waitForActionResult` reads this tag on the - // same condition, so the pair must not be split across the two predicates. - if (!this.#browser || isNativeAppSession(this.#browser)) { - return Promise.resolve() - } - return this.#browser - .execute(() => { - ;(window as Window & { __wdioSnapMark?: boolean }).__wdioSnapMark = true - }) - .catch(() => undefined) - } - async afterCommand( command: keyof WebDriverCommands, args: unknown[], @@ -726,14 +767,9 @@ export default class DevToolsHookService implements Services.ServiceInstance { this.#currentTestUid, this.#currentStepUid ) - if (this.#options.mode === 'trace') { - await captureActionResult( - this.#browser, - command, - this.#actionSnapshots, - () => this.#lastActionTimestamp() - ) - } else { + // Trace mode captures nothing here: the state this action produced is + // taken by the NEXT action's pre-capture, when the app has settled. + if (this.#options.mode !== 'trace') { await this.#drainAfterLiveCommand(command) } return captured @@ -778,6 +814,12 @@ export default class DevToolsHookService implements Services.ServiceInstance { return } + // The last action's result is captured by the NEXT action's pre-capture, so + // a session that ends without one — a standalone run has no per-test hook to + // finalize on — would lose it. A framework run has already finalized per + // test; there this only re-captures the same timestamp and merges. + await this.#finalizePerScenario() + // Stop and encode the screencast for the current session. await this.#screencast.finalize(this.#browser.sessionId) diff --git a/packages/service/src/session.ts b/packages/service/src/session.ts index 5c978ef9..d3c6ec68 100644 --- a/packages/service/src/session.ts +++ b/packages/service/src/session.ts @@ -30,11 +30,13 @@ import { type CapturedPerformancePayload } from '@wdio/devtools-core' import type { CommandLog } from './types.js' +import type { TraceMutation } from '@wdio/devtools-shared' const log = logger('@wdio/devtools-service:SessionCapturer') export class SessionCapturer extends SessionCapturerBase { #isScriptInjected = false + #replacedDocumentInLastDrain = false /** Session start wall time for trace event timestamps. */ readonly startWallTime = Date.now() /** Last find-element selector — carried forward to the next element command. */ @@ -376,11 +378,20 @@ export class SessionCapturer extends SessionCapturerBase { this.#isScriptInjected = false } + /** Whether the most recent `captureTrace` brought a document this session had + * not anchored before. The collector anchors once per document, so a new + * anchor means the page was replaced — the end-of-test settle reads this to + * know a navigation is still loading, rather than guessing from a clock. */ + get replacedDocumentInLastDrain(): boolean { + return this.#replacedDocumentInLastDrain + } + /** Drain the current page's buffered trace data (mutations/console/network) * into the capturer. Public so the plugin can flush BEFORE a navigating * command, capturing the outgoing page's field edits (value/checked * mutations fire no page transition) before its collector is discarded. */ async captureTrace(browser: WebdriverIO.Browser, forceAnchor = false) { + this.#replacedDocumentInLastDrain = false // A native app has no document to drain, so the collector probe, the // recovery injection and the url read are all round trips that can only // fail. Guarded here rather than at each call site, because two of the four @@ -420,6 +431,24 @@ export class SessionCapturer extends SessionCapturerBase { if (!payload) { return } + // `captureCurrentDom` is the only producer of a mutation carrying a url, + // and it anchors each document once — so one in this batch is a document + // the session had not seen. Shape-checked like `processTracePayload` + // does: this is page-side data, and a throw here would discard the whole + // payload's console and network streams with it. + const mutations = (payload as { mutations?: unknown }).mutations + if ( + Array.isArray(mutations) && + mutations.some( + (mutation) => + typeof mutation === 'object' && + mutation !== null && + 'url' in mutation && + (mutation as TraceMutation).url !== undefined + ) + ) { + this.#replacedDocumentInLastDrain = true + } this.processTracePayload(payload as Record) } catch (err) { log.error(`Failed to capture trace: ${errorMessage(err)}`) diff --git a/packages/service/tests/action-snapshot.test.ts b/packages/service/tests/action-snapshot.test.ts index 6c38c9b2..634cd4e4 100644 --- a/packages/service/tests/action-snapshot.test.ts +++ b/packages/service/tests/action-snapshot.test.ts @@ -1,9 +1,6 @@ import { describe, it, expect, vi } from 'vitest' import type { ActionSnapshot } from '@wdio/devtools-shared' -import { - captureActionResult, - pushActionSnapshotAt -} from '../src/action-snapshot.js' +import { pushActionSnapshotAt } from '../src/action-snapshot.js' const mockBrowser = () => ({ @@ -109,52 +106,3 @@ describe('an Appium session driving a browser', () => { expect(browser.getUrl).not.toHaveBeenCalled() }) }) - -/** - * The settle waits on the `__wdioSnapMark` tag that `#markDocument` writes, and - * both key on having a document — split across the two predicates, a session - * tags a document nothing ever settles on, and its post-action screenshot comes - * from the page it navigated away from. - */ -describe('the post-action settle', () => { - const settleable = (flags: Record) => - Object.assign(mockBrowser(), flags, { - execute: vi.fn().mockResolvedValue(true), - waitUntil: vi.fn().mockResolvedValue(undefined), - pause: vi.fn().mockResolvedValue(undefined) - }) as unknown as WebdriverIO.Browser - - it('runs for an Appium session driving a browser', async () => { - const browser = settleable({ - isMobile: false, - isAndroid: true, - capabilities: { platformName: 'Android', browserName: 'Chrome' } - }) - - await captureActionResult(browser, 'click', [], () => 1) - - // The mark probe is the settle's first act, so its body identifies it. - const bodies = vi - .mocked(browser.execute) - .mock.calls.map(([fn]) => String(fn)) - expect(bodies.some((body) => body.includes('__wdioSnapMark'))).toBe(true) - }) - - it('does not for a native app, which has no document to settle', async () => { - const browser = settleable({ - isMobile: true, - isAndroid: true, - capabilities: { - platformName: 'Android', - 'appium:app': '/app.apk' - } - }) - - await captureActionResult(browser, 'click', [], () => 1) - - const bodies = vi - .mocked(browser.execute) - .mock.calls.map(([fn]) => String(fn)) - expect(bodies.some((body) => body.includes('__wdioSnapMark'))).toBe(false) - }) -}) diff --git a/packages/service/tests/assertion-rows.test.ts b/packages/service/tests/assertion-rows.test.ts index 66890162..382d5c70 100644 --- a/packages/service/tests/assertion-rows.test.ts +++ b/packages/service/tests/assertion-rows.test.ts @@ -38,7 +38,7 @@ const pushActionSnapshotAt = vi.hoisted(() => vi.mock('../src/action-snapshot.js', () => ({ pushActionSnapshotAt, captureActionSnapshot: vi.fn().mockResolvedValue(null), - captureActionResult: vi.fn().mockResolvedValue(undefined) + settleAfterLastAction: vi.fn().mockResolvedValue(undefined) })) import DevToolsHookService from '../src/index.js' diff --git a/packages/service/tests/trace-action-capture.test.ts b/packages/service/tests/trace-action-capture.test.ts new file mode 100644 index 00000000..e05799f2 --- /dev/null +++ b/packages/service/tests/trace-action-capture.test.ts @@ -0,0 +1,397 @@ +import { describe, it, expect, vi, beforeEach } from 'vitest' +import type * as DevtoolsCore from '@wdio/devtools-core' +import { captureActionSnapshot } from '@wdio/devtools-core' +import DevToolsHookService from '../src/index.js' + +// One user-spec frame, so `beforeCommand` reads every command as top-level. +vi.mock('stack-trace', () => ({ + parse: () => [ + { + getFileName: () => '/test/specs/fake.spec.ts', + getLineNumber: () => 1, + getColumnNumber: () => 1 + } + ] +})) + +/** + * The command has to be in the log by the time `afterCommand` returns: + * `#lastActionTimestamp()` reads it to stamp the NEXT action's capture, and that + * stamp is what makes an action's result the following action's "before". + */ +const commandsLog: { command: string; timestamp: number }[] = [] +let clock = 0 +const capturer = { + afterCommand: vi.fn(async (_browser: unknown, command: string) => { + commandsLog.push({ command, timestamp: ++clock }) + }), + sendUpstream: vi.fn(), + mergeMetadata: vi.fn(), + captureTrace: vi.fn().mockResolvedValue(undefined), + noteResolvedSelector: vi.fn(), + resetLastSelector: vi.fn(), + resetRetryTracker: vi.fn(), + captureSource: vi.fn(), + captureAssertCommand: vi.fn(), + cleanup: vi.fn(), + commandsLog, + sources: new Map(), + mutations: [], + traceLogs: [], + consoleLogs: [], + networkRequests: [], + isReportingUpstream: false, + metadata: {}, + setBrowser: vi.fn(), + /** Set by a test to stand in for the drain having brought a document the + * session had not anchored before. */ + replacedDocumentInLastDrain: false +} + +vi.mock('../src/session.js', () => ({ + SessionCapturer: vi.fn(function () { + return capturer + }) +})) + +vi.mock('../src/screencast.js', () => ({ + ScreencastRecorder: vi.fn(function () { + return { + start: vi.fn().mockResolvedValue(undefined), + stop: vi.fn().mockResolvedValue(undefined), + setStartMarker: vi.fn(), + frames: [] + } + }) +})) + +vi.mock('@wdio/devtools-core', async (importOriginal) => { + const actual = await importOriginal() + return { + ...actual, + captureActionSnapshot: vi.fn(actual.captureActionSnapshot), + encodeToVideo: vi.fn().mockResolvedValue(undefined) + } +}) + +vi.mock('node:fs/promises', () => ({ + default: { writeFile: vi.fn().mockResolvedValue(undefined) } +})) + +/** A native Appium session: no `browserName` anywhere in the capabilities, so + * `isNativeAppSession` is true and the capture takes the screenshot + + * page-source path — the one an Appium run pays for. */ +const nativeBrowser = () => { + const capabilities = { platformName: 'Android', deviceName: 'emulator-5554' } + return { + isBidi: false, + isMobile: true, + isAndroid: true, + sessionId: 'native-session', + capabilities, + options: { capabilities }, + addCommand: vi.fn(), + on: vi.fn(), + emit: vi.fn(), + pause: vi.fn(async () => undefined), + execute: vi.fn(async () => []), + takeScreenshot: vi.fn(async () => 'SHOT'), + getPageSource: vi.fn( + async () => '' + ), + getWindowSize: vi.fn(async () => ({ width: 1080, height: 2424 })) + } as unknown as WebdriverIO.Browser +} + +/** A plain web session: a browser in the capabilities, so `isNativeAppSession` + * is false and the capture takes the page-script path. */ +const webBrowser = () => { + const capabilities = { browserName: 'chrome', platformName: 'linux' } + return { + isBidi: true, + isMobile: false, + sessionId: 'web-session', + capabilities, + options: { capabilities }, + addCommand: vi.fn(), + on: vi.fn(), + emit: vi.fn(), + pause: vi.fn(async () => undefined), + // Invokes the predicate, so the probe it runs is observable — WDIO's real + // `waitUntil` polls it. + waitUntil: vi.fn(async (predicate: () => Promise) => { + await predicate() + }), + execute: vi.fn(async () => []), + takeScreenshot: vi.fn(async () => 'SHOT'), + getUrl: vi.fn(async () => 'http://example.com/'), + getTitle: vi.fn(async () => 'Example') + } as unknown as WebdriverIO.Browser +} + +/** The service's own wrapper funnels into core's single-object signature. */ +const stampedAt = (call: number): number | undefined => + vi.mocked(captureActionSnapshot).mock.calls[call]?.[0]?.timestamp +const namedAt = (call: number): string | undefined => + vi.mocked(captureActionSnapshot).mock.calls[call]?.[0]?.command + +describe('trace mode: one capture per action, taken before it', () => { + beforeEach(() => { + vi.clearAllMocks() + commandsLog.length = 0 + clock = 0 + capturer.replacedDocumentInLastDrain = false + }) + + it('captures in beforeCommand and not again after the command', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(browser.takeScreenshot).mockClear() + vi.mocked(browser.getPageSource!).mockClear() + + await service.beforeCommand('click' as never, []) + expect(browser.takeScreenshot).toHaveBeenCalledTimes(1) + + await service.afterCommand('click' as never, [], undefined) + // The state this action produced belongs to the NEXT action's capture, taken + // once the app has settled. Capturing here instead is what makes a trace + // blurry: the screen is still moving when the command returns. + expect(browser.takeScreenshot).toHaveBeenCalledTimes(1) + }) + + it('costs one capture per action across a sequence', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(browser.takeScreenshot).mockClear() + vi.mocked(browser.getPageSource!).mockClear() + vi.mocked(captureActionSnapshot).mockClear() + + for (const command of ['click', 'setValue', 'click']) { + await service.beforeCommand(command as never, []) + await service.afterCommand(command as never, [], undefined) + } + + expect(vi.mocked(captureActionSnapshot)).toHaveBeenCalledTimes(3) + expect(browser.takeScreenshot).toHaveBeenCalledTimes(3) + expect(browser.getPageSource).toHaveBeenCalledTimes(3) + }) + + it('stamps each capture at the previous action end', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + vi.mocked(captureActionSnapshot).mockClear() + + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + await service.beforeCommand('setValue' as never, []) + await service.afterCommand('setValue' as never, [], undefined) + + // The first action runs against a state nothing has recorded yet, so it + // takes the capture now (it becomes the trace's initial frame). The second + // takes the state the first produced — the first action's result IS the + // second action's before, which is the whole design. + expect(stampedAt(0)).toBeGreaterThan(0) + expect(stampedAt(1)).toBe(commandsLog[0]!.timestamp) + }) + + it('captures the final state when the session ends', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(captureActionSnapshot).mockClear() + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + await service.after() + + // A standalone run has no per-test hook, so the last action's result would + // never be taken: the next action's pre-capture is what supplies it + // everywhere else. + expect(stampedAt(1)).toBe(commandsLog[0]!.timestamp) + expect(stampedAt(0)).toBeGreaterThan(0) + + // A framework run reaches this finalize twice — once per test and once from + // `after()`. The slot is recorded by then, so the second pass must not pay + // another screenshot and page-source round trip for it. + await service.after() + expect(vi.mocked(captureActionSnapshot)).toHaveBeenCalledTimes(2) + }) + + it('captures the no-action frame once per session', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(captureActionSnapshot).mockClear() + await service.after() + await service.after() + + // A session that ran no action has no timestamp to key on, so the marker + // carries the "already captured" answer — otherwise each finalize takes the + // same frame again under a fresh `Date.now()`. + expect(vi.mocked(captureActionSnapshot)).toHaveBeenCalledTimes(1) + expect(namedAt(0)).toBe('__final__') + }) + + it('settles the driver once, only for the final capture', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(browser.pause).mockClear() + for (const command of ['click', 'setValue']) { + await service.beforeCommand(command as never, []) + await service.afterCommand(command as never, [], undefined) + } + // Per-action captures take the page at a moment the driver is already idle — + // paying a settle for each of them is the cost this design removed. + expect(browser.pause).not.toHaveBeenCalled() + + await service.after() + // The last action has no successor, so its capture is the one that needs it. + expect(browser.pause).toHaveBeenCalledTimes(1) + }) + + it('takes the final capture at the last action, past an internal command', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + // A read the capture gates exclude, and the last thing the test did. It is + // mapped, so counting it would stamp the final capture at a timestamp no + // visible row owns — and skipping it entirely would lose the click's result. + await service.beforeCommand('getTitle' as never, []) + await service.afterCommand('getTitle' as never, [], 'title') + + vi.mocked(captureActionSnapshot).mockClear() + await service.after() + + expect(namedAt(0)).toBe('click') + expect(stampedAt(0)).toBe(commandsLog[0]!.timestamp) + }) + + it('does not merge the next test first capture into the previous test slot', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + const first = { file: '/spec/a.ts', title: 'first' } + service.beforeTest(first as never) + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + await service.afterTest(first as never, {} as never, {} as never) + + const lastOfFirst = commandsLog[0]!.timestamp + vi.mocked(captureActionSnapshot).mockClear() + + await new Promise((resolve) => setTimeout(resolve, 5)) + const secondTestStart = Date.now() + service.beforeTest({ file: '/spec/a.ts', title: 'second' } as never) + await service.beforeCommand('click' as never, []) + + // The previous test's last action already has its own capture, taken by that + // test's finalize. Stamping this test's initial frame at the same timestamp + // lets the richer-screenshot merge replace it — under a reloadSession the + // row then shows the post-reload page instead of that test's last state. + expect(stampedAt(0)).not.toBe(lastOfFirst) + expect(stampedAt(0)).toBeGreaterThanOrEqual(secondTestStart) + }) + + it('still lets the paint land when the wait for a load times out', async () => { + const browser = webBrowser() + capturer.replacedDocumentInLastDrain = true + vi.mocked(browser.waitUntil).mockRejectedValueOnce(new Error('timeout')) + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + + vi.mocked(browser.pause).mockClear() + await service.after() + + // A page slow enough to blow the timeout is still mid-paint, so it is the + // one that most needs the pause — the wait's rejection must not skip it. + expect(browser.pause).toHaveBeenCalledTimes(1) + }) + + it('names the final capture after the action it captures', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + + vi.mocked(captureActionSnapshot).mockClear() + await service.after() + + // Not `__final__`: this capture IS the last action's result, and the + // per-test screenshot reader (`lastRenderedScreenshot`) skips that marker, + // so naming it `__final__` made the Allure screenshot show the page from + // BEFORE the last action — the one a failure is inspected for. + expect(namedAt(0)).toBe('click') + }) + + it('never settles the driver', async () => { + const browser = nativeBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + + vi.mocked(browser.pause).mockClear() + vi.mocked(browser.execute).mockClear() + for (const command of ['click', 'setValue', 'getText']) { + await service.beforeCommand(command as never, []) + await service.afterCommand(command as never, [], undefined) + } + + // No pause, no readyState poll, no document tag: the capture happens at a + // moment the driver is already idle, so there is nothing to wait for. + expect(browser.pause).not.toHaveBeenCalled() + expect(browser.execute).not.toHaveBeenCalled() + }) + + it('waits for a document the last action navigated to, and only that', async () => { + const browser = webBrowser() + const service = new DevToolsHookService({ mode: 'trace' }) + await service.before({} as never, [], browser) + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + + vi.mocked(browser.pause).mockClear() + vi.mocked(browser.waitUntil).mockClear() + vi.mocked(browser.execute).mockClear() + await service.after() + + // No new document in the final drain: the app has been at rest since the + // last action, so its paint already landed. Waiting here is the cost this + // design removes from every test. + expect(browser.waitUntil).not.toHaveBeenCalled() + expect(browser.pause).not.toHaveBeenCalled() + + capturer.replacedDocumentInLastDrain = true + await service.beforeCommand('click' as never, []) + await service.afterCommand('click' as never, [], undefined) + vi.mocked(browser.pause).mockClear() + vi.mocked(browser.waitUntil).mockClear() + vi.mocked(browser.execute).mockClear() + await service.after() + + // A document the session had not seen IS loading, so readyState is the + // right question — it describes the incoming document, not the outgoing one + // that still reports 'complete'. + expect(browser.waitUntil).toHaveBeenCalledTimes(1) + const bodies = vi + .mocked(browser.execute) + .mock.calls.map(([fn]) => String(fn)) + expect(bodies.some((body) => body.includes('readyState'))).toBe(true) + // The old poll also required a non-empty body, which made a legitimately + // blank destination a guaranteed timeout rather than a settled page. + expect(bodies.some((body) => body.includes('childElementCount'))).toBe( + false + ) + }) +}) diff --git a/packages/service/tests/trace-granularity.test.ts b/packages/service/tests/trace-granularity.test.ts index f74e4089..3d51f228 100644 --- a/packages/service/tests/trace-granularity.test.ts +++ b/packages/service/tests/trace-granularity.test.ts @@ -59,10 +59,13 @@ vi.mock('../src/session.js', () => ({ }) })) +// `pushActionSnapshotAt` is imported by the assertion tracker, which this file +// reaches through the service — leave it out and a test that drives a failing +// matcher calls undefined. vi.mock('../src/action-snapshot.js', () => ({ captureActionSnapshot: vi.fn().mockResolvedValue(null), - captureActionResult: vi.fn().mockResolvedValue(undefined), - waitForActionResult: vi.fn().mockResolvedValue(undefined) + pushActionSnapshotAt: vi.fn().mockResolvedValue(undefined), + settleAfterLastAction: vi.fn().mockResolvedValue(undefined) })) vi.mock('@wdio/devtools-core', async (importOriginal) => { diff --git a/packages/service/tests/trace-metadata.test.ts b/packages/service/tests/trace-metadata.test.ts index 22607ff5..e76bf228 100644 --- a/packages/service/tests/trace-metadata.test.ts +++ b/packages/service/tests/trace-metadata.test.ts @@ -42,8 +42,8 @@ vi.mock('../src/session.js', () => ({ // Keep the after* hooks from touching a real browser/CDP. vi.mock('../src/action-snapshot.js', () => ({ captureActionSnapshot: vi.fn().mockResolvedValue(null), - captureActionResult: vi.fn().mockResolvedValue(undefined), - waitForActionResult: vi.fn().mockResolvedValue(undefined) + pushActionSnapshotAt: vi.fn().mockResolvedValue(undefined), + settleAfterLastAction: vi.fn().mockResolvedValue(undefined) })) vi.mock('@wdio/devtools-core', async (importOriginal) => { diff --git a/packages/shared/src/types.ts b/packages/shared/src/types.ts index 7fc79a35..936f1861 100644 --- a/packages/shared/src/types.ts +++ b/packages/shared/src/types.ts @@ -507,7 +507,15 @@ export function isMutationsTruncationMarker( * downstream trace.zip exporter (Phase 4). `screenshot` is base64-encoded JPEG. */ export interface ActionSnapshot { + /** The key every reader joins on. A capture is stamped, once the exporter + * has run, with the action whose RESULT it is — which is why `command` + * below is not that action's name. */ timestamp: number + /** A label, not a key: the action the capture was taken for, which mid-run is + * the one it PRECEDES (the capture is its state before it ran), while the + * timestamp names the action it follows. No reader may select on it — the + * one value with meaning is core's `FINAL_SNAPSHOT_COMMAND`, which marks a + * frame carrying no result to show. */ command: string url?: string title?: string