commit 2d08a35dc96c78224db08c9d8eb7b0e568c7e9ea
parent 65ad76b909588a5d218156f9ccda9026497e950c
Author: I Mean I'm Just Saying <imeanimjustsaying@kiwifarms.st>
Date: Sat, 26 Sep 2026 02:36:57 -0400
editor: safeRevalidate counts its skips instead of warning once per bundle
Release 9's warning fired once per module instance and then went silent, so
the log could not say whether a queued job skipped its revalidation once a
day or every time — and Next can load the module more than once (review
LOW-4). Each skip (one `safeRevalidate` call with no request store, however
many targets) is now counted by a `SkipReporter` on globalThis, one per
process: the first skip of a quiet period is logged at once with its paths
and opens a 10-minute window; the rest of the window are counted, and one
line at its end reports how many and the latest paths. Every line carries
the total since the process started. At most two lines per window; the
first line keeps its old prefix. The end-of-window timer is unref'd.
safeRevalidate.test.ts 3 → 9: a hand-clocked reporter (one call is one
skip; a busy window is one line at its end; a quiet window reports nothing;
a skip after the window whose timer has not run reports the old window
first), the process-wide holder, the 10 min constant, the rethrow.
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Diffstat:
2 files changed, 275 insertions(+), 38 deletions(-)
diff --git a/editor/app/lib/safeRevalidate.test.ts b/editor/app/lib/safeRevalidate.test.ts
@@ -1,6 +1,8 @@
import { test } from "node:test";
import assert from "node:assert/strict";
import {
+ SKIP_REPORT_WINDOW_MS,
+ SkipReporter,
resetSafeRevalidateWarning,
runGuarded,
safeRevalidate,
@@ -10,7 +12,9 @@ import {
//
// Outside a Next request (which is where a QUEUED job's body runs, and where
// this test runs) revalidatePath throws the missing-store invariant. The helper
-// must swallow exactly that, warn once per process, and rethrow anything else.
+// must swallow exactly that, rethrow anything else, and — since release 10 —
+// COUNT every skip: the first in a quiet period is logged at once, the rest of
+// its window are reported together when the window ends.
function captureWarn<T>(fn: () => T): { result: T; warnings: string[] } {
const warnings: string[] = [];
@@ -25,16 +29,130 @@ function captureWarn<T>(fn: () => T): { result: T; warnings: string[] } {
}
}
-test("outside a request, safeRevalidate does not throw and warns once", () => {
+// A reporter on a hand-driven clock. `advance` moves time and, unless told
+// not to, fires the end-of-window timer if it came due — like the event loop.
+function harness(windowMs = 60_000) {
+ let t = 1_000_000;
+ const lines: string[] = [];
+ type Pending = { at: number; fn: () => void; live: boolean };
+ let pending: Pending | null = null;
+ const reporter = new SkipReporter({
+ windowMs,
+ now: () => t,
+ warn: (l) => lines.push(l),
+ schedule: (fn, ms) => {
+ const entry: Pending = { at: t + ms, fn, live: true };
+ pending = entry;
+ return {
+ cancel: () => {
+ entry.live = false;
+ },
+ };
+ },
+ });
+ const current = (): Pending | null => pending;
+ return {
+ reporter,
+ lines,
+ advance(ms: number, opts: { fire?: boolean } = {}) {
+ t += ms;
+ const p = current();
+ if (opts.fire !== false && p && p.live && p.at <= t) {
+ pending = null;
+ p.fn();
+ }
+ },
+ armed: () => Boolean(current()?.live),
+ };
+}
+
+test("outside a request, safeRevalidate does not throw and logs the first skip with its paths", () => {
resetSafeRevalidateWarning();
const { warnings } = captureWarn(() => {
safeRevalidate(["/channels/x", "/channels", ["/operations/[id]", "page"]]);
safeRevalidate(["/"]);
});
+ resetSafeRevalidateWarning(); // drop the pending end-of-window report
const ours = warnings.filter((w) => w.includes("[safeRevalidate]"));
+ // ONE line for two calls inside one window: the second is counted.
assert.equal(ours.length, 1);
assert.match(ours[0], /\/channels\/x/);
assert.match(ours[0], /\/operations\/\[id\] \(page\)/);
+ assert.match(ours[0], /1 skip\(s\) since this process started/);
+ assert.match(ours[0], /next 10 min are counted and reported together/);
+});
+
+test("one call is one skip, however many targets it names", () => {
+ const h = harness();
+ h.reporter.record(["/a", "/b", "tag:c"]);
+ assert.equal(h.lines.length, 1);
+ assert.match(h.lines[0], /skipped revalidating \/a, \/b, tag:c\./);
+});
+
+test("skips inside the window are counted, and reported once when it ends", () => {
+ const h = harness(60_000);
+ h.reporter.record(["/channels/one"]);
+ h.advance(1_000);
+ for (let i = 0; i < 5; i++) {
+ h.reporter.record([`/channels/n${i}`]);
+ h.advance(1_000);
+ }
+ // Nothing more logged while the window is open: no flooding.
+ assert.equal(h.lines.length, 1);
+ assert.equal(h.armed(), true);
+ h.advance(60_000);
+ assert.equal(h.lines.length, 2);
+ assert.equal(
+ h.lines[1],
+ "[safeRevalidate] 5 more skip(s) with no request store in the last 1 min " +
+ "(latest: /channels/n4); 6 since this process started.",
+ );
+});
+
+test("a quiet window reports nothing at its end, and the next skip is logged at once", () => {
+ const h = harness(60_000);
+ h.reporter.record(["/a"]);
+ // No second skip: no timer armed, no end-of-window line.
+ assert.equal(h.armed(), false);
+ h.advance(10 * 60_000);
+ assert.equal(h.lines.length, 1);
+ h.reporter.record(["/b"]);
+ assert.equal(h.lines.length, 2);
+ assert.match(
+ h.lines[1],
+ /skipped revalidating \/b\. .*2 skip\(s\) since this process started/,
+ );
+});
+
+test("a skip after the window, before its timer ran, reports the old window first", () => {
+ const h = harness(60_000);
+ h.reporter.record(["/a"]);
+ h.advance(30_000);
+ h.reporter.record(["/b"]); // counted; the report is due at +60 s
+ // The clock passes the window but the timer has not run yet (a busy loop).
+ h.advance(40_000, { fire: false });
+ h.reporter.record(["/c"]); // a new window: old report first, then this one
+ assert.equal(h.lines.length, 3);
+ assert.equal(
+ h.lines[1],
+ "[safeRevalidate] 1 more skip(s) with no request store in the last 1 min " +
+ "(latest: /b); 2 since this process started.",
+ );
+ assert.match(h.lines[2], /skipped revalidating \/c\. .*3 skip\(s\) since/);
+ // The old timer was cancelled: it reports nothing when it would have fired.
+ assert.equal(h.armed(), false);
+});
+
+test("the process-wide reporter is on globalThis, so every module instance shares one", () => {
+ resetSafeRevalidateWarning();
+ captureWarn(() => safeRevalidate(["/x"]));
+ assert.ok(globalThis.__yttSafeRevalidateSkips__ instanceof SkipReporter);
+ resetSafeRevalidateWarning();
+ assert.equal(globalThis.__yttSafeRevalidateSkips__, undefined);
+});
+
+test("the production window is 10 minutes", () => {
+ assert.equal(SKIP_REPORT_WINDOW_MS, 10 * 60 * 1000);
});
test("the real revalidatePath does throw here (the premise of the helper)", async () => {
@@ -45,17 +163,16 @@ test("the real revalidatePath does throw here (the premise of the helper)", asyn
);
});
-test("any other error is rethrown", () => {
- resetSafeRevalidateWarning();
+test("any other error is rethrown; a revalidation that runs is not a skip", () => {
assert.throws(
() =>
- runGuarded(
- () => {
- throw new Error("disk on fire");
- },
- "/x",
- ["/x"],
- ),
+ runGuarded(() => {
+ throw new Error("disk on fire");
+ }),
/disk on fire/,
);
+ assert.equal(
+ runGuarded(() => {}),
+ false,
+ );
});
diff --git a/editor/app/lib/safeRevalidate.ts b/editor/app/lib/safeRevalidate.ts
@@ -13,8 +13,8 @@ import { revalidatePath, revalidateTag } from "next/cache";
// Nothing is lost by skipping the revalidation there: every page these paths
// name is dynamic and re-reads disk on the next request, and the snapshot
// scheduler revalidates the channel pages itself when it regenerates. So the
-// missing-store invariant is swallowed (logged once per process, naming the
-// paths), and ANY OTHER error is rethrown — a real failure stays a failure.
+// missing-store invariant is swallowed (and reported — see SkipReporter), and
+// ANY OTHER error is rethrown — a real failure stays a failure.
//
// Use it ONLY inside job bodies and job hooks. A plain server action (a form
// handler that revalidates and returns) runs inside its request and keeps
@@ -24,8 +24,6 @@ export type RevalidateTarget = string | [string, "page" | "layout"];
const MISSING_STORE = /static generation store missing/;
-let warned = false;
-
function isMissingStore(err: unknown): boolean {
return err instanceof Error && MISSING_STORE.test(err.message);
}
@@ -34,25 +32,139 @@ function describe(target: RevalidateTarget): string {
return typeof target === "string" ? target : `${target[0]} (${target[1]})`;
}
+// HOW OFTEN IT HAPPENS, WITHOUT A LINE EACH TIME (release 10, L2).
+//
+// Release 9 warned once per module instance and then went silent, so the log
+// could not say whether this was one job a day or every job in the queue — and
+// Next can load a module more than once, so "once" was not even once. Now each
+// skip (one `safeRevalidate` call, however many targets it names) is COUNTED,
+// on a process-wide holder:
+// - the first skip in a quiet period is logged at once, with its paths, and
+// opens a SKIP_REPORT_WINDOW_MS window;
+// - further skips inside the window are counted, not logged;
+// - when the window ends, one line reports how many there were and the latest
+// paths (nothing, if there were none).
+// So the log carries at most two lines per window, and every skip is in a
+// number. The running total since the process started is on every line.
+export const SKIP_REPORT_WINDOW_MS = 10 * 60 * 1000;
+
+type Timer = { cancel: () => void };
+
+export type SkipReporterDeps = {
+ windowMs?: number;
+ now?: () => number;
+ // Arms the end-of-window report. The default is an unref'd setTimeout: a log
+ // line must never hold the process open.
+ schedule?: (fn: () => void, ms: number) => Timer;
+ warn?: (line: string) => void;
+};
+
+function defaultSchedule(fn: () => void, ms: number): Timer {
+ const t = setTimeout(fn, ms);
+ t.unref?.();
+ return { cancel: () => clearTimeout(t) };
+}
+
+function minutes(ms: number): string {
+ const m = Math.round(ms / 60_000);
+ return m >= 1 ? `${m} min` : `${Math.round(ms / 1000)} s`;
+}
+
+export class SkipReporter {
+ private readonly windowMs: number;
+ private readonly now: () => number;
+ private readonly schedule: (fn: () => void, ms: number) => Timer;
+ private readonly warn: (line: string) => void;
+ private total = 0;
+ // End of the open window; at or before `now()` means no window is open.
+ private windowEndsAt = 0;
+ private suppressed = 0;
+ private latest = "";
+ private timer: Timer | null = null;
+
+ constructor(deps: SkipReporterDeps = {}) {
+ this.windowMs = deps.windowMs ?? SKIP_REPORT_WINDOW_MS;
+ this.now = deps.now ?? Date.now;
+ this.schedule = deps.schedule ?? defaultSchedule;
+ this.warn = deps.warn ?? ((line) => console.warn(line));
+ }
+
+ // One skip: one safeRevalidate call that had no request store.
+ record(labels: readonly string[]): void {
+ const now = this.now();
+ const paths = labels.join(", ");
+ if (now >= this.windowEndsAt) {
+ // A quiet period ended (or this is the first skip): report what the last
+ // window held, if its timer has not already, then this one, at once.
+ this.flush();
+ this.total++;
+ this.windowEndsAt = now + this.windowMs;
+ this.warn(
+ `[safeRevalidate] no request store (a queued job ran outside a request); ` +
+ `skipped revalidating ${paths}. The pages re-read disk on their next request. ` +
+ `${this.total} skip(s) since this process started; more in the next ` +
+ `${minutes(this.windowMs)} are counted and reported together.`,
+ );
+ return;
+ }
+ this.total++;
+ this.suppressed++;
+ this.latest = paths;
+ if (!this.timer) {
+ this.timer = this.schedule(() => {
+ this.timer = null;
+ this.flush();
+ }, this.windowEndsAt - now);
+ }
+ }
+
+ // Report the counted skips, if any. Called by the window's timer, and by the
+ // first skip of the next window in case the timer has not fired yet.
+ flush(): void {
+ if (this.timer) {
+ this.timer.cancel();
+ this.timer = null;
+ }
+ if (this.suppressed === 0) return;
+ this.warn(
+ `[safeRevalidate] ${this.suppressed} more skip(s) with no request store in the last ` +
+ `${minutes(this.windowMs)} (latest: ${this.latest}); ` +
+ `${this.total} since this process started.`,
+ );
+ this.suppressed = 0;
+ this.latest = "";
+ }
+
+ // Test seam: drop the pending report without writing it.
+ dispose(): void {
+ this.timer?.cancel();
+ this.timer = null;
+ }
+}
+
+// ONE PER PROCESS, not per module instance: on globalThis, like the job
+// registry. Not reset by /api/test/invalidate-cache — it decides only how many
+// log lines a skip costs, and nothing reads that log.
+declare global {
+ // eslint-disable-next-line no-var
+ var __yttSafeRevalidateSkips__: SkipReporter | undefined;
+}
+
+function skipReporter(): SkipReporter {
+ globalThis.__yttSafeRevalidateSkips__ ??= new SkipReporter();
+ return globalThis.__yttSafeRevalidateSkips__;
+}
+
// The guard itself, exported for the unit test so the rethrow path can be
-// exercised without a Next runtime. `call` is one revalidation.
-export function runGuarded(
- call: () => void,
- label: string,
- allLabels: readonly string[],
-): void {
+// exercised without a Next runtime. `call` is one revalidation. True when it
+// was skipped for want of a request store.
+export function runGuarded(call: () => void): boolean {
try {
call();
+ return false;
} catch (err) {
if (!isMissingStore(err)) throw err;
- if (!warned) {
- warned = true;
- console.warn(
- `[safeRevalidate] no request store (a queued job ran outside a request); ` +
- `skipped revalidating ${allLabels.join(", ")} — first skip was ${label}. ` +
- `Logged once per process; the pages re-read disk on their next request.`,
- );
- }
+ return true;
}
}
@@ -60,23 +172,31 @@ export function safeRevalidate(
paths: RevalidateTarget[],
tags: string[] = [],
): void {
- const labels = [...paths.map(describe), ...tags.map((t) => `tag:${t}`)];
+ let skipped = false;
for (const target of paths) {
- runGuarded(
- () =>
+ if (
+ runGuarded(() =>
typeof target === "string"
? revalidatePath(target)
: revalidatePath(target[0], target[1]),
- describe(target),
- labels,
- );
+ )
+ ) {
+ skipped = true;
+ }
}
for (const tag of tags) {
- runGuarded(() => revalidateTag(tag, "max"), `tag:${tag}`, labels);
+ if (runGuarded(() => revalidateTag(tag, "max"))) skipped = true;
+ }
+ if (skipped) {
+ skipReporter().record([
+ ...paths.map(describe),
+ ...tags.map((t) => `tag:${t}`),
+ ]);
}
}
-// Test seam: the once-per-process latch.
+// Test seam: a fresh process-wide reporter (any pending report dropped).
export function resetSafeRevalidateWarning(): void {
- warned = false;
+ globalThis.__yttSafeRevalidateSkips__?.dispose();
+ globalThis.__yttSafeRevalidateSkips__ = undefined;
}