Keep the polling filmstrip from queueing in front of the test

.changeset/filmstrip-poll-queue.md

@@ -0,0 +1,7 @@
+---
+'@wdio/devtools-service': patch
+'@wdio/selenium-devtools': patch
+'@wdio/nightwatch-devtools': patch
+---
+
+Without a CDP screencast (Safari, Appium), the `filmstrip` recorder no longer queues its screenshots in front of the test. It skips a poll while a command or a per-action capture holds the driver (polling anyway once the newest frame is three intervals old, so the longest gap is about three intervals plus one screenshot, but never during a click, typing or a capture), keeps each per-action capture's screenshot as a filmstrip frame, and skips the poll that would only repeat it. The interval and the filmstrip default are unchanged, and Chrome's CDP push mode is untouched. With `DEVTOOLS_CAPTURE_TIMING=1`, the report adds a `filmstrip recorder` line: the screenshots the recorder took and their time, the polls it skipped and why, and the capture screenshots it kept as frames.

CLAUDE.md

@@ -396,10 +396,10 @@ Documented divergences from the conventions above. They exist today as debt to b
 
 ### What a per-action trace capture costs
 
-- **Measure before proposing a change: `DEVTOOLS_CAPTURE_TIMING=1`.** Every adapter then times each probe of each capture (issue and settle, so a probe's own service time is separable from its wait behind the probes the driver served first) and, when the trace is written, prints a per-probe table and appends the raw records to `capture-timing-<pid>.ndjson` beside the trace. The JS recording is `core/capture-timing.ts`, wired once in `captureActionSnapshot` and reported from `finalizeTraceExport`, so no adapter carries more than the capture's trigger (action, wait poll, matcher poll, final); Python mirrors it in `capture_timing.py`, held to the same summary by `mirror-vectors.json`. Off, it costs a flag read per capture. The per-platform commands are in the README's "Measuring capture cost".
+- **Measure before proposing a change: `DEVTOOLS_CAPTURE_TIMING=1`.** Every adapter then times each probe of each capture (issue and settle, so a probe's own service time is separable from its wait behind the probes the driver served first) and, when the trace is written, prints a per-probe table and appends the raw records to `capture-timing-<pid>.ndjson` beside the trace. The JS recording is `core/capture-timing.ts`, wired once in `captureActionSnapshot` and reported from `finalizeTraceExport`, so no adapter carries more than the capture's trigger (action, wait poll, matcher poll, final); Python mirrors it in `capture_timing.py`, held to the same summary by `mirror-vectors.json`. Off, it costs a flag read per capture. The per-platform commands are in the README's "Measuring capture cost". The polling filmstrip recorder's own screenshots are counted beside it (`recordRecorderShot`/`recordRecorderSkip`/`recordRecorderReuse`, one `filmstrip recorder:` line, not written to the NDJSON); Python has no polling recorder and prints none, so the mirrored summary is unchanged. The shot durations are a ring of the newest 2000 (`RECORDER_SHOT_SAMPLE_MAX`), since a live run never reports and never drains them.
 - **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.
 - **Locator generation from a native page source must stay linear, and iOS is where it did not.** Every native action snapshot builds element locators from the page-source XML (`core/locators`), and each uniqueness check was a `//*[@name="…"]` XPath run by the `xpath` library over the whole document, several per element. Measured on the iOS Settings page source tiled up: 38 KB 82 ms, 188 KB 1.4 s, 752 KB 23.5 s, which is what a reporter saw as trace mode adding 1.5 min to a 2 min 20 s iOS test while Android, with smaller flatter trees, added 10 s. `locators/xpath-index.ts` indexes the document once per `generateAllElementLocators` walk (`withXPathIndex`) and answers `//*`, `//Tag` and `//Tag[@a="x" and …]` from it: 15 ms, 49 ms, 268 ms for the same three, identical elements. It is scoped to the walk so a caller of the exported `evaluateXPath` that edits its document is never answered stale, and it declines a namespaced document, where XPath name tests resolve namespaces and the index does not. The page-source request itself remains: 0.75-1.2 s per action on XCUITest even for Settings, against 0.09-0.5 s on UiAutomator2.
-- 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 after the stop or clearing its successor's latch.
+- 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 after the stop or clearing its successor's latch. One outstanding shot still queues in front of everything after it (measured in #516: a per-action screenshot 600-665 ms on the Android emulator with the poller running, 229 ms without), so a tick is also skipped while the driver is held: `core/driver-activity.ts` keeps one bounded in-flight gate per adapter bundle, opened by each adapter's command hook (`beginDriverCommand`, the service's `beforeCommand`, Selenium's patched methods, Nightwatch's proxy at enqueue) and by `captureActionSnapshot` around its probes (`beginDriverCapture`). A wait and a host-side command (`pause`, `perform`, ...) open none (shared `occupiesDriver`): the driver is idle between a wait's polls, and a pause holding the gate would blank the filmstrip for nothing. A skipped tick is dropped rather than deferred, so a run of commands that take no capture (reads, lookups, wait polls, every command of a live run) would starve the filmstrip: once the newest frame is `MAX_FILMSTRIP_GAP_INTERVALS` (3) intervals old the recorder polls through a busy driver anyway, one shot at a time; that poll still waits behind the command and takes its own screenshot time, so the longest gap is about three intervals plus one screenshot. The gate tags each window (`DriverWindowKind`) and two kinds are never overridden: input (`isInputDispatchInFlight`, shared `isInputDispatchingCommand`, which names the WebDriver protocol commands WDIO re-runs its hooks for inside `click`/`setValue`, since the service keeps one window and the nested one replaces it), because a screenshot between chromedriver's coordinate read and its dispatch makes the click report success and activate nothing; and a capture (`isCaptureInFlight`), whose own screenshot is the frame, where a capped poll would only queue behind it on a 1.4 to 2.4 s native capture and hold the driver in front of the next command. Selenium's `actions().perform()` reaches the driver through `execute()`, so `actions-patcher.ts` opens its input window itself. The service opens no window for its own injection calls (`#afterCommand` returns before closing one while `#injecting`), and Nightwatch opens one only for a command known to call back from the driver (`helpers/commandWindow.ts`), since its window closes from the appended callback and a builder API (`actions()`, v3's scoped `browser.element()`) or a custom command that never calls back would hold the gate to its bound. Each per-action capture's screenshot is offered to the recorder as a frame stamped when it settled (`ScreencastRecorderBase.offerCapturedFrame`), and the next tick within one interval is skipped as redundant. The offer is taken only when exactly one recorder is recording in the process and it polls, since the capture names no session; a shot no newer than the newest frame is dropped rather than reordered. Residuals: the gate is process-wide, so in a multi-session process one session's commands also hold the other's poller off; a recorder never stopped stays in the registry and disables reuse for the process; a reused frame still passes through `maxBufferFrames` decimation and export thinning like a polled one; after a failed assert, Nightwatch's aborted queue strands the input windows of commands enqueued after it, so for up to 3 s the recorder takes no polled frame (trace mode still gets reused capture frames).
 - **`start()` and `stop()` are serialised against each other, because unserialised neither owns what it arms.** A `stop()` landing mid-handshake returned at its `#isRecording` guard — still false, the handshake not having finished — so it never reached its own CDP teardown, and the `start()` it interrupted then returned on the generation mismatch without stopping what it had armed: the session and its frame listener stayed live after teardown. The frames themselves were moot — every adapter builds a fresh recorder per session (`screencast-lifecycle.ts` does so even across `reloadSession`), so the leaked session and its browser-side stream were the damage, not buffer pollution. The obvious repair — stopping the session on that mismatch path — is wrong, and it is the shape to keep out: it guards a field both CDP overrides write at handshake **start** (`#cdpSession` / `#cdp`) with a flag they set only at handshake **end** (`#cdpActive`), so a start arriving in that window is indistinguishable from no start at all and the stale path tears down the *newer* recording's session instead. Overlapping starts are the adapters' normal mode rather than a corner: Selenium's `driverPatcher` documents the second test's body racing an in-flight `screencast.start()`, and Nightwatch's session rotation is fire-and-forget from a command hook. Queued, a stop always runs against a start that has finished arming and owns what it armed, which makes the mismatch branch unreachable and deleted — the tick-phase generation checks in `#startPolling` are **not**, since a shot orphaned by a stop still lands afterwards. Two consequences: `stop()` now waits on an in-flight handshake, and every awaited driver primitive in that handshake is ceilinged at `SCREENCAST_HANDSHAKE_TIMEOUT_MS` (the service's `getPuppeteer()`/`pages()`/`createCDPSession()`/`Page.startScreencast` and the stop-side `Page.stopScreencast`, Selenium's `createCDPConnection`, the polling path's first screenshot) — a driver that wedges gives up after the ceiling, falls back to polling, or reports the screencast unavailable when polling was what wedged. Nothing is claimed until the handshake has answered, so a timed-out start leaves nothing armed — and a session or connection that completes after the ceiling is detached (or its socket closed) when it lands, so no orphan outlives the recording. And a stop landing during a polling session's first screenshot now records that shot before tearing the loop down, where it previously cancelled the start outright; the interval is still never left armed underneath the stop.
 - **Only a command that can change the page is captured** (`shared/trace-actions.ts` `skipsCapture`, a deny-list: reads, waits, lookups and assertions are skipped, anything unlisted captures; the ACTION_MAP reads come from the typed `METHOD_EFFECT` table that every `ACTION_MAP` method must appear in). Reads and waits still render rows and inherit the latest earlier capture through `claimAfter`'s `latestAtOrBefore` fallback. The gate used to be `mapCommandToAction` itself, so `5c54ae4` adding the reads to the table for the timeline also made each of them a capture, and a polling matcher one capture per poll: a reported iOS suite made 187 page-source reads for 12 interactions and went from 3:10 to 7:10. The first mapped command of each test is still captured even when it reads, or a test that opens with reads has no frame to inherit.
 - 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.

README.md

@@ -348,7 +348,7 @@ The hash names a position in the trace, for a `?trace=` URL, a picked file and `
 | `traceGranularity` | `'session'` \| `'spec'` \| `'test'` | `'session'` | `'session'` writes one trace per worker; `'spec'` one per spec file; `'test'` one per test into its own `<spec>-<title>-<browser>[-retryN]/trace.zip` folder — the smallest, most navigable artifacts, and the best pairing for a retention policy. |
 | `tracePolicy` | `'on'` \| `'retain-on-failure'` \| `'retain-on-first-failure'` \| `'on-first-retry'` \| `'on-all-retries'` \| `'retain-on-failure-and-retries'` | `'on'` | Which traces to keep. `'on'` keeps every trace; the rest keep only failing/retried tests — pairs well with `traceGranularity: 'test'`. |
 | `captureAssertions` | `boolean` | `true` | Capture assertions as action rows: `node:assert` (all adapters), WebdriverIO `expect(...)` matchers, and Nightwatch `browser.assert`/`verify`. Set `false` to opt out. |
-| `filmstrip` | `boolean` | `true` | Record a dense, continuous screencast *into* the trace for smooth scrubbing in the player (not just one frame per action). Dense frames sit alongside the per-action frames; thinned + content-addressed at export. Runs the screencast recorder (CDP push on Chrome, polling elsewhere). |
+| `filmstrip` | `boolean` | `true` | Record a dense, continuous screencast *into* the trace for smooth scrubbing in the player (not just one frame per action). Dense frames sit alongside the per-action frames; thinned + content-addressed at export. Runs the screencast recorder (CDP push on Chrome, polling elsewhere). The polling recorder skips a tick while a command or a per-action capture holds the driver (once the newest frame is three intervals old it polls anyway, so the longest gap is about three intervals plus one screenshot; never during a click, typing or a capture), and keeps each per-action capture's screenshot as a frame, so its polls do not queue in front of the test. |
 | `maskInputs` | `boolean` | `true` | Mask password fields in the replayed page, live and trace mode alike; `false` records them as typed. Command rows always keep the typed text. See [Password masking](#-password-masking). |
 | `maskSelectors` | `string[]` | `[]` | Also mask the text and value of every element these CSS selectors match in the replayed page. |
 | `traceResources` | `'styles'` \| `'none'` | `'styles'` | Which page resources the trace stores so its replay does not load them from the site. `'styles'` stores the stylesheets and fonts each archive's pages used, each once by content hash, capped at 1 MiB per resource and 8 MiB per archive (past the cap a resource replays live); `'none'` stores nothing. Images always replay from the site. The page collector reads each one back from the browser's HTTP cache, cross-origin ones only where the site allows CORS (a same-origin stylesheet it cannot read again falls back to its parsed rules), and the trace leaves those reads out of its network rows. Live mode reads nothing back. |
@@ -393,13 +393,15 @@ screenshot  4   1616     254  1004  1004       1600         250
 process     4     24       6     6     6         24           6
 capture     4   1640     260  1010  1010       1640         260
 raw records: /out/capture-timing-1.ndjson
+[devtools] filmstrip recorder: 95 screenshots, total 57.0 s, median 600 ms; 40 ticks skipped (31 driver busy, 6 fresh frame, 3 shot in flight); 12 capture screenshots reused as frames
 ```
 
-(Illustrative numbers from a unit-test fixture, not a real run.)
+(Illustrative numbers, not a real run.)
 
 - **Columns.** The JS adapters issue every read of a capture at once and the driver serves them in order, so a read's time from issue to settle includes waiting behind the reads before it. `svc` subtracts that wait: it is the read's own cost. `process` is the in-process step that turns the reads into a snapshot (page-source parsing and locator generation on native). `capture` is the whole capture.
 - **Busy and wall.** `busy` is the time at least one capture was running, overlapping captures counted once; `wall` is the time since the process started, or since the previous report in the same process.
 - **Triggers.** `action` is a capture for a user command, `wait-poll` one for a command a wait issued, `matcher-poll` one taken while a WebdriverIO `expect` matcher was polling, and `final` the WebdriverIO capture of the last action's result. Matcher polls are told apart on WebdriverIO only, and only with `captureAssertions` on; Selenium and Nightwatch matchers expose no hook to tell them by.
+- **Filmstrip recorder.** With no CDP screencast (Safari, Appium), the `filmstrip` recorder polls a screenshot every 200 ms, and those screenshots share the driver with the captures. The last line counts them: the screenshots it took and their time from issue to settle, the ticks it let pass and why (`driver busy`: a command or a capture held the driver, so a poll would only have queued in front of it; once the newest frame is three intervals old it polls anyway, still waiting behind the command, but never during a click, typing or a capture; `fresh frame`: a capture's screenshot taken less than one interval earlier is already the frame; `shot in flight`: its previous screenshot had not answered yet), and how many per-action capture screenshots it kept as frames. Captures stay counted in the table only. CDP push mode takes no screenshots and prints no line. Python has no polling recorder; it records one frame per command.
 - **Python.** It reads one thing at a time, so `svc` equals the read's duration; it records the screenshot and the two page reads, and has no url, title or `process` rows.
 
 To measure each platform from the repo's examples (the desktop examples other than Selenium's drive Chrome only):