Refuse a module failure the prerender pool cannot be shown to have earned

packages/realm-server/prerender/prerender-app.ts

@@ -141,30 +141,48 @@ function respondDraining(ctxt: Koa.Context): void {
 // every anonymous reader until an unrelated reindex revisits the row.
 // Re-rendering on a page warmed against the current shell costs one render;
 // believing it costs an outage that lasts until something else repairs it.
-export function shouldRerenderForShellChange({
+//
+// The question is not whether the shell moved under this render — a pool can
+// be behind the current shell for a whole render without anything moving
+// during it — but whether the pool can be shown to have been on the current
+// shell throughout. Only then does a missing export describe the card.
+export function shouldRerenderForStaleShell({
   response,
-  shellAtStart,
-  shellAtCompletion,
+  warmedAtStart,
+  warmedAtCompletion,
+  reportedAtCompletion,
 }: {
   response: RenderVisitResponse;
-  shellAtStart: string | undefined;
-  shellAtCompletion: string | undefined;
+  warmedAtStart: string | undefined;
+  warmedAtCompletion: string | undefined;
+  reportedAtCompletion: string | undefined;
 }): boolean {
-  // Nothing reported by the end of the render: this server has never been told
-  // which shell is current, so it has no grounds in either direction.
-  if (shellAtCompletion === undefined) {
+  if (!hasMissingExportError(response)) {
     return false;
   }
-  // `undefined -> X` counts as a change, and it is the deploy shape this
-  // exists for. The train restarts prerender before the realm server, so a
-  // server booting mid-train warms against the outgoing bundle and the first
-  // token it ever hears is the new one — on such a server there is no
-  // `X -> Y` to observe until some later deploy. `decideHostShellRecycle`
-  // treats that first token as a definite change for the same reason.
-  if (shellAtStart === shellAtCompletion) {
+  // Nothing reported by the end of the render: this server has never been told
+  // which shell is current, so it has no grounds in either direction.
+  if (reportedAtCompletion === undefined) {
     return false;
   }
-  return hasMissingExportError(response);
+  // Trustworthy only if the pool was demonstrably on the current shell for the
+  // whole render. Both samples have to match the reported token, which rules
+  // out three separate ways of being stale with one comparison:
+  //
+  //   - the pool never caught up, because the recycle is still running or
+  //     failed and is waiting for another heartbeat to retry;
+  //   - the recycle landed mid-render, so the page this render started on was
+  //     the outgoing one even though the pool is current by the end;
+  //   - the token moved during the render, which drags `warmedAtStart` out of
+  //     step with it.
+  //
+  // `undefined` warmed values are stale by the same rule: a pool that has
+  // never been re-warmed against a token this server has heard cannot be shown
+  // to be on it.
+  return !(
+    warmedAtStart === reportedAtCompletion &&
+    warmedAtCompletion === reportedAtCompletion
+  );
 }
 
 function hasMissingExportError(response: RenderVisitResponse): boolean {
@@ -337,6 +355,11 @@ export function buildPrerenderApp(options: {
   // value twice and read as steady, which is precisely the case worth
   // catching. Owned by the HTTP server, which learns it from the heartbeat.
   getHostShellHash?: () => string | undefined;
+  // The token the pool has actually been re-warmed against, which trails the
+  // reported one for as long as a recycle takes — and indefinitely if that
+  // recycle fails. The gap between the two is what says a page may still be
+  // running the outgoing bundle.
+  getWarmedHostShellHash?: () => string | undefined;
   // The recycle triggered by the last token change, if one is still running.
   // A re-render awaits it so it lands on a page warmed against the current
   // shell instead of racing the teardown. Always resolves — the caller
@@ -1154,6 +1177,7 @@ export function buildPrerenderApp(options: {
         signal: ac.signal,
       };
       let shellAtStart = options.getHostShellHash?.();
+      let warmedAtStart = options.getWarmedHostShellHash?.();
       let execPromise = prerenderer
         .prerenderVisit(visitArgs)
         .then((result) => ({ result }));
@@ -1170,24 +1194,34 @@ export function buildPrerenderApp(options: {
       }
       let { response, timings, pool } = raceResult.result;
       let shellAtCompletion = options.getHostShellHash?.();
+      let warmedAtCompletion = options.getWarmedHostShellHash?.();
       if (
         !options.isDraining?.() &&
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response,
-          shellAtStart,
-          shellAtCompletion,
+          warmedAtStart,
+          warmedAtCompletion,
+          reportedAtCompletion: shellAtCompletion,
         })
       ) {
         log.warn(
-          'visit of %s failed to resolve a module while the reported host shell moved from %s to %s; re-rendering before returning that failure',
+          'visit of %s failed to resolve a module on a pool warmed against %s -> %s while the current host shell is %s; re-rendering before returning that failure',
           url,
-          shellAtStart ?? 'none',
+          warmedAtStart ?? 'none',
+          warmedAtCompletion ?? 'none',
           shellAtCompletion,
         );
-        // The token moved because `reconcileHostShell` saw it move, so the
-        // browser is being recycled around now and this visit lands on a page
-        // warmed against the current shell. One attempt only: if it fails
-        // again the failure is the card's, and the caller is owed an answer.
+        // One attempt only. If it fails again the caller is owed an answer,
+        // and this server has nothing better to offer: a 5xx here would be
+        // worse than the failure it replaces, because the manager prunes a
+        // server that returns one — and its proxy loop removes the pruned
+        // target from both the registry and its attempt set, so it walks on to
+        // the next server, prunes that one too, and can empty the registry
+        // over a single visit. Nor would it prevent the row: `remote-
+        // prerenderer` retries a 5xx for about six and a half minutes and then
+        // rethrows, and the indexer buffers a `file-error` row carrying
+        // whatever message arrived. Declining to persist a skew-shaped failure
+        // has to happen where the row is written, not here.
         //
         // Waits for the recycle the token change triggered before rendering
         // again. The reported token moves the moment the change is learned,
@@ -1496,6 +1530,7 @@ export function createPrerenderHttpServer(options?: {
   let serverURL = resolvePrerenderServerURL(options?.port);
   let { app, prerenderer } = buildPrerenderApp({
     getHostShellHash: () => reportedHostShellHash,
+    getWarmedHostShellHash: () => warmedHostShellHash,
     awaitHostShellRecycle: () => hostShellRecycle,
     maxPages: options?.maxPages,
     serverURL,

packages/realm-server/tests/prerender-host-shell-recycle-test.ts

@@ -7,7 +7,7 @@ import {
   createDrainSubscriber,
   decideHostShellRecycle,
   raceAgainstDrain,
-  shouldRerenderForShellChange,
+  shouldRerenderForStaleShell,
   stampHostShellTokens,
 } from '../prerender/prerender-app.ts';
 
@@ -60,7 +60,23 @@ module(basename(import.meta.filename), function () {
     });
   });
 
-  module('shouldRerenderForShellChange', function () {
+  module('shouldRerenderForStaleShell', function () {
+    // A pool on the current shell for the whole render, and one that is not.
+    // Most cases below differ only in which of these they pass, because that
+    // is the only thing the decision reads besides the error itself.
+    const CURRENT = 'b778fe76';
+    const OUTGOING = 'babf3612';
+    const onCurrentShell = {
+      warmedAtStart: CURRENT,
+      warmedAtCompletion: CURRENT,
+      reportedAtCompletion: CURRENT,
+    };
+    const poolBehind = {
+      warmedAtStart: OUTGOING,
+      warmedAtCompletion: OUTGOING,
+      reportedAtCompletion: CURRENT,
+    };
+
     // The message a page throws when it resolves current realm source against
     // a bundle that predates the export — the shape both production poisonings
     // took, minted in `package-shim-handler`.
@@ -77,71 +93,97 @@ module(basename(import.meta.filename), function () {
           }) as unknown as RenderVisitResponse;
     }
 
-    test('a module error under a changed shell is re-rendered', function (assert) {
+    test("the same error on a pool that is current is the card's own", function (assert) {
+      assert.false(
+        shouldRerenderForStaleShell({
+          response: visitResponse(MISSING_EXPORT),
+          ...onCurrentShell,
+        }),
+        'the bundle that rendered it is the one being served, so the failure describes the card',
+      );
+    });
+
+    // The case a token-move test cannot express, and the one that poisons
+    // rows: the token moved before this render began, so nothing moves under
+    // it, while the recycle it triggered is still running or has failed. The
+    // page is on the outgoing bundle for the whole render.
+    test('a pool that never caught up is stale even though nothing moved', function (assert) {
       assert.true(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: visitResponse(MISSING_EXPORT),
-          shellAtStart: 'babf3612',
-          shellAtCompletion: 'b778fe76',
+          ...poolBehind,
         }),
       );
     });
 
-    test("the same error under a steady shell is the card's own", function (assert) {
-      assert.false(
-        shouldRerenderForShellChange({
+    test('a recycle landing mid-render leaves the render suspect', function (assert) {
+      assert.true(
+        shouldRerenderForStaleShell({
+          response: visitResponse(MISSING_EXPORT),
+          warmedAtStart: OUTGOING,
+          warmedAtCompletion: CURRENT,
+          reportedAtCompletion: CURRENT,
+        }),
+        'the page it started on was the outgoing one, however current the pool is by the end',
+      );
+    });
+
+    test('a token learned mid-render outruns the pool', function (assert) {
+      assert.true(
+        shouldRerenderForStaleShell({
           response: visitResponse(MISSING_EXPORT),
-          shellAtStart: 'b778fe76',
-          shellAtCompletion: 'b778fe76',
+          warmedAtStart: CURRENT,
+          warmedAtCompletion: CURRENT,
+          reportedAtCompletion: 'c0ffee00',
         }),
-        'nothing moved under the render, so the failure describes the card',
+        'a newly reported token the pool has not been re-warmed against is a stale pool',
       );
     });
 
-    test('a changed shell alone does not re-render', function (assert) {
+    test('a stale pool alone does not re-render', function (assert) {
       assert.false(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: visitResponse(),
-          shellAtStart: 'babf3612',
-          shellAtCompletion: 'b778fe76',
+          ...poolBehind,
         }),
-        'a render that straddled a deploy and succeeded is left alone',
+        'a render on a stale pool that succeeded is left alone',
       );
       assert.false(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: visitResponse('Card is not found at http://example/x'),
-          shellAtStart: 'babf3612',
-          shellAtCompletion: 'b778fe76',
+          ...poolBehind,
         }),
-        'only module resolution is suspect when the bundle changes',
+        'only module resolution is suspect when the pool is behind',
       );
     });
 
     // The deploy shape this exists for: the train restarts prerender before the
     // realm server, so a server booting mid-train warms against the outgoing
-    // bundle and the first token it hears is the new one. On such a server
-    // there is no `X -> Y` to observe, so excluding `undefined -> X` excluded
-    // the whole boot window — the same transition `decideHostShellRecycle`
-    // treats as a definite change.
-    test('the first token learned mid-render counts as a change', function (assert) {
+    // bundle and the first token it hears is the new one. Until the recycle
+    // that token triggers completes, the pool has not been re-warmed against
+    // anything this server has heard — the same transition
+    // `decideHostShellRecycle` treats as a definite change.
+    test('a pool never re-warmed against a known token is stale', function (assert) {
       assert.true(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: visitResponse(MISSING_EXPORT),
-          shellAtStart: undefined,
-          shellAtCompletion: 'b778fe76',
+          warmedAtStart: undefined,
+          warmedAtCompletion: undefined,
+          reportedAtCompletion: CURRENT,
         }),
       );
     });
 
     test('a server that has heard no token at all is left alone', function (assert) {
-      for (let atStart of [undefined, 'babf3612']) {
+      for (let warmed of [undefined, OUTGOING]) {
         assert.false(
-          shouldRerenderForShellChange({
+          shouldRerenderForStaleShell({
             response: visitResponse(MISSING_EXPORT),
-            shellAtStart: atStart,
-            shellAtCompletion: undefined,
+            warmedAtStart: warmed,
+            warmedAtCompletion: warmed,
+            reportedAtCompletion: undefined,
           }),
-          `(${atStart} -> undefined) says nothing about which bundle rendered`,
+          `warmed=${warmed} with nothing reported says nothing about which bundle rendered`,
         );
       }
     });
@@ -153,22 +195,20 @@ module(basename(import.meta.filename), function () {
     test('the error counts from any sub-response that gets persisted', function (assert) {
       for (let key of ['fileRender', 'fileExtract'] as const) {
         assert.true(
-          shouldRerenderForShellChange({
+          shouldRerenderForStaleShell({
             response: {
               [key]: { error: { error: { message: MISSING_EXPORT } } },
             } as unknown as RenderVisitResponse,
-            shellAtStart: 'babf3612',
-            shellAtCompletion: 'b778fe76',
+            ...poolBehind,
           }),
           `${key}.error is checked`,
         );
         assert.false(
-          shouldRerenderForShellChange({
+          shouldRerenderForStaleShell({
             response: {
               [key]: { error: { error: { message: 'Card is not found' } } },
             } as unknown as RenderVisitResponse,
-            shellAtStart: 'babf3612',
-            shellAtCompletion: 'b778fe76',
+            ...poolBehind,
           }),
           `${key} is still only suspect for module resolution`,
         );
@@ -177,12 +217,11 @@ module(basename(import.meta.filename), function () {
 
     test('the error also counts when it made the page unusable', function (assert) {
       assert.true(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: {
             pageUnusableError: { error: { message: MISSING_EXPORT } },
           } as unknown as RenderVisitResponse,
-          shellAtStart: 'babf3612',
-          shellAtCompletion: 'b778fe76',
+          ...poolBehind,
         }),
       );
     });
@@ -192,7 +231,7 @@ module(basename(import.meta.filename), function () {
     // `additionalErrors` — and the row is persisted with it either way.
     test('the error counts when it is only among the merged console errors', function (assert) {
       assert.true(
-        shouldRerenderForShellChange({
+        shouldRerenderForStaleShell({
           response: {
             card: {
               error: {
@@ -203,8 +242,7 @@ module(basename(import.meta.filename), function () {
               },
             },
           } as unknown as RenderVisitResponse,
-          shellAtStart: 'babf3612',
-          shellAtCompletion: 'b778fe76',
+          ...poolBehind,
         }),
       );
     });