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