From 8deb0026dcac7df7f2e36199188c8da67f2698ec Mon Sep 17 00:00:00 2001 From: Jonas Templestein <242550+jonastemplestein@users.noreply.github.com> Date: Wed, 7 Oct 2026 07:49:14 +0100 Subject: [PATCH] spinner-waiter: a document that commits mid-check gets its own quick check MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Spinner-waiter decides "is anything loading?" after a 1s quick check. Both describe whatever document the page shows at the time. A click that sets off a redirect chain (OAuth consent → callback → app page) can swap the document in between: the quick check spends its second on the page the click left, or the loading check reads `readyState` from the old document and counts spinners once the new one has committed. Chromium holds evaluations and locator queries while a navigation is in flight (DevTools suspends renderer-bound commands from DidStartNavigation to DidFinishNavigation); a query that loses its document reports "not visible" or 0. So the decision reads "complete, no spinner" before the new page has drawn anything, and the action fast-fails at 1ms mid-flow. Count main-frame `framenavigated` events per page. When the main frame navigated during the quick check or the loading check, run the quick check again on the document that is there now. All of it is charged against one deadline, `spinnerTimeout` minus the action's last second, which the spinner wait respects too; a page still navigating at the deadline counts as loading and fails with the "navigation was still in flight" message. The common fast-fail path only adds two WeakMap reads. A fast-fail after a navigation costs one more second per observed navigation. Two specs. A real `node:http` redirect chain (Playwright continues redirected requests itself, so a route-fulfilled 302's next hop never reaches page.route) whose landing page draws its spinner 850ms after it commits: fails 20/20 on main with `Timeout 1ms exceeded`, passes 20/20 after. And a page that reloads itself every 300ms, which fails within the budget with the navigation message. Co-Authored-By: Claude Fable 5.1 --- README.md | 2 +- spec/spinner-waiter.spec.ts | 117 +++++++++++++++++- src/plugins/spinner-waiter.ts | 87 ++++++++++--- ...2026-10-07-spinner-waiter-redirect-race.md | 73 +++++++++++ 4 files changed, 259 insertions(+), 20 deletions(-) create mode 100644 tasks/complete/2026-10-07-spinner-waiter-redirect-race.md diff --git a/README.md b/README.md index 98b8860..f8bd6f3 100644 --- a/README.md +++ b/README.md @@ -110,7 +110,7 @@ Fair enough — *inside* Playwright's watchdog architecture it may not be. But i The flagship. Before each action, if the target element isn't visible but a spinner is, waits (up to `spinnerTimeout`) for the element — bailing out early if the spinner disappears without producing it. If there's no spinner and the action fails, the error message suggests adding one: -A document that hasn't finished loading counts as a spinner too: right after a cross-server hop (an OAuth popup, say) the page may still be fetching and rendering before its `load` event — no app spinner exists yet, but the browser's tab spinner is on — so actions wait through it the same way. That covers auto-wrapped OAuth popups without explicit timeouts. +A document that hasn't finished loading counts as a spinner too: right after a cross-server hop (an OAuth popup, say) the page may still be fetching and rendering before its `load` event — no app spinner exists yet, but the browser's tab spinner is on — so actions wait through it the same way. That covers auto-wrapped OAuth popups without explicit timeouts. If the main frame navigates while `spinnerWaiter` is checking (a click that set off a redirect chain, say), the new document gets the quick check again before the no-spinner fast-fail, within the same `spinnerTimeout` budget. ``` Timeout 1000ms exceeded. diff --git a/spec/spinner-waiter.spec.ts b/spec/spinner-waiter.spec.ts index 16f87f8..e303413 100644 --- a/spec/spinner-waiter.spec.ts +++ b/spec/spinner-waiter.spec.ts @@ -1,3 +1,5 @@ +import http from "node:http"; +import type { AddressInfo } from "node:net"; import { test as base, expect } from "@playwright/test"; import { addPlugins, defaultSelectors, spinnerWaiter, type Plugin } from "../src/index.ts"; @@ -317,9 +319,122 @@ test("fails fast once a navigation has fully loaded without the expected element .catch((e: Error) => e); // The navigation is over and the document is complete: nothing is loading, - // so this is the ordinary no-spinner fast-fail — not a long wait. + // so this is the ordinary no-spinner fast-fail — not a long wait. When the + // commit lands inside the quick check, the new document gets one more + // second first. expect(error).toBeInstanceOf(Error); expect(String(error)).toMatch(/Timeout 1ms exceeded/); expect(String(error)).toMatch(/add a spinner/i); expect(Date.now() - start).toBeLessThan(6_000); }); + +test("waits through a redirect chain whose landing page draws its spinner after it commits", async ({ + page, +}) => { + // A Connect button first creates the integration over fetch (no loading UI + // of its own), then follows a server redirect chain the way an OAuth + // connection does: consent, callback, project page. The project page + // commits inside spinner-waiter's 1s quick check and draws its loading + // state 850ms after that (a data fetch after hydration), then the result. + // + // From the click, in ms: fetch resolves ~400, consent 302 ~550, callback + // 302 ~700, project page commits ~750, spinner ~1600, result ~3250. The + // quick check spends most of its second on the page the click left, so the + // loading check runs ~1050ms in: the project page is complete and has not + // drawn its spinner yet. Unless the new document gets a quick check of its + // own, that reads as "nothing loading" and fast-fails at 1ms mid-flow. + // (A very slow runner can shift that ordering so the old code passes too; + // the fix passes in every ordering.) + await using app = await serveConnectFlow(); + await page.goto(app.url); + await page + .getByRole("button", { name: "Connect GitHub" }) + // noWaitAfter: the click must not wait for a navigation it sets off. + .click({ noWaitAfter: true }); + await page.getByText("GitHub connected").waitFor(); +}); + +test("gives up on a page that keeps navigating and blames the navigation", async ({ page }) => { + // A page that reloads itself every 300ms never gives the target a chance + // and never shows a spinner. Each navigation would buy the new document + // another quick check; the deadline (spinnerTimeout minus the action's + // last second) stops that and reports a navigation still in flight instead + // of the no-spinner hint. + await page.route("https://app.middlewright.test/**", async (route) => { + await route.fulfill({ + body: `

