From 6317fe5c99687c7837f05478985f775ee7dd64df Mon Sep 17 00:00:00 2001 From: Joe Date: Fri, 21 Aug 2026 15:36:17 -0400 Subject: [PATCH 1/5] feat(plugin): decide the render order from a scored ready set, not from the index; v0.50.0 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `claim` takes the first rows it finds from the claim floor, so the queue serves whatever is oldest-due. Two production measurements say that is the wrong order under scarcity (#80): ~46% of a 521,929-row overdue queue was bot-discovered rather than sitemap-submitted, and absolute due time treats a 1h-TTL homepage 3h overdue exactly like a 48h-TTL product page 3h overdue — 300% stale against 6%. Simulated over the real corpus the 1h route sits at 4.78x its own TTL even at FULL capacity. WHY IT COULD NOT BE FIXED IN THE SCAN. The claim window is anchored at the OLDEST due time and is already an EDF prefix, so under a backlog every row in it is ancient and a homepage two of its own cadences late is never read at all — a wider window anchored in the same place is just more ancient rows. Ranking by relative lateness cannot be an index either: it has slope 1/interval, so two rows with different intervals cross exactly once and no stored key can express an order that changes with the clock. Two earlier attempts died on those two facts respectively. So the ordering leaves the index. A sweep on worker 0 scores the WHOLE due set and publishes the best few thousand into a shared buffer; `claim` pops from it in priority order and reads no index at all. This is affordable because of one measured fact (#119): a projected one-sided read is ~2.4 us/row, FLAT from 200 to 20,000 rows, and yielding every 200 rows is free — 200,000 rows in ~480 ms, a 500k-row overdue set in ~1.2 s, with ZERO writes. Writes are 76-89 us/row, 32x a read, so reading liberally and writing not at all is the cheap direction. The claim path gets strictly faster: it used to scan the index under the claim mutex, and now it does not touch it. Score is `max(0, now - dueAt) / renderInterval`, times `sitemapBoost` for a sitemap row. Lateness rather than age, because `dueAt - interval` is not when the page last rendered for every row — suppression rechecks schedule 7 days, backoffWait up to maxBackoff, the unpin hatch a defaultInterval — so an age ratio would put a 7-day recheck at the head reading as 3.5 cadences stale. Three properties carry the safety argument: IT IS A CACHE IN FRONT OF THE OLD PATH. Cold, exhausted, disabled, or a buffer that could not be sized all fall through to the floored scan, so every failure mode is the PREVIOUS behaviour rather than a stalled queue. That is why it ships on. NOTHING HERE IS A CORRECTNESS INVARIANT. A stale entry costs at most one redundant render — the lease CAS refuses a duplicate and processJobResult already drops a result whose target is gone — and the next sweep re-reads the table, so it cannot lose a page. The claim floor, by contrast, never reads a row filed below it again, silently and terminally. THE SWEEP OWNS THE FLOOR. Claims served from memory observe nothing, and a floor nothing observes freezes — measured, an unfloored seek degrades 0.073 -> 5.60 ms over 40,000 reschedules while a floored one stays flat. The sweep applies the same floor rule and is better informed doing it: it sees every due row, so "the first due row observed" is the true minimum rather than a window's. `fromSitemap` is carried through shared memory rather than re-read: the renderer serializes a non-indexable page only when the url is sitemap-listed, so a job reporting false for a listed page silently stops it being cached — a bug this package has shipped twice — and the alternative is a point read per granted job against a residency-pinned table where an unowned read has no timeout. New metrics: `claim_granted` split ready/index (the only series that shows whether this engages, since it moves no totals), `ready_sweep_ms`, `ready_published`. 750 pass / 0 fail. The ready set and the scoring run against a plain ArrayBuffer with no Harper; the sweep and the claim run against a fake table. Pinned in particular: the production symptom (a late homepage behind 400 older rows granted first), the floor still advancing, the fallback on cold/exhausted/disabled, a leased row never granted twice, a key dropped rather than truncated, and the cursor handing each index out exactly once. Co-Authored-By: Claude Opus 5 --- packages/plugin/METRICS.md | 51 +-- packages/plugin/README.md | 66 ++++ packages/plugin/extension.js | 3 +- packages/plugin/package.json | 2 +- packages/plugin/src/configSchema.js | 73 ++++ packages/plugin/src/metrics.js | 33 +- packages/plugin/src/resources/RenderQueue.js | 73 ++++ packages/plugin/src/util/readyQueue.js | 276 +++++++++++++++ packages/plugin/src/util/renderPriority.js | 159 +++++++++ packages/plugin/src/util/renderSchedule.js | 337 +++++++++++++++++-- packages/plugin/test/config.test.js | 2 + packages/plugin/test/readyQueue.test.js | 256 ++++++++++++++ packages/plugin/test/readySweep.test.js | 318 +++++++++++++++++ 13 files changed, 1589 insertions(+), 60 deletions(-) create mode 100644 packages/plugin/src/util/readyQueue.js create mode 100644 packages/plugin/src/util/renderPriority.js create mode 100644 packages/plugin/test/readyQueue.test.js create mode 100644 packages/plugin/test/readySweep.test.js diff --git a/packages/plugin/METRICS.md b/packages/plugin/METRICS.md index fb84624..8e24c3a 100644 --- a/packages/plugin/METRICS.md +++ b/packages/plugin/METRICS.md @@ -121,17 +121,17 @@ PK drives the scan (an open range can make the planner walk a metric's entire hi One-line summaries; `src/metrics.js` carries the full description of every dimension value and the reasoning behind it. -| Metric | Kind | `path` | `method` | `type` | What it's for | -| ---------------- | ------- | ---------- | ----------- | ---------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `bot_request` | counter | host | botName | deviceType | Raw crawl volume and mix at ingress. The denominator for every serve-side ratio. | -| `bot_serve` | counter | source | cacheStatus | botName | **Origin offload** and **cache hit rate** — the two rollout numbers. | -| `route_serve` | counter | route | cacheStatus | deviceType | The same outcome per route: which route's `renderInterval` needs to move. | -| `page_age` | ms | botName | deviceType | — | Freshness as delivered: ms since the served snapshot rendered (cache serves only). | -| `route_page_age` | ms | route | cacheStatus | deviceType | Served age per route, split by freshness state — the "should this TTL move" number. | -| `render` | value | series | per-series | per-series | The render fleet in one scan: `time_ms` (duration by statusCode × candidacy — renders/hour = concurrency ÷ time_ms) and `outcome` (counter by outcome × detail, exactly one per posted result — the render-failure alert). | -| `origin_fetch` | ms | statusCode | reason | — | Cost of every non-cache serve: origin latency + status, by why the cache didn't answer (miss/stale/skip/invalidated/bypass/blob-missing/blob-timeout/render-timeout). | -| `prerender_ops` | value | series | detail | context | Every low-volume ops signal in one scan: `unrouted` (class, bucket), `sitemap_*`, `serve_error`, `config_warnings`, `page_age_negative` (bot, device), `demand_*` (ladder decisions + `fast_fraction`/`fill`), `invalidation_error` (kind), `invalidation_reenqueue` (outcome, scope). | -| `queue_health` | value | series | result | — | Every queue signal in one scan: the snapshot gauges (`overdue`, `lease_occupancy`, `below_floor`, `below_floor_age_ms`, `floor_pin_age_ms`, `paused`), `claim_scan_ms` (per pass, method = granted/empty/capped), `reconcile_restored`/`reconcile_missing` (per sweep). | +| Metric | Kind | `path` | `method` | `type` | What it's for | +| ---------------- | ------- | ---------- | ----------- | ---------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `bot_request` | counter | host | botName | deviceType | Raw crawl volume and mix at ingress. The denominator for every serve-side ratio. | +| `bot_serve` | counter | source | cacheStatus | botName | **Origin offload** and **cache hit rate** — the two rollout numbers. | +| `route_serve` | counter | route | cacheStatus | deviceType | The same outcome per route: which route's `renderInterval` needs to move. | +| `page_age` | ms | botName | deviceType | — | Freshness as delivered: ms since the served snapshot rendered (cache serves only). | +| `route_page_age` | ms | route | cacheStatus | deviceType | Served age per route, split by freshness state — the "should this TTL move" number. | +| `render` | value | series | per-series | per-series | The render fleet in one scan: `time_ms` (duration by statusCode × candidacy — renders/hour = concurrency ÷ time_ms) and `outcome` (counter by outcome × detail, exactly one per posted result — the render-failure alert). | +| `origin_fetch` | ms | statusCode | reason | — | Cost of every non-cache serve: origin latency + status, by why the cache didn't answer (miss/stale/skip/invalidated/bypass/blob-missing/blob-timeout/render-timeout). | +| `prerender_ops` | value | series | detail | context | Every low-volume ops signal in one scan: `unrouted` (class, bucket), `sitemap_*`, `serve_error`, `config_warnings`, `page_age_negative` (bot, device), `demand_*` (ladder decisions + `fast_fraction`/`fill`), `invalidation_error` (kind), `invalidation_reenqueue` (outcome, scope). | +| `queue_health` | value | series | result | — | Every queue signal in one scan: the snapshot gauges (`overdue`, `lease_occupancy`, `below_floor`, `below_floor_age_ms`, `floor_pin_age_ms`, `paused`), `claim_scan_ms` (per pass, method = granted/empty/capped), `claim_granted` (per claim, method = ready/index), `ready_sweep_ms` (per sweep, method = complete/capped), `ready_published`, `reconcile_restored`/`reconcile_missing` (per sweep). | Notes that bite: @@ -358,19 +358,22 @@ The catalog above is reference; this is the short list. "Sum across nodes" is im **Thresholds — warn, then investigate:** -| Condition | Meaning | -| ----------------------------------------------------------------------------------- | --------------------------------------------------------------------------------------------------------------------------------------- | -| `queue_health` `overdue` − `lease_occupancy` growing snapshot-over-snapshot | The fleet is falling behind demand (remember: `overdue`'s healthy floor IS the in-flight count). | -| `queue_health` `floor_pin_age_ms` > ~1 h | One key is holding the claim scan's seek position — the whole node's queue ages behind it. | -| `bot_serve` swr share rising / `route_page_age` p95 > that route's `renderInterval` | The cadence is configured but not delivered — a capacity or scheduling problem, not a config one. | -| `bot_serve` miss share rising | Coverage: new URLs the corpus doesn't have, or the CDN forwarding paths it shouldn't (check `unrouted`). | -| `duration` p95 (`path: 'p'`) or `success` ratio degrading | The crawler-facing SLO, independent of any plugin-level explanation. | -| `queue_status` report timestamp stale, or intent ≠ observed > one sync interval | A node stopped reporting (and likely claiming), or pause propagation is stuck. | -| `render` outcome `suppressed` or `failed` share rising | Mass suppression (an origin change disavowing pages) or a failing fleet — shares are readable directly because outcomes sum to results. | -| `queue_health` `claim_scan_ms` p95 trending up | The scan is degrading (dead index entries at the seek point) before any backlog shows. Watch the trend, not the absolute number. | -| `origin_fetch` p95 or 5xx/`0` share rising | Origin trouble that bots feel directly on every miss; a rising `render-timeout` share is renderNow falling back. | -| `queue_health` `paused` = 1 beyond the expected window | A node's queue is paused longer than whoever paused it intended. | -| `prerender_ops` series `config_warnings` changed after a deploy | The deploy introduced a finding; `GET /prerender_admin/config` names it. | +| Condition | Meaning | +| ----------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `queue_health` `overdue` − `lease_occupancy` growing snapshot-over-snapshot | The fleet is falling behind demand (remember: `overdue`'s healthy floor IS the in-flight count). | +| `queue_health` `floor_pin_age_ms` > ~1 h | One key is holding the claim scan's seek position — the whole node's queue ages behind it. | +| `bot_serve` swr share rising / `route_page_age` p95 > that route's `renderInterval` | The cadence is configured but not delivered — a capacity or scheduling problem, not a config one. | +| `bot_serve` miss share rising | Coverage: new URLs the corpus doesn't have, or the CDN forwarding paths it shouldn't (check `unrouted`). | +| `duration` p95 (`path: 'p'`) or `success` ratio degrading | The crawler-facing SLO, independent of any plugin-level explanation. | +| `queue_status` report timestamp stale, or intent ≠ observed > one sync interval | A node stopped reporting (and likely claiming), or pause propagation is stuck. | +| `render` outcome `suppressed` or `failed` share rising | Mass suppression (an origin change disavowing pages) or a failing fleet — shares are readable directly because outcomes sum to results. | +| `queue_health` `claim_scan_ms` p95 trending up | The scan is degrading (dead index entries at the seek point) before any backlog shows. Watch the trend, not the absolute number. | +| `queue_health` `claim_granted` all `index`, none `ready` | Prioritisation is not engaging: the sweep is failing, the ready buffer could not be sized, or the set is always dry. The queue looks healthy in every other series because the ready set reorders a fixed amount of work and moves no total. | +| `queue_health` `ready_sweep_ms` method `capped` | The sweep hit `queue.ready.sweepCap` without reaching a not-yet-due row, so it is ordering the oldest part of the backlog only — the rows it skipped are the youngest, i.e. exactly the recently-due pages the ordering exists to protect. | +| `queue_health` `ready_published` at 0 with a non-empty backlog | The sweep is running and finding nothing to publish. Check `queue.ready.capacity` was sizeable at boot (it is restart-scoped) and that the claim floor has not advanced past the due set. | +| `origin_fetch` p95 or 5xx/`0` share rising | Origin trouble that bots feel directly on every miss; a rising `render-timeout` share is renderNow falling back. | +| `queue_health` `paused` = 1 beyond the expected window | A node's queue is paused longer than whoever paused it intended. | +| `prerender_ops` series `config_warnings` changed after a deploy | The deploy introduced a finding; `GET /prerender_admin/config` names it. | **Absence is a signal — alert when a series stops:** diff --git a/packages/plugin/README.md b/packages/plugin/README.md index b54867a..47caf44 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -518,6 +518,72 @@ The floor advances to **the first due row a pass observed**, which is the same t Set `queue.claimFloor.enabled: false` to roll the floor back to the old full seek. It changes nothing else; leases stay where they are either way. +#### The ready set: which of the due rows goes first + +The floor decides _where the scan starts_. `queue.ready` decides _which rows get the leases_ — and it +had to stop being a property of the scan at all. + +`claim` takes the first rows it finds from the floor, so the queue serves whatever is oldest-due. Two +production measurements say that is the wrong order under scarcity +([#80](https://github.com/HarperFast/prerender-plugin/issues/80)): + +- **Provenance.** During a multi-hour backlog, **239,090 of 521,929 overdue rows (~46%)** were + bot-discovered rather than sitemap-submitted. +- **TTL-blindness.** Absolute due time treats a 1 h-TTL homepage 3 h overdue exactly like a 48 h-TTL + product page 3 h overdue — 300% stale against 6%. Simulated over the real corpus the 1 h route sits + at **4.78× its own TTL even at full capacity**, and 48.83× at half. + +**Why it cannot be fixed by re-sorting the claim window.** The window is anchored at the _oldest_ due +time and is already an EDF prefix. Under a backlog every row in it is ancient, so a homepage two of +its own cadences late is never read at all — and a wider window anchored in the same place is just +more ancient rows. (Ranking by relative lateness also cannot be an _index_: `(t − dueAt) / interval` +has slope `1/interval`, so two rows with different intervals cross exactly once and no stored key can +express an order that changes with the clock.) + +So the ordering moved out of the index. A background sweep on worker 0 scores the **whole** due set +and publishes the best few thousand into a shared buffer; `claim` pops from that in priority order and +reads no index at all. That is affordable because of one measured fact +([#119](https://github.com/HarperFast/prerender-plugin/pull/119)): a projected one-sided read costs +**~2.4 µs/row, flat** from 200 to 20,000 rows, and yielding every 200 rows is free — so 200,000 rows +cost ~480 ms and a 500k-row overdue set ~1.2 s, with **zero writes**. Writes are 76–89 µs/row, 32× a +read, so reading liberally and writing not at all is the cheap direction. + +The score is `max(0, now − dueAt) / renderInterval`, multiplied by `queue.ready.sitemapBoost` for a +sitemap-sourced row. Lateness rather than age, deliberately: `dueAt − interval` is not when the page +last rendered for every row — suppression rechecks schedule 7 days, `backoffWait` up to `maxBackoff`, +the unpin hatch a `defaultInterval` — so an age-based ratio would put a 7-day recheck on a 48 h route +at the _head_ of the queue reading as 3.5 cadences stale. + +Three properties are worth knowing: + +- **It is a cache in front of the old path, not a replacement.** Cold (a fresh worker generation), + exhausted (claims outrunning the sweep), disabled, or a buffer that could not be sized — all of them + fall through to the floored index scan. Every failure mode is _the previous behaviour_, which is why + it ships on by default. +- **Nothing here is a correctness invariant.** An entry naming a row that has since been rescheduled + or deleted costs at most one redundant render: the lease CAS refuses a duplicate and + `processJobResult` already drops a result whose target is gone. It cannot lose a page, because the + next sweep re-reads the table. Compare the claim floor, where a row filed below it is never read + again — silently and terminally. +- **The sweep owns the floor now.** Once claims are served from memory they observe nothing, and a + floor nothing observes freezes — measured, an unfloored seek degrades **0.073 → 5.60 ms over 40,000 + reschedules** while a floored one stays flat at 0.07 ms. So the sweep applies the same floor rule, + and is better informed doing it: it sees every due row, so "the first due row observed" is the true + minimum rather than the minimum of a window. + +`sitemapBoost` is a multiplier and never a tier, so it cannot starve discovered URLs: an unserved +row's lateness grows without bound while the boost stays constant, so a discovered page is served +within roughly `sitemapBoost ×` the worst sitemap ratio. + +Watch `queue_health` `claim_granted` (jobs per claim, split `ready`/`index`). The ready set reorders a +fixed amount of work and moves no total, so this is the only series that shows whether prioritisation +is engaging — a node quietly serving every claim from `index` looks identical to a healthy one +everywhere else. `ready_sweep_ms` with method `capped` means the sweep never reached a not-yet-due row, +so it is ordering over the oldest part of the backlog only and recently-due pages are going unranked; +raise `queue.ready.sweepCap`. + +`queue.ready.enabled: false` claims straight from the index scan and stops the sweep — a true revert. + ## HTTP & resource API | Method & path | Purpose | diff --git a/packages/plugin/extension.js b/packages/plugin/extension.js index 15b10af..0267077 100644 --- a/packages/plugin/extension.js +++ b/packages/plugin/extension.js @@ -15,7 +15,7 @@ import { seedOverrideFingerprint, startOverrideWatch, } from './src/util/configOverride.js'; -import { startQueueStatusSync } from './src/resources/RenderQueue.js'; +import { startQueueStatusSync, startReadySweep } from './src/resources/RenderQueue.js'; import { startSitemapRefreshScheduler } from './src/resources/Sitemap.js'; import { startScheduleReconciler } from './src/util/reconcile.js'; import { startUnroutedReporter } from './src/util/unrouted.js'; @@ -99,6 +99,7 @@ export async function handleApplication(scope) { // self-gate by worker/node. The reconciler is deliberately NOT pinned to one node: // every node repairs the schedule rows it owns (see util/reconcile.js). startQueueStatusSync(); + startReadySweep(); startSitemapRefreshScheduler(); startScheduleReconciler(); // Keeps the console's backlog histogram off the page-load path: the scan walks the same diff --git a/packages/plugin/package.json b/packages/plugin/package.json index d84ab29..77ef186 100644 --- a/packages/plugin/package.json +++ b/packages/plugin/package.json @@ -1,6 +1,6 @@ { "name": "@harperfast/prerender", - "version": "0.49.0", + "version": "0.50.0", "type": "module", "description": "Configurable Harper plugin for prerendering pages for bots and crawlers", "license": "Apache-2.0", diff --git a/packages/plugin/src/configSchema.js b/packages/plugin/src/configSchema.js index 479a6bd..bba76f7 100644 --- a/packages/plugin/src/configSchema.js +++ b/packages/plugin/src/configSchema.js @@ -1262,6 +1262,79 @@ export const configSchema = group('Prerender plugin configuration.', { 'about could not be detected.', { min: 1, scope: 'restart' } ), + ready: group( + 'THE READY SET — which of the due rows the next leases go to, decided by a background sweep ' + + 'instead of by the order the index happens to be in.\n\n' + + 'WHY: `claim` takes the first rows it finds from the claim floor, so the queue serves ' + + 'whatever is oldest-due. Two production measurements say that is the wrong order under ' + + 'scarcity (prerender-plugin#80): ~46% of a 521,929-row overdue queue was bot-discovered ' + + 'rather than sitemap-submitted, and absolute due time treats a 1h-TTL homepage 3h overdue ' + + 'exactly like a 48h-TTL product page 3h overdue — 300% stale against 6%. Simulated over ' + + 'the real corpus the 1h route sits at 4.78x its own TTL even at FULL capacity.\n\n' + + 'It could not be fixed by re-sorting the claim window, because the window is ANCHORED AT ' + + 'THE OLDEST DUE TIME: under a backlog every row in it is ancient, so the homepage is never ' + + 'read at all and a wider window is just more ancient rows. So a sweep scores the WHOLE due ' + + 'set and keeps the best few thousand in shared memory; claims pop from that and touch no ' + + 'index. Affordable because a projected one-sided read measures ~2.4us/row, flat — 200,000 ' + + 'rows in ~480ms, with zero writes.\n\n' + + 'ORDERING ONLY. Total render volume cannot change: every row it reorders is already due. ' + + 'And it is a CACHE in front of the old path — cold, exhausted or disabled, claims fall back ' + + 'to the index scan, so every failure mode here is the previous behaviour rather than a ' + + 'stalled queue.', + { + enabled: option( + true, + 'Kill switch. `false` claims straight from the index scan, exactly as before v0.50.0. The ' + + 'sweep also stops, so nothing is spent maintaining a set nothing reads.' + ), + capacity: option( + 5000, + 'Entries the ready set holds. Sized to cover several sweep intervals of claims so the set ' + + 'does not run dry between sweeps: at the recorded fleet throughput a node grants roughly ' + + '5 jobs a second, so 5,000 entries is about 16 minutes of work.\n\n' + + 'Costs `capacity x ~276` bytes of shared memory (1.4MB at the default). Raising it does ' + + 'NOT make the ordering better — the sweep already scores every due row and keeps the best ' + + 'of them — it only makes the set last longer between sweeps.\n\n' + + 'Restart-scoped: a named shared buffer is sized by its first allocation, so a live change ' + + 'would give workers in one generation differently-sized views of the same buffer. A ' + + 'mismatch is logged and the smaller size honoured.', + { min: 0, scope: 'restart' } + ), + sweepInterval: option( + MINUTE, + 'How often worker 0 re-scores the due set and republishes.\n\n' + + 'This is the ORDERING STALENESS: a row that becomes due just after a sweep waits up to one ' + + 'interval before it can be ranked. One minute against cadences of an hour and up is a ' + + 'rounding error, and the cost is one read of the due set — ~480ms per 200,000 due rows, on ' + + 'a worker that yields every 200 rows (measured free) so it never holds the loop.\n\n' + + '`0` disables the sweep, which leaves the set to go stale and then empty; claims fall back ' + + 'to the index scan as they always do.', + { unit: 'ms', min: 0 } + ), + sweepCap: option( + 500_000, + 'Ceiling on rows one sweep reads. The due set cannot exceed the corpus, so this is a ' + + 'guard against a runaway rather than a tuning knob — at ~2.4us/row the default is ~1.2s of ' + + 'reading.\n\n' + + 'If a sweep hits the cap WITHOUT reaching a not-yet-due row it is ordering over a prefix ' + + 'of the backlog, which is reported and warned about: the rows past the cap are the ' + + 'youngest, so the effect is that recently-due pages go unranked — exactly the pages this ' + + 'exists to protect.', + { min: 1 } + ), + sitemapBoost: option( + 2, + 'How much a sitemap-sourced row outranks a discovered one at the same overdue ratio. `1` ' + + 'disables the preference and orders on overdue ratio alone.\n\n' + + 'A MULTIPLIER, not a tier, so it cannot starve discovered URLs: an unserved row\u2019s ' + + 'lateness grows without bound while the boost stays constant, so a discovered row wins as ' + + 'soon as its ratio passes `sitemapBoost x` the highest sitemap ratio in the set. With ' + + 'sitemap pages held ~1.2 cadences late, a discovered page is served within ~2.4 cadences ' + + 'of its own interval at the default.', + { min: 1 } + ), + } + ), claimScanCap: option( 1000, 'Ceiling on schedule rows read per claim pass. A leased row keeps its overdue position in the ' + diff --git a/packages/plugin/src/metrics.js b/packages/plugin/src/metrics.js index 9464009..aba5d58 100644 --- a/packages/plugin/src/metrics.js +++ b/packages/plugin/src/metrics.js @@ -377,15 +377,25 @@ export const METRICS = Object.freeze({ 'paused = 1 when this node’s queue is paused at snapshot time, else 0 — makes "paused for hours" ' + 'alertable without polling the REST surface. ' + 'claim_scan_ms = claim-pass duration; watch the p95 trend, not the level. ' + + 'ready_sweep_ms = duration of the ready-set sweep (method complete|capped); `capped` means it ' + + 'never reached a not-yet-due row, so the ordering covers only the oldest part of the backlog ' + + 'and recently-due pages are going unranked. ' + + 'ready_published = entries the last sweep published — the ordering’s supply; a persistent 0 ' + + 'with a non-empty backlog means the sweep is failing. ' + + 'claim_granted = jobs granted per claim split by source (ready|index) — the only series that ' + + 'shows whether prioritisation is engaging, since it reorders a fixed amount of work and moves ' + + 'no total. All-`index` is the failure to look for and is indistinguishable from health ' + + 'elsewhere. ' + 'reconcile_restored / reconcile_missing = schedule gaps repaired / found per sweep (they differ ' + 'when the per-sweep restore cap truncates the pass); expect zero — a steady rate means ' + 'something is CREATING gaps, and the reconcile log line names the URLs.', }, method: { - name: 'result (claim_scan_ms only)', - values: ['granted', 'empty', 'capped'], + name: 'result (claim_scan_ms) | outcome (ready_sweep_ms) | source (claim_granted)', + values: ['granted', 'empty', 'capped', 'complete', 'ready', 'index'], description: - 'Only claim_scan_ms uses this slot: granted = jobs handed out, empty = nothing due, capped = the ' + + 'claim_scan_ms, ready_sweep_ms and claim_granted use this slot. On claim_scan_ms: ' + + 'granted = jobs handed out, empty = nothing due, capped = the ' + 'scan hit queue.claimScanCap without reaching a not-yet-due row (in-flight work is filling the ' + 'window). Every other series emits null here.', }, @@ -641,6 +651,23 @@ export const metrics = Object.freeze({ /** One claim pass's duration and how it ended — a queue_health series, so the queue reads in one scan. */ claimScan: (durationMs, result) => server.recordAnalytics(durationMs, 'queue_health', 'claim_scan_ms', result, null), + /** One ready-set sweep: how long it took, and whether it saw the whole due set or hit its cap. */ + readySweep: (durationMs, outcome) => + server.recordAnalytics(durationMs, 'queue_health', 'ready_sweep_ms', outcome, null), + + /** How many entries the last sweep published — the ordering's supply. */ + readyPublished: (count) => server.recordAnalytics(count, 'queue_health', 'ready_published', null, null), + + /** + * Jobs granted per claim, split by WHERE they came from: the ready set or the fallback index scan. + * + * This is the series that says whether prioritisation is actually happening. The ready set reorders + * a fixed amount of work, so no total moves when it engages — and a node quietly serving every + * claim from `index` (a sweep that is failing, a buffer that could not be sized, a set that is + * always dry) looks identical to a healthy one in every other number. + */ + claimSource: (count, source) => server.recordAnalytics(count, 'queue_health', 'claim_granted', source, null), + /** One origin proxy on the serve path: time to response headers, status, and why. */ originFetch: (durationMs, statusCode, reason) => server.recordAnalytics(durationMs, 'origin_fetch', statusCode, reason, null), diff --git a/packages/plugin/src/resources/RenderQueue.js b/packages/plugin/src/resources/RenderQueue.js index 562d5bb..28ac2d0 100644 --- a/packages/plugin/src/resources/RenderQueue.js +++ b/packages/plugin/src/resources/RenderQueue.js @@ -14,6 +14,7 @@ import { getDesiredPause, setDesiredPause } from '../util/queueControl.js'; import { getResidencyByUrl } from '../util/residency.js'; import { claimSchedules, + sweepReadySet, deleteSchedule, deriveQueueStatus, maybeResetFloor, @@ -800,6 +801,12 @@ export class RenderQueue extends Resource { pass.scanTruncated ? 'capped' : pass.jobs.length ? 'granted' : 'empty' ); + // WHERE the batch came from. Two emits per claim at most, on a path that runs a few times a + // second — and the only evidence that the ready set is doing anything, since it moves no totals. + const fromReady = pass.fromReady ?? 0; + if (fromReady > 0) metrics.claimSource(fromReady, 'ready'); + if (pass.jobs.length - fromReady > 0) metrics.claimSource(pass.jobs.length - fromReady, 'index'); + const jobs = []; let notOwnedHere = 0; @@ -933,6 +940,72 @@ let queueStatusSyncStarted = false; * handleApplication after config is applied (so the interval reflects overrides). * Idempotent. The interval follows `queue.statusSyncInterval` changes without a restart. */ +/** + * The ready-set sweep, on worker 0, on its own interval. + * + * SEPARATE FROM `startQueueStatusSync` DESPITE THE SIMILAR SHAPE, and the reason is the claim mutex. + * The status sync deliberately runs inside it — the floor reset and the lease-gauge walk both need + * that serialization. The sweep must NOT: it holds a read cursor over the due set for hundreds of + * milliseconds, and taking the claim mutex for that long would block every claim on the node for the + * duration of a scan whose entire purpose is to keep claims off the index. + * + * It needs no mutex of its own either. It writes nothing to the database, and its only shared-memory + * write is `publish`, which fills the inactive slot and flips one atomic — so a concurrent claim + * either sees the previous generation or the next one, never a partial set. Two overlapping sweeps + * would merely duplicate work, and `sweeping` prevents that within a worker. + */ +let readySweepStarted = false; + +export function startReadySweep() { + if (server.workerIndex !== 0 || readySweepStarted) return; + readySweepStarted = true; + + let sweeping = false; + + const sweep = () => { + if (sweeping || !config.queue.ready.enabled) return; + sweeping = true; + const started = performance.now(); + sweepReadySet() + .then((result) => { + if (result?.skipped) return; + metrics.readySweep(performance.now() - started, result.truncated ? 'capped' : 'complete'); + metrics.readyPublished(result.published); + if (result.truncated) { + // The rows past the cap are the YOUNGEST, so a truncated sweep leaves recently-due pages + // unranked — precisely the pages this feature exists to protect. That makes it a warning + // rather than a statistic. + logger.warn( + `[prerender] ready-set sweep read its ${config.queue.ready.sweepCap}-row cap without reaching a ` + + `not-yet-due row: ${result.due} due row(s) seen, ${result.published} published. The ordering ` + + `covers only the oldest part of the backlog, so recently-due pages are going unranked. Raise ` + + `queue.ready.sweepCap, or reduce the backlog.` + ); + } + }) + .catch(logger.error) + .finally(() => { + sweeping = false; + }); + }; + + // Once immediately, so a restarted worker generation does not serve a whole interval of claims + // from the index before the set exists. + sweep(); + + let armed = config.queue.ready.sweepInterval; + let timer = armed > 0 ? setInterval(sweep, armed) : null; + timer?.unref?.(); + + onConfigApplied(() => { + if (config.queue.ready.sweepInterval === armed) return; + if (timer) clearInterval(timer); + armed = config.queue.ready.sweepInterval; + timer = armed > 0 ? setInterval(sweep, armed) : null; + timer?.unref?.(); + }); +} + export function startQueueStatusSync() { if (server.workerIndex !== 0 || queueStatusSyncStarted) return; queueStatusSyncStarted = true; diff --git a/packages/plugin/src/util/readyQueue.js b/packages/plugin/src/util/readyQueue.js new file mode 100644 index 0000000..356bf52 --- /dev/null +++ b/packages/plugin/src/util/readyQueue.js @@ -0,0 +1,276 @@ +/** + * THE READY SET — the node's answer to "which page next", held in shared memory rather than derived + * from an index. + * + * ── WHY THIS EXISTS AT ALL ───────────────────────────────────────────────────────────────────── + * + * `claim` reads `nextRenderTime >= floor` and takes the first rows it finds, so the queue serves + * whatever is oldest-due. That is the wrong order under scarcity (see `util/renderPriority.js` for + * the two production measurements), and the reason it could not simply be re-sorted is structural: + * the claim window is ANCHORED AT THE OLDEST DUE TIME. Under a deep backlog every row in it is + * ancient, so a homepage two of its own cadences late is nowhere near the window and no amount of + * re-ranking finds a row that was never read. Widening the window does not help — a wider window + * anchored in the same place is more ancient rows. + * + * The fix is to stop deciding from a window. A background sweep scores the WHOLE due set and keeps + * the best few thousand here; `claim` then pops from this in priority order and touches no index at + * all. That is affordable because of one measured fact (#119): a projected one-sided read costs + * ~2.4 us/row, flat from 200 to 20,000 rows, and yielding every 200 rows is free — so scoring + * 200,000 rows costs ~480 ms, and even a 500k-row overdue set is ~1.2 s. Writes, by contrast, are + * 76-89 us/row, i.e. 32x a read. Reading liberally and writing not at all is the cheap direction, and + * this structure adds ZERO writes. + * + * ── IT IS A CACHE IN FRONT OF THE OLD PATH, NOT A REPLACEMENT ───────────────────────────────── + * + * The single most important property for shipping this safely: when the set is cold, empty, or + * exhausted, `claim` falls back to the floored scan it has always used. So the failure mode of + * everything here is TODAY'S BEHAVIOUR — not a stalled queue. A sweep that never runs, a buffer sized + * to zero, a worker that never publishes: all of them degrade to the current ordering rather than to + * no ordering. + * + * That also means nothing here is a correctness invariant. An entry naming a row that has since been + * rescheduled or deleted costs at most one redundant render (the lease CAS refuses a duplicate, and + * `processJobResult` already drops a result whose target is gone). Compare that with the claim + * floor, where a row filed below it is never claimed again — silently, terminally. This structure + * cannot lose a page, because the next sweep re-reads the table. + * + * ── WHY A SHARED BUFFER, AND WHY DOUBLE-BUFFERED ────────────────────────────────────────────── + * + * Claims arrive on whichever worker the consumer's poll landed on, so a per-worker set would mean N + * workers each sweeping the corpus — N times the cost for the same answer. One worker sweeps and + * publishes here; every worker reads. + * + * The set is REBUILT WHOLE on every sweep, never mutated in place, which is what makes the layout + * trivial: two slots, write the inactive one, flip an atomic. No fragmentation, no compaction, no + * partially-visible set — a reader is always looking at one complete generation. Variable-length + * cache keys would otherwise force an allocator in shared memory, which is exactly the kind of thing + * that has taken this node down twice. + * + * ── AND WHY THE CURSOR IS A BARE ATOMIC ──────────────────────────────────────────────────────── + * + * Entries are written BEST FIRST, so consumption order is already priority order and a consumer needs + * to compare nothing. Claiming is `Atomics.add(cursor, 1)`: no lock, no scan, no coordination, and two + * workers can never be handed the same index. Popping past the end simply reports exhaustion, which + * is the signal to fall back. + * + * NO DEPENDENCIES beyond the encoder, deliberately — same discipline as `util/renderLease.js`. This + * is a data structure, so `test/readyQueue.test.js` drives it against a plain `new ArrayBuffer()` + * with no Harper at all. + */ + +// Header, Int32 slots: +// 0 activeSlot which slot readers should use (0 or 1) +// 1 generation bumped on every publish; lets a reader notice it was mid-flight +// 2 cursor next index to hand out, shared across workers +// 3 count[slot 0] +// 4 count[slot 1] +// 5 sweptAtSec when the active slot was published (relative epoch, see below) +// 6 scannedRows how many rows the publishing sweep examined, for reporting +const H_ACTIVE = 0; +const H_GENERATION = 1; +const H_CURSOR = 2; +const H_COUNT_0 = 3; +const H_COUNT_1 = 4; +const H_SWEPT_AT = 5; +const H_SCANNED = 6; +const HEADER_INT32 = 8; // one spare, so a future field does not move the slots + +/** + * Timestamps are Int32 SECONDS relative to a fixed constant, matching `util/renderLease.js`: raw + * epoch seconds overflow an Int32 in 2038, and a baked-in constant means two workers can never + * disagree about what a stored number means. + */ +export const READY_EPOCH_SEC = 1_700_000_000; + +/** + * Per entry: a fixed record plus its key bytes in the slot's blob region. + * + * scoreMilli Int32 the score x 1000, so a reader can report it without recomputing + * dueAtSec Int32 seconds relative to READY_EPOCH_SEC + * keyOffset Int32 byte offset of the key within the slot's blob region + * keyLen Int32 key length in bytes + * flags Int32 bit 0 = fromSitemap + * + * `fromSitemap` is carried even though ordering does not need it — the boost is already folded into + * the score. The renderer needs the LIVE value: it serializes a non-indexable page only when the url + * is sitemap-listed, so a job that reports `false` for a listed page silently stops that page being + * cached at all. That bug has been introduced twice in this package by a caller that let the flag go + * absent, and the alternative here is a point read per granted job on the claim path against a + * residency-pinned table, where an unowned read takes an untimed replication fetch. + */ +const E_SCORE = 0; +const E_DUE_AT = 1; +const E_KEY_OFFSET = 2; +const E_KEY_LEN = 3; +const E_FLAGS = 4; +const ENTRY_INT32 = 5; + +const F_FROM_SITEMAP = 1; + +/** + * Bytes reserved per entry for its key. The production cache key is a URL plus a device suffix; + * measured against the corpus the long tail of product URLs sits comfortably under this, and a key + * that does not fit is DROPPED FROM THE SET rather than truncated — a truncated key is a key that + * names a different row, which would grant a lease on the wrong page. + */ +export const READY_KEY_BYTES = 256; + +export const READY_SAB_KEY = 'prerender/ready-queue'; + +/** Byte size of a ready-set buffer holding `capacity` entries per slot. */ +export const readyBufferBytes = (capacity) => { + const cap = Math.max(1, capacity | 0); + const perSlot = cap * ENTRY_INT32 * 4 + cap * READY_KEY_BYTES; + return HEADER_INT32 * 4 + 2 * perSlot; +}; + +/** How many entries per slot a buffer of this size holds. */ +export const readyCapacityIn = (byteLength) => + Math.max(0, Math.floor((byteLength - HEADER_INT32 * 4) / (2 * (ENTRY_INT32 * 4 + READY_KEY_BYTES)))); + +const encoder = new TextEncoder(); +const decoder = new TextDecoder(); + +const toSec = (ms) => Math.round(ms / 1000) - READY_EPOCH_SEC; +const fromSec = (sec) => (sec + READY_EPOCH_SEC) * 1000; + +/** + * @param {object} opts + * @param {ArrayBuffer} opts.buffer shared across the node's workers + * @param {number} [opts.capacity] entries per slot; clamped to what the buffer actually holds + * @param {() => number} [opts.now] injected clock, late-bound by the caller + */ +export const createReadyQueue = ({ buffer, capacity, now = Date.now } = {}) => { + const i32 = new Int32Array(buffer); + const bytes = new Uint8Array(buffer); + // Clamped to the buffer, never trusted from the argument: indexing past a short buffer is silent + // memory corruption, whereas deriving the capacity from the buffer we actually got is merely a + // smaller set — and a smaller set degrades to the fallback scan, which is safe. + const cap = Math.min( + Math.max(0, capacity | 0) || readyCapacityIn(buffer.byteLength), + readyCapacityIn(buffer.byteLength) + ); + + const perSlotEntryBytes = cap * ENTRY_INT32 * 4; + const slotEntryBase = (slot) => HEADER_INT32 * 4 + slot * (perSlotEntryBytes + cap * READY_KEY_BYTES); + const slotBlobBase = (slot) => slotEntryBase(slot) + perSlotEntryBytes; + const entryIndex = (slot, i) => slotEntryBase(slot) / 4 + i * ENTRY_INT32; + + const countSlot = (slot) => (slot === 0 ? H_COUNT_0 : H_COUNT_1); + + const readEntry = (slot, i) => { + const base = entryIndex(slot, i); + const keyOffset = Atomics.load(i32, base + E_KEY_OFFSET); + const keyLen = Atomics.load(i32, base + E_KEY_LEN); + if (keyLen <= 0 || keyLen > READY_KEY_BYTES) return null; + return { + cacheKey: decoder.decode(bytes.subarray(keyOffset, keyOffset + keyLen)), + dueAt: fromSec(Atomics.load(i32, base + E_DUE_AT)), + score: Atomics.load(i32, base + E_SCORE) / 1000, + fromSitemap: (Atomics.load(i32, base + E_FLAGS) & F_FROM_SITEMAP) !== 0, + }; + }; + + return { + capacity: cap, + + /** + * Publish a whole generation. `rows` must already be BEST FIRST — the cursor hands out indices + * in order and compares nothing, so ordering is this function's contract, not the reader's. + * + * Writes the INACTIVE slot and flips at the end, so a reader is never looking at a half-written + * set. Returns how many entries were actually stored. + */ + publish(rows, { scannedRows = 0 } = {}) { + if (cap === 0) return 0; + const target = Atomics.load(i32, H_ACTIVE) === 0 ? 1 : 0; + const blobBase = slotBlobBase(target); + + let stored = 0; + for (const { entry, score } of rows) { + if (stored >= cap) break; + const encoded = encoder.encode(entry.cacheKey); + // DROPPED, NOT TRUNCATED. A truncated key names a different row, and granting a lease on + // the wrong page is worse than not granting one — the fallback scan will find this row. + if (encoded.length > READY_KEY_BYTES) continue; + const keyOffset = blobBase + stored * READY_KEY_BYTES; + bytes.set(encoded, keyOffset); + const base = entryIndex(target, stored); + Atomics.store(i32, base + E_SCORE, Math.round(Math.min(2_147_483, score) * 1000)); + Atomics.store(i32, base + E_DUE_AT, toSec(entry.dueAt)); + Atomics.store(i32, base + E_KEY_OFFSET, keyOffset); + Atomics.store(i32, base + E_KEY_LEN, encoded.length); + Atomics.store(i32, base + E_FLAGS, entry.fromSitemap ? F_FROM_SITEMAP : 0); + stored++; + } + + Atomics.store(i32, countSlot(target), stored); + Atomics.store(i32, H_SCANNED, Math.min(scannedRows, 2_147_483_647)); + Atomics.store(i32, H_SWEPT_AT, toSec(now())); + // ORDER MATTERS: reset the cursor BEFORE flipping, or a claim landing between the two reads + // the new slot with the old slot's cursor and skips the head of a fresh generation. + Atomics.store(i32, H_CURSOR, 0); + Atomics.store(i32, H_ACTIVE, target); + Atomics.add(i32, H_GENERATION, 1); + return stored; + }, + + /** + * Take the next `n` entries in priority order. Returns fewer (or none) when the set is + * exhausted, which is the caller's signal to fall back to the index scan. + * + * `Atomics.add` on the cursor is the whole concurrency story: two workers can never be handed + * the same index, and there is no lock to hold while a claim is in flight. + */ + take(n) { + const out = []; + if (cap === 0) return out; + const slot = Atomics.load(i32, H_ACTIVE); + const count = Atomics.load(i32, countSlot(slot)); + for (let i = 0; i < n; i++) { + const index = Atomics.add(i32, H_CURSOR, 1); + if (index >= count) { + // Do not let the cursor run away past the count while a set is exhausted: it is an + // Int32 and a busy node claims several times a second, so an unbounded increment would + // wrap in about eight days of idling and start handing out valid indices again. + Atomics.store(i32, H_CURSOR, count); + break; + } + const entry = readEntry(slot, index); + if (entry) out.push(entry); + } + return out; + }, + + /** What the console and the metrics read. No database work, all atomic loads. */ + state() { + const slot = Atomics.load(i32, H_ACTIVE); + const count = Atomics.load(i32, countSlot(slot)); + const cursor = Math.min(Atomics.load(i32, H_CURSOR), count); + const sweptAtSec = Atomics.load(i32, H_SWEPT_AT); + return { + capacity: cap, + count, + consumed: cursor, + remaining: Math.max(0, count - cursor), + generation: Atomics.load(i32, H_GENERATION), + scannedRows: Atomics.load(i32, H_SCANNED), + sweptAt: sweptAtSec === 0 ? null : fromSec(sweptAtSec), + ageMs: sweptAtSec === 0 ? null : Math.max(0, now() - fromSec(sweptAtSec)), + }; + }, + + /** Peek at the head without consuming — for the explainer and for tests. */ + peek(n = 10) { + const slot = Atomics.load(i32, H_ACTIVE); + const count = Atomics.load(i32, countSlot(slot)); + const cursor = Math.min(Atomics.load(i32, H_CURSOR), count); + const out = []; + for (let i = cursor; i < Math.min(count, cursor + n); i++) { + const entry = readEntry(slot, i); + if (entry) out.push(entry); + } + return out; + }, + }; +}; diff --git a/packages/plugin/src/util/renderPriority.js b/packages/plugin/src/util/renderPriority.js new file mode 100644 index 0000000..2e1c965 --- /dev/null +++ b/packages/plugin/src/util/renderPriority.js @@ -0,0 +1,159 @@ +/** + * HOW URGENT A DUE ROW IS — the scoring policy, and nothing else. + * + * `claim` orders by `nextRenderTime` and nothing else, which expresses priority perfectly while the + * queue is caught up and not at all once two rows are both past due. A due time encodes when a page + * last rendered plus its cadence, not how much it matters: + * + * home (1h cadence) due 2h ago -> 2.00 cadences late + * PDP (48h cadence) due 3h ago -> 0.06 cadences late + * + * Index order gives the lease to the PDP, because 3h > 2h. Nothing looks wrong while it does: the + * floor advances, the scan stays fast, no row is wedged. Measured on the production corpus + * (prerender-plugin#80), the 1h route sits at 4.78x its own TTL even at FULL capacity and 48.83x at + * half, against 1.08x / 2.00x for the 48h route. And ~46% of a 521,929-row overdue queue was + * bot-discovered rather than sitemap-submitted, so roughly half the capacity was going to pages + * nobody submitted. + * + * ── WHY THIS IS A FUNCTION AND NOT AN INDEX ──────────────────────────────────────────────────── + * + * Relative lateness cannot be an ORDER. `(t - dueAt) / interval` is linear in `t` with slope + * `1/interval`, so two rows with different intervals cross exactly once — no stored key can express + * an order that changes with the clock, and #80 rejected it as a comparator for exactly that reason. + * + * That objection is fatal to an index and irrelevant to a function that is re-evaluated. Measured + * (#119): a projected one-sided read costs ~2.4 us/row, flat from 200 to 20,000 rows, and yielding + * every 200 rows is free. So re-scoring the whole due set costs ~480 ms per 200,000 rows — cheap + * enough to redo on a timer, which is what `util/readyQueue.js` does. Nothing is stored, so the + * crossing never has to be represented. + * + * The consequence worth stating plainly: BECAUSE THIS IS NOT IN THE KEY, changing the policy is a + * config change with no data migration. Encoding priority into `nextRenderTime` (the rejected + * alternative) would make every policy change a rewrite of 1.6M rows. + * + * ── THE FORMULA, AND WHY LATENESS RATHER THAN AGE ────────────────────────────────────────────── + * + * score = max(0, now - dueAt) / interval x (fromSitemap ? sitemapBoost : 1) + * + * The tempting form is `(now - lastRender) / interval` — staleness relative to cadence, the same + * number plus one, and it reads better. It is wrong here, because `dueAt - interval` is not when the + * page last rendered for every row in the table. Three writers deliberately schedule a gap that is + * not the cadence: `Target.suppress` writes `render.suppression.recheckInterval` (7 days), + * `backoffWait` writes up to `render.failureRetry.maxBackoff`, and the unpin hatch pushes by + * `render.defaultInterval`. Under the age form a 7-day suppression recheck on a 48h route arrives + * reading as 3.5 cadences stale and outranks a genuinely late homepage — promoting exactly the rows + * worth deprioritizing. + * + * Lateness has no such coupling: it is zero at the moment any row comes due, whatever gap preceded + * it, so a recheck or a backed-off retry enters at the back and climbs from there like anything else. + * + * ── STARVATION IS BOUNDED, AND THE BOUND IS STATABLE ────────────────────────────────────────── + * + * `sitemapBoost` is a MULTIPLIER, never an additive tier or a separate lane. A lane would let a large + * sitemap corpus starve discovered URLs outright; a multiplier cannot, because an unserved row's + * lateness grows without bound while the boost stays constant. A discovered row wins as soon as its + * ratio passes `sitemapBoost x` the highest sitemap ratio in the set — so if sitemap pages are being + * held at `U` cadences late, a discovered page is served by `sitemapBoost x U` cadences late. + */ + +/** + * How overdue a row is in units of its own cadence, with sitemap membership applied. + * + * Clamped at zero rather than allowed to go negative: only rows already established as due are + * scored, and a negative score from a clock skew would sort a due row BELOW rows that are exactly on + * time, which is the one ordering that makes no sense at all. + * + * The only guard is the division. A zero or negative interval would produce Infinity or a sign flip, + * so it degrades to raw lateness — which still orders sensibly among rows that share the problem. + */ +export const scoreOf = ({ dueAt, fromSitemap }, { nowMs, intervalMs, sitemapBoost = 1 }) => { + const lateness = Math.max(0, nowMs - dueAt); + const ratio = intervalMs > 0 ? lateness / intervalMs : lateness; + return fromSitemap ? ratio * sitemapBoost : ratio; +}; + +/** + * A BOUNDED MAX-K SELECTION over a stream, as a min-heap of size K. + * + * The point is that the sweep must be able to walk a due set far larger than anything it can hold: + * 500,000 overdue rows at the recorded corpus, against a ready set of a few thousand. So rows stream + * THROUGH this and only the best K are ever retained — memory is a function of K, not of the corpus, + * which is what makes "sweep everything" affordable in the first place. A sort would need the whole + * set resident, and this node has twice been taken down by an unbounded structure over this corpus. + * + * A min-heap (not a max-heap) because the operation on every row after the first K is "is this better + * than the WORST one I am keeping" — one comparison against the root, and a rejected row costs + * exactly that. At a 500k-row sweep into a 5k set, ~99% of rows are rejected on that single compare. + */ +export const createTopK = (k) => { + const capacity = Math.max(1, k | 0); + // [score, entry] pairs kept as parallel arrays: one allocation each rather than an object per + // candidate, on a path that sees every due row on the node. + const scores = []; + const entries = []; + + const swap = (i, j) => { + const s = scores[i]; + scores[i] = scores[j]; + scores[j] = s; + const e = entries[i]; + entries[i] = entries[j]; + entries[j] = e; + }; + + const up = (i) => { + while (i > 0) { + const parent = (i - 1) >> 1; + if (scores[parent] <= scores[i]) break; + swap(parent, i); + i = parent; + } + }; + + const down = (i) => { + for (;;) { + const left = 2 * i + 1; + const right = left + 1; + let smallest = i; + if (left < scores.length && scores[left] < scores[smallest]) smallest = left; + if (right < scores.length && scores[right] < scores[smallest]) smallest = right; + if (smallest === i) break; + swap(i, smallest); + i = smallest; + } + }; + + return { + get size() { + return scores.length; + }, + + /** True if the candidate was kept. */ + offer(score, entry) { + if (scores.length < capacity) { + scores.push(score); + entries.push(entry); + up(scores.length - 1); + return true; + } + // The single comparison the whole design rests on: the root is the worst kept row. + if (score <= scores[0]) return false; + scores[0] = score; + entries[0] = entry; + down(0); + return true; + }, + + /** + * The kept entries, BEST FIRST, with their scores. + * + * Best-first is what lets the shared cursor in `util/readyQueue.js` be a bare atomic + * increment: consumption order IS priority order, so no consumer has to compare anything. + */ + drainDescending() { + const out = entries.map((entry, i) => ({ entry, score: scores[i] })); + out.sort((a, b) => b.score - a.score); + return out; + }, + }; +}; diff --git a/packages/plugin/src/util/renderSchedule.js b/packages/plugin/src/util/renderSchedule.js index d3c9757..132dd74 100644 --- a/packages/plugin/src/util/renderSchedule.js +++ b/packages/plugin/src/util/renderSchedule.js @@ -124,12 +124,15 @@ * mis-set — without it an operator will spend the incident tuning `renderInterval`. */ +import { setImmediate as yieldNow } from 'node:timers/promises'; import { config } from '../config.js'; import { getSab } from './coordination.js'; import { CacheKey } from './cacheKey.js'; import { resolveRenderInterval } from './routeClass.js'; import { MINUTE, numberOf } from './time.js'; import { LEASE_SAB_KEY, createLeaseTable, leaseBufferBytes, leaseSlotsIn } from './renderLease.js'; +import { READY_SAB_KEY, createReadyQueue, readyBufferBytes, readyCapacityIn } from './readyQueue.js'; +import { createTopK, scoreOf } from './renderPriority.js'; /** * The live lease table + claim floor, over one named buffer shared by every worker on this node. @@ -187,6 +190,34 @@ export const leaseTable = () => { // package depend on when `databases` was populated. const scheduleTable = () => databases.render_schedule.RenderSchedule; +/** + * The node's ready set, over one named buffer shared by every worker. + * + * Allocated on first use for the same reason `leaseTable` is: `queue.ready.capacity` sizes it, and + * module scope precedes the host applying its options. Restart-scoped for the same reason too — a + * named shared buffer's size is fixed by its first allocation, so a later worker asking for a + * different size gets a view of the first size. A mismatch is logged loudly and then honoured, since + * deriving the capacity from the buffer we actually got is merely a smaller set, and a smaller set + * degrades to the fallback scan rather than to anything unsafe. + */ +let liveReadyQueue = null; + +export const readyQueue = () => { + if (liveReadyQueue) return liveReadyQueue; + const wanted = Math.max(0, config.queue.ready.capacity | 0); + const buffer = getSab(READY_SAB_KEY, readyBufferBytes(Math.max(1, wanted))); + if (wanted > 0 && readyCapacityIn(buffer.byteLength) < wanted) { + logger.error( + `[prerender] ready-set buffer holds ${readyCapacityIn(buffer.byteLength)} entries but ` + + `queue.ready.capacity=${wanted}. The named shared buffer was sized by an earlier worker generation — ` + + `this node runs with the smaller set until it restarts. queue.ready.capacity is restart-scoped for ` + + `exactly that reason; the only effect is that more claims fall through to the index scan.` + ); + } + liveReadyQueue = createReadyQueue({ buffer, now: () => Date.now() }); + return liveReadyQueue; +}; + /** Minutes since the epoch. Every due time in the system is already minute-floored. */ export const minuteOf = (ms) => Math.floor(ms / MINUTE); @@ -532,38 +563,47 @@ const maybeUnpinFloor = async (pass) => { return { cacheKey, pinnedForMs: pass.floorPinnedForMs, nextRenderTime }; }; -/** `runClaimPass` bound to the live table and config. Called by `RenderQueue.claim`. */ -export const claimSchedules = async ({ grantLimit } = {}) => { +/** + * THE ONE QUERY SHAPE, shared by the claim scan and the ready-set sweep. + * + * Extracted rather than written twice because the two callers must agree about it exactly: they read + * the same index for the same rows, and a difference between them would show up as the sweep and the + * fallback disagreeing about what is due — which is unfalsifiable from either site. + */ +const searchSchedulesFrom = ({ floorMinute, limit }) => + scheduleTable().search( + { + // EXACTLY ONE CONDITION, and it stays present even at floorMinute 0 (`>= 0` is the + // same seek-from-the-absolute-minimum). Dropping the conditions array entirely + // would leave Harper to inject its own primary-key full-scan condition beside a + // sort on a secondary attribute, and whether that still resolves to an + // index-ordered walk of `nextRenderTime` is unverified — on 1.6M rows a wrong + // answer there is a full table scan plus a sort on the claim path. + // + // ONE-SIDED, AND A TWO-SIDED RANGE IS NOT A SAFE ALTERNATIVE HERE. Adding the + // `<= now` half measures fine (0.74 ms) only while the window can FILL the limit. + // Measured on 400k rows when it cannot — which is the normal steady state, "nothing + // is due" — it costs 1,128–2,977 ms: only the FIRST condition becomes the index + // range and the second is applied as a post-filter, so the cost is O(rows above the + // lower bound) rather than O(window), and the limit can never short-circuit it. + // That is a ~480× regression on the claim path, in the state the queue spends most + // of its time in. The `<= now` half stays in application code, where it is free. + // (On a PRIMARY key a two-sided range collapses to a filtered intersection — + // 289–1490 ms — which is why the shape of this query is worth a comment at all.) + conditions: [{ attribute: 'nextRenderTime', comparator: 'greater_than_equal', value: floorMinute * MINUTE }], + sort: { attribute: 'nextRenderTime' }, + // ARRAY select. A string `select` returns the bare scalar rather than a record — + // the trap that has caused two silent bugs in this package already. + select: ['cacheKey', 'nextRenderTime', 'fromSitemap'], + limit, + }, + { replicateFrom: false } + ); + +/** `runClaimPass` bound to the live table and config — the FALLBACK path behind the ready set. */ +const claimFromIndex = async ({ grantLimit } = {}) => { const pass = await runClaimPass({ - searchSchedules: ({ floorMinute, limit }) => - scheduleTable().search( - { - // EXACTLY ONE CONDITION, and it stays present even at floorMinute 0 (`>= 0` is the - // same seek-from-the-absolute-minimum). Dropping the conditions array entirely - // would leave Harper to inject its own primary-key full-scan condition beside a - // sort on a secondary attribute, and whether that still resolves to an - // index-ordered walk of `nextRenderTime` is unverified — on 1.6M rows a wrong - // answer there is a full table scan plus a sort on the claim path. - // - // ONE-SIDED, AND A TWO-SIDED RANGE IS NOT A SAFE ALTERNATIVE HERE. Adding the - // `<= now` half measures fine (0.74 ms) only while the window can FILL the limit. - // Measured on 400k rows when it cannot — which is the normal steady state, "nothing - // is due" — it costs 1,128–2,977 ms: only the FIRST condition becomes the index - // range and the second is applied as a post-filter, so the cost is O(rows above the - // lower bound) rather than O(window), and the limit can never short-circuit it. - // That is a ~480× regression on the claim path, in the state the queue spends most - // of its time in. The `<= now` half stays in application code, where it is free. - // (On a PRIMARY key a two-sided range collapses to a filtered intersection — - // 289–1490 ms — which is why the shape of this query is worth a comment at all.) - conditions: [{ attribute: 'nextRenderTime', comparator: 'greater_than_equal', value: floorMinute * MINUTE }], - sort: { attribute: 'nextRenderTime' }, - // ARRAY select. A string `select` returns the bare scalar rather than a record — - // the trap that has caused two silent bugs in this package already. - select: ['cacheKey', 'nextRenderTime', 'fromSitemap'], - limit, - }, - { replicateFrom: false } - ), + searchSchedules: searchSchedulesFrom, leases: leaseTable(), nowMs: Date.now(), grantLimit, @@ -585,6 +625,241 @@ export const claimSchedules = async ({ grantLimit } = {}) => { return floorUnpinned ? { ...pass, floorUnpinned } : pass; }; +/** + * THE SWEEP — score the whole due set and publish the best of it. + * + * This is the part that makes priority possible at all, and the reason it can exist is one measured + * fact (#119): a projected one-sided read is ~2.4 us/row, FLAT from 200 to 20,000 rows, and yielding + * every 200 rows costs nothing. So 200,000 rows cost ~480 ms and a 500k-row overdue set ~1.2 s — on a + * timer, off the claim path, with zero writes. The claim path meanwhile stops reading the index at + * all. Reads are 2.4 us and writes are 76-89 us; reading liberally and writing not at all is the + * cheap direction. + * + * ── IT OWNS THE FLOOR NOW, AND THAT IS NOT INCIDENTAL ───────────────────────────────────────── + * + * The claim floor only advances when something OBSERVES the head of the index. Once claims are served + * from memory they observe nothing, so a floor left to the claim path would freeze — and a frozen + * floor is precisely the degradation it exists to prevent: measured, an unfloored seek goes 0.073 -> + * 5.60 ms over 40,000 reschedules while a floored one stays flat at 0.07 ms. So the sweep applies the + * same floor rule the claim pass applies, and it is strictly better informed while doing it: it + * observes EVERY due row rather than a window, so "the first due row observed" is the true minimum + * rather than the minimum of a window. + * + * ── WHAT IT DELIBERATELY DOES NOT DO ───────────────────────────────────────────────────────── + * + * No writes, no lease grants, and no `<= now` in the query. The cut at "past now" is applied in + * application code because the two-sided form is 256x slower when its limit cannot fill (739 ms + * against 2.89 ms, measured) — which is the state a caught-up queue is in essentially always. + * + * It also does not skip leased rows. A row being rendered right now is still a row that is due, and + * excluding it would let the floor advance past a lease whose result has not landed. It is scored, + * published, and refused at grant time by the lease CAS — one wasted array slot, versus a floor rule + * that no longer holds. + */ +export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { + const { enabled, capacity, sweepCap, sitemapBoost } = config.queue.ready; + if (!enabled || capacity <= 0) return { skipped: 'disabled' }; + + const queue = readyQueue(); + if (queue.capacity === 0) return { skipped: 'no-capacity' }; + + const leases = leaseTable(); + const nowMinute = minuteOf(nowMs); + const floorEnabled = config.queue.claimFloor.enabled; + const floorFrom = floorEnabled ? leases.readFloorMinute(nowMinute, guardMinutes()) : 0; + const cap = Math.max(1, sweepCap | 0); + + const heap = createTopK(queue.capacity); + // Route resolution parses a URL and walks the route list, and a URL's device variants share both — + // so this memo halves the work at minimum, on the one loop that sees every due row on the node. + // Per sweep rather than process-lifetime: the route list is live-reloadable, and a cache keyed by + // URL over an 814k-target corpus to serve one sweep is the unbounded-structure mistake this node + // has already been taken down by twice. + const intervals = new Map(); + const intervalFor = (url) => { + let interval = intervals.get(url); + if (interval === undefined) { + interval = resolveRenderInterval(url, null); + intervals.set(url, interval); + } + return interval; + }; + + let scanned = 0; + let due = 0; + let nonFinite = 0; + let firstDueMinute = null; + let firstDueKey = null; + let reachedNotYetDue = false; + + // DRAINED WITH NO WRITES AND NO ATOMICS INSIDE THE LOOP. Harper's long-transaction monitor aborts + // a transaction that has pending writes when it fires, and a cursor left open across writes is + // that shape; the publish below is atomics-only and happens after the cursor is done. And no + // `break` out of the `for await` either — an abandoned iterator leaves its read transaction + // unreleased (see util/reconcile.js). The cut at "past now" is applied per row instead. + for await (const row of searchSchedulesFrom({ floorMinute: floorFrom, limit: cap })) { + scanned++; + const dueAt = numberOf(row.nextRenderTime); + if (!Number.isFinite(dueAt)) { + nonFinite++; + continue; + } + if (dueAt > nowMs) { + // Rows arrive ascending, so the first not-yet-due row means the due set is exhausted — + // recorded, but the cursor is still drained to the end rather than abandoned. + reachedNotYetDue = true; + continue; + } + due++; + if (firstDueMinute === null) { + firstDueMinute = minuteOf(dueAt); + firstDueKey = row.cacheKey; + } + const url = CacheKey.extractUrl(row.cacheKey); + const score = scoreOf( + { dueAt, fromSitemap: !!row.fromSitemap }, + { nowMs, intervalMs: intervalFor(url), sitemapBoost } + ); + heap.offer(score, { cacheKey: row.cacheKey, dueAt, fromSitemap: !!row.fromSitemap }); + // Yielding is free (measured: 2.375 vs 2.387 us/row at 20,000 rows) and this runs beside bot + // traffic on a worker that also serves requests, so it must not hold the loop for a whole sweep. + if (scanned % 200 === 0) await yieldNow(); + } + + const published = queue.publish(heap.drainDescending(), { scannedRows: scanned }); + + // THE FLOOR, on the same rule the claim pass uses: the due minute of the first due row observed, + // or `nowMinute - guard` when nothing was due. CAS against the value this sweep started from and + // abandon on conflict — a conflict means a funnel write lowered the floor for a row this sweep + // never saw, and re-advancing over it would strand that row until the next sweep. + let floorAdvanced = false; + if (floorEnabled) { + floorAdvanced = leases.advanceFloor(floorFrom, Math.max(0, firstDueMinute ?? nowMinute - guardMinutes())); + } + leases.recordPassOutcome({ sawDue: due > 0, earliestNotYetDueMinute: 0 }); + + return { + scanned, + due, + nonFinite, + published, + capacity: queue.capacity, + floorFrom, + floorAdvanced, + firstDueKey, + // `scanned >= cap` alone says nothing — the query is one-sided, so on any real corpus the window + // fills. Reaching a not-yet-due row is what proves the due set was seen to its end, and only its + // absence means the sweep was truncated and the ordering is over a prefix of the backlog. + truncated: scanned >= cap && !reachedNotYetDue, + }; +}; + +/** + * Grant up to `grantLimit` jobs — the ready set first, the index scan for whatever is left. + * + * THE FALLBACK IS THE WHOLE SAFETY ARGUMENT. A cold set (a fresh worker generation), an exhausted one + * (claims outrunning the sweep), a disabled one, or a buffer sized to nothing all land on + * `claimFromIndex`, which is the path this queue has always used. So every failure mode of the ready + * set degrades to TODAY'S ORDERING rather than to a stalled queue — which is also why it can ship on + * by default. + * + * The ready set is a CACHE, never a source of truth. An entry naming a row that has since been + * rescheduled or deleted costs at most one redundant render: the lease CAS refuses a duplicate, and + * `processJobResult` already drops a result whose target is gone. Nothing here can lose a page, + * because the next sweep re-reads the table — which is a categorically weaker invariant than the + * claim floor's, where a row filed below it is never read again, silently and terminally. + */ +export const claimSchedules = async ({ grantLimit } = {}) => { + const wanted = Math.max(0, grantLimit | 0); + if (!config.queue.ready.enabled || wanted === 0) return claimFromIndex({ grantLimit }); + + const queue = readyQueue(); + const leases = leaseTable(); + const nowMs = Date.now(); + const leaseTimeMs = config.queue.jobLeaseTime; + + const jobs = []; + let skippedLeased = 0; + let leaseRefused = false; + + // Over-take, because an entry may name a row that is already leased — the set does not exclude + // leased rows on purpose (see `sweepReadySet`), so a run of them must not end the attempt while the + // set still holds grantable work. Bounded, so an entirely-leased set costs a fixed number of + // atomic loads rather than draining the whole thing. + const attempts = Math.min(queue.capacity, wanted * 4); + for (let taken = 0; jobs.length < wanted && taken < attempts; ) { + const batch = queue.take(Math.min(wanted - jobs.length, attempts - taken)); + if (batch.length === 0) break; + taken += batch.length; + for (const entry of batch) { + if (jobs.length >= wanted) break; + if (leases.isLeased(entry.cacheKey)) { + skippedLeased++; + continue; + } + const expiresAtMs = nowMs + leaseTimeMs; + if (!leases.grant(entry.cacheKey, { dueMinute: minuteOf(entry.dueAt), leaseExpiryMs: expiresAtMs })) { + // No slot, no job — a granted-but-unrecorded job is a double render. + leaseRefused = true; + break; + } + jobs.push({ + cacheKey: entry.cacheKey, + dueMinute: minuteOf(entry.dueAt), + expiresAtMs, + // Carried through from the sweep, NOT left absent. The renderer serializes a non-indexable + // page only when the url is sitemap-listed, so a job reporting `false` for a listed page + // silently stops it being cached — the bug this package has shipped twice. + fromSitemap: entry.fromSitemap, + score: entry.score, + }); + } + if (leaseRefused) break; + } + + if (jobs.length >= wanted) { + // Filled entirely from memory: no index read at all on this claim. The floor is not advanced + // here and does not need to be — `sweepReadySet` owns it precisely because this path observes + // nothing. + const floor = floorState(nowMs); + return { + jobs, + sawDue: true, + granted: jobs.length, + skippedLeased, + nonFinite: 0, + earliestNotYetDueMinute: 0, + floorFrom: floor.floorMinute, + floorTo: floor.floorMinute, + floorHeldBy: lastFloorHeldBy, + floorHeldByRow: null, + floorPinnedForMs: floor.floorPinnedForMs ?? 0, + floorAdvanced: false, + scanned: 0, + scanLimit: 0, + scanTruncated: false, + leaseRefused, + occupancy: leases.occupancy(), + fromReady: jobs.length, + ready: queue.state(), + }; + } + + // Short. Take the remainder from the index, which also lets the floor advance and the wedged-row + // warning fire on a node whose ready set is doing most of the work. + const pass = await claimFromIndex({ grantLimit: wanted - jobs.length }); + return { + ...pass, + jobs: [...jobs, ...pass.jobs], + granted: jobs.length + pass.granted, + skippedLeased: skippedLeased + pass.skippedLeased, + leaseRefused: leaseRefused || pass.leaseRefused, + sawDue: jobs.length > 0 || pass.sawDue, + fromReady: jobs.length, + ready: queue.state(), + }; +}; + // ---- lease lifecycle exposed to the result path --------------------------------------------- export const releaseLease = (cacheKey) => leaseTable().release(cacheKey); diff --git a/packages/plugin/test/config.test.js b/packages/plugin/test/config.test.js index 07f1834..3d8813c 100644 --- a/packages/plugin/test/config.test.js +++ b/packages/plugin/test/config.test.js @@ -267,6 +267,8 @@ test('secret and restart paths are what the schema declares', () => { // The render-lease shared buffer is sized by the first allocation in the process, so a live // change would give workers in one generation differently-sized views of the same buffer. 'queue.maxLeases', + // Same reason, same mechanism: the ready set is a named shared buffer too. + 'queue.ready.capacity', 'render.reconcile.startDelay', 'render.reconcile.startJitter', ]); diff --git a/packages/plugin/test/readyQueue.test.js b/packages/plugin/test/readyQueue.test.js new file mode 100644 index 0000000..2c9fdc7 --- /dev/null +++ b/packages/plugin/test/readyQueue.test.js @@ -0,0 +1,256 @@ +import { test } from 'node:test'; +import assert from 'node:assert/strict'; +import { createReadyQueue, readyBufferBytes, readyCapacityIn, READY_KEY_BYTES } from '../src/util/readyQueue.js'; +import { createTopK, scoreOf } from '../src/util/renderPriority.js'; + +/** + * The ready set and the scoring policy, against a plain ArrayBuffer with no Harper at all. + * + * What is pinned here, and why each one is a bug nothing else would catch: + * + * - A KEY IS NEVER TRUNCATED. A truncated cache key names a DIFFERENT row, so a lease would be + * granted on the wrong page and its render stored under the wrong key. Dropping the entry costs + * one fallback scan; truncating it corrupts a page. + * - THE CURSOR HANDS EACH INDEX OUT ONCE. It is the entire concurrency story — two workers claiming + * concurrently must never receive the same entry, and there is no lock to fall back on. + * - ...AND IT CANNOT RUN AWAY. It is an Int32 incremented on every claim including exhausted ones; + * unbounded, it wraps in about eight days of idling and starts handing out valid indices again. + * - A READER NEVER SEES A HALF-WRITTEN SET. `publish` writes the inactive slot and flips, and the + * cursor must reset BEFORE the flip or a claim landing between the two skips the head of a fresh + * generation. + * - TOP-K IS BOUNDED BY K, NOT BY THE CORPUS. The sweep walks a due set far larger than the set it + * fills; retaining more than K would be the unbounded-structure failure this node has hit twice. + * - LATENESS, NOT AGE. A 7-day suppression recheck must not outrank a genuinely late page. + */ + +const MINUTE = 60_000; +const HOUR = 60 * MINUTE; +const T0 = 1_700_000_400_000; + +const queueOf = (capacity, now = () => T0) => + createReadyQueue({ buffer: new ArrayBuffer(readyBufferBytes(capacity)), capacity, now }); + +const row = (cacheKey, score, dueAt = T0 - HOUR) => ({ entry: { cacheKey, dueAt }, score }); + +// ---- scoring ----------------------------------------------------------------------------------- + +test('a page late by one of its own cadences scores 1, whatever the cadence is', () => { + assert.equal(scoreOf({ dueAt: T0 - HOUR }, { nowMs: T0, intervalMs: HOUR }), 1); + assert.equal(scoreOf({ dueAt: T0 - 48 * HOUR }, { nowMs: T0, intervalMs: 48 * HOUR }), 1); +}); + +test('the documented inversion: a 1h page 2h late outranks a 48h page 3h late', () => { + const home = scoreOf({ dueAt: T0 - 2 * HOUR }, { nowMs: T0, intervalMs: HOUR }); + const pdp = scoreOf({ dueAt: T0 - 3 * HOUR }, { nowMs: T0, intervalMs: 48 * HOUR }); + // Absolute due time says the PDP (3h > 2h). Relative lateness says the homepage, by ~32x. + assert.equal(home, 2); + assert.ok(home > pdp); +}); + +test('LATENESS, NOT AGE: a 7-day suppression recheck coming due does not outrank a late page', () => { + // The row `Target.suppress` wrote: due now, scheduled 7 days ago, scored against a 48h cadence. + // Under an age-based formula this reads as 3.5 cadences stale and wins. + const recheck = scoreOf({ dueAt: T0 }, { nowMs: T0, intervalMs: 48 * HOUR }); + const late = scoreOf({ dueAt: T0 - 6 * HOUR }, { nowMs: T0, intervalMs: 48 * HOUR }); + assert.equal(recheck, 0); + assert.ok(late > recheck); +}); + +test('the sitemap boost is a multiplier, so a far-behind discovered row still wins', () => { + const listed = scoreOf({ dueAt: T0 - HOUR, fromSitemap: true }, { nowMs: T0, intervalMs: HOUR, sitemapBoost: 2 }); + const discovered = scoreOf({ dueAt: T0 - 3 * HOUR }, { nowMs: T0, intervalMs: HOUR, sitemapBoost: 2 }); + assert.equal(listed, 2); + assert.equal(discovered, 3); + assert.ok(discovered > listed, 'a multiplier cannot become a starvation lane'); +}); + +test('a zero or negative interval degrades to raw lateness rather than Infinity or a sign flip', () => { + assert.equal(scoreOf({ dueAt: T0 - 5 }, { nowMs: T0, intervalMs: 0 }), 5); + assert.equal(scoreOf({ dueAt: T0 - 5 }, { nowMs: T0, intervalMs: -HOUR }), 5); +}); + +test('a row scored at or before its due moment is 0, never negative', () => { + assert.equal(scoreOf({ dueAt: T0 }, { nowMs: T0, intervalMs: HOUR }), 0); + assert.equal(scoreOf({ dueAt: T0 + HOUR }, { nowMs: T0, intervalMs: HOUR }), 0); +}); + +// ---- top-K ------------------------------------------------------------------------------------- + +test('TOP-K IS BOUNDED BY K while streaming a set far larger than K', () => { + const heap = createTopK(5); + for (let i = 0; i < 100_000; i++) heap.offer(i, { cacheKey: `k${i}` }); + assert.equal(heap.size, 5, 'memory is a function of K, not of the corpus'); + assert.deepEqual( + heap.drainDescending().map((r) => r.score), + [99999, 99998, 99997, 99996, 99995] + ); +}); + +test('top-K keeps the best regardless of arrival order, and rejects on one comparison', () => { + const heap = createTopK(3); + for (const s of [5, 1, 9, 3, 7, 2, 8]) assert.equal(typeof heap.offer(s, { cacheKey: `k${s}` }), 'boolean'); + assert.deepEqual( + heap.drainDescending().map((r) => r.score), + [9, 8, 7] + ); + assert.equal(heap.offer(0, { cacheKey: 'no' }), false, 'a worse-than-worst candidate is refused'); + assert.equal(heap.offer(100, { cacheKey: 'yes' }), true); +}); + +test('drainDescending is best-first, which is what lets the cursor compare nothing', () => { + const heap = createTopK(4); + heap.offer(1, { cacheKey: 'a' }); + heap.offer(4, { cacheKey: 'b' }); + heap.offer(2, { cacheKey: 'c' }); + assert.deepEqual( + heap.drainDescending().map((r) => r.entry.cacheKey), + ['b', 'c', 'a'] + ); +}); + +// ---- the shared set --------------------------------------------------------------------------- + +test('publish then take hands rows out in the order they were published', () => { + const q = queueOf(8); + assert.equal(q.publish([row('a|desktop', 3), row('b|desktop', 2), row('c|desktop', 1)]), 3); + assert.deepEqual( + q.take(2).map((e) => e.cacheKey), + ['a|desktop', 'b|desktop'] + ); + assert.deepEqual( + q.take(2).map((e) => e.cacheKey), + ['c|desktop'], + 'a partial take is the signal that the set is exhausted' + ); + assert.deepEqual(q.take(1), [], 'and it stays exhausted until the next publish'); +}); + +test('THE CURSOR HANDS EACH INDEX OUT ONCE, across interleaved consumers', () => { + const q = queueOf(64); + q.publish(Array.from({ length: 50 }, (_, i) => row(`k${i}|desktop`, 50 - i))); + // Two "workers" interleaved over the same buffer — which is what the atomic cursor is for. + const a = []; + const b = []; + for (let i = 0; i < 25; i++) { + a.push(...q.take(1)); + b.push(...q.take(1)); + } + const all = [...a, ...b].map((e) => e.cacheKey); + assert.equal(all.length, 50); + assert.equal(new Set(all).size, 50, 'no entry may be handed to two consumers'); +}); + +test('the cursor CANNOT RUN AWAY past the count while the set is exhausted', () => { + const q = queueOf(4); + q.publish([row('a|desktop', 1)]); + q.take(1); + for (let i = 0; i < 10_000; i++) q.take(5); + // Unbounded, this is an Int32 incremented on every claim: it would wrap in about eight days of + // idling and start handing out valid indices again. + assert.equal(q.state().consumed, 1); + assert.equal(q.state().remaining, 0); +}); + +test('a fresh publish resets consumption, and a reader never sees a half-written set', () => { + const q = queueOf(8); + q.publish([row('old-1|desktop', 5), row('old-2|desktop', 4)]); + q.take(1); + assert.equal(q.state().remaining, 1); + + q.publish([row('new-1|desktop', 9), row('new-2|desktop', 8), row('new-3|desktop', 7)]); + const state = q.state(); + assert.equal(state.count, 3); + assert.equal(state.consumed, 0, 'the cursor must reset with the generation'); + assert.equal(state.generation, 2); + assert.deepEqual( + q.take(3).map((e) => e.cacheKey), + ['new-1|desktop', 'new-2|desktop', 'new-3|desktop'] + ); +}); + +test('publishing alternates slots, so the set being read is never the set being written', () => { + const q = queueOf(4); + q.publish([row('gen1|desktop', 1)]); + const first = q.peek(1)[0].cacheKey; + q.publish([row('gen2|desktop', 1)]); + const second = q.peek(1)[0].cacheKey; + q.publish([row('gen3|desktop', 1)]); + assert.equal(first, 'gen1|desktop'); + assert.equal(second, 'gen2|desktop'); + assert.equal(q.peek(1)[0].cacheKey, 'gen3|desktop'); +}); + +test('A KEY IS NEVER TRUNCATED — an oversized one is dropped instead', () => { + const q = queueOf(4); + const huge = `https://www.kohls.com/${'x'.repeat(READY_KEY_BYTES)}|desktop`; + const stored = q.publish([row('fits|desktop', 5), row(huge, 9)]); + assert.equal(stored, 1, 'the oversized entry is not stored at all'); + // A truncated key would name a different row and grant a lease on the wrong page; a dropped one + // just falls to the scan. + assert.deepEqual( + q.take(2).map((e) => e.cacheKey), + ['fits|desktop'] + ); +}); + +test('a multi-byte key round-trips by BYTES, not characters', () => { + const q = queueOf(4); + const key = 'https://www.kohls.com/café-über/日本|mobile'; + q.publish([row(key, 1)]); + assert.equal(q.take(1)[0].cacheKey, key); +}); + +test('publishing more than capacity keeps the head, which is the best of the set', () => { + const q = queueOf(3); + const stored = q.publish(Array.from({ length: 10 }, (_, i) => row(`k${i}|desktop`, 10 - i))); + assert.equal(stored, 3); + assert.deepEqual( + q.take(5).map((e) => e.cacheKey), + ['k0|desktop', 'k1|desktop', 'k2|desktop'] + ); +}); + +test('a zero-capacity buffer degrades to empty rather than corrupting memory', () => { + // The fallback path is what makes this safe: an unusable set means today's scan, not a stalled + // queue. + const q = createReadyQueue({ buffer: new ArrayBuffer(readyBufferBytes(1)), capacity: 0 }); + assert.equal(q.capacity, 1, 'capacity is derived from the buffer when the argument is unusable'); + const tiny = createReadyQueue({ buffer: new ArrayBuffer(32), capacity: 100 }); + assert.equal(tiny.capacity, 0); + assert.equal(tiny.publish([row('a|desktop', 1)]), 0); + assert.deepEqual(tiny.take(5), []); +}); + +test('capacity is clamped to the buffer, never trusted from the argument', () => { + const buffer = new ArrayBuffer(readyBufferBytes(4)); + const q = createReadyQueue({ buffer, capacity: 10_000 }); + assert.equal(q.capacity, readyCapacityIn(buffer.byteLength)); + assert.ok(q.capacity <= 4); +}); + +test('state reports age and what the sweep examined, with no database work', () => { + let clock = T0; + const q = queueOf(8, () => clock); + assert.equal(q.state().sweptAt, null, 'never swept reads as null, not as the epoch'); + q.publish([row('a|desktop', 1)], { scannedRows: 200_000 }); + clock = T0 + 90_000; + const state = q.state(); + assert.equal(state.scannedRows, 200_000); + assert.equal(state.ageMs, 90_000); + assert.equal(state.sweptAt, T0); +}); + +test('score survives the round trip, so what is reported is what it was ordered by', () => { + const q = queueOf(4); + q.publish([row('a|desktop', 2.5), row('b|desktop', 0.125)]); + const taken = q.take(2); + assert.equal(taken[0].score, 2.5); + assert.equal(taken[1].score, 0.125); +}); + +test('an absurd score is clamped rather than overflowing the Int32 it is stored in', () => { + const q = queueOf(4); + q.publish([row('a|desktop', 1e12)]); + const [entry] = q.take(1); + assert.ok(Number.isFinite(entry.score) && entry.score > 0, `got ${entry.score}`); +}); diff --git a/packages/plugin/test/readySweep.test.js b/packages/plugin/test/readySweep.test.js new file mode 100644 index 0000000..f221efb --- /dev/null +++ b/packages/plugin/test/readySweep.test.js @@ -0,0 +1,318 @@ +import { test, before, beforeEach } from 'node:test'; +import assert from 'node:assert/strict'; + +/** + * The sweep and the ready-first claim, driven against a fake schedule table. + * + * What is pinned here, and why each one is a bug nothing else would catch: + * + * - THE PRODUCTION SYMPTOM. A homepage two of its own cadences late, behind a deep backlog of rows + * that are older in absolute terms, must be granted FIRST. This is the whole reason the feature + * exists, and the reason re-sorting the claim window could not do it: the window is anchored at + * the oldest due time, so the homepage is never read at all. + * - THE SWEEP ADVANCES THE FLOOR. Once claims are served from memory they observe nothing, so a + * floor left to the claim path freezes — and a frozen floor is measured at 0.073 -> 5.60 ms over + * 40,000 reschedules. If this regresses, the queue silently degrades back to the state the floor + * exists to prevent. + * - THE FALLBACK IS REAL. Cold, exhausted and disabled must all land on the index scan, because + * that is the entire safety argument: every failure mode here is the previous behaviour. + * - A LEASED ROW IS NEVER GRANTED TWICE. The set deliberately does not exclude leased rows (a row + * being rendered is still due, and excluding it would let the floor advance past a lease whose + * result has not landed), so the claim path has to refuse them. + * - `fromSitemap` SURVIVES. The renderer serializes a non-indexable page only when the url is + * sitemap-listed, so a job reporting `false` for a listed page silently stops it being cached. + * That bug has shipped twice in this package. + * - A NOT-YET-DUE ROW IS NEVER PUBLISHED, however urgent its cadence would make it. + */ + +const MINUTE = 60_000; +const HOUR = 60 * MINUTE; +const T0 = 1_700_000_400_000; +const minuteOf = (ms) => Math.floor(ms / MINUTE); + +let funnel, config, applyOptions; +const sabs = new Map(); +let table = new Map(); +let searches = 0; + +before(async () => { + globalThis.server = { hostname: 'test-node', workerIndex: 0, nodes: [], config: { http: { port: 9926 } } }; + globalThis.logger = { debug() {}, info() {}, warn() {}, error() {} }; + globalThis.databases = { + coordination: { + SharedBuffer: { + primaryStore: { + getUserSharedBuffer: (key, buffer) => { + if (!sabs.has(key)) sabs.set(key, buffer); + return sabs.get(key); + }, + tryLock: () => true, + unlock() {}, + }, + }, + }, + render_schedule: { + RenderSchedule: { + put: async () => {}, + delete: async () => {}, + get: async () => undefined, + // The one-sided ascending walk the real query performs: `>= value`, sorted, limited. + search: (query) => { + searches++; + const from = query.conditions[0].value; + const rows = [...table.values()] + .filter((row) => Number(row.nextRenderTime) >= from) + .sort((a, b) => Number(a.nextRenderTime) - Number(b.nextRenderTime)) + .slice(0, query.limit); + return (async function* () { + for (const row of rows) yield { ...row }; + })(); + }, + }, + }, + }; + + ({ config, applyOptions } = await import('../src/config.js')); + funnel = await import('../src/util/renderSchedule.js'); +}); + +// THE ROUTES ARE THE POINT. Without them every URL resolves to `render.defaultInterval`, so relative +// lateness collapses to absolute lateness and the ordering under test cannot be distinguished from +// the ordering it replaces — which is exactly how the first version of this file "failed". +const withRoutes = () => + applyOptions({ + ingress: { + mode: 'forwarded', + routes: [ + { match: 'exact', path: '/', queryParams: [], renderInterval: HOUR }, + { match: 'prefix', path: '/product/prd-', queryParams: [], renderInterval: 48 * HOUR }, + { match: 'prefix', path: '/a', queryParams: [] }, + { match: 'prefix', path: '/b', queryParams: [] }, + ], + }, + }); + +const seed = (rows) => { + table = new Map(rows.map((r) => [r.cacheKey, r])); +}; + +const row = (url, device, dueAt, fromSitemap = true) => ({ + cacheKey: `${url}|${device}`, + nextRenderTime: dueAt, + fromSitemap, +}); + +beforeEach(() => { + withRoutes(); + // ZERO EVERY SHARED BUFFER, not just the floor. Both the lease table and the ready set live in + // named buffers that outlive a test, and both leak in ways that make the next test pass or fail + // for the wrong reason: a leftover generation makes a "cold set" warm, and leases granted by an + // earlier test's claim make the fallback scan skip rows and start further down the index. Zeroing + // the bytes resets the floor, the leases, the occupancy gauge and the set in one step, and the + // views the modules hold stay valid because only the contents change. + for (const buffer of sabs.values()) new Uint8Array(buffer).fill(0); + config.queue.ready.enabled = true; + config.queue.ready.sweepCap = 500_000; + config.queue.ready.sitemapBoost = 2; + searches = 0; +}); + +// A backlog of 48h-cadence product pages that are older in absolute terms, plus a 1h homepage that +// is two of its own cadences late. Index order serves the products; relative lateness serves home. +const backlogWithLateHome = () => { + const rows = []; + for (let i = 0; i < 400; i++) { + rows.push(row(`https://www.kohls.com/product/prd-${i}/x`, 'desktop', T0 - 3 * 24 * HOUR + i * MINUTE)); + } + rows.push(row('https://www.kohls.com/', 'desktop', T0 - 2 * HOUR)); + return rows; +}; + +test('THE PRODUCTION SYMPTOM: a late homepage behind a deep backlog is granted first', async () => { + seed(backlogWithLateHome()); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 401, 'the sweep scores the whole due set, not a window'); + assert.ok(sweep.published > 0); + + const pass = await funnel.claimSchedules({ grantLimit: 1 }); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/|desktop'], + '2 cadences late on a 1h route beats 3 days late on a 48h route' + ); + assert.equal(pass.fromReady, 1); +}); + +test('...and the claim that serves it reads the index ZERO times', async () => { + seed(backlogWithLateHome()); + await funnel.sweepReadySet({ nowMs: T0 }); + searches = 0; + const pass = await funnel.claimSchedules({ grantLimit: 5 }); + assert.equal(pass.jobs.length, 5); + assert.equal(searches, 0, 'the claim path must not touch the index while the set can serve it'); +}); + +test('THE SWEEP ADVANCES THE FLOOR — otherwise the index degrades with nothing observing it', async () => { + seed(backlogWithLateHome()); + const leases = funnel.leaseTable(); + assert.equal(leases.rawFloorMinute(), 0, 'precondition: unbounded'); + + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.floorAdvanced, true); + // The floor rule, unchanged: the due minute of the FIRST due row observed. The sweep sees every + // due row, so that is the true minimum rather than the minimum of a window. + assert.equal(leases.rawFloorMinute(), minuteOf(T0 - 3 * 24 * HOUR)); + assert.equal(sweep.firstDueKey, 'https://www.kohls.com/product/prd-0/x|desktop'); +}); + +test('a cold set falls back to the index scan, which is the previous behaviour', async () => { + seed(backlogWithLateHome()); + // No sweep has run. + const pass = await funnel.claimSchedules({ grantLimit: 3 }); + assert.equal(pass.fromReady, 0); + assert.ok(searches > 0, 'it must have read the index'); + // Index order: the oldest in absolute terms. + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + [ + 'https://www.kohls.com/product/prd-0/x|desktop', + 'https://www.kohls.com/product/prd-1/x|desktop', + 'https://www.kohls.com/product/prd-2/x|desktop', + ] + ); +}); + +test('an exhausted set tops up from the index rather than granting short', async () => { + seed([ + row('https://www.kohls.com/a1', 'desktop', T0 - HOUR), + row('https://www.kohls.com/a2', 'desktop', T0 - HOUR), + row('https://www.kohls.com/a3', 'desktop', T0 - HOUR), + ]); + await funnel.sweepReadySet({ nowMs: T0 }); + const ready = funnel.readyQueue(); + // Drain it to one remaining entry. `capacity` cannot be shrunk at runtime — the buffer is sized by + // its first allocation — so exhaustion has to be produced by consumption, which is also how it + // happens in production when claims outrun the sweep. + ready.take(ready.state().count - 1); + searches = 0; + + const pass = await funnel.claimSchedules({ grantLimit: 3 }); + assert.equal(pass.fromReady, 1, 'one from the set...'); + assert.equal(pass.jobs.length, 3, '...and the batch is still filled, not truncated'); + assert.ok(searches > 0, 'the remainder came from the index'); +}); + +test('disabled is a true revert: no sweep, and claims come straight from the index', async () => { + seed(backlogWithLateHome()); + config.queue.ready.enabled = false; + assert.deepEqual(await funnel.sweepReadySet({ nowMs: T0 }), { skipped: 'disabled' }); + const pass = await funnel.claimSchedules({ grantLimit: 2 }); + assert.equal(pass.fromReady, undefined); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/product/prd-0/x|desktop', 'https://www.kohls.com/product/prd-1/x|desktop'] + ); +}); + +test('A LEASED ROW IS NEVER GRANTED TWICE, and the set does not drop it', async () => { + seed([row('https://www.kohls.com/', 'desktop', T0 - 2 * HOUR), row('https://www.kohls.com/a', 'desktop', T0 - HOUR)]); + await funnel.sweepReadySet({ nowMs: T0 }); + const leases = funnel.leaseTable(); + // Lease the head of the set out from under the claim, the way a concurrent worker would. + // + // EXPIRY ON THE REAL CLOCK, not on T0. The lease table is built with `() => Date.now()`, and T0 is + // a fixed past timestamp — so a `T0 + HOUR` expiry is already long expired and `isLeased` answers + // false. The first version of this test granted a lease that never existed and then asserted the + // row was not re-granted, which is a test that cannot fail for the right reason. + leases.grant('https://www.kohls.com/|desktop', { + dueMinute: minuteOf(T0 - 2 * HOUR), + leaseExpiryMs: Date.now() + HOUR, + }); + + const pass = await funnel.claimSchedules({ grantLimit: 2 }); + const keys = pass.jobs.map((j) => j.cacheKey); + assert.equal(keys.includes('https://www.kohls.com/|desktop'), false, 'the leased row must not be re-granted'); + assert.ok(pass.skippedLeased >= 1); +}); + +test('a not-yet-due row is never published, however urgent its cadence would make it', async () => { + seed([ + row('https://www.kohls.com/', 'desktop', T0 + HOUR), // 1h route, not yet due + row('https://www.kohls.com/product/prd-1/x', 'desktop', T0 - HOUR), + ]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 1); + assert.deepEqual( + funnel + .readyQueue() + .peek(5) + .map((e) => e.cacheKey), + ['https://www.kohls.com/product/prd-1/x|desktop'] + ); +}); + +test('`fromSitemap` survives the round trip through shared memory', async () => { + seed([ + row('https://www.kohls.com/a', 'desktop', T0 - HOUR, true), + row('https://www.kohls.com/b', 'desktop', T0 - HOUR, false), + ]); + await funnel.sweepReadySet({ nowMs: T0 }); + const pass = await funnel.claimSchedules({ grantLimit: 2 }); + const byKey = new Map(pass.jobs.map((j) => [j.cacheKey, j.fromSitemap])); + assert.equal(byKey.get('https://www.kohls.com/a|desktop'), true); + assert.equal(byKey.get('https://www.kohls.com/b|desktop'), false); +}); + +test('the sitemap boost orders a listed page ahead of a discovered one at equal lateness', async () => { + seed([ + row('https://www.kohls.com/a', 'desktop', T0 - HOUR, false), + row('https://www.kohls.com/b', 'desktop', T0 - HOUR, true), + ]); + await funnel.sweepReadySet({ nowMs: T0 }); + assert.deepEqual( + funnel + .readyQueue() + .peek(2) + .map((e) => e.cacheKey), + ['https://www.kohls.com/b|desktop', 'https://www.kohls.com/a|desktop'] + ); +}); + +test('a sweep that hits its cap without reaching a not-yet-due row reports truncated', async () => { + seed(backlogWithLateHome()); + config.queue.ready.sweepCap = 10; + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.scanned, 10); + assert.equal(sweep.truncated, true, 'the ordering covers only a prefix of the backlog'); + + // ...and a sweep that DOES reach one is not truncated even if it read every row it was allowed. + seed([row('https://www.kohls.com/a', 'desktop', T0 - HOUR), row('https://www.kohls.com/b', 'desktop', T0 + HOUR)]); + config.queue.ready.sweepCap = 2; + const complete = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(complete.truncated, false); + config.queue.ready.sweepCap = 500_000; +}); + +test('a row with an unusable due time is counted and skipped, never scored', async () => { + seed([ + { cacheKey: 'https://www.kohls.com/a|desktop', nextRenderTime: null, fromSitemap: true }, + row('https://www.kohls.com/b', 'desktop', T0 - HOUR), + ]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.nonFinite, 1); + assert.equal(sweep.due, 1); + assert.deepEqual( + funnel + .readyQueue() + .peek(5) + .map((e) => e.cacheKey), + ['https://www.kohls.com/b|desktop'] + ); +}); + +test('a BigInt due time from a Long column is scored, not thrown on', async () => { + seed([{ cacheKey: 'https://www.kohls.com/a|desktop', nextRenderTime: BigInt(T0 - HOUR), fromSitemap: true }]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 1); + assert.equal(funnel.readyQueue().peek(1)[0].cacheKey, 'https://www.kohls.com/a|desktop'); +}); From b8d47ba7509dc7a314308455668b11421013e227 Mon Sep 17 00:00:00 2001 From: Joe Date: Fri, 21 Aug 2026 15:50:33 -0400 Subject: [PATCH 2/5] fix(plugin): keep the signals that depended on a CLAIM observing the index MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Self-review of the ready set found three regressions with one shape: the sweep took over OBSERVING the index, and three separate signals were quietly derived from the fact that a claim did the observing. On a node serving every claim from the ready set — the intended steady state — nothing observed the index at all. All three passed the 750-test suite. 1. THE SWEEP WIPED THE NOT-YET-DUE MINUTE. `deriveQueueStatus` flips a node from `empty` to `queued` the moment a known future minute arrives, at zero database cost. The sweep runs every minute and overwrites the recorded outcome, and it was recording 0 — so a node with nothing due but a row due in thirty seconds would tell the whole fleet to go idle. The sweep observed that minute and threw it away; it now carries it. 2. THE PIN AGE FROZE. It only advances when something calls `notePinnedBy`, and both the wedged-row warning and `maybeUnpinFloor` key off it. Left to the claim path, a permanently failing URL would hold the floor with no warning and no automatic push — precisely the unbounded case `queue.claimFloor.unpinAfter` exists to bound. The sweep now notes the pin and runs the hatch, after its cursor is closed (the hatch writes, and a write with an open scan cursor is the shape Harper's long-transaction monitor aborts). 3. `lastFloorHeldBy` WENT STALE, so the warning — when something else made it fire — would name an innocent URL as the thing pinning the queue, which is the exact failure the comment on that variable warns about. Also: the shared-memory figure in `queue.ready.capacity` was per-slot and there are two slots, so ~2.8MB at the default rather than the 1.4MB documented. Three of the four new tests were verified to FAIL against the pre-fix code. The fourth — asserting the sweep notes the pin — passed against it, because the age is stored in whole seconds and a same-tick pin is legitimately 0; it is deleted rather than kept, with a note saying why, since the unpin test's `floorPinnedForMs >= 1000` across two sweeps is only reachable if the pin was noted with a stable key both times. A redundant test that cannot fail reads as coverage. 753 pass / 0 fail. Co-Authored-By: Claude Opus 5 --- packages/plugin/src/configSchema.js | 3 +- packages/plugin/src/util/renderSchedule.js | 38 ++++++++++- packages/plugin/test/readySweep.test.js | 75 +++++++++++++++++++++- 3 files changed, 113 insertions(+), 3 deletions(-) diff --git a/packages/plugin/src/configSchema.js b/packages/plugin/src/configSchema.js index bba76f7..0e589fb 100644 --- a/packages/plugin/src/configSchema.js +++ b/packages/plugin/src/configSchema.js @@ -1292,7 +1292,8 @@ export const configSchema = group('Prerender plugin configuration.', { 'Entries the ready set holds. Sized to cover several sweep intervals of claims so the set ' + 'does not run dry between sweeps: at the recorded fleet throughput a node grants roughly ' + '5 jobs a second, so 5,000 entries is about 16 minutes of work.\n\n' + - 'Costs `capacity x ~276` bytes of shared memory (1.4MB at the default). Raising it does ' + + 'Costs `capacity x ~276 x 2` bytes of shared memory — two slots, so ~2.8MB at the default. ' + + 'Raising it does ' + 'NOT make the ordering better — the sweep already scores every due row and keeps the best ' + 'of them — it only makes the set last longer between sweeps.\n\n' + 'Restart-scoped: a named shared buffer is sized by its first allocation, so a live change ' + diff --git a/packages/plugin/src/util/renderSchedule.js b/packages/plugin/src/util/renderSchedule.js index 132dd74..201b03d 100644 --- a/packages/plugin/src/util/renderSchedule.js +++ b/packages/plugin/src/util/renderSchedule.js @@ -690,6 +690,8 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { let nonFinite = 0; let firstDueMinute = null; let firstDueKey = null; + let firstDueRow = null; + let earliestNotYetDueMinute = 0; let reachedNotYetDue = false; // DRAINED WITH NO WRITES AND NO ATOMICS INSIDE THE LOOP. Harper's long-transaction monitor aborts @@ -707,6 +709,13 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { if (dueAt > nowMs) { // Rows arrive ascending, so the first not-yet-due row means the due set is exhausted — // recorded, but the cursor is still drained to the end rather than abandoned. + // + // ITS MINUTE IS CARRIED, not discarded. `deriveQueueStatus` uses it to flip a node from + // `empty` to `queued` the moment that minute arrives, with zero database cost — so a sweep + // that reported 0 here would WIPE that (it runs every minute and overwrites whatever the + // claim pass recorded), and a node with nothing due but a row due in thirty seconds would + // tell the whole fleet to go idle. + if (!reachedNotYetDue) earliestNotYetDueMinute = minuteOf(dueAt); reachedNotYetDue = true; continue; } @@ -714,6 +723,10 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { if (firstDueMinute === null) { firstDueMinute = minuteOf(dueAt); firstDueKey = row.cacheKey; + // The row itself, because `maybeUnpinFloor` has to REWRITE it and `put` replaces the record — + // so it needs the `fromSitemap` flag this sweep already has in hand. Re-reading the row to + // recover a flag that was in hand is how `Target.revalidate` silently cleared it for a year. + firstDueRow = { cacheKey: row.cacheKey, dueMinute: firstDueMinute, fromSitemap: !!row.fromSitemap }; } const url = CacheKey.extractUrl(row.cacheKey); const score = scoreOf( @@ -736,7 +749,27 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { if (floorEnabled) { floorAdvanced = leases.advanceFloor(floorFrom, Math.max(0, firstDueMinute ?? nowMinute - guardMinutes())); } - leases.recordPassOutcome({ sawDue: due > 0, earliestNotYetDueMinute: 0 }); + leases.recordPassOutcome({ sawDue: due > 0, earliestNotYetDueMinute }); + + // THE SWEEP TOOK OVER OBSERVING THE INDEX, SO IT HAS TO TAKE OVER THE REPORTING THAT DEPENDS ON + // OBSERVING IT. The pin age only advances when something calls `notePinnedBy`, and the wedged-row + // warning and `maybeUnpinFloor` both key off it — so on a node serving every claim from the ready + // set, neither would ever fire and a permanently failing URL would pin the floor with no warning + // and no automatic push. That is precisely the unbounded case `queue.claimFloor.unpinAfter` exists + // to bound, so it cannot be allowed to depend on which path served the last claim. + const floorPinnedForMs = leases.notePinnedBy(firstDueKey); + // ...and the KEY, for the same reason. `floorState` reads this, so a stale value would name an + // innocent URL as the thing pinning the queue. + lastFloorHeldBy = firstDueKey; + lastFloorHeldByAt = Date.now(); + + // AFTER the cursor is closed, never inside the drain: the hatch WRITES, and a write issued with a + // scan cursor still open is the shape Harper's long-transaction monitor aborts. + const floorUnpinned = await maybeUnpinFloor({ + floorHeldByRow: firstDueRow, + floorPinnedForMs, + floorTo: firstDueMinute, + }); return { scanned, @@ -746,6 +779,9 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { capacity: queue.capacity, floorFrom, floorAdvanced, + floorPinnedForMs, + floorUnpinned, + earliestNotYetDueMinute, firstDueKey, // `scanned >= cap` alone says nothing — the query is one-sided, so on any real corpus the window // fills. Reaching a not-yet-due row is what proves the due set was seen to its end, and only its diff --git a/packages/plugin/test/readySweep.test.js b/packages/plugin/test/readySweep.test.js index f221efb..bd07789 100644 --- a/packages/plugin/test/readySweep.test.js +++ b/packages/plugin/test/readySweep.test.js @@ -34,6 +34,7 @@ let funnel, config, applyOptions; const sabs = new Map(); let table = new Map(); let searches = 0; +let puts = []; before(async () => { globalThis.server = { hostname: 'test-node', workerIndex: 0, nodes: [], config: { http: { port: 9926 } } }; @@ -53,7 +54,9 @@ before(async () => { }, render_schedule: { RenderSchedule: { - put: async () => {}, + put: async (cacheKey, row) => { + puts.push({ cacheKey, ...row }); + }, delete: async () => {}, get: async () => undefined, // The one-sided ascending walk the real query performs: `>= value`, sorted, limited. @@ -115,6 +118,7 @@ beforeEach(() => { config.queue.ready.sweepCap = 500_000; config.queue.ready.sitemapBoost = 2; searches = 0; + puts = []; }); // A backlog of 48h-cadence product pages that are older in absolute terms, plus a 1h homepage that @@ -316,3 +320,72 @@ test('a BigInt due time from a Long column is scored, not thrown on', async () = assert.equal(sweep.due, 1); assert.equal(funnel.readyQueue().peek(1)[0].cacheKey, 'https://www.kohls.com/a|desktop'); }); + +// ---- what the sweep took over, and therefore has to keep reporting --------------------------- +// +// These four are the findings of a self-review, and every one of them passed the 750-test suite +// while broken. The shape of the mistake is the same each time: the sweep took over OBSERVING the +// index, and three separate signals were quietly derived from the fact that a CLAIM did the +// observing. On a node serving every claim from the ready set, nothing observed the index at all. + +test('the sweep carries the earliest NOT-YET-DUE minute, so a node does not report empty with work coming', async () => { + // `deriveQueueStatus` flips `empty` -> `queued` the moment that minute arrives, at zero database + // cost, and there is a test elsewhere pinning that it needs no search. The sweep runs every minute + // and OVERWRITES the recorded outcome, so reporting 0 here would wipe the mechanism and tell the + // whole fleet to idle while a row was seconds from being due. + seed([row('https://www.kohls.com/a', 'desktop', T0 + 30 * MINUTE)]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + + assert.equal(sweep.due, 0, 'nothing is due yet...'); + assert.equal(sweep.earliestNotYetDueMinute, minuteOf(T0 + 30 * MINUTE), '...but the sweep knows when it will be'); + assert.equal(funnel.deriveQueueStatus(T0), 'empty', 'empty before that minute arrives'); + assert.equal( + funnel.deriveQueueStatus(T0 + 31 * MINUTE), + 'queued', + 'and queued once it has, with no scan — the mechanism the sweep must not wipe' + ); +}); + +// The fourth finding — that the sweep must call `notePinnedBy`, or the pin age never advances and +// both the wedged-row warning and the unpin hatch become unreachable — has no test of its own on +// purpose. The obvious one (assert a pin age is reported) passes against the broken code, because the +// age is stored in whole seconds and a same-tick pin is legitimately 0. The unpin test below is the +// real coverage: `floorPinnedForMs >= 1000` across two sweeps is only reachable if the sweep noted +// the pin with a stable key both times. + +test('...and it publishes WHICH row, so the warning cannot name an innocent URL', async () => { + seed(backlogWithLateHome()); + await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal( + funnel.floorState().floorHeldBy, + 'https://www.kohls.com/product/prd-0/x|desktop', + 'floorState is what the console and the warning read; stale here names the wrong page' + ); +}); + +test('the sweep notes the pin AND runs the unpin hatch, so one wedged row cannot hold the floor forever', async () => { + // `unpinAfter` is the bound on a row whose render never posts a result. It is reached from the + // claim path today; if the ready set serves every claim, the sweep has to reach it instead. + const previous = config.queue.claimFloor.unpinAfter; + config.queue.claimFloor.unpinAfter = 1; + try { + seed([row('https://www.kohls.com/product/prd-0/x', 'desktop', T0 - 10 * 24 * HOUR)]); + // First sweep starts the pin clock; the hatch needs the pin to have LASTED, and the age is + // stored in whole seconds, so this waits past a second boundary rather than faking a clock the + // lease table does not take. + await funnel.sweepReadySet({ nowMs: T0 }); + await new Promise((resolve) => setTimeout(resolve, 1100)); + puts = []; + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + + assert.ok(sweep.floorPinnedForMs >= 1000, `pin should have aged, got ${sweep.floorPinnedForMs}`); + assert.ok(sweep.floorUnpinned, 'the hatch must fire from the sweep path'); + assert.equal(sweep.floorUnpinned.cacheKey, 'https://www.kohls.com/product/prd-0/x|desktop'); + // It moves the row FORWARD — the whole point is to let the floor advance past it. + const written = puts.find((p) => p.cacheKey === 'https://www.kohls.com/product/prd-0/x|desktop'); + assert.ok(written, 'the hatch writes the row'); + assert.ok(Number(written.nextRenderTime) > T0, 'and writes it into the future'); + } finally { + config.queue.claimFloor.unpinAfter = previous; + } +}); From 128bd497fda8860fe1801f101a9fc17cab42ec9e Mon Sep 17 00:00:00 2001 From: Joe Date: Fri, 21 Aug 2026 16:00:13 -0400 Subject: [PATCH 3/5] fix(plugin): default the sweep to 5 minutes, on evidence from the live cluster MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Checked the design against the reference deployment before rollout (4 nodes, 16 workers, Harper Pro 5.2.3), using already-computed signals only — analytics, system_information, logs. No scans. WHAT CONFIRMED THE DESIGN. `claim_scan_ms` reports `method: capped` on essentially every pass, 280 samples over six hours. `capped` means the pass read its whole window and never reached a not-yet-due row — and with lease_occupancy at 75-155 that window is ~205 rows. So the queue is choosing ~4 jobs out of ~205 rows that are all ancient and never sees the rest of the due set. That is the anchoring problem, measured in production rather than argued from a simulation. `floor_pin_age_ms` also moves between 2s and 481s, so the pin mechanism is genuinely live — which makes the regression the self-review caught (a sweep that stopped noting the pin would silently disable the wedged-row warning and unpinAfter) a real one on this cluster, not a theoretical one. WHAT CHANGED A DEFAULT. The marginal per-row read cost is uncertain by an order of magnitude: the synthetic benchmark says ~2.4us/row, but live a ~205-row window takes a 5-6ms median (p95 9-12ms) and `empty` passes average 25ms with 47ms observed, which are seek-dominated. At the wide end a one-minute sweep would spend a noticeable fraction of a core continuously on a worker that also serves bot traffic — for no benefit, since the ordering does not go stale that fast and `capacity` covers ~16 minutes of claims. So `sweepInterval` defaults to 5 minutes and `ready_sweep_ms` is what tightens it, because nothing else can: `overdue` saturates at `management.scanCap` (observed pinned at 2,000), so the backlog snapshot cannot tell an operator how many rows a sweep will walk. The nodes also swap (4.6GB used, 5.2GB free of 33.6GB), which promotes the bounded top-K from tidy to load-bearing and is now stated where someone would otherwise raise `capacity`. Routes are deployed with the intervals the scoring needs (/ 1h, /catalog/ 24h, /catalog.jsp 24h, /product/prd- 48h), so relative lateness will discriminate. Deployed plugin is v0.49.0, so this is the next version. 753 pass / 0 fail. Co-Authored-By: Claude Opus 5 --- packages/plugin/README.md | 25 +++++++++++++++++++++++++ packages/plugin/src/configSchema.js | 29 ++++++++++++++++++++++++----- 2 files changed, 49 insertions(+), 5 deletions(-) diff --git a/packages/plugin/README.md b/packages/plugin/README.md index 47caf44..faad79c 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -584,6 +584,31 @@ raise `queue.ready.sweepCap`. `queue.ready.enabled: false` claims straight from the index scan and stops the sweep — a true revert. +##### What the live cluster says about the defaults + +Checked against the reference deployment (4 nodes, 16 workers, Harper Pro 5.2.3) before rollout: + +- **`claim_scan_ms` reports `method: capped` on essentially every pass** — 280 samples over six hours. + `capped` means the pass read its whole window and never reached a not-yet-due row. With + `lease_occupancy` at 75–155 the window is ~205 rows, so the queue is choosing ~4 jobs out of ~205 + rows that are all ancient and never seeing the rest of the due set. That is the anchoring problem + this section describes, measured in production rather than argued from a simulation. +- **The marginal per-row read cost is uncertain by an order of magnitude.** A synthetic benchmark says + ~2.4 µs/row; live, a ~205-row window takes a 5–6 ms median (p95 9–12 ms) and `empty` passes average + 25 ms with 47 ms observed, which are seek-dominated. That is why `sweepInterval` defaults to five + minutes rather than one, and why `ready_sweep_ms` exists — it is the only thing that will tell you + the real number for your corpus. +- **The due-set size cannot be read from the backlog snapshot.** `overdue` saturates at + `management.scanCap` (observed pinned at 2,000), so "how many rows will the sweep walk" is answered + by `ready_sweep_ms` and the sweep's own `scanned` count, not by the overview. +- **The nodes swap** (4.6 GB in use, 5.2 GB free of 33.6 GB). This is why the sweep streams rows + through a bounded heap and retains only `capacity` of them: its memory is a function of the set + size, never of the due set. A design that sorted the due set would be actively unsafe here, and it + is why `capacity` should not be raised casually. +- **The sweep cannot make a cross-node request.** It reuses the same query the claim scan uses, which + carries `replicateFrom: false`, and it performs no point reads at all — so it cannot take the + untimed replication fetch that an unowned point read on this residency-pinned table would. + ## HTTP & resource API | Method & path | Purpose | diff --git a/packages/plugin/src/configSchema.js b/packages/plugin/src/configSchema.js index 0e589fb..543a158 100644 --- a/packages/plugin/src/configSchema.js +++ b/packages/plugin/src/configSchema.js @@ -1291,7 +1291,14 @@ export const configSchema = group('Prerender plugin configuration.', { 5000, 'Entries the ready set holds. Sized to cover several sweep intervals of claims so the set ' + 'does not run dry between sweeps: at the recorded fleet throughput a node grants roughly ' + - '5 jobs a second, so 5,000 entries is about 16 minutes of work.\n\n' + + '5 jobs a second (observed live: ~70-75 claims a minute), so 5,000 entries is about 16 ' + + 'minutes of work — three sweep intervals at the default.\n\n' + + 'DO NOT RAISE THIS CASUALLY. The reference cluster runs with 4.6GB of swap in use and 5.2GB ' + + 'free of 33.6GB, so shared memory on these nodes is not free. A larger set does not improve ' + + 'the ordering either — the sweep already scores every due row and keeps the best of them, so ' + + 'this only buys time between sweeps. What makes the sweep safe on a swapping node is that ' + + 'its own memory is a function of THIS number and not of the due set: it streams rows through ' + + 'a bounded heap and retains only the best `capacity`.\n\n' + 'Costs `capacity x ~276 x 2` bytes of shared memory — two slots, so ~2.8MB at the default. ' + 'Raising it does ' + 'NOT make the ordering better — the sweep already scores every due row and keeps the best ' + @@ -1302,12 +1309,24 @@ export const configSchema = group('Prerender plugin configuration.', { { min: 0, scope: 'restart' } ), sweepInterval: option( - MINUTE, + 5 * MINUTE, 'How often worker 0 re-scores the due set and republishes.\n\n' + 'This is the ORDERING STALENESS: a row that becomes due just after a sweep waits up to one ' + - 'interval before it can be ranked. One minute against cadences of an hour and up is a ' + - 'rounding error, and the cost is one read of the due set — ~480ms per 200,000 due rows, on ' + - 'a worker that yields every 200 rows (measured free) so it never holds the loop.\n\n' + + 'interval before it can be ranked. Five minutes against cadences of an hour and up is a ' + + 'rounding error, and `capacity` covers roughly three of these intervals of claims, so the ' + + 'set does not run dry between sweeps.\n\n' + + 'FIVE MINUTES RATHER THAN ONE, on production evidence. A synthetic benchmark puts a ' + + 'projected one-sided read at ~2.4us/row, which would make a sweep sub-second — but the live ' + + 'cluster reports `claim_scan_ms` at a 5-6ms median over a window of roughly 205 rows ' + + '(grantLimit + in-flight + grantLimit, at an observed lease occupancy of 75-155), and ' + + '`empty` passes at a 25ms mean with 47ms observed, which are seek-dominated. So the real ' + + 'marginal per-row cost sits somewhere between 2.4us and ~25us — an order of magnitude of ' + + 'uncertainty — and the sweep shares a worker with bot traffic. At the wide end a ' + + 'one-minute interval would spend a noticeable fraction of a core continuously, for no ' + + 'benefit: the ordering does not go stale that fast.\n\n' + + 'WATCH `ready_sweep_ms` AND TIGHTEN FROM THERE. It reports the real number for your corpus, ' + + 'which is the only way to know it — the backlog snapshot cannot tell you the due-set size ' + + 'either, because `overdue` saturates at `management.scanCap` (observed pinned at 2,000).\n\n' + '`0` disables the sweep, which leaves the set to go stale and then empty; claims fall back ' + 'to the index scan as they always do.', { unit: 'ms', min: 0 } From 8774a7ce3c45c91a3a31e33d470bf612043f2308 Mon Sep 17 00:00:00 2001 From: Joe Date: Fri, 21 Aug 2026 16:06:10 -0400 Subject: [PATCH 4/5] =?UTF-8?q?fix(plugin):=20address=20review=20=E2=80=94?= =?UTF-8?q?=20a=20cursor=20clamp=20that=20could=20skip=20a=20whole=20gener?= =?UTF-8?q?ation?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four findings from @gemini-code-assist on #120; three applied, one declined. THE REAL ONE. `take()` clamped the exhausted cursor with a plain `Atomics.store(H_CURSOR, count)`, which races `publish`: publish resets the cursor to 0 and flips the slot, and a store landing just after that rewinds it to the PREVIOUS generation's count — so every entry of the fresh set is skipped, silently, until the next sweep replaces it. A `compareExchange` from `index + 1` only clamps if the cursor is still where this call's own increment left it, so a concurrent reset always wins. No test can reach it: two threads are needed, and single-threaded nothing can interleave between the add and the clamp. That is stated in the comment rather than left to be rediscovered. THE LATCH. `sweeping` is set before `sweepReadySet()` is called, so a synchronous throw from that call would leave it set forever — the sweep permanently dead for the life of the process, with claims quietly falling back to the index scan and nothing saying why. The invocation is now inside the try, and errors go through a `messageOf` helper for the reason `util/configOverride.js` already documents: anything can be thrown, and `null.message` is a TypeError raised from inside the handler that exists to keep the path alive. THE TIMER CEILING. `sweepInterval` now carries `max: 2147483647` in the schema and is clamped at the `setInterval` site, following the pattern and the reasoning in `util/configOverride.js`: past 2^31-1 ms node warns and then fires the callback after ONE MILLISECOND, so an over-large interval turns the sweep into a hot loop over the due set rather than slowing it down. The schema rejection is the loud path; the clamp is so the loud path working is not the only thing between a typo and that loop. DECLINED, WITH THE UNDERLYING CONCERN ACCEPTED. The suggested `safeDivide` helper for `scoreOf` guards a trap that is already closed: `intervalMs > 0` is false for null, undefined, NaN, 0 and every negative, so nothing is ever coerced and `Number(null) === 0` cannot arise. Adding a `typeof` check would only change behaviour for a numeric-string interval, which works correctly today and is now pinned by a test. But it made me look at the other half of the same expression, where the trap is real: `nowMs - null` is `nowMs`, so an absent DUE TIME produces a lateness of ~1.8e12 and sorts a broken row straight to the head of the set. The sweep filters non-finite due times before scoring, but `scoreOf` is exported, so the guard now lives with the arithmetic. Zero is the right answer — a row with no due time makes no claim to urgency. 755 pass / 0 fail. --- packages/plugin/src/configSchema.js | 6 +- packages/plugin/src/resources/RenderQueue.js | 80 ++++++++++++++------ packages/plugin/src/util/readyQueue.js | 10 ++- packages/plugin/src/util/renderPriority.js | 18 ++++- packages/plugin/test/readyQueue.test.js | 15 ++++ 5 files changed, 99 insertions(+), 30 deletions(-) diff --git a/packages/plugin/src/configSchema.js b/packages/plugin/src/configSchema.js index 543a158..333d828 100644 --- a/packages/plugin/src/configSchema.js +++ b/packages/plugin/src/configSchema.js @@ -1328,8 +1328,10 @@ export const configSchema = group('Prerender plugin configuration.', { 'which is the only way to know it — the backlog snapshot cannot tell you the due-set size ' + 'either, because `overdue` saturates at `management.scanCap` (observed pinned at 2,000).\n\n' + '`0` disables the sweep, which leaves the set to go stale and then empty; claims fall back ' + - 'to the index scan as they always do.', - { unit: 'ms', min: 0 } + 'to the index scan as they always do. The ceiling is node\u2019s own timer limit of 2^31-1 ms ' + + '(~24.8 days) \u2014 past it a timer fires every millisecond rather than never, which would ' + + 'turn the sweep into a hot loop over the due set.', + { unit: 'ms', min: 0, max: 2147483647 } ), sweepCap: option( 500_000, diff --git a/packages/plugin/src/resources/RenderQueue.js b/packages/plugin/src/resources/RenderQueue.js index 28ac2d0..b379d33 100644 --- a/packages/plugin/src/resources/RenderQueue.js +++ b/packages/plugin/src/resources/RenderQueue.js @@ -956,6 +956,22 @@ let queueStatusSyncStarted = false; */ let readySweepStarted = false; +/** + * `e?.message`, never `e.message`: anything can be thrown, and `null.message` is a TypeError raised + * from inside the very handler that exists to keep this path alive. Same helper and same reasoning as + * `util/configOverride.js`. + */ +const messageOf = (e) => e?.message ?? String(e); + +/** + * Node's `setInterval` ceiling. Past 2^31-1 ms the delay overflows: node warns and then fires the + * callback after ONE MILLISECOND. So an over-large sweep interval does not merely slow the sweep + * down, it converts it into a hot loop re-reading the due set on worker 0 — the opposite of what the + * number asked for. The schema rejects anything larger with a warning, which is the loud path; this + * clamp is here so that the loud path working is not the only thing between a typo and that loop. + */ +const MAX_TIMER_MS = 2147483647; + export function startReadySweep() { if (server.workerIndex !== 0 || readySweepStarted) return; readySweepStarted = true; @@ -966,43 +982,57 @@ export function startReadySweep() { if (sweeping || !config.queue.ready.enabled) return; sweeping = true; const started = performance.now(); - sweepReadySet() - .then((result) => { - if (result?.skipped) return; - metrics.readySweep(performance.now() - started, result.truncated ? 'capped' : 'complete'); - metrics.readyPublished(result.published); - if (result.truncated) { - // The rows past the cap are the YOUNGEST, so a truncated sweep leaves recently-due pages - // unranked — precisely the pages this feature exists to protect. That makes it a warning - // rather than a statistic. - logger.warn( - `[prerender] ready-set sweep read its ${config.queue.ready.sweepCap}-row cap without reaching a ` + - `not-yet-due row: ${result.due} due row(s) seen, ${result.published} published. The ordering ` + - `covers only the oldest part of the backlog, so recently-due pages are going unranked. Raise ` + - `queue.ready.sweepCap, or reduce the backlog.` - ); - } - }) - .catch(logger.error) - .finally(() => { - sweeping = false; - }); + // THE SYNCHRONOUS INVOCATION IS INSIDE THE TRY, not just the promise chain. `sweeping` is a + // latch: if the call throws before returning a promise, `finally` never runs, the latch is never + // released, and the sweep is permanently dead for the life of the process — with claims quietly + // falling back to the index scan and nothing saying why. That silent-forever failure is worth + // more than the narrow chance of the throw. + try { + sweepReadySet() + .then((result) => { + if (result?.skipped) return; + metrics.readySweep(performance.now() - started, result.truncated ? 'capped' : 'complete'); + metrics.readyPublished(result.published); + if (result.truncated) { + // The rows past the cap are the YOUNGEST, so a truncated sweep leaves recently-due pages + // unranked — precisely the pages this feature exists to protect. That makes it a warning + // rather than a statistic. + logger.warn( + `[prerender] ready-set sweep read its ${config.queue.ready.sweepCap}-row cap without reaching a ` + + `not-yet-due row: ${result.due} due row(s) seen, ${result.published} published. The ordering ` + + `covers only the oldest part of the backlog, so recently-due pages are going unranked. Raise ` + + `queue.ready.sweepCap, or reduce the backlog.` + ); + } + }) + .catch((e) => logger.error(messageOf(e))) + .finally(() => { + sweeping = false; + }); + } catch (e) { + logger.error(messageOf(e)); + sweeping = false; + } }; // Once immediately, so a restarted worker generation does not serve a whole interval of claims // from the index before the set exists. sweep(); + const arm = (ms) => { + const timer = ms > 0 ? setInterval(sweep, Math.min(MAX_TIMER_MS, ms)) : null; + timer?.unref?.(); + return timer; + }; + let armed = config.queue.ready.sweepInterval; - let timer = armed > 0 ? setInterval(sweep, armed) : null; - timer?.unref?.(); + let timer = arm(armed); onConfigApplied(() => { if (config.queue.ready.sweepInterval === armed) return; if (timer) clearInterval(timer); armed = config.queue.ready.sweepInterval; - timer = armed > 0 ? setInterval(sweep, armed) : null; - timer?.unref?.(); + timer = arm(armed); }); } diff --git a/packages/plugin/src/util/readyQueue.js b/packages/plugin/src/util/readyQueue.js index 356bf52..6fdeff6 100644 --- a/packages/plugin/src/util/readyQueue.js +++ b/packages/plugin/src/util/readyQueue.js @@ -233,7 +233,15 @@ export const createReadyQueue = ({ buffer, capacity, now = Date.now } = {}) => { // Do not let the cursor run away past the count while a set is exhausted: it is an // Int32 and a busy node claims several times a second, so an unbounded increment would // wrap in about eight days of idling and start handing out valid indices again. - Atomics.store(i32, H_CURSOR, count); + // + // A COMPARE-EXCHANGE, NOT A STORE, and the difference is a whole generation. A plain + // store here races `publish`: publish resets the cursor to 0 and flips the slot, and a + // store landing just after that rewinds it to the PREVIOUS generation's count — so every + // entry of the fresh set is skipped, silently, until the next sweep replaces it. The CAS + // only clamps if the cursor is still where this call's own increment left it, so a + // concurrent reset always wins. (Two threads are needed to hit it, which is why no test + // here can: single-threaded, nothing can interleave between the add and the clamp.) + Atomics.compareExchange(i32, H_CURSOR, index + 1, count); break; } const entry = readEntry(slot, index); diff --git a/packages/plugin/src/util/renderPriority.js b/packages/plugin/src/util/renderPriority.js index 2e1c965..3623585 100644 --- a/packages/plugin/src/util/renderPriority.js +++ b/packages/plugin/src/util/renderPriority.js @@ -63,11 +63,25 @@ * scored, and a negative score from a clock skew would sort a due row BELOW rows that are exactly on * time, which is the one ordering that makes no sense at all. * - * The only guard is the division. A zero or negative interval would produce Infinity or a sign flip, - * so it degrades to raw lateness — which still orders sensibly among rows that share the problem. + * Two guards, and they are guarding different things. The DUE TIME is validated because an absent one + * does not degrade gracefully — `nowMs - null` is `nowMs`, a lateness of ~1.8e12 that sorts a broken + * row straight to the head. The INTERVAL is only compared, not validated, because `> 0` is already + * false for every unusable value; a zero or negative one would produce Infinity or a sign flip, so it + * degrades to raw lateness, which still orders sensibly among rows that share the problem. */ export const scoreOf = ({ dueAt, fromSitemap }, { nowMs, intervalMs, sitemapBoost = 1 }) => { + // THE DUE TIME IS GUARDED, AND IT IS THE DANGEROUS ONE. `nowMs - null` is `nowMs`, so an absent + // due time does not produce a small score or a NaN — it produces a lateness of ~1.8e12, which sorts + // straight to the head of the set and hands the next lease to a broken row. `sweepReadySet` filters + // non-finite due times before it gets here, but this is exported and scored by callers that have + // not, so the guard belongs with the arithmetic. Zero is the right answer: a row with no due time + // makes no claim to urgency. + if (!Number.isFinite(dueAt) || !Number.isFinite(nowMs)) return 0; const lateness = Math.max(0, nowMs - dueAt); + // The interval needs no such guard, and deliberately does not get one: `> 0` is already false for + // null, undefined, NaN, 0 and every negative, so the `Number(null) === 0` trap is closed by the + // comparison rather than by a coercion. Adding a `typeof` check would only change behaviour for a + // numeric STRING interval, which works correctly today. const ratio = intervalMs > 0 ? lateness / intervalMs : lateness; return fromSitemap ? ratio * sitemapBoost : ratio; }; diff --git a/packages/plugin/test/readyQueue.test.js b/packages/plugin/test/readyQueue.test.js index 2c9fdc7..2847201 100644 --- a/packages/plugin/test/readyQueue.test.js +++ b/packages/plugin/test/readyQueue.test.js @@ -69,6 +69,21 @@ test('a zero or negative interval degrades to raw lateness rather than Infinity assert.equal(scoreOf({ dueAt: T0 - 5 }, { nowMs: T0, intervalMs: -HOUR }), 5); }); +test('an ABSENT due time scores 0, not the epoch — it must not sort to the head', () => { + // `nowMs - null` is `nowMs`, so the naive form gives a lateness of ~1.8e12 and a broken row wins + // the next lease outright. This is the trap that actually bites; the interval's `> 0` guard already + // closes the divisor half. + for (const dueAt of [null, undefined, Number.NaN, 'x']) { + assert.equal(scoreOf({ dueAt }, { nowMs: T0, intervalMs: HOUR }), 0, `dueAt=${dueAt}`); + } + // ...and a genuinely late row still scores, so the guard has not swallowed the real case. + assert.equal(scoreOf({ dueAt: T0 - HOUR }, { nowMs: T0, intervalMs: HOUR }), 1); +}); + +test('a numeric-string interval still divides — the guard is a comparison, not a typeof check', () => { + assert.equal(scoreOf({ dueAt: T0 - HOUR }, { nowMs: T0, intervalMs: String(HOUR) }), 1); +}); + test('a row scored at or before its due moment is 0, never negative', () => { assert.equal(scoreOf({ dueAt: T0 }, { nowMs: T0, intervalMs: HOUR }), 0); assert.equal(scoreOf({ dueAt: T0 + HOUR }, { nowMs: T0, intervalMs: HOUR }), 0); From 4c8cacdcdb6534404209a2575257ac6d6eb86dc3 Mon Sep 17 00:00:00 2001 From: Joe Date: Fri, 21 Aug 2026 16:39:30 -0400 Subject: [PATCH 5/5] fix(plugin): score a row by its own cadence, not its route's ceiling MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The sweep resolved every row's cadence from config, which cannot see the demand ladder. A route grants a CEILING — `/catalog/` at 24h — and `render.demand` promotes bot-visited targets beneath it to 12h or 6h, writing `now + rung` as the due time. So dividing lateness by the route understated a promoted page's overdue-ness by up to 4x, on precisely the pages the ladder singled out as worth rendering more often. The feature was discarding the ladder's work. Priority cannot be recovered from RenderTarget at scoring time: that is a cross-database point read per row over the whole due set, ~75% of them replication fetches on a residency-pinned table. So the cadence travels ON the row. `RenderSchedule.effectiveInterval` (non-indexed) is written by every schedule writer through the funnel and read in a projection the sweep already pays for — no extra read. `resolveEffectiveInterval` resolves rung > route > stored > default, clamping a stale rung to the ceiling exactly as `decideInterval` does, so a lowered route cannot make an old rung read as slower. The field is the page's CADENCE, not the gap that was written: a suppression recheck files 7 days and a backoff files its backoff, and neither is a cadence. That is the same distinction that makes the score lateness rather than age, so those writers file the cadence and not the gap they used. Absent is legal and self-healing. Pre-upgrade rows and the writers with no cadence in hand fall back to resolving from config, which is what the sweep did before — so the first sweep after a deploy behaves exactly as it does today and the corpus fills in as rows re-render. `queue_health` `ready_cadence` (carried/resolved) is the gauge for that crossover; a ratio that stays low means rows are being filed without a cadence, which no other series would show. Required explicitly, like `fromSitemap`, and for the same hazard: `put` replaces the record, so a writer that omits it does not leave the old value alone, it ERASES a correct cadence off a row that had one. Found while wiring it, and it would have been a silent deploy-day regression: `maybeUnpinFloor` handed the row's raw cadence back to the funnel. Every row written before this field exists carries `undefined`, the funnel now refuses that, and the refusal lands inside the hatch's own try/catch — logged, swallowed, nothing pushed, nothing reported. The one mechanism that bounds a wedged row would have been dead on every node for a full cadence after the upgrade. It now files the cadence it resolved, which also keeps `nextRenderTime - effectiveInterval === now` and leaves the row self-describing. Closes the sitemap half too: ingest goes through `Target.put` with the changefreq-derived interval, so those cadences now reach the row instead of being scored as `render.defaultInterval`. 763 tests pass. Four of the new tests were verified to fail against the code they describe. Co-Authored-By: Claude Opus 5 --- packages/plugin/METRICS.md | 55 ++++----- packages/plugin/README.md | 19 ++- .../plugin/src/http_handlers/bot_request.js | 22 +++- packages/plugin/src/metrics.js | 14 +++ .../plugin/src/resources/PrerenderAdmin.js | 12 +- packages/plugin/src/resources/RenderQueue.js | 51 +++++++- packages/plugin/src/resources/Target.js | 25 +++- packages/plugin/src/schemas/schema.graphql | 18 +++ .../plugin/src/util/invalidationReenqueue.js | 14 ++- packages/plugin/src/util/reconcile.js | 12 +- packages/plugin/src/util/renderSchedule.js | 110 ++++++++++++++---- packages/plugin/src/util/routeClass.js | 27 +++++ packages/plugin/test/readySweep.test.js | 103 +++++++++++++++- packages/plugin/test/renderQueueFloor.test.js | 46 ++++++-- packages/plugin/test/renderQueuePin.test.js | 45 +++++++ packages/plugin/test/routeClass.test.js | 47 ++++++++ 16 files changed, 542 insertions(+), 78 deletions(-) diff --git a/packages/plugin/METRICS.md b/packages/plugin/METRICS.md index 8e24c3a..75b6ba7 100644 --- a/packages/plugin/METRICS.md +++ b/packages/plugin/METRICS.md @@ -121,17 +121,17 @@ PK drives the scan (an open range can make the planner walk a metric's entire hi One-line summaries; `src/metrics.js` carries the full description of every dimension value and the reasoning behind it. -| Metric | Kind | `path` | `method` | `type` | What it's for | -| ---------------- | ------- | ---------- | ----------- | ---------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `bot_request` | counter | host | botName | deviceType | Raw crawl volume and mix at ingress. The denominator for every serve-side ratio. | -| `bot_serve` | counter | source | cacheStatus | botName | **Origin offload** and **cache hit rate** — the two rollout numbers. | -| `route_serve` | counter | route | cacheStatus | deviceType | The same outcome per route: which route's `renderInterval` needs to move. | -| `page_age` | ms | botName | deviceType | — | Freshness as delivered: ms since the served snapshot rendered (cache serves only). | -| `route_page_age` | ms | route | cacheStatus | deviceType | Served age per route, split by freshness state — the "should this TTL move" number. | -| `render` | value | series | per-series | per-series | The render fleet in one scan: `time_ms` (duration by statusCode × candidacy — renders/hour = concurrency ÷ time_ms) and `outcome` (counter by outcome × detail, exactly one per posted result — the render-failure alert). | -| `origin_fetch` | ms | statusCode | reason | — | Cost of every non-cache serve: origin latency + status, by why the cache didn't answer (miss/stale/skip/invalidated/bypass/blob-missing/blob-timeout/render-timeout). | -| `prerender_ops` | value | series | detail | context | Every low-volume ops signal in one scan: `unrouted` (class, bucket), `sitemap_*`, `serve_error`, `config_warnings`, `page_age_negative` (bot, device), `demand_*` (ladder decisions + `fast_fraction`/`fill`), `invalidation_error` (kind), `invalidation_reenqueue` (outcome, scope). | -| `queue_health` | value | series | result | — | Every queue signal in one scan: the snapshot gauges (`overdue`, `lease_occupancy`, `below_floor`, `below_floor_age_ms`, `floor_pin_age_ms`, `paused`), `claim_scan_ms` (per pass, method = granted/empty/capped), `claim_granted` (per claim, method = ready/index), `ready_sweep_ms` (per sweep, method = complete/capped), `ready_published`, `reconcile_restored`/`reconcile_missing` (per sweep). | +| Metric | Kind | `path` | `method` | `type` | What it's for | +| ---------------- | ------- | ---------- | ----------- | ---------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `bot_request` | counter | host | botName | deviceType | Raw crawl volume and mix at ingress. The denominator for every serve-side ratio. | +| `bot_serve` | counter | source | cacheStatus | botName | **Origin offload** and **cache hit rate** — the two rollout numbers. | +| `route_serve` | counter | route | cacheStatus | deviceType | The same outcome per route: which route's `renderInterval` needs to move. | +| `page_age` | ms | botName | deviceType | — | Freshness as delivered: ms since the served snapshot rendered (cache serves only). | +| `route_page_age` | ms | route | cacheStatus | deviceType | Served age per route, split by freshness state — the "should this TTL move" number. | +| `render` | value | series | per-series | per-series | The render fleet in one scan: `time_ms` (duration by statusCode × candidacy — renders/hour = concurrency ÷ time_ms) and `outcome` (counter by outcome × detail, exactly one per posted result — the render-failure alert). | +| `origin_fetch` | ms | statusCode | reason | — | Cost of every non-cache serve: origin latency + status, by why the cache didn't answer (miss/stale/skip/invalidated/bypass/blob-missing/blob-timeout/render-timeout). | +| `prerender_ops` | value | series | detail | context | Every low-volume ops signal in one scan: `unrouted` (class, bucket), `sitemap_*`, `serve_error`, `config_warnings`, `page_age_negative` (bot, device), `demand_*` (ladder decisions + `fast_fraction`/`fill`), `invalidation_error` (kind), `invalidation_reenqueue` (outcome, scope). | +| `queue_health` | value | series | result | — | Every queue signal in one scan: the snapshot gauges (`overdue`, `lease_occupancy`, `below_floor`, `below_floor_age_ms`, `floor_pin_age_ms`, `paused`), `claim_scan_ms` (per pass, method = granted/empty/capped), `claim_granted` (per claim, method = ready/index), `ready_sweep_ms` (per sweep, method = complete/capped), `ready_published`, `ready_cadence` (per sweep, method = carried/resolved), `reconcile_restored`/`reconcile_missing` (per sweep). | Notes that bite: @@ -358,22 +358,23 @@ The catalog above is reference; this is the short list. "Sum across nodes" is im **Thresholds — warn, then investigate:** -| Condition | Meaning | -| ----------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `queue_health` `overdue` − `lease_occupancy` growing snapshot-over-snapshot | The fleet is falling behind demand (remember: `overdue`'s healthy floor IS the in-flight count). | -| `queue_health` `floor_pin_age_ms` > ~1 h | One key is holding the claim scan's seek position — the whole node's queue ages behind it. | -| `bot_serve` swr share rising / `route_page_age` p95 > that route's `renderInterval` | The cadence is configured but not delivered — a capacity or scheduling problem, not a config one. | -| `bot_serve` miss share rising | Coverage: new URLs the corpus doesn't have, or the CDN forwarding paths it shouldn't (check `unrouted`). | -| `duration` p95 (`path: 'p'`) or `success` ratio degrading | The crawler-facing SLO, independent of any plugin-level explanation. | -| `queue_status` report timestamp stale, or intent ≠ observed > one sync interval | A node stopped reporting (and likely claiming), or pause propagation is stuck. | -| `render` outcome `suppressed` or `failed` share rising | Mass suppression (an origin change disavowing pages) or a failing fleet — shares are readable directly because outcomes sum to results. | -| `queue_health` `claim_scan_ms` p95 trending up | The scan is degrading (dead index entries at the seek point) before any backlog shows. Watch the trend, not the absolute number. | -| `queue_health` `claim_granted` all `index`, none `ready` | Prioritisation is not engaging: the sweep is failing, the ready buffer could not be sized, or the set is always dry. The queue looks healthy in every other series because the ready set reorders a fixed amount of work and moves no total. | -| `queue_health` `ready_sweep_ms` method `capped` | The sweep hit `queue.ready.sweepCap` without reaching a not-yet-due row, so it is ordering the oldest part of the backlog only — the rows it skipped are the youngest, i.e. exactly the recently-due pages the ordering exists to protect. | -| `queue_health` `ready_published` at 0 with a non-empty backlog | The sweep is running and finding nothing to publish. Check `queue.ready.capacity` was sizeable at boot (it is restart-scoped) and that the claim floor has not advanced past the due set. | -| `origin_fetch` p95 or 5xx/`0` share rising | Origin trouble that bots feel directly on every miss; a rising `render-timeout` share is renderNow falling back. | -| `queue_health` `paused` = 1 beyond the expected window | A node's queue is paused longer than whoever paused it intended. | -| `prerender_ops` series `config_warnings` changed after a deploy | The deploy introduced a finding; `GET /prerender_admin/config` names it. | +| Condition | Meaning | +| ----------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| `queue_health` `overdue` − `lease_occupancy` growing snapshot-over-snapshot | The fleet is falling behind demand (remember: `overdue`'s healthy floor IS the in-flight count). | +| `queue_health` `floor_pin_age_ms` > ~1 h | One key is holding the claim scan's seek position — the whole node's queue ages behind it. | +| `bot_serve` swr share rising / `route_page_age` p95 > that route's `renderInterval` | The cadence is configured but not delivered — a capacity or scheduling problem, not a config one. | +| `bot_serve` miss share rising | Coverage: new URLs the corpus doesn't have, or the CDN forwarding paths it shouldn't (check `unrouted`). | +| `duration` p95 (`path: 'p'`) or `success` ratio degrading | The crawler-facing SLO, independent of any plugin-level explanation. | +| `queue_status` report timestamp stale, or intent ≠ observed > one sync interval | A node stopped reporting (and likely claiming), or pause propagation is stuck. | +| `render` outcome `suppressed` or `failed` share rising | Mass suppression (an origin change disavowing pages) or a failing fleet — shares are readable directly because outcomes sum to results. | +| `queue_health` `claim_scan_ms` p95 trending up | The scan is degrading (dead index entries at the seek point) before any backlog shows. Watch the trend, not the absolute number. | +| `queue_health` `claim_granted` all `index`, none `ready` | Prioritisation is not engaging: the sweep is failing, the ready buffer could not be sized, or the set is always dry. The queue looks healthy in every other series because the ready set reorders a fixed amount of work and moves no total. | +| `queue_health` `ready_sweep_ms` method `capped` | The sweep hit `queue.ready.sweepCap` without reaching a not-yet-due row, so it is ordering the oldest part of the backlog only — the rows it skipped are the youngest, i.e. exactly the recently-due pages the ordering exists to protect. | +| `queue_health` `ready_published` at 0 with a non-empty backlog | The sweep is running and finding nothing to publish. Check `queue.ready.capacity` was sizeable at boot (it is restart-scoped) and that the claim floor has not advanced past the due set. | +| `queue_health` `ready_cadence` still mostly `resolved` after a full cadence | Rows are being filed without an `effectiveInterval`, so the sweep is scoring them against their ROUTE ceiling rather than their demand-ladder rung — a promoted page reads as up to 4x less overdue than it is. Expected to be all `resolved` on the first sweep after an upgrade and to cross over as rows re-render; if it does not, a writer is passing `null` or the corpus is not re-rendering. | +| `origin_fetch` p95 or 5xx/`0` share rising | Origin trouble that bots feel directly on every miss; a rising `render-timeout` share is renderNow falling back. | +| `queue_health` `paused` = 1 beyond the expected window | A node's queue is paused longer than whoever paused it intended. | +| `prerender_ops` series `config_warnings` changed after a deploy | The deploy introduced a finding; `GET /prerender_admin/config` names it. | **Absence is a signal — alert when a series stops:** diff --git a/packages/plugin/README.md b/packages/plugin/README.md index faad79c..cc50b38 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -548,12 +548,29 @@ reads no index at all. That is affordable because of one measured fact cost ~480 ms and a 500k-row overdue set ~1.2 s, with **zero writes**. Writes are 76–89 µs/row, 32× a read, so reading liberally and writing not at all is the cheap direction. -The score is `max(0, now − dueAt) / renderInterval`, multiplied by `queue.ready.sitemapBoost` for a +The score is `max(0, now − dueAt) / effectiveInterval`, multiplied by `queue.ready.sitemapBoost` for a sitemap-sourced row. Lateness rather than age, deliberately: `dueAt − interval` is not when the page last rendered for every row — suppression rechecks schedule 7 days, `backoffWait` up to `maxBackoff`, the unpin hatch a `defaultInterval` — so an age-based ratio would put a 7-day recheck on a 48 h route at the _head_ of the queue reading as 3.5 cadences stale. +**The cadence is the row's own, not the route's** — and this is load-bearing rather than a detail. +A route grants a _ceiling_ (`/catalog/` at 24 h) and `render.demand` promotes bot-visited targets +beneath it to 12 h or 6 h, writing `now + rung` as the due time. Resolving the denominator from config +would therefore divide a promoted page's lateness by 24 h when it is really on 6 h — a **4× under- +statement, on precisely the pages the ladder singled out as worth rendering more often**, silently +undoing the ladder's work. So every schedule writer files the cadence it used onto the row as +`effectiveInterval` (`resolveEffectiveInterval`: rung > route > stored > default, the rung clamped to +the ceiling so a stale one cannot read as slower), and the sweep divides by that. It rides along in a +projection the sweep already pays for, so it costs no extra read — recovering it from `RenderTarget` +instead would be a cross-database point read per row over the whole due set, ~75% of them replication +fetches on a residency-pinned table. + +The field is **absent and self-healing** on rows written before it existed, and on the writers with no +cadence in hand: the sweep falls back to resolving from config, which is exactly what it did before, +and each row fills in when it next renders. `queue_health` `ready_cadence` (`carried`/`resolved`) is +the gauge — all `resolved` on the first sweep after an upgrade, crossing over within one cadence. + Three properties are worth knowing: - **It is a cache in front of the old path, not a replacement.** Cold (a fresh worker generation), diff --git a/packages/plugin/src/http_handlers/bot_request.js b/packages/plugin/src/http_handlers/bot_request.js index 59d4321..7ab1c08 100644 --- a/packages/plugin/src/http_handlers/bot_request.js +++ b/packages/plugin/src/http_handlers/bot_request.js @@ -6,7 +6,13 @@ import { canonicalizeUrl } from '../util/url.js'; import { config } from '../config.js'; import { sanitizeDeviceType } from '../util/device_type.js'; import { resolveForwardedRequest } from '../util/ingress.js'; -import { classifyPath, isForwardedMode, routeScopeForEntry, PRERENDER } from '../util/routeClass.js'; +import { + classifyPath, + isForwardedMode, + resolveEffectiveInterval, + routeScopeForEntry, + PRERENDER, +} from '../util/routeClass.js'; import { Target } from '../resources/Target.js'; import { QueueState } from '../resources/QueueState.js'; import { fetchOriginResource } from '../util/upstream.js'; @@ -371,7 +377,7 @@ async function renderNow({ url, cacheUrl, deviceType, cacheKey, request, routeSc // The target is the field's source of truth (`RenderQueue` re-derives it from there on every // reschedule for exactly that reason). NO target is the legitimate render-now one-off shape, where // `false` is the true answer. - const renderTarget = await Target.get({ id: cacheUrl, select: ['sitemapUrl'] }); + const renderTarget = await Target.get({ id: cacheUrl, select: ['sitemapUrl', 'renderInterval', 'demandInterval'] }); // Force an immediately-claimable, one-off schedule. No Target is created, so // processJobResult won't reschedule it — and drops the schedule row once the result @@ -383,7 +389,17 @@ async function renderNow({ url, cacheUrl, deviceType, cacheKey, request, routeSc // would strand: on this node the funnel lowers the floor in-process, and on any other node — // which is ~75% of keys, since schedule rows are residency-pinned — the guard band is what // keeps the row above the owner's floor and therefore claimable. - await writeSchedule(cacheKey, { nextRenderTime: currentMinuteMs(), fromSitemap: !!renderTarget?.sitemapUrl }); + await writeSchedule(cacheKey, { + nextRenderTime: currentMinuteMs(), + fromSitemap: !!renderTarget?.sitemapUrl, + // PRESERVED WHEN THERE IS A TARGET, `null` WHEN THERE IS NOT — and the difference matters because + // `put` replaces the record. This key may be a real target's recurring row (a warm-on-demand + // render-now), and filing `null` there would strip its cadence and demote the page in the next + // sweep. With no target this is the render-now one-off shape, which has no cadence to record: the + // row is dropped once the result lands. Either way it is due at the current minute, so its own + // ranking is unaffected — this is about not damaging the row on the way past. + effectiveInterval: renderTarget ? resolveEffectiveInterval(cacheUrl, renderTarget) : null, + }); // Wake idle consumers now instead of waiting out the periodic status sync. Non-force // so a paused queue stays paused (the render then simply times out to the fallback). diff --git a/packages/plugin/src/metrics.js b/packages/plugin/src/metrics.js index aba5d58..0e5cd19 100644 --- a/packages/plugin/src/metrics.js +++ b/packages/plugin/src/metrics.js @@ -658,6 +658,20 @@ export const metrics = Object.freeze({ /** How many entries the last sweep published — the ordering's supply. */ readyPublished: (count) => server.recordAnalytics(count, 'queue_health', 'ready_published', null, null), + /** + * How much of the due set the last sweep could score against its REAL cadence, `carried` vs + * `resolved`. + * + * The backfill gauge, and the only way to see it land. `effectiveInterval` is written by the + * schedule writers, so it is absent on every row until that row re-renders: this reads all + * `resolved` on the first sweep after an upgrade and should cross over within one cadence. A ratio + * that STAYS low is the interesting signal — it means rows are being filed without a cadence (a + * writer passing `null`, a corpus that is not re-rendering) and the demand ladder's promotions are + * being scored against their route ceilings, which is the exact bug this field exists to fix. It + * cannot be inferred from anything else: the ordering still works in both states, just less well. + */ + readyCadenceSource: (count, source) => server.recordAnalytics(count, 'queue_health', 'ready_cadence', source, null), + /** * Jobs granted per claim, split by WHERE they came from: the ready set or the fallback index scan. * diff --git a/packages/plugin/src/resources/PrerenderAdmin.js b/packages/plugin/src/resources/PrerenderAdmin.js index e08ab89..cc93256 100644 --- a/packages/plugin/src/resources/PrerenderAdmin.js +++ b/packages/plugin/src/resources/PrerenderAdmin.js @@ -95,7 +95,7 @@ import { MAX_REASON_LENGTH, CLUSTER_SCOPE as CLUSTER_INVALIDATION, } from '../util/invalidation.js'; -import { inspectRoutes, routeScopes, routeScopeForUrl } from '../util/routeClass.js'; +import { inspectRoutes, resolveEffectiveInterval, routeScopes, routeScopeForUrl } from '../util/routeClass.js'; import { CLUSTER_SCOPE } from '../util/queueControl.js'; import { getResidencyByUrl } from '../util/residency.js'; import { fetchScheduleFromPeer } from '../util/peer.js'; @@ -1047,7 +1047,7 @@ export class PrerenderAdmin extends Resource { const timedOutReads = []; const target = await readWithTimeout('renderTarget', timedOutReads, () => - Target.get({ id: canonicalUrl, select: ['url', 'sitemapUrl'] }) + Target.get({ id: canonicalUrl, select: ['url', 'sitemapUrl', 'renderInterval', 'demandInterval'] }) ); if (timedOutReads.length) return json({ error: 'target read timed out' }, 504); @@ -1065,7 +1065,13 @@ export class PrerenderAdmin extends Resource { const nextRenderTime = currentMinuteMs(); // The write is residency-routed, so this reaches the owning node from any node — and it // goes through the funnel, which lowers this node's claim floor to cover it. - await writeSchedule(cacheKey, { nextRenderTime, fromSitemap: !!target.sitemapUrl }); + await writeSchedule(cacheKey, { + nextRenderTime, + fromSitemap: !!target.sitemapUrl, + // The target's real cadence, off the point read above — an admin rejoin should not cost the + // page its ranking on the way back into rotation. + effectiveInterval: resolveEffectiveInterval(canonicalUrl, target), + }); // `claim` reads a node-local flag, so waking consumers only helps on the node that owns // the row. When another node owns it, what makes the row claimable there is the CLAIM diff --git a/packages/plugin/src/resources/RenderQueue.js b/packages/plugin/src/resources/RenderQueue.js index b379d33..52be321 100644 --- a/packages/plugin/src/resources/RenderQueue.js +++ b/packages/plugin/src/resources/RenderQueue.js @@ -4,7 +4,13 @@ import { currentMinuteMs } from '../util/time.js'; import { QueueState } from './QueueState.js'; import { CacheKey } from '../util/cacheKey.js'; import { canonicalizeUrl } from '../util/url.js'; -import { classifyPath, queryAllowlistFor, resolveRenderInterval, PRERENDER } from '../util/routeClass.js'; +import { + classifyPath, + queryAllowlistFor, + resolveEffectiveInterval, + resolveRenderInterval, + PRERENDER, +} from '../util/routeClass.js'; import { decideInterval } from '../util/demandLadder.js'; import { backoffWait } from '../util/failureBackoff.js'; import { recordUnroutedPath } from '../util/unrouted.js'; @@ -385,7 +391,15 @@ export class RenderQueue extends Resource { // path costs one atomic load and moves the floor not at all. That is load-bearing: a // lowering on every completed render would rewind the floor to the current minute // continuously and the whole 14× seek win would evaporate. - await writeSchedule(cacheKey, { nextRenderTime, fromSitemap: !!renderTarget.sitemapUrl }); + await writeSchedule(cacheKey, { + nextRenderTime, + fromSitemap: !!renderTarget.sitemapUrl, + // `interval`, i.e. the rung `decideInterval` JUST chose — not the route ceiling. This is + // the writer every target passes through on every cycle, so it is what backfills the + // cadence across the corpus, and it is the only site holding a rung fresher than the + // stored one. The ready-set sweep divides lateness by this to rank the row. + effectiveInterval: interval, + }); // Persist the rung ONLY on an actual move. 'held' must not write even when the // stored field is absent — absence already resolves to the base ceiling, so writing @@ -641,7 +655,12 @@ export class RenderQueue extends Resource { static async recordRedirectStrike(cacheKey, why) { const sourceUrl = CacheKey.extractUrl(cacheKey); // One read serves both the strike decision and the reschedule below. - const renderTarget = await Target.get({ id: sourceUrl, select: ['strikes', 'renderInterval', 'sitemapUrl'] }); + const renderTarget = await Target.get({ + id: sourceUrl, + // `demandInterval` rides along on a point read this path already makes, so the cadence filed + // on the schedule row is the ladder's rung rather than the route ceiling. + select: ['strikes', 'renderInterval', 'sitemapUrl', 'demandInterval'], + }); if (!renderTarget) { await deleteSchedule(cacheKey); return; @@ -703,7 +722,12 @@ export class RenderQueue extends Resource { */ static async retryAfterFailure(cacheKey) { const sourceUrl = CacheKey.extractUrl(cacheKey); - const renderTarget = await Target.get({ id: sourceUrl, select: ['strikes', 'renderInterval', 'sitemapUrl'] }); + const renderTarget = await Target.get({ + id: sourceUrl, + // `demandInterval` rides along on a point read this path already makes, so the cadence filed + // on the schedule row is the ladder's rung rather than the route ceiling. + select: ['strikes', 'renderInterval', 'sitemapUrl', 'demandInterval'], + }); if (!renderTarget) { await deleteSchedule(cacheKey); return 'dropped'; @@ -720,12 +744,17 @@ export class RenderQueue extends Resource { const interval = resolveRenderInterval(sourceUrl, renderTarget.renderInterval); const fromSitemap = !!renderTarget.sitemapUrl; const wait = backoffWait(interval, strikes, fromSitemap); + // THE CADENCE, NOT `wait`. The backoff is how long until the retry; the cadence is how often the + // page wants to render. Filing `wait` here would tell the sweep a repeatedly-failing 1h page is + // on a multi-hour cadence and rank it as barely late — rewarding failure with lower priority on + // every strike. `backoffWait` is derived FROM the cadence, so both are in hand. + const cadence = resolveEffectiveInterval(sourceUrl, renderTarget); const nextRenderTime = currentMinuteMs() + wait; logger.debug( `Retrying ${cacheKey} in ${Math.round(wait / 60000)}m (failure strike ${strikes}` + `${fromSitemap ? '' : ', non-sitemap'})` ); - await writeSchedule(cacheKey, { nextRenderTime, fromSitemap }); + await writeSchedule(cacheKey, { nextRenderTime, fromSitemap, effectiveInterval: cadence }); return 'slow'; } @@ -744,7 +773,7 @@ export class RenderQueue extends Resource { preloaded ?? (await Target.get({ id: sourceUrl, - select: ['renderInterval', 'sitemapUrl'], + select: ['renderInterval', 'sitemapUrl', 'demandInterval'], })); if (!renderTarget) { await deleteSchedule(cacheKey); @@ -755,6 +784,12 @@ export class RenderQueue extends Resource { await writeSchedule(cacheKey, { nextRenderTime: currentMinuteMs() + interval, fromSitemap: !!renderTarget.sitemapUrl, + // The ladder rung when the row carried one, else the ceiling. A caller-supplied `preloaded` + // row is documented as "at least renderInterval + sitemapUrl", so an absent `demandInterval` + // means "not read" rather than "not promoted" — resolving to the ceiling is the safe reading, + // and the next render files the true rung either way. (`recordRedirectStrike`, the one + // in-tree preloader, now selects it.) + effectiveInterval: resolveEffectiveInterval(sourceUrl, renderTarget), }); } @@ -993,6 +1028,10 @@ export function startReadySweep() { if (result?.skipped) return; metrics.readySweep(performance.now() - started, result.truncated ? 'capped' : 'complete'); metrics.readyPublished(result.published); + // Both halves, every sweep, so the ratio is readable without needing the total from a + // second series — and so `carried: 0` is an explicit observation rather than an absence. + metrics.readyCadenceSource(result.cadenceCarried, 'carried'); + metrics.readyCadenceSource(result.due - result.cadenceCarried, 'resolved'); if (result.truncated) { // The rows past the cap are the YOUNGEST, so a truncated sweep leaves recently-due pages // unranked — precisely the pages this feature exists to protect. That makes it a warning diff --git a/packages/plugin/src/resources/Target.js b/packages/plugin/src/resources/Target.js index 3a95349..d0596d1 100644 --- a/packages/plugin/src/resources/Target.js +++ b/packages/plugin/src/resources/Target.js @@ -108,6 +108,11 @@ export class Target extends TargetTable { ? nextRenderTime : getInitialRenderTime(cacheKey, interval), fromSitemap, + // `interval`, and no ladder rung applied — deliberately. `super.put` above REPLACES the + // target row, so a put clears `demandInterval` along with the suppression fields; the + // target genuinely restarts at its route/stored cadence and this records that. Reading + // the old rung to carry it forward would file a cadence the target no longer has. + effectiveInterval: interval, })) ); @@ -200,6 +205,13 @@ export class Target extends TargetTable { cacheKey, nextRenderTime: recheckAt, fromSitemap: !!existing?.sitemapUrl, + // THE CADENCE, NOT `recheckInterval` — this is the case `util/renderPriority.js` calls + // out by name. A 7-day recheck filed as a cadence would make a suppressed 48h page read + // as 3.5 cadences stale the moment it comes due and outrank a genuinely late homepage, + // promoting exactly the rows worth deprioritizing. No rung applied for the same reason + // as `put`: the `TargetTable.put` above omits `demandInterval`, so the rung is cleared + // with it and the target resumes at its route/stored cadence. + effectiveInterval: resolveRenderInterval(url, existing?.renderInterval ?? null), })) ), ...cacheKeysOf(url).map((cacheKey) => PrerenderedPage.delete(cacheKey)), @@ -304,7 +316,18 @@ export class Target extends TargetTable { // that changes nothing. Hoisting the lowering out of the loop would mean carrying the // batch's rows in memory to no measurable end. await writeSchedules( - cacheKeysOf(url).map((cacheKey) => ({ cacheKey, nextRenderTime, fromSitemap: !!sitemapUrl })) + cacheKeysOf(url).map((cacheKey) => ({ + cacheKey, + nextRenderTime, + fromSitemap: !!sitemapUrl, + // `null` — the sweep resolves from config instead, which is what it did before this + // field existed. Phase 1's projection is deliberately just `url` + `sitemapUrl` (and + // an API-facing guard enforces exactly those two), so carrying a cadence here would + // mean widening that contract. It cannot affect this row's ranking anyway: every row + // is filed at the current minute, so its lateness is ~0 whatever the denominator, + // and the render it is being queued for refills the cadence on completion. + effectiveInterval: null, + })) ); }, }); diff --git a/packages/plugin/src/schemas/schema.graphql b/packages/plugin/src/schemas/schema.graphql index 8f9ced2..e8634ab 100644 --- a/packages/plugin/src/schemas/schema.graphql +++ b/packages/plugin/src/schemas/schema.graphql @@ -114,6 +114,24 @@ type RenderSchedule @table(database: "render_schedule") @export { # cross-database read just to flag sitemap-sourced jobs. Refreshed on every # reschedule (job result), so it self-corrects when a URL leaves its sitemap. fromSitemap: Boolean + # The page's CADENCE in ms — route > stored > default with the demand ladder's rung applied + # (`resolveEffectiveInterval`). How often this page should render, which is NOT the same as the + # gap `nextRenderTime` was actually written with: a suppression recheck files 7 days out and a + # failure backoff files its backoff, and neither is a cadence. The distinction is the whole + # reason `util/renderPriority.js` scores lateness rather than age — the numerator is how far + # past due the row is, the denominator is how often it wants to render. Writers file the + # cadence here even when the gap they wrote differs. Denormalized for the same reason + # `fromSitemap` is: the ready-set sweep scores every due row on the node by lateness RELATIVE + # TO CADENCE, and recovering that per row from RenderTarget would be a cross-database point + # read per row over the whole due set — on a residency-pinned table, ~75% of them replication + # fetches. NOT @indexed: it is only ever read alongside a row already selected by + # `nextRenderTime`, and a second index costs ~13% on every write (bench/queue-index). + # + # Absent is legal and self-healing — pre-upgrade rows, and the writers that genuinely have no + # cadence in hand (a render-now one-off) — and the sweep falls back to resolving from config, + # which is what it did before this field existed. Every row re-renders on its own cadence, so + # the active corpus fills in within one cycle. + effectiveInterval: Long } type QueueStatus @table(database: "render_service") @sealed @export(name: "queue_status") { diff --git a/packages/plugin/src/util/invalidationReenqueue.js b/packages/plugin/src/util/invalidationReenqueue.js index d36d09e..4914312 100644 --- a/packages/plugin/src/util/invalidationReenqueue.js +++ b/packages/plugin/src/util/invalidationReenqueue.js @@ -116,7 +116,7 @@ import { QueueState } from '../resources/QueueState.js'; import { getSab } from './coordination.js'; import { getScheduleRow, leaseInfo, writeSchedules } from './renderSchedule.js'; import { getResidencyByUrl } from './residency.js'; -import { PRERENDER, resolveRenderInterval } from './routeClass.js'; +import { PRERENDER, resolveEffectiveInterval, resolveRenderInterval } from './routeClass.js'; import { MINUTE, getInitialRenderTime, numberOf } from './time.js'; import { metrics } from '../metrics.js'; @@ -257,7 +257,7 @@ export const accelerateHeal = async ({ url, cacheKey, invalidatedBy }) => { for (const key of keys) if (leaseInfo(key)) return refuse('leased', { leasedKey: key }); const [target, ...rows] = await Promise.all([ - Target.get({ id: url, select: ['url', 'strikes', 'renderInterval', 'sitemapUrl'] }), + Target.get({ id: url, select: ['url', 'strikes', 'renderInterval', 'sitemapUrl', 'demandInterval'] }), // `replicateFrom: false` rides along inside the funnel's reader. Ownership makes this read // AUTHORITATIVE; only the option makes it LOCAL, and an unowned point read on this // residency-pinned table takes Harper's untimed replication fetch — inside a `setImmediate`, @@ -316,7 +316,15 @@ export const accelerateHeal = async ({ url, cacheKey, invalidatedBy }) => { // schedule row we just read: `put` REPLACES the record, and the target is the field's source of // truth, so this self-corrects a row whose flag went stale (same choice as the reschedule path). await writeSchedules( - eligible.map((row) => ({ cacheKey: row.cacheKey, nextRenderTime: dueAt, fromSitemap: !!target.sitemapUrl })) + eligible.map((row) => ({ + cacheKey: row.cacheKey, + nextRenderTime: dueAt, + fromSitemap: !!target.sitemapUrl, + // The cadence, not the acceleration. `dueAt` is when the invalidation wants this rendered; + // how often the page renders is unchanged by being accelerated, and it is what the sweep + // ranks by. Same source as `interval` above, with the ladder rung applied. + effectiveInterval: resolveEffectiveInterval(url, target), + })) ); } catch (e) { logger.error(e, `[prerender] could not accelerate ${cacheKey} after an invalidation`); diff --git a/packages/plugin/src/util/reconcile.js b/packages/plugin/src/util/reconcile.js index 3a9935b..77417ce 100644 --- a/packages/plugin/src/util/reconcile.js +++ b/packages/plugin/src/util/reconcile.js @@ -104,6 +104,9 @@ export const reconcileSchedules = async ({ // Phase 2 — writes, with the scan's cursor now closed. for (const { cacheKey, target } of toRestore) { + // Hoisted because the jittered time and the recorded cadence must be the same number — see both + // comments below. + const interval = resolveRenderInterval(target.url, target.renderInterval); await putSchedule(cacheKey, { // The jittered initial time, NOT "now": a repair pass can restore a great many rows at // once, and scheduling them all immediately would replace a silent outage with a @@ -120,8 +123,15 @@ export const reconcileSchedules = async ({ // inclusive (`greater_than_equal`). If that comparator were ever made exclusive, every // repaired row would be filed one step behind the floor and this sweep would restore // rows into the very silent gap it exists to close. - nextRenderTime: getInitialRenderTime(cacheKey, resolveRenderInterval(target.url, target.renderInterval)), + nextRenderTime: getInitialRenderTime(cacheKey, interval), fromSitemap: !!target.sitemapUrl, + // The same cadence the jitter above was drawn from, so a repaired row is ranked by the + // window it was actually spread across. No ladder rung applied: `streamTargets` is an + // unconstrained scan of the whole target corpus and `demandInterval` would widen it by a + // fourth attribute on every row, to refine the ranking of rows that are (a) rare — this + // only fires on a missing row — and (b) filed at a FUTURE jittered time, so not yet + // competing for anything. The row's next render files the true rung. + effectiveInterval: interval, }); stats.restored++; } diff --git a/packages/plugin/src/util/renderSchedule.js b/packages/plugin/src/util/renderSchedule.js index 201b03d..45c7b0b 100644 --- a/packages/plugin/src/util/renderSchedule.js +++ b/packages/plugin/src/util/renderSchedule.js @@ -271,11 +271,19 @@ const lowerFloorFor = (nextRenderTime) => { * in 10.7 ms, mean 0.021 ms, against residency pinned to a node that does not exist). v0.15.0 * assumed the read/write symmetry and wrapped these in a deadline that could never fire. */ -export const writeSchedule = async (cacheKey, { nextRenderTime, fromSitemap } = {}) => { +export const writeSchedule = async (cacheKey, { nextRenderTime, fromSitemap, effectiveInterval } = {}) => { if (fromSitemap === undefined) { throw new Error(`writeSchedule(${cacheKey}) needs an explicit fromSitemap — put replaces the record`); } - await scheduleTable().put(cacheKey, { nextRenderTime, fromSitemap }); + // REQUIRED FOR THE SAME REASON, AND IT IS THE SAME HAZARD. `put` replaces the record, so a writer + // that omits this does not leave the old value alone — it ERASES a correct cadence off a row that + // had one, and the ready-set sweep then scores that page against its route ceiling instead of its + // ladder rung. `null` is the legitimate explicit answer for a writer with no cadence in hand (a + // render-now one-off has no cadence at all); what must not be possible is forgetting. + if (effectiveInterval === undefined) { + throw new Error(`writeSchedule(${cacheKey}) needs an explicit effectiveInterval — put replaces the record`); + } + await scheduleTable().put(cacheKey, { nextRenderTime, fromSitemap, effectiveInterval }); lowerFloorFor(nextRenderTime); }; @@ -291,11 +299,14 @@ export const writeSchedule = async (cacheKey, { nextRenderTime, fromSitemap } = */ export const writeSchedules = async (rows = []) => { let lowest = Number.POSITIVE_INFINITY; - for (const { cacheKey, nextRenderTime, fromSitemap } of rows) { + for (const { cacheKey, nextRenderTime, fromSitemap, effectiveInterval } of rows) { if (fromSitemap === undefined) { throw new Error(`writeSchedules(${cacheKey}) needs an explicit fromSitemap — put replaces the record`); } - await scheduleTable().put(cacheKey, { nextRenderTime, fromSitemap }); + if (effectiveInterval === undefined) { + throw new Error(`writeSchedules(${cacheKey}) needs an explicit effectiveInterval — put replaces the record`); + } + await scheduleTable().put(cacheKey, { nextRenderTime, fromSitemap, effectiveInterval }); // Same trap as `lowerFloorFor`, and WORSE here: with a bare `Number` a single null row anywhere // in the batch becomes 0, wins the minimum, and unbounds the floor for the whole fan-out. const at = numberOf(nextRenderTime); @@ -396,7 +407,15 @@ export const runClaimPass = async ({ if (firstDueMinute === null) { firstDueMinute = dueMinute; floorHeldBy = row.cacheKey; - floorHeldByRow = { cacheKey: row.cacheKey, dueMinute, fromSitemap: !!row.fromSitemap }; + floorHeldByRow = { + cacheKey: row.cacheKey, + dueMinute, + fromSitemap: !!row.fromSitemap, + // Carried so the unpin hatch can PRESERVE it: `put` replaces the record, so a push that + // rewrote this row without the field would strip the cadence off the one row already known + // to be in trouble. + effectiveInterval: row.effectiveInterval, + }; } if (leases.isLeased(row.cacheKey)) { @@ -478,6 +497,19 @@ export const runClaimPass = async ({ * rather than somebody else's answer. `null` also legitimately means "the last pass saw no due row", * i.e. nothing is holding the floor. */ +/** + * The cadence a schedule row carries, or `null` when it carries none. + * + * One helper rather than the check inlined twice, because the two callers must agree: the sweep + * divides lateness by this to score, and `maybeUnpinFloor` pushes a wedged row forward by it. If + * they resolved a cadence differently the push distance would stop matching the number the row was + * ranked by. `Number` first for the BigInt-from-`Long` coercion; `> 0` rejects null/NaN/negatives. + */ +const carriedCadence = (effectiveInterval) => { + const ms = Number(effectiveInterval); + return Number.isFinite(ms) && ms > 0 ? ms : null; +}; + let lastFloorHeldBy = null; let lastFloorHeldByAt = 0; @@ -521,7 +553,7 @@ const maybeUnpinFloor = async (pass) => { if (!config.queue.claimFloor.enabled) return null; if (!pass.floorHeldByRow || !(pass.floorPinnedForMs >= unpinAfter)) return null; - const { cacheKey, fromSitemap } = pass.floorHeldByRow; + const { cacheKey, fromSitemap, effectiveInterval } = pass.floorHeldByRow; // ONE RENDER INTERVAL, RESOLVED THE WAY EVERY OTHER SCHEDULE WRITER RESOLVES IT — not a flat // `render.defaultInterval`. Two reasons, and the second one is a bug this used to cause: // @@ -535,15 +567,26 @@ const maybeUnpinFloor = async (pass) => { // fixing now: the row is the only record, it outlives the pass that wrote it, and a later // reader has no way to know this particular value was synthetic. // - // Route > default here, where `processJobResult` resolves route > the target's stored interval > - // default: reading the Target from the funnel would mean a point read on the claim path and an - // import cycle (`resources/Target.js` imports this module). The residual, stated because it is - // invisible from either site: a target whose STORED interval differs from the default with no route - // interval to override it still desynchronises the two by that difference. Cost of that residual is - // one extra render per crawl of one URL, rate-limited by the accelerator's own budget. - const nextRenderTime = Date.now() + resolveRenderInterval(CacheKey.extractUrl(cacheKey), null); + // THE ROW'S OWN CADENCE FIRST, which closes a residual this comment used to have to state. Reading + // the Target from the funnel is still out of the question — a point read on the claim path, and an + // import cycle (`resources/Target.js` imports this module) — but the cadence now travels ON the row, + // so the push distance matches what the writer actually scheduled by, including a demand-ladder rung + // that config cannot see at all. Falling back to route > default leaves the old residual only for + // rows written before this field existed: a target whose STORED interval differs from the default + // with no route interval to override it is pushed by that difference. Cost of that residual is one + // extra render per crawl of one URL, rate-limited by the accelerator's own budget. + const interval = carriedCadence(effectiveInterval) ?? resolveRenderInterval(CacheKey.extractUrl(cacheKey), null); + const nextRenderTime = Date.now() + interval; try { - await writeSchedule(cacheKey, { nextRenderTime, fromSitemap }); + // `interval`, NOT the raw `effectiveInterval` off the row — and the difference is a silent + // regression that only shows up on the first deploy. Every row written before this field existed + // carries `undefined`, which the funnel now REFUSES; the refusal lands inside this try, is logged + // and swallowed, and the hatch does nothing while looking healthy. So on a node where no row has + // re-rendered yet — i.e. every node, for one full cadence after an upgrade — the one mechanism + // that bounds a wedged row would have been dead. Filing the resolved cadence instead also keeps + // `nextRenderTime - effectiveInterval === now`, the arithmetic the comment above is about, and + // leaves the row self-describing for the next sweep. + await writeSchedule(cacheKey, { nextRenderTime, fromSitemap, effectiveInterval: interval }); } catch (e) { logger.error(e, `[prerender] could not unpin the claim floor from ${cacheKey}`); return null; @@ -594,7 +637,13 @@ const searchSchedulesFrom = ({ floorMinute, limit }) => sort: { attribute: 'nextRenderTime' }, // ARRAY select. A string `select` returns the bare scalar rather than a record — // the trap that has caused two silent bugs in this package already. - select: ['cacheKey', 'nextRenderTime', 'fromSitemap'], + // + // `effectiveInterval` rides along so the sweep can score a row without a per-row read of + // RenderTarget — which on a residency-pinned table would be a replication fetch for ~75% of + // keys, over the whole due set. The claim path shares this select and ignores the field: one + // more decoded Long across `queue.claimScanCap` rows, against the guarantee that the two + // paths cannot drift onto different queries. + select: ['cacheKey', 'nextRenderTime', 'fromSitemap', 'effectiveInterval'], limit, }, { replicateFrom: false } @@ -670,6 +719,10 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { const cap = Math.max(1, sweepCap | 0); const heap = createTopK(queue.capacity); + // THE FALLBACK PATH ONLY. A row that carries its own `effectiveInterval` never reaches this — no URL + // parse, no route walk — so once the corpus has re-rendered once this memo serves the remainder: + // pre-upgrade rows and the writers with no cadence in hand. + // // Route resolution parses a URL and walks the route list, and a URL's device variants share both — // so this memo halves the work at minimum, on the one loop that sees every due row on the node. // Per sweep rather than process-lifetime: the route list is live-reloadable, and a cache keyed by @@ -688,6 +741,11 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { let scanned = 0; let due = 0; let nonFinite = 0; + // How much of the due set could be scored against its REAL cadence. Reported because it is the only + // way to see the backfill land: this reads 0 on the first sweep after an upgrade and climbs toward + // `due` as rows re-render, and a value that stays low means writers are filing rows without a + // cadence rather than that the field is not working. + let cadenceCarried = 0; let firstDueMinute = null; let firstDueKey = null; let firstDueRow = null; @@ -726,13 +784,22 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { // The row itself, because `maybeUnpinFloor` has to REWRITE it and `put` replaces the record — // so it needs the `fromSitemap` flag this sweep already has in hand. Re-reading the row to // recover a flag that was in hand is how `Target.revalidate` silently cleared it for a year. - firstDueRow = { cacheKey: row.cacheKey, dueMinute: firstDueMinute, fromSitemap: !!row.fromSitemap }; + firstDueRow = { + cacheKey: row.cacheKey, + dueMinute: firstDueMinute, + fromSitemap: !!row.fromSitemap, + effectiveInterval: row.effectiveInterval, + }; } - const url = CacheKey.extractUrl(row.cacheKey); - const score = scoreOf( - { dueAt, fromSitemap: !!row.fromSitemap }, - { nowMs, intervalMs: intervalFor(url), sitemapBoost } - ); + // THE ROW'S OWN CADENCE, NOT THE ROUTE'S. They differ wherever the demand ladder has promoted a + // target beneath its route ceiling — a `/catalog/` page on the 6h rung is scheduled 6h out while + // the route still grants 24h, so resolving from config alone would divide by 24h and report a + // quarter of its true lateness, on exactly the pages the ladder singled out as worth rendering + // more often. Config resolution stays as the fallback for rows that carry nothing. + const carried = carriedCadence(row.effectiveInterval); + if (carried !== null) cadenceCarried++; + const intervalMs = carried ?? intervalFor(CacheKey.extractUrl(row.cacheKey)); + const score = scoreOf({ dueAt, fromSitemap: !!row.fromSitemap }, { nowMs, intervalMs, sitemapBoost }); heap.offer(score, { cacheKey: row.cacheKey, dueAt, fromSitemap: !!row.fromSitemap }); // Yielding is free (measured: 2.375 vs 2.387 us/row at 20,000 rows) and this runs beside bot // traffic on a worker that also serves requests, so it must not hold the loop for a whole sweep. @@ -775,6 +842,7 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { scanned, due, nonFinite, + cadenceCarried, published, capacity: queue.capacity, floorFrom, diff --git a/packages/plugin/src/util/routeClass.js b/packages/plugin/src/util/routeClass.js index 54425cf..2740d96 100644 --- a/packages/plugin/src/util/routeClass.js +++ b/packages/plugin/src/util/routeClass.js @@ -392,3 +392,30 @@ export const resolveRenderInterval = (url, storedInterval) => { const stored = Number(storedInterval); return Number.isFinite(stored) && stored > 0 ? stored : config.render.defaultInterval; }; + +/** + * The cadence a target's `nextRenderTime` is ACTUALLY computed from — `resolveRenderInterval` + * with the demand ladder's current rung applied on top. + * + * THE LADDER IS NOT VISIBLE TO CONFIG, and that is the whole reason this exists. A route grants a + * CEILING (`/catalog/` grants 24h) and `render.demand` promotes bot-visited targets beneath it to + * 12h or 6h, storing the rung on the target as `demandInterval`. So `resolveRenderInterval` alone + * reports 24h for a page that is really on a 6h cadence — a 4x overstatement, on precisely the + * pages the ladder singled out as worth rendering more often. Anything dividing by a cadence + * (see `util/renderPriority.js`) must divide by this one, or it discounts every promotion the + * ladder made. + * + * CLAMPED TO THE CEILING, because the stored rung can outlive the config that produced it: lower a + * route's `renderInterval` and every target still carries a rung from the old, slower ladder until + * its next render. `decideInterval` clamps the same way (`Math.min(rungIndexOf(...), ceiling)`), so + * a stale rung reads as "at the ceiling" here exactly as it does there rather than understating the + * cadence. + */ +export const resolveEffectiveInterval = (url, { renderInterval, demandInterval } = {}) => { + const base = resolveRenderInterval(url, renderInterval); + // Same BigInt-from-`Long` coercion as above, and the same reason `> 0` rather than a typeof + // check: `Number(null)` is 0 and `Number(undefined)` is NaN, so an unevaluated target — which + // is most of the corpus until the ladder reaches it — falls through to the ceiling. + const rung = Number(demandInterval); + return Number.isFinite(rung) && rung > 0 ? Math.min(rung, base) : base; +}; diff --git a/packages/plugin/test/readySweep.test.js b/packages/plugin/test/readySweep.test.js index bd07789..6280092 100644 --- a/packages/plugin/test/readySweep.test.js +++ b/packages/plugin/test/readySweep.test.js @@ -23,6 +23,11 @@ import assert from 'node:assert/strict'; * sitemap-listed, so a job reporting `false` for a listed page silently stops it being cached. * That bug has shipped twice in this package. * - A NOT-YET-DUE ROW IS NEVER PUBLISHED, however urgent its cadence would make it. + * - THE ROW'S OWN CADENCE WINS OVER THE ROUTE'S. `render.demand` promotes visited targets beneath + * their route ceiling and files the rung on the schedule row; scoring from the route alone + * divides a promoted page's lateness by up to 4x too much, deprioritising exactly the pages the + * ladder singled out as worth rendering more often. Nothing else in this suite can see it — the + * route resolves identically either way. */ const MINUTE = 60_000; @@ -99,12 +104,22 @@ const seed = (rows) => { table = new Map(rows.map((r) => [r.cacheKey, r])); }; -const row = (url, device, dueAt, fromSitemap = true) => ({ +const row = (url, device, dueAt, fromSitemap = true, effectiveInterval = undefined) => ({ cacheKey: `${url}|${device}`, nextRenderTime: dueAt, fromSitemap, + // Absent unless a test asks for it, which is also the shape of every row written before the field + // existed — so the default here exercises the upgrade path. + ...(effectiveInterval === undefined ? {} : { effectiveInterval }), }); +// The reset `beforeEach` performs, extracted so a test that claims more than once can repeat it. +// Claims LEASE what they grant, and leases outlive an iteration in shared memory — so a loop that +// re-seeds the table but not the buffers silently starts skipping the row it granted last time. +const resetShared = () => { + for (const buffer of sabs.values()) new Uint8Array(buffer).fill(0); +}; + beforeEach(() => { withRoutes(); // ZERO EVERY SHARED BUFFER, not just the floor. Both the lease table and the ready set live in @@ -113,7 +128,7 @@ beforeEach(() => { // earlier test's claim make the fallback scan skip rows and start further down the index. Zeroing // the bytes resets the floor, the leases, the occupancy gauge and the set in one step, and the // views the modules hold stay valid because only the contents change. - for (const buffer of sabs.values()) new Uint8Array(buffer).fill(0); + resetShared(); config.queue.ready.enabled = true; config.queue.ready.sweepCap = 500_000; config.queue.ready.sitemapBoost = 2; @@ -389,3 +404,87 @@ test('the sweep notes the pin AND runs the unpin hatch, so one wedged row cannot config.queue.claimFloor.unpinAfter = previous; } }); + +test('THE LADDER GAP: a promoted row outranks one that is later in absolute AND route-relative terms', async () => { + // Both on the 48h product route, both sitemap-listed, so the route and the boost are identical and + // the carried cadence is the only thing that can separate them. + // + // promoted 6h late, cadence 6h (the ladder's rung) -> 1.00 cadences late + // ceiling 12h late, cadence 48h (the route) -> 0.25 cadences late + // + // Scoring from the route alone reverses this: 6/48 = 0.125 loses to 12/48 = 0.25. So this fails on + // the version that resolves every row from config, which is the bug being fixed. + seed([ + row('https://www.kohls.com/product/prd-promoted/x', 'desktop', T0 - 6 * HOUR, true, 6 * HOUR), + row('https://www.kohls.com/product/prd-ceiling/x', 'desktop', T0 - 12 * HOUR, true), + ]); + + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 2); + assert.equal(sweep.cadenceCarried, 1, 'one row carried a cadence, one fell back to config'); + + const pass = await funnel.claimSchedules({ grantLimit: 1 }); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/product/prd-promoted/x|desktop'], + 'a full cadence late on its 6h rung beats a quarter of a cadence late on the 48h ceiling' + ); +}); + +test('a row carrying no cadence is scored from config — the upgrade path, and the default here', async () => { + // Every row on a node is in this state immediately after an upgrade, so "falls back correctly" is + // the behaviour that has to hold on deploy day. + seed(backlogWithLateHome()); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.cadenceCarried, 0, 'nothing carried, so the count reports the backfill has not landed'); + + const pass = await funnel.claimSchedules({ grantLimit: 1 }); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/|desktop'], + 'and the ordering is still right, from route resolution alone' + ); +}); + +test('an unusable carried cadence falls back instead of producing an infinite score', async () => { + // `0` is the dangerous one: dividing by it yields Infinity, which would sort a junk row to the head + // of the set and hand it every lease. `carriedCadence` requires `> 0`, so each of these resolves + // from the route instead, leaving the genuinely late homepage in front. + for (const junk of [0, -1, null, NaN, 'nonsense']) { + // Per iteration, not per test: the previous iteration LEASED the homepage it granted, and a + // leased row is skipped — so without this the second iteration grants the junk row and the + // assertion "fails" for a reason that has nothing to do with the cadence. + resetShared(); + seed([ + row('https://www.kohls.com/product/prd-junk/x', 'desktop', T0 - 30 * MINUTE, true, junk), + row('https://www.kohls.com/', 'desktop', T0 - 2 * HOUR, true, HOUR), + ]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.cadenceCarried, 1, `only the homepage carries a usable cadence (junk: ${junk})`); + + const pass = await funnel.claimSchedules({ grantLimit: 1 }); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/|desktop'], + `a junk cadence does not jump the queue (junk: ${junk})` + ); + } +}); + +test('a BigInt carried cadence from a Long column is used, not discarded', async () => { + // Same coercion trap as the due time: `Number.isFinite` rejects a BigInt outright, so without the + // `Number()` first every promoted row would silently fall back to its route ceiling — the exact bug + // this field exists to fix, reintroduced invisibly. + seed([ + row('https://www.kohls.com/product/prd-promoted/x', 'desktop', T0 - 6 * HOUR, true, BigInt(6 * HOUR)), + row('https://www.kohls.com/product/prd-ceiling/x', 'desktop', T0 - 12 * HOUR, true), + ]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.cadenceCarried, 1); + + const pass = await funnel.claimSchedules({ grantLimit: 1 }); + assert.deepEqual( + pass.jobs.map((j) => j.cacheKey), + ['https://www.kohls.com/product/prd-promoted/x|desktop'] + ); +}); diff --git a/packages/plugin/test/renderQueueFloor.test.js b/packages/plugin/test/renderQueueFloor.test.js index 19197b8..9caaf03 100644 --- a/packages/plugin/test/renderQueueFloor.test.js +++ b/packages/plugin/test/renderQueueFloor.test.js @@ -22,6 +22,9 @@ import assert from 'node:assert/strict'; */ const MINUTE = 60_000; +// A stand-in cadence for the write shapes below. These tests are about the FLOOR, so the value only +// has to be present and plausible — `writeSchedule` requires it explicitly. +const HOUR = 60 * MINUTE; const T0 = 1_700_000_400_000; // a whole minute const minuteOf = (ms) => Math.floor(ms / MINUTE); @@ -336,7 +339,7 @@ test('every write shape lowers the floor only when it should', async () => { funnel.resetRenderQueueState(); assert.equal(funnel.leaseTable().advanceFloor(0, nowMinute), true, 'precondition: establish a floor'); - await funnel.writeSchedule('k|desktop', { nextRenderTime, fromSitemap: false }); + await funnel.writeSchedule('k|desktop', { nextRenderTime, fromSitemap: false, effectiveInterval: HOUR }); const raw = funnel.leaseTable().rawFloorMinute(); if (shouldLower) { @@ -353,9 +356,9 @@ test('writeSchedules lowers ONCE, with the batch minimum', async () => { funnel.leaseTable().advanceFloor(0, nowMinute); await funnel.writeSchedules([ - { cacheKey: 'a|desktop', nextRenderTime: T0 + 90 * MINUTE, fromSitemap: false }, - { cacheKey: 'b|desktop', nextRenderTime: T0 - 3 * MINUTE, fromSitemap: false }, - { cacheKey: 'c|desktop', nextRenderTime: T0 + 10 * MINUTE, fromSitemap: false }, + { cacheKey: 'a|desktop', nextRenderTime: T0 + 90 * MINUTE, fromSitemap: false, effectiveInterval: HOUR }, + { cacheKey: 'b|desktop', nextRenderTime: T0 - 3 * MINUTE, fromSitemap: false, effectiveInterval: HOUR }, + { cacheKey: 'c|desktop', nextRenderTime: T0 + 10 * MINUTE, fromSitemap: false, effectiveInterval: HOUR }, ]); assert.equal(funnel.leaseTable().rawFloorMinute(), minuteOf(T0 - 3 * MINUTE), 'the batch minimum, not the last row'); @@ -578,21 +581,21 @@ test('an ABSENT nextRenderTime does not unbound the floor, but a real 0 still do funnel.leaseTable().advanceFloor(0, established); assert.equal(funnel.leaseTable().rawFloorMinute(), established, 'precondition: a floor exists'); - await funnel.writeSchedule('a|desktop', { nextRenderTime: null, fromSitemap: false }); + await funnel.writeSchedule('a|desktop', { nextRenderTime: null, fromSitemap: false, effectiveInterval: HOUR }); assert.equal(funnel.leaseTable().rawFloorMinute(), established, 'a null due time lowers nothing'); - await funnel.writeSchedule('b|desktop', { nextRenderTime: undefined, fromSitemap: false }); + await funnel.writeSchedule('b|desktop', { nextRenderTime: undefined, fromSitemap: false, effectiveInterval: HOUR }); assert.equal(funnel.leaseTable().rawFloorMinute(), established, 'nor an undefined one'); // The batch form is the worse case: one null row would win the minimum for the whole fan-out. await funnel.writeSchedules([ - { cacheKey: 'c|desktop', nextRenderTime: null, fromSitemap: false }, - { cacheKey: 'd|desktop', nextRenderTime: T0 + 10 * MINUTE, fromSitemap: false }, + { cacheKey: 'c|desktop', nextRenderTime: null, fromSitemap: false, effectiveInterval: HOUR }, + { cacheKey: 'd|desktop', nextRenderTime: T0 + 10 * MINUTE, fromSitemap: false, effectiveInterval: HOUR }, ]); assert.equal(funnel.leaseTable().rawFloorMinute(), established, 'and one null row cannot unbound a batch'); // ...while an explicit epoch due time is honoured, because that is a real request. - await funnel.writeSchedule('e|desktop', { nextRenderTime: 0, fromSitemap: false }); + await funnel.writeSchedule('e|desktop', { nextRenderTime: 0, fromSitemap: false, effectiveInterval: HOUR }); assert.equal(funnel.leaseTable().rawFloorMinute(), 0, 'a due time AT the epoch unbounds the scan on purpose'); }); @@ -737,7 +740,11 @@ test('ONE schedule write per render, claim to result — the halved audit volume assert.equal(puts.length, 0, 'claiming writes NOTHING to the table now'); // The result lands and reschedules. - await funnel.writeSchedule('a|desktop', { nextRenderTime: T0 + 24 * 60 * MINUTE, fromSitemap: false }); + await funnel.writeSchedule('a|desktop', { + nextRenderTime: T0 + 24 * 60 * MINUTE, + fromSitemap: false, + effectiveInterval: HOUR, + }); assert.equal(puts.length, 1, 'exactly one write for the whole cycle'); }); @@ -830,6 +837,25 @@ test('writeSchedule refuses a write with no explicit fromSitemap (put REPLACES t await assert.rejects(() => funnel.writeSchedules([{ cacheKey: 'a|desktop', nextRenderTime: T0 }]), /fromSitemap/); }); +test('writeSchedule refuses a write with no explicit effectiveInterval (same hazard)', async () => { + // Same reason as `fromSitemap`, one step worse in its consequence: `put` replaces the record, so a + // writer that omits the cadence strips it off a row that had one and the ready-set sweep then ranks + // that page by its route ceiling instead of its demand-ladder rung. `null` is a legal answer — a + // render-now one-off has no cadence — so the guard is on `undefined` alone. + await assert.rejects( + () => funnel.writeSchedule('a|desktop', { nextRenderTime: T0, fromSitemap: false }), + /effectiveInterval/ + ); + await assert.rejects( + () => funnel.writeSchedules([{ cacheKey: 'a|desktop', nextRenderTime: T0, fromSitemap: false }]), + /effectiveInterval/ + ); + await funnel.writeSchedule('a|desktop', { nextRenderTime: T0, fromSitemap: false, effectiveInterval: null }); + await funnel.writeSchedules([ + { cacheKey: 'b|desktop', nextRenderTime: T0, fromSitemap: false, effectiveInterval: null }, + ]); +}); + test('maybeResetFloor honours its interval and is a no-op at 0', () => { funnel.resetRenderQueueState(); const original = config.queue.claimFloor.resetInterval; diff --git a/packages/plugin/test/renderQueuePin.test.js b/packages/plugin/test/renderQueuePin.test.js index 340706a..3c82efc 100644 --- a/packages/plugin/test/renderQueuePin.test.js +++ b/packages/plugin/test/renderQueuePin.test.js @@ -325,3 +325,48 @@ test('the escape hatch is off with the floor off: an unfloored scan is not held config.queue.claimFloor.enabled = original; } }); + +test('THE UPGRADE PATH: the hatch still fires for a row carrying no cadence, and files one', async () => { + // `seed` writes rows with no `effectiveInterval`, which is the shape of EVERY row on a node until + // it has re-rendered once — so this is the state of the whole corpus on deploy day. + // + // The bug this pins was invisible in every other test here: the hatch reads the cadence off the row + // and hands it back to `writeSchedule`, whose guard REFUSES `undefined`. The refusal lands inside + // the hatch's own try/catch, is logged and swallowed, and the hatch does nothing while reporting + // nothing — so the one mechanism that bounds a wedged row would have been dead on arrival, on every + // node, for a full cadence after the upgrade. + seed(); + assert.equal(schedule.get(WEDGED).effectiveInterval, undefined, 'precondition: a pre-upgrade row'); + + await RenderQueue.claim({ limit: 5 }); + nowMs += config.queue.claimFloor.unpinAfter + MINUTE; + await RenderQueue.claim({ limit: 5 }); + + assert.equal(unpinWarnings().length, 1, 'the hatch fired'); + const row = schedule.get(WEDGED); + assert.equal(Number(row.nextRenderTime), nowMs + config.render.defaultInterval, 'pushed by the resolved cadence'); + // And the row is left self-describing, so the sweep that ranks it next does not have to resolve it + // again — and `nextRenderTime - effectiveInterval` still reads back as "completed now". + assert.equal(Number(row.effectiveInterval), config.render.defaultInterval, 'the push records the cadence it used'); + assert.equal(Number(row.nextRenderTime) - Number(row.effectiveInterval), nowMs); +}); + +test('...and a row that DOES carry a cadence is pushed by that, not by the route', async () => { + // The residual the hatch used to have to state in a comment: it resolved route > default only, so a + // target whose cadence came from anywhere else (a stored `changefreq`, a demand-ladder rung) was + // pushed by the wrong distance. A carried cadence closes it — 6h here, against the target's stored + // DAY and no route interval at all. + seed(); + schedule.get(WEDGED).effectiveInterval = 6 * 60 * MINUTE; + + await RenderQueue.claim({ limit: 5 }); + nowMs += config.queue.claimFloor.unpinAfter + MINUTE; + await RenderQueue.claim({ limit: 5 }); + + assert.equal(unpinWarnings().length, 1); + assert.equal( + Number(schedule.get(WEDGED).nextRenderTime), + nowMs + 6 * 60 * MINUTE, + "the row's own cadence, not render.defaultInterval and not the target's stored DAY" + ); +}); diff --git a/packages/plugin/test/routeClass.test.js b/packages/plugin/test/routeClass.test.js index 821861c..f2c4d44 100644 --- a/packages/plugin/test/routeClass.test.js +++ b/packages/plugin/test/routeClass.test.js @@ -7,6 +7,7 @@ import { matchRoute, prerenderRouteCount, queryAllowlistFor, + resolveEffectiveInterval, resolveRenderInterval, PASSTHROUGH, PRERENDER, @@ -275,3 +276,49 @@ test('a per-URL cadence exception is an exact route above its class prefix', () assert.equal(resolveRenderInterval(`${base}/catalog/hot-deals.jsp`, null), HOUR_MS); assert.equal(resolveRenderInterval(`${base}/catalog/girls.jsp`, null), 6 * HOUR_MS); }); + +test('resolveEffectiveInterval applies the demand ladder rung the route ceiling hides', () => { + // The gap this exists to close. A route grants a CEILING and `render.demand` promotes visited + // targets beneath it, storing the rung on the target — so route resolution alone reports 24h for a + // page really on 6h. Anything dividing lateness by a cadence has to divide by the rung. + const DAY_MS = 24 * HOUR_MS; + forwarded({ + routes: [ + { match: 'prefix', path: '/catalog/', queryParams: ['CN'], renderInterval: DAY_MS }, + { match: 'exact', path: '/', queryParams: [] }, + ], + }); + const catalog = 'https://www.example.com/catalog/girls.jsp'; + + assert.equal(resolveRenderInterval(catalog, null), DAY_MS, 'the route ceiling, as before'); + assert.equal( + resolveEffectiveInterval(catalog, { demandInterval: 6 * HOUR_MS }), + 6 * HOUR_MS, + 'a promoted target is on its rung, not on the ceiling' + ); + + // CLAMPED, because a rung outlives the config that produced it: lower a route's cadence and every + // target still carries a rung from the old, slower ladder until its next render. `decideInterval` + // clamps to the ceiling the same way, so a stale rung must not read as SLOWER than the route. + assert.equal( + resolveEffectiveInterval(catalog, { demandInterval: 7 * DAY_MS }), + DAY_MS, + 'a stale rung slower than the ceiling reads as the ceiling' + ); + + // Unevaluated is most of the corpus until the ladder reaches it, and the absent forms differ: + // `Number(null)` is 0 and `Number(undefined)` is NaN. Both must fall through, not become 0. + for (const absent of [null, undefined, 0, -1, NaN, 'nonsense']) { + assert.equal(resolveEffectiveInterval(catalog, { demandInterval: absent }), DAY_MS, `absent: ${absent}`); + } + assert.equal(resolveEffectiveInterval(catalog), DAY_MS, 'and no target at all resolves to the route'); + + // Stored interval still loses to the route, and the rung still beats both — the full precedence. + assert.equal( + resolveEffectiveInterval(catalog, { renderInterval: 3 * DAY_MS, demandInterval: 12 * HOUR_MS }), + 12 * HOUR_MS, + 'rung > route > stored' + ); + // A BigInt from a `Long` column, which `Number.isFinite` rejects outright without the coercion. + assert.equal(resolveEffectiveInterval(catalog, { demandInterval: BigInt(6 * HOUR_MS) }), 6 * HOUR_MS); +});