diff --git a/bench/queue-index/README.md b/bench/queue-index/README.md index 269e54c..8151225 100644 --- a/bench/queue-index/README.md +++ b/bench/queue-index/README.md @@ -1,5 +1,31 @@ # `bench/queue-index` — what the render queue's storage actually costs +> ## READ THIS BEFORE QUOTING ANY NUMBER BELOW +> +> **Every absolute per-row cost here is a FLOOR measured on a fresh corpus, not a steady state.** This +> harness writes ~200k rows and reads them immediately. Production holds **1.3M rows that have been +> rewritten on every render for months**, and on an LSM store that is the whole difference: each +> reschedule is a `put` superseding the old value, and a range scan walks past every superseded version +> until compaction removes it. +> +> Measured here: a projected one-sided read at **~2.4 µs/row**. Measured on the live cluster +> (2026-08-21) — **same storage engine both times**, RocksDB, Harper's default — the sweep runs +> **~55 µs/row warm and ~80 µs/row cold**, roughly 20–30× more. +> +> **This harness already told us that, and it was read too narrowly.** Q6 below measures an unfloored +> seek degrading **0.073 → 5.60 ms after 40,000 head reschedules — 77×** — same engine, same corpus, +> churn alone. That result got filed as "the claim floor is justified" when it was also saying _every +> other number on this page decays with churn_. +> +> It cost something real: the ready-set sweep (#120) was sized from 2.4 µs/row and expected to run +> sub-second over a ~300k-row due set. It measured **27 s warm, 40–46 s cold**, and the fix (#124) was +> to stop reading past the due boundary — a change nobody would have bothered with at 0.5 s of waste. +> +> The _comparative_ results all still hold and are the reason to keep this: writes cost ~32× a read, +> `patch` is worse than `put`, a second index is ~13%, a two-sided range that cannot fill its limit is +> catastrophic. **Ratios travel; absolute per-row costs do not.** To size something for production, +> either run this at production row count WITH churn, or measure production. + Every scheduling decision in this package is justified by a number, and the two numbers the queue design rests on **cannot be reproduced**: prerender-plugin#80 cites `20-lanesim.mjs` and `21-duerank.mjs`, neither of which is in this repository. This harness exists so the next schema diff --git a/bench/queue-index/bench.js b/bench/queue-index/bench.js index 1521bbf..9975e39 100644 --- a/bench/queue-index/bench.js +++ b/bench/queue-index/bench.js @@ -100,6 +100,9 @@ const drain = async (iterable) => { /** The same drain, yielding to the event loop every `every` rows — backlogSnapshot's shape. */ const drainYielding = async (iterable, every = 200) => { let n = 0; + // The row is deliberately unread: this measures the cost of DRAINING the cursor, so reaching into + // the value would put decode work inside the measurement. + // eslint-disable-next-line no-unused-vars for await (const _row of iterable) { if (++n % every === 0) await new Promise((resolve) => setImmediate(resolve)); } diff --git a/packages/plugin/README.md b/packages/plugin/README.md index 0982983..f51c4e0 100644 --- a/packages/plugin/README.md +++ b/packages/plugin/README.md @@ -544,8 +544,22 @@ So the ordering moved out of the index. A background sweep on worker 0 scores th 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 +**~2.4 µs/row, flat** from 200 to 20,000 rows, and yielding every 200 rows is free, with **zero +writes**. + +> **That figure is a floor for a FRESH corpus and does not describe production.** Measured on the +> live cluster (2026-08-21) the sweep runs **~55 µs/row warm, ~80 µs/row cold** — a ~300k-row due set +> is a **~27 s sweep**, not the sub-second one the bench predicted. Same storage engine both times +> (RocksDB, Harper's default); what differs is the corpus. The bench wrote 200k rows and read them +> immediately; production holds 1.3M rows rewritten on every render for months, and on an LSM store a +> range scan walks past every superseded version until compaction removes it. +> +> The harness already measured this and it was read too narrowly: an unfloored seek after 40,000 head +> reschedules went **0.073 → 5.60 ms, 77×**, same engine, same corpus. The design argument still holds +> (reads remain far cheaper than writes, so recomputing beats a 1.3M-row restamp) — but size nothing +> off a fresh-corpus number. + +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) / effectiveInterval`, multiplied by `queue.ready.sitemapBoost` for a diff --git a/packages/plugin/package.json b/packages/plugin/package.json index 1c0d2b8..c7e4625 100644 --- a/packages/plugin/package.json +++ b/packages/plugin/package.json @@ -1,6 +1,6 @@ { "name": "@harperfast/prerender", - "version": "0.51.1", + "version": "0.52.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 333d828..c572668 100644 --- a/packages/plugin/src/configSchema.js +++ b/packages/plugin/src/configSchema.js @@ -1275,8 +1275,10 @@ export const configSchema = group('Prerender plugin configuration.', { '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' + + 'index. Affordable because the read is projected, one-sided and write-free — though HOW affordable ' + + 'depends on the corpus, not just the query: ~2.4us/row on a fresh 200k-row bench corpus, but ' + + '~55us/row over production 1.3M churned rows, where a ~300k due set is a ~27s sweep (measured ' + + 'live 2026-08-21).\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 ' + @@ -1316,7 +1318,7 @@ export const configSchema = group('Prerender plugin configuration.', { '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 ' + + 'projected one-sided read at ~2.4us/row on a FRESH corpus, which would make a sweep sub-second — but ' + '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 ' + @@ -1336,7 +1338,7 @@ export const configSchema = group('Prerender plugin configuration.', { 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 ' + + 'guard against a runaway rather than a tuning knob — though at the ~55us/row a churned corpus costs, ' + '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 ' + diff --git a/packages/plugin/src/util/readyQueue.js b/packages/plugin/src/util/readyQueue.js index 6fdeff6..67b5d0b 100644 --- a/packages/plugin/src/util/readyQueue.js +++ b/packages/plugin/src/util/readyQueue.js @@ -15,8 +15,9 @@ * 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 + * ~2.4 us/row on a freshly-written 200k-row bench corpus — but ~55 us/row warm on the production + * corpus of 1.3M churned rows, where a ~300k-row due set is a ~27s sweep (see + * `util/renderPriority.js`). 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. * diff --git a/packages/plugin/src/util/renderPriority.js b/packages/plugin/src/util/renderPriority.js index 3623585..f683fc5 100644 --- a/packages/plugin/src/util/renderPriority.js +++ b/packages/plugin/src/util/renderPriority.js @@ -21,11 +21,28 @@ * `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. + * That objection is fatal to an index and irrelevant to a function that is re-evaluated. Re-scoring + * the whole due set on a timer is affordable because the read is projected, one-sided and write-free. + * HOW affordable was badly mis-estimated, and the correction is worth carrying because it is a trap + * anyone re-running the harness will fall into. + * + * `bench/queue-index` (#119) measured ~2.4 us/row. MEASURED ON THE PRODUCTION CORPUS (2026-08-21) the + * sweep runs ~55 us/row warm, ~80 us/row cold — a ~300k-row due set is a ~27s sweep, not the + * sub-second one the bench predicted. Same storage engine in both cases (RocksDB, Harper's default). + * What differs is the CORPUS: the bench wrote 200k rows fresh and read them immediately, where + * production holds 1.3M rows that have been rewritten on every render for months. + * + * On an LSM store that difference is the whole cost. Every reschedule is a `put` that supersedes the + * old value, and a range scan has to walk past superseded entries until compaction removes them — the + * same shape as the dead-index-entry degradation the claim floor exists to bound. The harness ALREADY + * measured this and it was read too narrowly: an unfloored seek after 40,000 head reschedules went + * 0.073 -> 5.60 ms, 77x, on the same engine and corpus. 2.4 us/row was a FLOOR for a fresh corpus, + * never a steady state. + * + * The ARGUMENT survives intact: reads are still vastly cheaper than writes (76-89 us/row, and `patch` + * worse than `put`), so recomputing in memory still beats encoding priority into `nextRenderTime`, + * which would have made every policy change a rewrite of 1.3M rows. What does not survive is sizing + * anything off a fresh-corpus number. * * 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 diff --git a/packages/plugin/src/util/renderSchedule.js b/packages/plugin/src/util/renderSchedule.js index 45c7b0b..445cb2b 100644 --- a/packages/plugin/src/util/renderSchedule.js +++ b/packages/plugin/src/util/renderSchedule.js @@ -678,7 +678,8 @@ const claimFromIndex = async ({ grantLimit } = {}) => { * 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 + * fact — CORPUS-DEPENDENT, see `util/renderPriority.js`: a projected one-sided read is ~2.4 us/row on + * a fresh bench corpus but ~55 us/row on production's churned one, 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 @@ -752,11 +753,32 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { let earliestNotYetDueMinute = 0; 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. + // 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. + // + // IT DOES BREAK EARLY, and the comment this replaces said it must not. That claim conflated two + // different things. An ABANDONED iterator — one driven by hand with `.next()` and never returned — + // does hold its read transaction open: Harper's own long-transaction test + // (`integrationTests/database/longtxn-secondary-index`) uses exactly that as its mechanism, and + // states the contract: a `search()` iterator marks the read txn in use and releases it only when + // FULLY CONSUMED. But `for await ... of` is not that. On `break` the language calls + // `iterator.return()`, and Harper's search iterator implements it (`resources/Table.ts`): + // + // return() { if (results.onDone) results.onDone(); return dbIterator.return(); } + // + // where `onDone` is what calls `txn.doneReadTxn()`. `throw()` does the same. So breaking releases + // the transaction on the same path a full drain does. + // + // WHY IT MATTERS ENOUGH TO REVISIT: the query is one-sided (`>= floor`), so after the due rows it + // keeps returning rows that are NOT yet due, and the old code read every one of them to the cap + // and discarded them. Measured on the production corpus (RocksDB, 4 nodes, 2026-08-21): ~300k due + // rows against a 500k cap, so ~198k rows — 40% of the scan — were read to be thrown away, about + // 11s of a 27s sweep. At the ~2.4us/row the bench measured on a FRESH corpus that waste was ~0.5s + // and draining was the free, obviously-safe choice; at the ~55us/row a churned 1.3M-row corpus + // actually costs, it is the single largest cost in the sweep. And the + // caught-up case, which is where the queue spends most of its time, goes from reading `cap` rows to + // reading one. for await (const row of searchSchedulesFrom({ floorMinute: floorFrom, limit: cap })) { scanned++; const dueAt = numberOf(row.nextRenderTime); @@ -765,17 +787,19 @@ export const sweepReadySet = async ({ nowMs = Date.now() } = {}) => { 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. + // Rows arrive ascending, so the FIRST not-yet-due row means the due set is exhausted and + // every remaining row in the window is also not due. Nothing after this point can change + // the ranking, the floor, or any counter — so stop reading. // // 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); + // tell the whole fleet to go idle. Breaking on the first such row is what makes this the + // EARLIEST one, which is the value that flip needs. + earliestNotYetDueMinute = minuteOf(dueAt); reachedNotYetDue = true; - continue; + break; } due++; if (firstDueMinute === null) { diff --git a/packages/plugin/test/readySweep.test.js b/packages/plugin/test/readySweep.test.js index 6280092..a8ba6de 100644 --- a/packages/plugin/test/readySweep.test.js +++ b/packages/plugin/test/readySweep.test.js @@ -488,3 +488,72 @@ test('a BigInt carried cadence from a Long column is used, not discarded', async ['https://www.kohls.com/product/prd-promoted/x|desktop'] ); }); + +test('THE SWEEP STOPS AT THE DUE BOUNDARY instead of draining the window', async () => { + // The query is one-sided (`>= floor`), so it keeps returning rows past the due set. Reading them + // to the cap and discarding them was 40% of the scan on the production corpus — ~198k of 500k rows, + // about 11s of a 27s sweep on RocksDB. Rows arrive ascending, so the first not-yet-due row proves + // the rest of the window is not due either. + const rows = []; + for (let i = 0; i < 10; i++) + rows.push(row(`https://www.kohls.com/product/prd-${i}/x`, 'desktop', T0 - (i + 1) * HOUR)); + for (let i = 0; i < 500; i++) + rows.push(row(`https://www.kohls.com/product/prd-f${i}/x`, 'desktop', T0 + (i + 1) * HOUR)); + seed(rows); + + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 10, 'every due row is still seen'); + assert.equal(sweep.scanned, 11, 'ten due rows plus the ONE not-yet-due row that ended the walk'); + assert.equal(sweep.published, 10); + assert.equal(sweep.truncated, false, 'reaching a not-yet-due row is the opposite of truncation'); +}); + +test('...and a caught-up node reads ONE row, not its whole window', async () => { + // The steady state the queue spends most of its time in. This is the case that went from `cap` rows + // to a single row. + seed( + Array.from({ length: 300 }, (_, i) => + row(`https://www.kohls.com/product/prd-${i}/x`, 'desktop', T0 + (i + 1) * HOUR) + ) + ); + + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 0); + assert.equal(sweep.scanned, 1, 'one row read to learn nothing is due'); + assert.equal(sweep.published, 0); + assert.equal( + sweep.earliestNotYetDueMinute, + minuteOf(T0 + HOUR), + 'and it is the EARLIEST not-yet-due minute, which is what flips a node from empty to queued' + ); +}); + +test('breaking early still reports the earliest not-yet-due minute, not a later one', async () => { + // Ascending order is what makes the first one the earliest. If the walk ever stopped being ordered + // this assertion is what catches it — a later minute here would make a node with work coming in + // thirty seconds tell the fleet to go idle for longer than it should. + seed([ + row('https://www.kohls.com/', 'desktop', T0 - 2 * HOUR), + row('https://www.kohls.com/product/prd-1/x', 'desktop', T0 + 5 * MINUTE), + row('https://www.kohls.com/product/prd-2/x', 'desktop', T0 + 90 * MINUTE), + ]); + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.due, 1); + assert.equal(sweep.scanned, 2, 'stopped at the +5m row, never read the +90m one'); + assert.equal(sweep.earliestNotYetDueMinute, minuteOf(T0 + 5 * MINUTE)); +}); + +test('a due set that fills the cap is still reported truncated', async () => { + // The break must not mask truncation: if EVERY row in the window is due, the walk ends on the cap + // having never seen a not-yet-due row, and the ordering covers only a prefix of the backlog. + config.queue.ready.sweepCap = 25; + seed( + Array.from({ length: 60 }, (_, i) => + row(`https://www.kohls.com/product/prd-${i}/x`, 'desktop', T0 - (i + 1) * HOUR) + ) + ); + + const sweep = await funnel.sweepReadySet({ nowMs: T0 }); + assert.equal(sweep.scanned, 25, 'read exactly the cap'); + assert.equal(sweep.truncated, true, 'never reached a not-yet-due row, so the ordering is over a prefix'); +});