Reload loop

`, + contentType: "text/html", + }); + }); + await page.goto("https://app.middlewright.test/"); + spinnerWaiter.settings.enterWith({ spinnerTimeout: 3001 }); + + const start = Date.now(); + const error = await page.getByText("Settled").waitFor().catch((e: Error) => e); + + expect(error).toBeInstanceOf(Error); + expect(String(error)).toMatch(/navigation was still in flight/); + expect(Date.now() - start).toBeLessThan(6_000); +}); + +/** + * A tiny app on 127.0.0.1 whose Connect button creates the integration over + * fetch and then follows the OAuth-style redirect chain consent → callback → + * project page. Real HTTP, because Chromium follows a route-fulfilled 302 + * without passing the next hop back through page.route. + */ +async function serveConnectFlow() { + const delay = (ms: number) => new Promise((resolve) => setTimeout(resolve, ms)); + const pages: Record = { + "/": ` + + + `, + "/project": ` +

Project

+
+ + `, + }; + const server = http.createServer(async (request, response) => { + const { pathname } = new URL(request.url ?? "/", "http://127.0.0.1"); + if (pathname === "/api/connect") { + await delay(400); + response.setHeader("content-type", "application/json"); + response.end(JSON.stringify({ url: "/oauth/consent" })); + } else if (pathname === "/oauth/consent") { + await delay(150); + response.writeHead(302, { location: "/oauth/callback?code=1" }).end(); + } else if (pathname === "/oauth/callback") { + await delay(150); + response.writeHead(302, { location: "/project" }).end(); + } else if (pathname in pages) { + response.setHeader("content-type", "text/html"); + response.end(pages[pathname]); + } else { + response.writeHead(404).end(); + } + }); + await new Promise((resolve, reject) => { + server.once("error", reject); + server.listen(0, "127.0.0.1", resolve); + }); + const { port } = server.address() as AddressInfo; + return { + url: `http://127.0.0.1:${port}/`, + [Symbol.asyncDispose]: async () => { + const closed = new Promise((resolve) => server.close(resolve)); + server.closeAllConnections(); + await closed; + }, + }; +} diff --git a/src/plugins/spinner-waiter.ts b/src/plugins/spinner-waiter.ts index 43a5558..d724660 100644 --- a/src/plugins/spinner-waiter.ts +++ b/src/plugins/spinner-waiter.ts @@ -120,18 +120,44 @@ export const spinnerWaiter = Object.assign( const start = Date.now(); settings.log(`${locator}.${method}(...) starting`); - // Quick check if element is already ready for the attempted action. - const elementReady = await waitForReady(locator, method, { timeout: 1000 }); - if (elementReady) { - settings.log(`${locator} already ready, proceeding`); - return next(); - } - - // Check for loading UI: an app spinner, or a navigation in flight - // (loading UI the app cannot draw itself — see loadingVisible). const spinnerSelector = settings.spinnerSelectors.join(","); const spinnerLocator = page.locator(spinnerSelector) as LocatorWithOriginal; - const loading = await loadingVisible(page, spinnerLocator); + // All waiting here, quick checks included, ends at the deadline; the + // action's own timeout gets the last second. + const deadline = start + settings.spinnerTimeout - 1000; + + // Quick check if element is already ready for the attempted action, + // otherwise check for loading UI: an app spinner, or a navigation in + // flight (loading UI the app cannot draw itself — see loadingVisible). + // + // Both describe whatever document the page shows at the time, and the + // main frame can navigate in between: the quick check spends its + // second on the page a click left behind, or the loading check reads + // readyState from the old document and counts spinners once the new + // one has committed (Chromium holds locator queries while a navigation + // is in flight; a query that loses its document reports "not visible" + // and 0). A fast-fail would then hit a document that never had its + // second, so after a navigation the quick check runs again. A page + // still navigating at the deadline counts as loading. + let navigations = mainFrameNavigations(page); + let loading: boolean; + for (;;) { + if (await waitForReady(locator, method, { timeout: 1000 })) { + settings.log(`${locator} already ready, proceeding`); + return next(); + } + loading = await loadingVisible(page, spinnerLocator); + const seen = mainFrameNavigations(page); + if (loading || seen === navigations) break; + if (Date.now() >= deadline) { + loading = true; + break; + } + navigations = seen; + settings.log( + `The main frame navigated while checking, giving the new document its own quick check`, + ); + } if (!loading) { // No spinner, no navigation - call action, suggest a spinner if it fails @@ -144,14 +170,13 @@ export const spinnerWaiter = Object.assign( } } - settings.log( - `Loading (spinner or navigation), waiting up to ${settings.spinnerTimeout - 2000}ms for ${locator}`, - ); + const remaining = Math.max(0, deadline - Date.now()); + settings.log(`Loading (spinner or navigation), waiting up to ${remaining}ms for ${locator}`); // Something is loading — wait for the element, but bail early once loading // finishes (the operation completed without producing the expected element). const waitResult = await waitForReadyWhileSpinning(locator, method, page, spinnerLocator, { - timeout: settings.spinnerTimeout - 2000, + timeout: remaining, }); if (waitResult === "appeared") { @@ -277,10 +302,13 @@ async function loadingVisible(page: Page, spinnerLocator: Locator): Promise { if (page.isClosed()) return false; @@ -297,6 +325,29 @@ async function pageIsNavigating(page: Page): Promise { return readyState !== "complete"; } +/** + * How often the page's main frame has navigated since spinner-waiter first + * looked at the page: new documents and same-document navigations alike + * (pushState, hash changes — Playwright's framenavigated does not tell them + * apart, and a route change can bring new loading UI as much). A changed + * count means an earlier check may describe a page that is gone. A failed + * navigation does not count; Chromium's error page commit does. + */ +const navigationCounts = new WeakMap(); + +function mainFrameNavigations(page: Page): number { + let count = navigationCounts.get(page); + if (count === undefined) { + count = 0; + navigationCounts.set(page, count); + page.on("framenavigated", (frame) => { + if (frame !== page.mainFrame()) return; + navigationCounts.set(page, (navigationCounts.get(page) ?? 0) + 1); + }); + } + return count; +} + /** * Multi-element-safe "is any spinner visible": the spinner selector union can * legitimately match several loading indicators at once (e.g. two panels each diff --git a/tasks/complete/2026-10-07-spinner-waiter-redirect-race.md b/tasks/complete/2026-10-07-spinner-waiter-redirect-race.md new file mode 100644 index 0000000..d666d57 --- /dev/null +++ b/tasks/complete/2026-10-07-spinner-waiter-redirect-race.md @@ -0,0 +1,73 @@ +--- +status: done +size: small +branch: spinner-redirect-race +--- + +# spinner-waiter: a document that commits mid-check gets its own quick check + +**Status summary**: done. One real-server spec that fails on main 20/20 with the 1ms fast-fail and passes with the fix, one spec for a page that never stops navigating; README updated; Codex review taken. + +## Why + +`../iterate`'s `integrations.spec.ts` ("a project connects X…") failed in CI +mid-redirect: a click set off consent → callback → app page, and the next +action fast-failed with `Timeout 1ms exceeded` while the app was still +loading. Its trace showed `readyState` "complete" and, 1.6s later, a spinner +count of 0 on the page the redirect returned. + +## What is really going on + +Chromium suspends renderer-bound DevTools commands from `DidStartNavigation` +to `DidFinishNavigation` (`render_frame_devtools_agent_host.cc`). So +`page.evaluate`, `isVisible()` and `count()` issued during a navigation stall +until it finishes; a query bound to the old document then fails with a +destroyed context, which Playwright reports as `false` / `0`, and a fresh +query sees the new document. The 250ms race in `pageIsNavigating` reads a +stalled evaluate as loading, but nothing in the "is loading" decision noticed +when the main frame *navigated under it*: + +- the quick check spends its second on the page the click left, then the + loading check runs on a freshly committed page that has not drawn its + spinner yet; or +- `readyState` comes from the old document and the spinner count reports 0 + after the navigation, when the navigation starts between the two. + +Either way the fast-fail hits a document that never had its second. + +## Decision + +Count main-frame `framenavigated` events per page (new documents and +same-document navigations alike; failed navigations do not fire it, Chromium's +error-page commit does). If the count changed during the quick check or the +loading check, run the quick check again on the page that is there now. All of +it is charged against one deadline, `spinnerTimeout` minus the action's last +second, which the spinner wait also respects; a page still navigating at the +deadline counts as loading and fails with the "navigation was still in flight" +message. The common fast-fail path (no navigation) only adds two WeakMap reads. + +Considered and not taken: + +- Tracking pending main-frame navigation requests: network events do stay + observable while renderer commands stall, but it does nothing for the + post-commit, pre-spinner window the failing spec reproduces. +- Reading `readyState` after the spinner count: probes can still span two + documents, and it does nothing for the spent quick check. +- A stable "not loading" window before every fast-fail: a one-second window + would cover a spinner drawn late in the new document's first second, at the + cost of a second on every ordinary failure. + +Known limits, unchanged: the probes themselves carry no deadline (a navigation +that never finishes holds them past `spinnerTimeout`); the straddled-decision +variant has no deterministic spec, since it needs a navigation to start in +the few milliseconds between two probes; `waitForReadyWhileSpinning`'s grace +period starts once and does not restart on a later navigation. + +## Checklist + +- [x] spec: a Connect button that fetches, then follows a redirect chain to a page that draws its spinner 850ms after commit _(fails 20/20 on main with `Timeout 1ms exceeded`, passes 20/20 after)_ +- [x] spec: a page that reloads itself every 300ms fails within the budget with the navigation message +- [x] `mainFrameNavigations(page)` + re-run of the quick check after a navigation, one deadline for the whole wait +- [x] README: the new document gets the quick check again, within the same budget +- [x] existing "fails fast once a navigation has fully loaded" spec still passes, 4.2s instead of 3.2s +- [x] Codex review (gpt-6-astra, max): budget accounting, navigation-aware exhaustion message, counter naming, comment claims, server shutdown order, repeated-navigation spec — all taken; a deterministic straddle spec was asked for and is recorded above as not constructible